sidekiqctl does not check for PIDfile existence. Capistrano deployment fails as well. #1490

Closed
wants to merge 2 commits into
from

Conversation

4 participants

skrobul commented Feb 17, 2014

I am deploying sidekiq with Capistrano 3 and got weird errors in case where worker process was dead and PID file did not exist. For some reason, the exception was raised despite the fact that PIDfile existence is checked on initialisation of Sidekiqctl.

Example of such situation:

 INFO [a826c429] Running /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiqctl stop /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid 10 on XXXXXXXXXX.COM
DEBUG [a826c429] Command: cd /home/deployer/ntp_scanner/current && /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiqctl stop /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid 10
DEBUG [a826c429]  /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:43:in `read': No such file or directory - /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid (Errno::ENOENT)
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:43:in `pid'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:54:in `block in stop'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:52:in `times'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:52:in `stop'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:21:in `initialize'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in `new'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in `<top (required)>'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/bin/sidekiqctl:23:in `load'
DEBUG [a826c429]    from /home/deployer/ntp_scanner/shared/bundle/ruby/2.0.0/bin/sidekiqctl:23:in `<main>'
cap aborted!
bundle stdout: Nothing written
bundle stderr: Nothing written
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/command.rb:94:in `exit_status='
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:142:in `block (4 levels) in _execute'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/channel.rb:551:in `call'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/channel.rb:551:in `do_request'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:561:in `channel_request'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:465:in `dispatch_incoming_packets'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:221:in `preprocess'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:205:in `process'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `block in loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/channel.rb:269:in `wait'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:164:in `block (2 levels) in _execute'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/channel.rb:514:in `call'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/channel.rb:514:in `do_open_confirmation'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:545:in `channel_open_confirmation'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:465:in `dispatch_incoming_packets'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:221:in `preprocess'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:205:in `process'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `block in loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/net-ssh-2.8.0/lib/net/ssh/connection/session.rb:169:in `loop'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:166:in `block in _execute'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:123:in `tap'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:123:in `_execute'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:66:in `execute'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:80:in `block (5 levels) in <top (required)>'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/abstract.rb:81:in `within'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:76:in `block (4 levels) in <top (required)>'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:35:in `block in for_each_process'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:34:in `times'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:34:in `for_each_process'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sidekiq-2.17.5/lib/sidekiq/tasks/sidekiq.rake:74:in `block (3 levels) in <top (required)>'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:54:in `instance_exec'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/backends/netssh.rb:54:in `run'
/Users/marek.skrobacki/.rvm/gems/ruby-2.1.0@rscan/gems/sshkit-1.3.0/lib/sshkit/runners/parallel.rb:12:in `block (2 levels) in execute'
Tasks: TOP => sidekiq:stop
(See full trace by running task with --trace)
 $

While ugly stack trace instead of an error is usually not a huge problem, I felt it should be fixed hence this PR.

Second, bigger problem is that sidekiqctl returns non-zero exit status if PID does not exist and that stops code deployment if using built-in Capistrano integration tasks. I addressed it with a changes in lib/sidekiq/tasks/sidekiq.rake.

Following this change, the deploy task behaves as expected - it produces message about non-existent PID file and continues the deployment process:

INFO [6b656737] Running /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiqctl stop /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid 10 on my.target.host.com
DEBUG [6b656737] Command: cd /home/deployer/ntp_scanner/current && /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiqctl stop /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid 10
DEBUG [6b656737]  Pidfile /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid does not exist
 INFO [6b656737] Finished in 2.745 seconds with exit status 1 (failed).
DEBUG [012509f9] Running /usr/bin/env if test ! -d /home/deployer/ntp_scanner/current; then echo "Directory does not exist '/home/deployer/ntp_scanner/current'" 1>&2; false; fi on my.target.host.com
DEBUG [012509f9] Command: if test ! -d /home/deployer/ntp_scanner/current; then echo "Directory does not exist '/home/deployer/ntp_scanner/current'" 1>&2; false; fi
DEBUG [012509f9] Finished in 0.229 seconds with exit status 0 (successful).
 INFO [e8f0c208] Running /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiq -d -i 0 -P /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid -r /home/deployer/ntp_scanner/current/ntp_distributed_scanner.rb -L /home/deployer/ntp_scanner/current/log/sidekiq.log on my.target.host.com
DEBUG [e8f0c208] Command: cd /home/deployer/ntp_scanner/current && /usr/local/rvm/bin/rvm 2.0.0-p247@ntpscanner do bundle exec sidekiq -d -i 0 -P /home/deployer/ntp_scanner/current/tmp/pids/sidekiq.pid -r /home/deployer/ntp_scanner/current/ntp_distributed_scanner.rb -L /home/deployer/ntp_scanner/current/log/sidekiq.log

@mperham mperham commented on the diff Feb 17, 2014

bin/sidekiqctl
@@ -40,7 +40,11 @@ class Sidekiqctl
end
def pid
- File.read(pidfile).to_i
@mperham

mperham Feb 17, 2014

Owner

I believe the correct solution is to cache the value:

   def pid
-    File.read(pidfile).to_i
+    @pid ||= File.read(pidfile).to_i
   end
Owner

mperham commented Feb 17, 2014

I would still like capistrano to fail on errors, we just need to fix what is an actual error. Here's my suggested fix:

+++ b/bin/sidekiqctl
@@ -12,7 +12,7 @@ class Sidekiqctl
     @timeout = timeout

     done('No pidfile given', :error) if !pidfile
-    done("Pidfile #{pidfile} does not exist", :error) if !File.exist?(pidfile)
+    done("Pidfile #{pidfile} does not exist", :warn) if !File.exist?(pidfile)
     done('Invalid pidfile content', :error) if pid == 0

     fetch_process
@@ -40,7 +40,7 @@ class Sidekiqctl
   end

   def pid
-    File.read(pidfile).to_i
+    @pid ||= File.read(pidfile).to_i
   end

ixti commented Feb 18, 2014

Actually breaking change was introduced here: e7eaa7a

Server removes PIDFILE automagically upon exit. Thus calling sidekiq shutdown which calls quiet and then stop fails, as there's no PIDFILE after quiet (if manager stopped very fast).

So we really should either cache PID or at least check PIDFILE existence BEFORE sending signals (reading PID).

skrobul commented Feb 18, 2014

I like the idea with caching PID file, just wasn't sure if this is better solution. Just tested in my specific use case and it seems to work.
Also, changing 'error' to 'warn' is enough to execute full restart in case workers were dead already.
Thanks for looking into this.

mperham closed this in efb624c Feb 18, 2014

aserafin commented Mar 3, 2014

Still having this issue with 2.17.7

/home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:43:in `read': No such file or directory @ rb_sysopen - /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid (Errno::ENOENT)
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:43:in `pid'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:54:in `block in stop'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:52:in `times'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:52:in `stop'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:21:in `initialize'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in `new'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in `<top (required)>'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/sidekiqctl:23:in `load'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/sidekiqctl:23:in `<main>'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/ruby_executable_hooks:15:in `eval'
 ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/ruby_executable_hooks:15:in `<main>'

And the command that fails actually does check if .pid file is present

if [ -d /home/tradeapp/app/tradeapp/current ] && [ -f /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid ] && kill -0 `cat /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid`> /dev/null 2>&1; then cd /home/tradeapp/app/tradeapp/current && bundle exec sidekiqctl stop /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid 10 ; else echo '\\''Sidekiq is not running'\\''; fi'
Owner

mperham commented Mar 3, 2014

Upgrade

On Mar 3, 2014, at 3:52, Adrian Serafin notifications@github.com wrote:

Still having this issue with 2.17.2

/home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:43:in read': No such file or directory @ rb_sysopen - /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid (Errno::ENOENT) ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:43:inpid'
** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:54:in block in stop' ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:52:intimes'
** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:52:in stop' ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:21:ininitialize'
** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in new' ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/gems/sidekiq-2.17.5/bin/sidekiqctl:78:in<top (required)>'
** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/sidekiqctl:23:in load' ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/sidekiqctl:23:in

'
** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/ruby_executable_hooks:15:in eval' ** [out :: 148.251.53.7] from /home/tradeapp/.rvm/gems/ruby-2.1.1@tradeapp/bin/ruby_executable_hooks:15:in'
And the command that fails actually does check if .pid file is present

if [ -d /home/tradeapp/app/tradeapp/current ] && [ -f /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid ] && kill -0 cat /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid> /dev/null 2>&1; then cd /home/tradeapp/app/tradeapp/current && bundle exec sidekiqctl stop /home/tradeapp/app/tradeapp/current/tmp/pids/sidekiq.pid 10 ; else echo '''Sidekiq is not running'''; fi'

Reply to this email directly or view it on GitHub.

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