sidekiq-unique-jobs: `while_executing` has problems at low concurrency

Describe the bug When lock type while_executing is used with lock_timeout: nil, sometimes the system fails to lock the jobs properly and jobs are being executed in parallel.

Expected behavior The jobs never get executed in parallel.

Worker class

class Job
  include Sidekiq::Worker

  sidekiq_options lock: :while_executing,
                  lock_timeout: nil,
                  on_conflict: :reschedule

  def perform
    puts 'hello'
    sleep 1
    puts 'bye'
  end
end

Additional context Hi Mikael, Thank you very much for your amazing work on this gem.

I believe I might have run into an issue here and would like to verify it with you. I’m running the given worker using something like this:

25.times { Job.perform_async }

Now, since the job must be uniq while executing, “hello” and “bye” must always follow each other. But here is a part of what I get in sidekiq output:

2019-04-16T15:19:43.196Z 50070 TID-ovffchvmm Job JID-af6bca983c0fbcf5b22a585f INFO: start
2019-04-16T15:19:43.196Z 50070 TID-ovffchuy2 Job JID-f0af723412d0dc5c9371d0d1 INFO: start
2019-04-16T15:19:43.196Z 50070 TID-ovffchtn6 Job JID-442ba288ae6a074c84a85f50 INFO: start
hello
bye
2019-04-16T15:19:44.206Z 50070 TID-ovffchtwa Job JID-502c09235b292f57b7ecc712 INFO: done: 1.015 sec
2019-04-16T15:19:44.207Z 50070 TID-ovffchtwa Job JID-e255e583fa30d86b7e225d3d INFO: start
hello
hello
bye
bye
2019-04-16T15:19:45.214Z 50070 TID-ovffchuhu Job JID-6969ccaaac1b67c91c8a53da SidekiqUniqueJobs::Server::Middleware DIG-uniquejobs:4e839ff6799d5d8ba6a9c5d6129c4fe2 WARN: might need to be unlocked manually
2019-04-16T15:19:45.214Z 50070 TID-ovffchuhu Job JID-6969ccaaac1b67c91c8a53da INFO: done: 2.018 sec
2019-04-16T15:19:45.215Z 50070 TID-ovffchuhu Job JID-091344c663f8b08d84179cb1 INFO: start
2019-04-16T15:19:45.215Z 50070 TID-ovffchv06 Job JID-e17fd36a4e76b825bd3094fa INFO: done: 2.022 sec
2019-04-16T15:19:45.216Z 50070 TID-ovffchv06 Job JID-5b2776d26e44520af510c545 INFO: start
hello
hello
bye
bye
2019-04-16T15:19:46.221Z 50070 TID-ovffchuq6 Job JID-1380eb73bc55cd2b7003d7cb INFO: done: 3.028 sec
2019-04-16T15:19:46.222Z 50070 TID-ovffchvuu Job JID-be5ed8dcf06dbca9f21ccc5c INFO: done: 3.028 sec

As you can see, jobs are being executed in parallel from time to time. I’m wondering, is this a bug or have I misconfigured/misunderstood something?

If it is a bug, I believe it must be the scenario when thread 1 checks whether Redis contains the lock and at this moment (before thread 1 writes the digest into Redis) thread 2 starts execution and checks the same.

Please note that everything works properly with lock_tomeout: 0.