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.

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

Version 5&6: uniqueness not respected for Job without params #349

Closed
mathieujobin opened this issue Nov 19, 2018 · 8 comments
Closed

Version 5&6: uniqueness not respected for Job without params #349

mathieujobin opened this issue Nov 19, 2018 · 8 comments

Comments

@mathieujobin
Copy link

Describe the bug
We just found out a job without any params would be allowed to run concurrently
although we have the following options enabled

Expected behavior
jobs without argument with unique constraint should not run concurrently

Current behavior
we had jobs running concurrently

Worker class

class MyWorker
  include Sidekiq::Worker
  sidekiq_options retry: false, backtrace: true, unique: :until_and_while_executing, on_conflict: :log
  def perform; ExpensiveDbQueriesWithWrites(); end

  # we did not have this defined, assuming default would be correct
  #def self.unique_args(args)
    # the way you consider unique arguments
  #end
end

Additional context

I will try to come up with a better example to reproduce

@mathieujobin
Copy link
Author

class DupTestJob
  include Sidekiq::Worker

  sidekiq_options retry: false, backtrace: true, unique: :until_and_while_executing, on_conflict: :log

  def perform
    t = Time.now
    Sidekiq.logger.info("DupTestJob started:  #{t}")
    sleep(180)
    Sidekiq.logger.info("DupTestJob done:  #{Time.now - t}")
  end
end

image

@mathieujobin
Copy link
Author

Added this

  def self.unique_args(args)
    "8914bee5-b06e-407d-80ab-0a5748a2aab4" # whatever
  end

no changes

12 minutes of processing within 6 minutes timeframe

image

@mathieujobin
Copy link
Author

Added a parameter, and called the job with a single value param

def perform(foo)

the jobs seems to be allowed to run twice at the time still

image

irb(main):002:0* DupTestJob.perform_async(543)
Passing 'script' command to redis as is; administrative commands cannot be effectively namespaced and should be called on the redis connection directly; passthrough has been deprecated and will be removed in redis-namespace 2.0 (at /var/lib/gems/2.3.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/scripts.rb:35:in `block in internal_call')
=> "8294020f83e7ed066ef0ba25"
irb(main):003:0> DupTestJob.perform_async(543)
=> "3a58c1d1d3fc290072215334"
irb(main):004:0> DupTestJob.perform_async(543)
=> nil
irb(main):005:0> DupTestJob.perform_async(543)
=> nil
irb(main):006:0> DupTestJob.perform_async(543)
=> nil
irb(main):007:0> DupTestJob.perform_async(543)
=> nil
irb(main):008:0> DupTestJob.perform_async(543)
=> nil
irb(main):009:0> DupTestJob.perform_async(543)
=> nil
irb(main):010:0> DupTestJob.perform_async(543)
=> nil
irb(main):011:0> DupTestJob.perform_async(543)
=> nil
irb(main):012:0> DupTestJob.perform_async(543)
=> nil
irb(main):013:0> DupTestJob.perform_async(543)
=> nil
irb(main):014:0> DupTestJob.perform_async(543)
=> nil
irb(main):015:0> DupTestJob.perform_async(543)
=> "921007c49c80e09e4d74512c"
irb(main):016:0> DupTestJob.perform_async(543)
=> "01a9d174baaf3dae31589127"
irb(main):017:0> DupTestJob.perform_async(543)
=> nil
irb(main):018:0> DupTestJob.perform_async(543)
=> nil
irb(main):019:0> DupTestJob.perform_async(543)
=> nil
irb(main):020:0> DupTestJob.perform_async(543)
=> nil
irb(main):021:0> DupTestJob.perform_async(543)
=> "f1b4ad128d64acdc01a4374c"
irb(main):022:0> DupTestJob.perform_async(543)
=> nil
irb(main):023:0> 

@mathieujobin
Copy link
Author

switch the lock type to

class DupTestJob
  include Sidekiq::Worker

  sidekiq_options retry: false, backtrace: true, unique: :until_executing, on_conflict: :log

  def perform # (foo)
    t = Time.now
    Sidekiq.logger.info("DupTestJob started:  #{t}")
    sleep(180)
    Sidekiq.logger.info("DupTestJob done:  #{Time.now - t}")
  end

  #def self.unique_args(args)
  #  "8914bee5-b06e-407d-80ab-0a5748a2aab4" # whatever
  #end
end
Loading dev environment (Rails 5.2.1)
irb(main):001:0> DupTestJob.perform_async
Passing 'script' command to redis as is; administrative commands cannot be effectively namespaced and should be called on the redis connection directly; passthrough has been deprecated and will be removed in redis-namespace 2.0 (at /var/lib/gems/2.3.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/scripts.rb:35:in `block in internal_call')
=> "aff142fa0895a13b836d7aff"
irb(main):002:0> DupTestJob.perform_async
=> "80d5b736e1bc7528d361f4a6"
irb(main):003:0> DupTestJob.perform_async
=> "70a93bbf43d03530394a51e3"
irb(main):004:0> DupTestJob.perform_async
=> "20e0676d04a6f04a6ab3a940"
irb(main):005:0> DupTestJob.perform_async
=> "d4852a5ca0c13c445b9625cb"
irb(main):006:0> DupTestJob.perform_async
=> "0af637ab996a2f3dbe779f2e"
irb(main):007:0> DupTestJob.perform_async
=> "5d4317517db64e6234f7ef1e"
irb(main):008:0> DupTestJob.perform_async
=> "966b7e3b45e159d0538b4636"
irb(main):009:0> DupTestJob.perform_async
=> "1c35b908cb612cf013b79df8"
irb(main):010:0> DupTestJob.perform_async
=> "ab8425da90dc512c861b4851"
irb(main):011:0> DupTestJob.perform_async
=> "82ca5213c7f0d0186fbb9a64"
irb(main):012:0> DupTestJob.perform_async
=> "b8c6e155afed2930bae33a42"
irb(main):013:0> DupTestJob.perform_async
=> "ff9fb2c920d4ad019e29f0be"
irb(main):014:0> DupTestJob.perform_async
=> "ca6d18abf8e05dfe2271738d"
irb(main):015:0> DupTestJob.perform_async
=> "caca42c86f6cb9b41b1bcaac"
irb(main):016:0> 

it ran concurrently as many time as I ran it...

image

@mathieujobin mathieujobin changed the title Version 5: unicity not respected for Job without params Version 5: uniqueness not respected for Job without params Nov 19, 2018
@mathieujobin
Copy link
Author

mathieujobin commented Nov 19, 2018

I tried adding the unique_args method call back and a lock expiration.

jobs still runs in parallel

class DupTestJob
  include Sidekiq::Worker

  sidekiq_options retry: false, backtrace: true, lock_expiration: 10.minutes, 
              unique: :until_and_while_executing, 
              unique_args: :unique_args, on_conflict: :log

  def perform
    t = Time.now
    Sidekiq.logger.info("DupTestJob started:  #{t}")
    sleep(180)
    Sidekiq.logger.info("DupTestJob done:  #{Time.now - t}")
  end

  def self.unique_args(args)
    "8914bee5-b06e-407d-80ab-0a5748a2aab4" # whatever
  end
end

looks like the lock holds for 1minute, then 2nd job starts, I can't queue 3rd right away, but about 90 seconds after scheduling the first two, I can schedule one more, which will start exactly 2 minutes after the first one

image

@mathieujobin
Copy link
Author

image

for the sake of completeness it behaves as expected with 6.0.6, but we're afraid to hit that problem described in #332

@mathieujobin mathieujobin changed the title Version 5: uniqueness not respected for Job without params Version 5&6: uniqueness not respected for Job without params Nov 19, 2018
@mathieujobin
Copy link
Author

mathieujobin commented Nov 19, 2018

confirmed, perform without params or unique_args callback will ignore unique lock

class DupTestJob
  include Sidekiq::Worker

  sidekiq_options retry: 0, backtrace: true,
     #lock_expiration: 10.minutes,
     unique: :until_executing,
# unique_args: :unique_args,
 on_conflict: :log

  def perform
    t = Time.now
    Sidekiq.logger.info("DupTestJob started:  #{t}")
    sleep(180)
    Sidekiq.logger.info("DupTestJob done:  #{Time.now - t}")
  end

  #def self.unique_args(args)
  #  "8914bee5-b06e-407d-80ab-0a5748a2aab4" # whatever
  #end
end

runs as many jobs in parallel as I scheduled them
on 6.0.6

@mathieujobin
Copy link
Author

mathieujobin commented Nov 20, 2018

problem is caused by run lock timeout, which we can override

class DupTestJob
  include Sidekiq::Worker

  sidekiq_options retry: 0, backtrace: true,
     unique: :until_and_while_executing,
     run_lock_expiration: 5.minutes.to_i

  def perform
    t = Time.now
    Sidekiq.logger.info("DupTestJob started:  #{t}")
    sleep(180)
    Sidekiq.logger.info("DupTestJob done:  #{Time.now - t}")
  end
end

WORKS_FOR_ME

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant