puma/puma — pull request #472 by rubencaro (2014-02-21 12:04:49+00:00)
Title: React when a worker does not load on a `phased_restart`

When I do a `phased_restart` on a puma with (say) 2 workers, the process is clear: it stops one of the workers, boots a new worker, and when it is booted, then stops the second worker and boots it. The `phase` counter is updated at the beginning, and for `phase = 2` you can see `{ "workers": 2, "phase": 2 }` on `pumaclt stats` response.

But if you are in a symlink deployment environment, it is possible that the new code is broken somehow. Then in a `phased_restart` the behaviour is this: it stops the first worker, and ends up an infinite loop trying to spawn the first worker. Like this:

```
An exception occurred in a forked block

no such file to load -- /home/ruben/Documentos/codigo/nailer/nailer/config/nonexisting (LoadError)

Backtrace:

Rubinius::CodeLoader#load_error at kernel/common/code_loader.rb:440
Rubinius::CodeLoader#resolve_require_path at kernel/common/code_loader.rb:423
{ } in Rubinius::CodeLoader#require at kernel/common/code_loader.rb:103
Rubinius.synchronize at kernel/bootstrap/rubinius.rb:137
Rubinius::CodeLoader#require at kernel/common/code_loader.rb:102
Rubinius::CodeLoader.require at kernel/common/code_loader.rb:237
Rubinius::CodeLoader.require_relative at kernel/common/code_loader.rb:143
Kernel(Object)#require_relative at kernel/common/kernel.rb:711
Object#__script__ at nailer.rb:7
Rubinius::CodeLoader.require at kernel/common/code_loader.rb:243
Kernel(Rack::Builder)#require at kernel/common/kernel.rb:705
{ } in Object(Rack::Builder)#__script__ at config.ru:2
BasicObject(Rack::Builder)#instance_eval at kernel/common/eval.rb:43
Rack::Builder#initialize at /home/ruben/.rvm/gems/rbx-2.2.4/gems/rack-1.5.2/lib/rack/builder.rb:55
Class#new at kernel/alpha.rb:94
{ } in Object#__script__ at config.ru+9
Rubinius::BlockEnvironment#call_on_instance at kernel/common/block_environment.rb:53
Kernel(Class)#eval at kernel/common/eval.rb:176
Rack::Builder.new_from_string at /home/ruben/.rvm/gems/rbx-2.2.4/gems/rack-1.5.2/lib/rack/builder.rb:49
Rack::Builder.parse_file at /home/ruben/.rvm/gems/rbx-2.2.4/gems/rack-1.5.2/lib/rack/builder.rb:40
Puma::Configuration#app at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/configuration.rb:95
Puma::Runner(Puma::Cluster)#app at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/runner.rb:123
Puma::Runner(Puma::Cluster)#start_server at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/runner.rb:130
Puma::Cluster#worker at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:192
{ } in Puma::Cluster#spawn_workers at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:90
Process.fork at kernel/common/process.rb:357
Kernel(Puma::Cluster)#fork at kernel/common/process.rb:1135
{ } in Puma::Cluster#spawn_workers at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:90
Integer(Fixnum)#times at kernel/common/integer.rb:198
Puma::Cluster#spawn_workers at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:87
Puma::Cluster#check_workers at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:137
Puma::Cluster#run at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cluster.rb:370
Puma::CLI#run at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/lib/puma
/cli.rb:465
Object#__script__ at /home/ruben/.rvm/gems/rbx-2.2.4/bundler/gems/puma-f8d49e86ab99/bin
/puma:10
Kernel(Object)#load at kernel/common/kernel.rb:447
{ } in Object#__script__ at /home/ruben/.rvm/gems/rbx-2.2.4/bin/puma:23
Rubinius::BlockEnvironment#call_on_instance at kernel/common/block_environment.rb:53
Kernel(Object)#eval at kernel/common/eval.rb:176
Object#__script__ at /home/ruben/.rvm/gems/rbx-2.2.4/bin/ruby_executable_hooks:15
Rubinius::CodeLoader#load_script at kernel/delta/code_loader.rb:66
Rubinius::CodeLoader.load_script at kernel/delta/code_loader.rb:140
Rubinius::Loader#script at kernel/loader.rb:649
Rubinius::Loader#main at kernel/loader.rb:831

```

The `phase` counter is updated at the beginning, so now for `phase = 3` you can see `{ "workers": 2, "phase": 3 }` on `pumaclt stats` response. But really there is only one worker booted (and with the old version of my code).

Also, `pumactl phased-restart` returned ok, right before the process started. And the server never fails serving, as it still has one working worker. So I have no way to know that the restart failed.

I added this workaround to be able to poll `pumactl stats` and see if all workers were able to boot, but don't think it's the way to go. Now I see something like `{ "workers": 2, "phase": 2, "booted_workers": 1 }`, so I know that `phased-restart` really failed to restart all my workers.

Maybe `pumactl` should wait until the process ends and then report details. On the `puma` side, at some point when spawning workers (maybe inside fork https://github.com/puma/puma/blob/master/lib/puma/cluster.rb#L90), it should rescue any booting exception and exit cleanly to allow `pumactl` to report failure.

What do you think guys?