bundler を1.10+ にupdate したらunicorn が起動しなくなった件


なぜかunicorn が起動しなくなった件

  • bundler を1.8.x => 1.10.6 にupdate したら、unicorn 起動時に以下のエラーが出る
$ bundle -v
Bundler version 1.10.6
$ bundle list | grep unicorn
  * unicorn (4.9.0)

$ /etc/init.d/unicorn start
master failed to start, check stderr log for details
  • init script はこんなかんじ
#!/bin/sh

# Source function library.
. /etc/rc.d/init.d/functions

export RBENV_DIR=/opt/rbenv
export RBENV_ROOT=/opt/rbenv
export PATH="$RBENV_ROOT/shims:$RBENV_ROOT/bin:$PATH"

APP_ROOT=/var/www/app
PID=$APP_ROOT/tmp/pids/unicorn.pid
RAILS_ENV=staging
TIMEOUT=${TIMEOUT-60}

CMD="bundle exec unicorn_rails -D -E $RAILS_ENV -c $APP_ROOT/config/unicorn/$RAILS_ENV.rb"

old_pid="$PID.oldbin"
action="$1"

sig () {
    test -s "$PID" && kill -$1 `cat $PID`
}

oldsig () {
    test -s $old_pid && kill -$1 `cat $old_pid`
}

pushd $APP_ROOT > /dev/null || exit 1
case $action in
    start)
        sig 0 && echo >&2 "Already running" && exit 0
        $CMD
        ;;
    stop)
        sig QUIT && exit 0
        echo >&2 "Not running"
        ;;
    status)
        if [ -e $PID ]; then
          pstree -aup `cat $PID`  && exit 0
        fi
        echo >&2 "Not running"
        ;;
    restart|reload)
        sig USR2 && sleep 20 && oldsig QUIT && echo "Killing old master" `cat $old_pid` && exit 0
        echo >&2 "Couldn't reload, starting '$CMD' instead"
        $CMD
        ;;
    *)
        echo >&2 "Usage $0 <start|stop|restart>"
        exit 1
        ;;
esac
  • エラーログ
I, [2015-08-08T12:11:35.984321 #26873]  INFO -- : Refreshing Gem list
/var/www/app/vendor/bundler/ruby/2.0.0/gems/execjs-2.5.2/lib/execjs/runtimes.rb:48:in `autodetect': Could not find a JavaScript runtime. See https://github.com/rails/execjs for a list of available runtimes. (ExecJS::RuntimeUnavailable)
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/execjs-2.5.2/lib/execjs.rb:5:in `<module:ExecJS>'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/execjs-2.5.2/lib/execjs.rb:4:in `<top (required)>'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/uglifier-2.7.1/lib/uglifier.rb:3:in `require'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/uglifier-2.7.1/lib/uglifier.rb:3:in `<top (required)>'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:76:in `require'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:76:in `block (2 levels) in require'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:72:in `each'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:72:in `block in require'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:61:in `each'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler/runtime.rb:61:in `require'
  from /opt/rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/bundler-1.10.6/lib/bundler.rb:134:in `require'
  from /var/www/app/config/application.rb:7:in `<top (required)>'
  from /var/www/app/config/environment.rb:2:in `require'
  from /var/www/app/config/environment.rb:2:in `<top (required)>'
  from config.ru:4:in `require'
  from config.ru:4:in `block in <main>'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/rack-1.5.3/lib/rack/builder.rb:55:in `instance_eval'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/rack-1.5.3/lib/rack/builder.rb:55:in `initialize'
  from config.ru:1:in `new'
  from config.ru:1:in `<main>'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn.rb:48:in `eval'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn.rb:48:in `block in builder'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/bin/unicorn_rails:139:in `call'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/bin/unicorn_rails:139:in `block in rails_builder'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:768:in `call'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:768:in `build_app!'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:137:in `start'
  from /var/www/app/vendor/bundler/ruby/2.0.0/gems/unicorn-4.9.0/bin/unicorn_rails:209:in `<top (required)>'
  from /var/www/app/vendor/bundler/ruby/2.0.0/bin/unicorn_rails:23:in `load'
  from /var/www/app/vendor/bundler/ruby/2.0.0/bin/unicorn_rails:23:in `<main>'
  • 調査

    • ruby のバージョンは関係なし
      • 2.0.0 => 2.2.2 でも同じ
    • init スクリプトのときにbundle のバージョンがおかしい?
      • デバッグログを仕込んだら1.10.6 で実行されてるっぽい
    • 手動でunicorn を起動すると問題ない
      • $ bundle exec unicorn_rails -D -E staging -c /var/www/compathy2/config/unicorn/staging.rb
    • init スクリプト経由で起動するとエラーになる
    • bundler のバージョンを1.8.x に戻すと、直る
  • 原因

  • 対策

    • Gemfile に下記を書いてbundle install する
gem 'therubyracer', :platforms => :ruby
  • 疑問
    • なんで手動だとエラーにならないんだろう。。。

おまけ

なぜかGemfile.lock が先祖返り(BUNDLED WITH が消える) する件

  • 予備知識

  • 現象

    • bundler を1.8.x => 1.10.6 に変えた
    • Gemfile.lock にはBUNDLED WITH が有る状態でコミット
    • デプロイすると、BUNDLED WITH が消える
    • 手動でbundle install しても、BUNDLED WITH は消えない
  • 調査

    • デプロイスクリプトを1段階ずつ減らして調査
    • 結果、unicorn のrestart をするところで先祖返りすることがわかった
      • 手動でも、「/etc/init.d/unicorn restart」で再現した
  • 原因

    • unicorn は下記のコマンドで動いている
      • bundle exec unicorn_rails -D -E staging -c /var/www/app/config/unicorn/staging.rb
    • 「/etc/init.d/unicorn restart」 は下記を実行する
      • kill -USR2 14119
    • => 上記2点より、restart 時にunicorn プロセスはそのまま利用されるので、古いbundle で起動したまま
      • => 古いbundle がなんらかのタイミングでGemfile.lock を上書きしたと考えられる
  • 対策

    • 一度unicorn をstop して、再度起動する