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

Locked jobs after kill -9 with while_executing lock #546

Closed
fstybel opened this issue Oct 30, 2020 · 2 comments
Closed

Locked jobs after kill -9 with while_executing lock #546

fstybel opened this issue Oct 30, 2020 · 2 comments

Comments

@fstybel
Copy link

fstybel commented Oct 30, 2020

Describe the bug
During execution of the job, the server receive kill -9 signal. After the server will start, any job for this worker can't be processed.

Expected behavior
New incoming jobs for the worker can be process

Current behavior
New incoming jobs are start processing but not execute worker code

Versions

  • Ruby 2.5.3
  • Rails 5.2.2
  • Sidekiq 6.1.2
  • sidekiq-unique-jobs 6.0.25

Worker class

class TestWorker
  include Sidekiq::Worker
  sidekiq_options lock: :while_executing,
    lock_timeout: 0,
    on_conflict: :reschedule

  def perform
    sleep 30.second
    puts "IN PROGRESS"
    sleep 30.second
  end
end

Example

Before start the test I clear redis keys.
The job after Killed is a new one

{"ts":"2020-10-30T13:09:04.814Z","pid":6,"tid":"gq1i01xni","lvl":"INFO","msg":{"m":"done"},"ctx":{"class":"TestWorker","jid":"0cf38c2abc61658526a627c6","elapsed":"0.029"}}
{"ts":"2020-10-30T13:10:13.669Z","pid":6,"tid":"gq1i01x4y","lvl":"INFO","msg":{"m":"start"},"ctx":{"class":"TestWorker","jid":"e4d7b4be49287563dac57905"}}
Killed
bash-5.0$ bundle exec sidekiq -C config/sidekiq.yml
2020-10-30T13:10:31.308Z pid=44 tid=gnxktk2gg INFO: Booting Sidekiq 6.1.2 with redis options {:url=>"redis://redis:6379/0"}


               m,
               `$b
          .ss,  $$:         .,d$
          `$$P,d$P'    .,md$P"'
           ,$$$$$b/md$$$P^'
         .d$$$$$$/$$$P'
         $$^' `"/$$$'       ____  _     _      _    _
         $:     ,$$:       / ___|(_) __| | ___| | _(_) __ _
         `b     :$$        \___ \| |/ _` |/ _ \ |/ / |/ _` |
                $$:         ___) | | (_| |  __/   <| | (_| |
                $$         |____/|_|\__,_|\___|_|\_\_|\__, |
              .d$$                                       |_|


{"ts":"2020-10-30T13:10:37.054Z","pid":44,"tid":"gnxktk2gg","lvl":"INFO","msg":{"m":"Booted Rails 5.2.2 application in development environment"}}
{"ts":"2020-10-30T13:10:37.055Z","pid":44,"tid":"gnxktk2gg","lvl":"INFO","msg":{"m":"Running in ruby 2.5.3p105 (2018-10-18 revision 65156) [x86_64-linux-musl]"}}
{"ts":"2020-10-30T13:10:37.056Z","pid":44,"tid":"gnxktk2gg","lvl":"INFO","msg":{"m":"See LICENSE and the LGPL-3.0 for licensing details."}}
{"ts":"2020-10-30T13:10:37.056Z","pid":44,"tid":"gnxktk2gg","lvl":"INFO","msg":{"m":"Upgrade to Sidekiq Pro for more features and support: https://sidekiq.org"}}
{"ts":"2020-10-30T13:10:37.073Z","pid":44,"tid":"gnxktk2gg","lvl":"INFO","msg":{"m":"Starting processing, hit Ctrl-C to stop"}}
{"ts":"2020-10-30T13:10:57.491Z","pid":44,"tid":"gnxlrco8w","lvl":"INFO","msg":{"m":"start"},"ctx":{"class":"TestWorker","jid":"b100f2dea24f0c2f0309092a"}}
{"ts":"2020-10-30T13:10:57.533Z","pid":44,"tid":"gnxlrco8w","lvl":"INFO","msg":{"m":"done"},"ctx":{"class":"TestWorker","jid":"b100f2dea24f0c2f0309092a","elapsed":"0.042"}}
{"ts":"2020-10-30T13:11:07.613Z","pid":44,"tid":"gnxlrco8w","lvl":"INFO","msg":{"m":"start"},"ctx":{"class":"TestWorker","jid":"6caf82d01b0bfd0ef5382090"}}
{"ts":"2020-10-30T13:11:07.619Z","pid":44,"tid":"gnxlrco8w","lvl":"INFO","msg":{"m":"done"},"ctx":{"class":"TestWorker","jid":"6caf82d01b0bfd0ef5382090","elapsed":"0.006"}}
{"ts":"2020-10-30T13:11:18.462Z","pid":44,"tid":"gnxlrco00","lvl":"INFO","msg":{"m":"start"},"ctx":{"class":"TestWorker","jid":"a2d6f10306daa62d08e40954"}}
{"ts":"2020-10-30T13:11:18.465Z","pid":44,"tid":"gnxlrco00","lvl":"INFO","msg":{"m":"done"},"ctx":{"class":"TestWorker","jid":"a2d6f10306daa62d08e40954","elapsed":"0.002"}}

Redis keys:

irb(main):017:0> Cache.redis.keys
=> ["schedule", "stat:processed:2020-10-30", "uniquejobs:f46bc25dd7800206da7159bd516aa7e1:RUN:GRABBED", "stat:failed", "queues", "uniquejobs:f46bc25dd7800206da7159bd516aa7e1:RUN:EXISTS", "processes", "1fabaf7addca:44:d5d92ea8bb96", "stat:failed:2020-10-30", "unique:keys", "stat:processed"]

If I remove the key uniquejobs:f46bc25dd7800206da7159bd516aa7e1:RUN:EXISTS, the queue will be unlocked.
The problem can by solve by the gem https://github.com/restaurant-cheetah/sidekiq_unique_digests_cleaner but it's a bug in this gem I think

@mhenrixon
Copy link
Owner

Hi @fist28, add a lock_expiration to your lock; that way, it will automatically be created with expiration and expire. Unfortunately, in a kill -9 situation, there is nothing I can do. Even an ensure block won't help me there, so please, send use proper signals instead to allow sidekiq to cleanup. I already have cleanup for with_executing since these jobs should never keep the lock afterward.

@mhenrixon
Copy link
Owner

mhenrixon commented Nov 2, 2020

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

2 participants