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

we are receiving SidekiqUniqueJobs::ScriptError "Problem compiling convert_legacy_lock" after upgrading from 5.0.10 -> 6.0.11 #377

Closed
ccleung opened this issue Feb 28, 2019 · 6 comments
Closed

we are receiving SidekiqUniqueJobs::ScriptError "Problem compiling convert_legacy_lock" after upgrading from 5.0.10 -> 6.0.11 #377

ccleung opened this issue Feb 28, 2019 · 6 comments
Assignees
@mhenrixon
Labels
bug

Comments

@ccleung
Copy link

ccleung commented Feb 28, 2019 •
edited
Loading

Describe the bug

  • upgraded gem from 5.0.10 -> 6.0.11
  • changed all unique: :until_executed => lock: :until_executed

Expected behavior

  • no exceptions are thrown

Current behavior

  • exceptions are thrown

vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:72:in handle_error': Problem compiling convert_legacy_lock. Message: ERR Error running script (call to f_27db703fc092c8f53319e798cace06a2d7f96fe6): @user_script:19: @user_script: 19: Write commands not allowed after non deterministic commands. Call redis.replicate_commands() at the start of your script in order to switch to single commands replication mode. (SidekiqUniqueJobs::ScriptError),

see stacktrace:

vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:72:in `handle_error': Problem compiling convert_legacy_lock. Message: ERR Error running script (call to f_27db703fc092c8f53319e798cace06a2d7f96fe6): @user_script:19: @user_script: 19: Write commands not allowed after non deterministic commands. Call redis.replicate_commands() at the start of your script in order to switch to single commands replication mode. (SidekiqUniqueJobs::ScriptError)
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:30:in `rescue in call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:27:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/locksmith.rb:89:in `locked?'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/lock/base_lock.rb:64:in `locked?'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/lock/until_executed.rb:16:in `execute'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/server/middleware.rb:27:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:48:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/sidekiq_unique_jobs.rb:41:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/server/middleware.rb:26:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-pro-4.0.2/lib/sidekiq/batch/middleware.rb:56:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:133:in `invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:168:in `block in process'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:139:in `block (6 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/job_retry.rb:98:in `local'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:138:in `block (5 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/rails.rb:42:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/reloader.rb:73:in `block in wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/reloader.rb:72:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/rails.rb:41:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:134:in `block (4 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:199:in `stats'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:129:in `block (3 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/tagged_logging-0.2.3/lib/job_logger/sidekiq_logger.rb:17:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `block in tagged'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:28:in `tagged'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `tagged'
    from vendor/bundle/ruby/2.5.0/gems/tagged_logging-0.2.3/lib/job_logger/sidekiq_logger.rb:13:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:128:in `block (2 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/job_retry.rb:73:in `global'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:127:in `block in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:48:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:42:in `with_job_hash_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:126:in `dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:167:in `process'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:85:in `process_one'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:73:in `run'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/util.rb:16:in `watchdog'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/util.rb:25:in `block in safe_thread'
    from vendor/bundle/ruby/2.5.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'

Caused by: vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:119:in `call': ERR Error running script (call to f_27db703fc092c8f53319e798cace06a2d7f96fe6): @user_script:19: @user_script: 19: Write commands not allowed after non deterministic commands. Call redis.replicate_commands() at the start of your script in order to switch to single commands replication mode. (Redis::CommandError)
    from vendor/bundle/ruby/2.5.0/gems/newrelic_rpm-5.0.0.342/lib/new_relic/agent/instrumentation/redis.rb:74:in `call'
    from vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis.rb:2448:in `block in _eval'
    from vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis.rb:45:in `block in synchronize'
    from vendor/ruby-2.5.3/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
    from vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis.rb:45:in `synchronize'
    from vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis.rb:2447:in `_eval'
    from vendor/bundle/ruby/2.5.0/gems/redis-4.0.1/lib/redis.rb:2499:in `evalsha'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:44:in `block in execute_script'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/connection.rb:18:in `block in redis'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq.rb:95:in `block in redis'
    from vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:65:in `block (2 levels) in with'
    from vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:64:in `handle_interrupt'
    from vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:64:in `block in with'
    from vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:61:in `handle_interrupt'
    from vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:61:in `with'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq.rb:92:in `redis'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/connection.rb:18:in `redis'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:42:in `execute_script'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/scripts.rb:28:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/locksmith.rb:89:in `locked?'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/lock/base_lock.rb:64:in `locked?'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/lock/until_executed.rb:16:in `execute'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/server/middleware.rb:27:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:48:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/sidekiq_unique_jobs.rb:41:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-6.0.11/lib/sidekiq_unique_jobs/server/middleware.rb:26:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-pro-4.0.2/lib/sidekiq/batch/middleware.rb:56:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/middleware/chain.rb:133:in `invoke'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:168:in `block in process'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:139:in `block (6 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/job_retry.rb:98:in `local'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:138:in `block (5 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/rails.rb:42:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/reloader.rb:73:in `block in wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/reloader.rb:72:in `wrap'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/rails.rb:41:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:134:in `block (4 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:199:in `stats'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:129:in `block (3 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/tagged_logging-0.2.3/lib/job_logger/sidekiq_logger.rb:17:in `block in call'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `block in tagged'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:28:in `tagged'
    from vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `tagged'
    from vendor/bundle/ruby/2.5.0/gems/tagged_logging-0.2.3/lib/job_logger/sidekiq_logger.rb:13:in `call'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:128:in `block (2 levels) in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/job_retry.rb:73:in `global'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:127:in `block in dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:48:in `with_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/logging.rb:42:in `with_job_hash_context'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:126:in `dispatch'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:167:in `process'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:85:in `process_one'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/processor.rb:73:in `run'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/util.rb:16:in `watchdog'
    from vendor/bundle/ruby/2.5.0/gems/sidekiq-5.1.3/lib/sidekiq/util.rb:25:in `block in safe_thread'
    from vendor/bundle/ruby/2.5.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'

Example Worker class configuration

class MyWorker
  include Sidekiq::Worker
  sidekiq_options queue: <queue>, retry: 4, lock: :until_executed
  def perform(args); end
end

Additional context
@mhenrixon
Copy link
Owner

Let me see if I can fix this real fast for you @ccleung. Which redis version are you on?

@mhenrixon mhenrixon added the bug label Feb 28, 2019
@mhenrixon mhenrixon self-assigned this Feb 28, 2019
@mhenrixon
Copy link
Owner

A crap, you must be on redis < 3.2. It doesn't support HSET without replicate_commands. I completely forgot about that.

@ccleung
Copy link
Author

ccleung commented Feb 28, 2019

thanks @mhenrixon - added some more info in the "additional context", we are on redis redis_version:3.2.11

@mhenrixon
Copy link
Owner

Thanks for the additional info @ccleung. Weird... If I recall correctly redis.replicate_commands() is only available for the redis version you are on and later. The least supported redis version for the gem can't use it yet. I'll pass a timestamp into the script instead.

The PR you linked to actually fixes the problem for later redis versions I suppose. If you know how I could test against different redis versions on Travis CI that would be amazing!

@mhenrixon mhenrixon mentioned this issue Feb 28, 2019
Merged
@ccleung
Copy link
Author

ccleung commented Feb 28, 2019

thanks for the fix! did a quick google search myself but i haven't been able to find out how to run travis ci against multiple redis versions

@mhenrixon
Copy link
Owner

Released in 6.0.12

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mhenrixon mhenrixon

Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mhenrixon @ccleung