Railsでunicornがforkするタイミング


Amazon Linux + Rails 4.2.3 + unicorn 4.9.0
preload_app trueにしている環境。

unicornがどのタイミングでforkするのか知りたくてこんなログを仕込んでみた。
結果、config/environments/development.rbの読み込みよりは後だと分かった。
Railsがある程度の初期化を行った後でforkしているのだろうが、どうやって「Railsの初期化完了」を検知しているのだろうか。
誰か知っていたら教えて下さい。

config/environments/development.rb
Rails.application.configure do
  open("/path/to/log", "a") do |f|
    f.puts "in configure #{Time.now}"
  end
end
config/unicorn.rb
worker_processes 3

before_fork do |server, worker|
  open("/path/to/log", "a") do |f|
    f.puts "before_fork"
  end
end

after_fork do |server, worker|
  open("/path/to/log", "a") do |f|
    f.puts "after_fork"
  end
end

結果

in configure 2016-02-16 11:12:29 +0900
before_fork
before_fork
before_fork
after_fork
after_fork
after_fork

[2016-02-17]
straceしてみた。初めstraceログをforkで検索したところ見つからず。代わりにcloneがログに残っていた。
forkは内部でcloneを呼んでいる単なるglibcレベルのラッパーらしい。
http://thorstenball.com/blog/2014/06/13/where-did-fork-go/
さて、昨日仕込んでopen()のおかげで、before_forkが呼ばれた直後にcloneしていることはわかったが、まだ詳細は不明。
次はunicornのソースでpreload_appの周辺を調べてみよう。

[2016-02-20]
build_app! if preload_appのようにしてbuild_app!を呼んでいる箇所がある。

  def build_app!
    if app.respond_to?(:arity) && app.arity == 0
      if defined?(Gem) && Gem.respond_to?(:refresh)
        logger.info "Refreshing Gem list"
        Gem.refresh
      end 
      self.app = app.call
    end 
  end

appの引数が0個ならばapp.callで得られる別のオブジェクトをappに代入しなおしている。これによって初期化済みのRailsが返っているのだろうか。Rackの仕様ではcallの引数はenv1個だと思っていたが、0個の場合とは何かで決まっているのだろうか。