Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

#clear_locks! doesn't handle exceptions #802

Closed
contentfree opened this issue Apr 16, 2015 · 3 comments
Closed

#clear_locks! doesn't handle exceptions #802

contentfree opened this issue Apr 16, 2015 · 3 comments

Comments

@contentfree
Copy link

I've recently switched to TokuMX engine (drop-in replacement for MongoDB). It has document-level locking which means sometimes there's timeouts waiting for locks to be granted. This is OK if a failure is handled.

However, in the ClearLocks plugin, there's no protection for failure in the ensure block of clear_locks!. At least in the delayed_job_mongoid backend for DJ, clear_locks! does an update_all that can fail when a lock isn't granted (raises a Moped::Errors::OperationFailure currently). This operation should be retried, as suggested by the error message text: "Lock not granted. Try restarting the transaction.".

Unfortunately, this causes the DJ worker to exit in a ball of fire, which leads to a Very Bad Day™
@contentfree
Copy link
Author

The error that kills the worker looks something like this:

/var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/operation/read.rb:50:in `block in execute': The operation: #<Moped::Protocol::Command (Moped::Errors::OperationFailure)
  @length=90
  @request_id=947
  @response_to=0
  @op_code=2004
  @flags=[]
  @full_collection_name="app_delayed_job_production.$cmd"
  @skip=0
  @limit=-1
  @selector={:getlasterror=>1, :w=>1}
  @fields=nil>
failed with error 16759: "Lock not granted. Try restarting the transaction."

See https://github.com/mongodb/mongo/blob/master/docs/errors.md
for details about this error.
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:594:in `[]'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:594:in `block (2 levels) in flush'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:593:in `map'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:593:in `block in flush'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:617:in `block in logging'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/activesupport-4.2.0/lib/active_support/notifications.rb:164:in `block in instrument'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/activesupport-4.2.0/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/activesupport-4.2.0/lib/active_support/notifications.rb:164:in `instrument'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/instrumentable.rb:31:in `instrument'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:616:in `logging'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:587:in `flush'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:358:in `pipeline'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/operation/write.rb:47:in `execute'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:665:in `write'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:502:in `update'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/query.rb:427:in `block in update'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/cluster.rb:249:in `block in with_primary'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:204:in `block in ensure_primary'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/executable.rb:25:in `execute'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/node.rb:203:in `ensure_primary'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/cluster.rb:248:in `with_primary'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/query.rb:426:in `update'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/mongoid-4.0.0/lib/mongoid/query_cache.rb:117:in `update_with_clear_cache'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/moped-2.0.2/lib/moped/query.rb:449:in `update_all'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/mongoid-4.0.0/lib/mongoid/query_cache.rb:117:in `update_all_with_clear_cache'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/mongoid-4.0.0/lib/mongoid/contextual/mongo.rb:472:in `update_documents'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/mongoid-4.0.0/lib/mongoid/contextual/mongo.rb:433:in `update_all'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/mongoid-4.0.0/lib/mongoid/contextual.rb:20:in `update_all'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job_mongoid-2.1.0/lib/delayed/backend/mongoid.rb:58:in `clear_locks!'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/plugins/clear_locks.rb:9:in `ensure in block (2 levels) in <class:ClearLocks>'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/plugins/clear_locks.rb:9:in `block (2 levels) in <class:ClearLocks>'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:79:in `call'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:79:in `block (2 levels) in add'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:61:in `call'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:61:in `block in initialize'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:79:in `call'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:79:in `block in add'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:66:in `call'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:66:in `execute'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/lifecycle.rb:40:in `run_callbacks'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/delayed_job-4.0.6/lib/delayed/worker.rb:146:in `start'
  from tasks/jobs.rake:16:in `block (2 levels) in <top (required)>'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:236:in `call'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:236:in `block in execute'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:231:in `each'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:231:in `execute'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:175:in `block in invoke_with_call_chain'
  from /usr/share/ruby/2.1/monitor.rb:211:in `mon_synchronize'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:168:in `invoke_with_call_chain'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/task.rb:161:in `invoke'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:149:in `invoke_task'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:106:in `block (2 levels) in top_level'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:106:in `each'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:106:in `block in top_level'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:115:in `run_with_threads'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/rake-10.1.1/lib/rake/application.rb:100:in `top_level'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/padrino-core-0.12.4/lib/padrino-core/cli/base.rb:23:in `rake'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/thor-0.19.1/lib/thor/command.rb:27:in `run'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/thor-0.19.1/lib/thor/invocation.rb:126:in `invoke_command'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/thor-0.19.1/lib/thor.rb:359:in `dispatch'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/thor-0.19.1/lib/thor/base.rb:440:in `start'
  from /var/www/my-app/shared/bundle/ruby/2.1/gems/padrino-core-0.12.4/bin/padrino:9:in `<top (required)>'
  from /var/www/my-app/shared/bundle/ruby/2.1/bin/padrino:23:in `load'
  from /var/www/my-app/shared/bundle/ruby/2.1/bin/padrino:23:in `<main>'

@contentfree
Copy link
Author

I've also opened an issue in Moped's repo to see if we can get a more granular exception.

@albus522
Copy link
Member

Closing stale

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@albus522 @contentfree