cloudfoundry / cloudfoundry/cloud_controller_ng
Concurrency: DELETE /v3/route/:guid and DELETE /v3/service_route_bindings/:guid can cause 500 - unknown error
Nobody has claimed this yet.
- Dominant language
- Ruby
- Stars
- 207
- Forks
- 373
- Avg merge
- 2d 12h
- Merged PRs (30d)
- 56
Description
Issue
A route delete request led to an unknown error 500 response.
Context
This was caused by trying to delete the service binding from the DB, but the service binding was already gone. A concurrently running request to delete the service route binding (DELETE /v3/service_route_bindings) deleted the resource first.
Here the error message from the logs:
"message":"Request failed: 500: {\"error_code\"=>\"UnknownError\", \"description\"=>\"An unknown error occurred.\", \"code\"=>10001, \"test_mode_info\"=>{\"description\"=>\"Attempt to delete object did not result in a single row modification (Rows Deleted: 0, SQL: DELETE FROM \\\"route_bindings\\\" WHERE (\\\"id\\\" = 745543))\", \"error_code\"=>\"CF-NoExistingObject\", \"backtrace\"=>[\"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1674:in _delete'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1208:in delete'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1715:in _destroy_delete'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1704:in block in _destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1047:in around_destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1701:in _destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in block (2 levels) in destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:235:in block in transaction'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/connection_pool/threaded.rb:88:in hold'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/connecting.rb:293:in synchronize'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:197:in transaction'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1954:in checked_transaction'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in block in destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1940:in checked_save_failure'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/services/service_key_delete.rb:29:in delete_service_binding'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/services/service_key_delete.rb:9:in block in delete'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/dataset/actions.rb:162:in block in each'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:651:in block (2 levels) in fetch_rows'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:651:in yield_hash_rows'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:651:in block in fetch_rows'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:161:in execute'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:532:in _execute'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:348:in block (2 levels) in execute'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:555:in check_database_errors'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:348:in block in execute'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/connection_pool/threaded.rb:88:in hold'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/connecting.rb:293:in synchronize'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:348:in execute'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/dataset/actions.rb:1189:in execute'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/adapters/postgres.rb:651:in fetch_rows'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/dataset/actions.rb:162:in each'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel_pg-1.17.1/lib/sequel_pg/sequel_pg.rb:83:in each'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/services/service_key_delete.rb:8:in each_with_object'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/services/service_key_delete.rb:8:in delete'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/models/runtime/route.rb:248:in destroy_route_bindings'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/models/runtime/route.rb:212:in before_destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1703:in block in _destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1047:in around_destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/models/runtime/route.rb:254:in around_destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1701:in _destroy'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in block (2 levels) in destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:235:in block in transaction'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/connection_pool/threaded.rb:88:in hold'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/connecting.rb:293:in synchronize'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:197:in transaction'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1954:in checked_transaction'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in block in destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1940:in checked_save_failure'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/model/base.rb:1220:in destroy'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/route_delete.rb:10:in block (2 levels) in delete'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:264:in _transaction'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:239:in block in transaction'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/connection_pool/threaded.rb:88:in hold'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/connecting.rb:293:in synchronize'", "/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/gem_home/ruby/3.2.0/gems/sequel-5.77.0/lib/sequel/database/transactions.rb:197:in transaction'\", \"/var/vcap/data/packages/cloud_controller_ng/45d435008ea60f85e1594223ed03a635d74d9055/cloud_controller_ng/app/actions/route_delete.rb:9:in block in delete'
`
Steps to Reproduce
This can be reproduced with the following commands:
cf create-app test-app
cf create-route customer-app-domain1.com --hostname test-app
cf create-service async-service async-plan test-instance
# service must have `"requires": ["route_forwarding"],` in the catalog's service entry
cf bind-route-service customer-app-domain1.com --hostname test-app test-instance
# before running the next command the worker process should be in debug mode and a breakpoint should be set in app/actions/services/service_key_delete.rb line 29 `service_binding.destroy`
cf delete-route customer-app-domain1.com --hostname test-app
# while the previous command stops at the breakpoint run the following
cf urs customer-app-domain1.com --hostname test-app
# after this command finished, let the worker continue on the first request, which will fail with above error
Expected result
The route delete request continues even if the service binding is gone already.
Or locks prevent that two jobs try to delete the binding at the same time and the route delete job fails with ServiceBindingOperation in progress.
Current result
The route delete request fails with Attempt to delete object did not result in a single row modification.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with app/actions/route_delete.rb, app/models/runtime/route.rb, and app/actions/services/service_key_delete.rb, especially service_key_delete.rb line 29 where service_binding.destroy is called. Reproduce the concurrent DELETE requests using the commands in the issue and the suggested breakpoint. Done means the concurrent deletion no longer produces the reported 500 response.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- ruby
- Domain
- api, backend, databases
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100