@kyanny's blog

My thoughts, my life. Views/opinions are my own.

fluentd のソースを読む (1)

fluentd のソースを読み始めました。単なる趣味です。

経緯: fluentd の exec buffered output plugin を試してみたらflush_interval を短くしても USR1 シグナルを送ってもバッファが flush されず command が実行されなくて悩んでいたらTimeSlicedOutput はスライスの時間が経過しないとバッファから出てこないと教えてもらい、ソースを読んでちゃんと理解したいと思ったため、です。

とはいえ plugin/out_exec.rb をいきなり読んでもさっぱりわからなかったので、順を追って読んでみることにします。

まずは bin/fluentd を実行すると fluend が起動するところまで。

  • bin/fluend は fluend/command/fluentd.rb を実行してるだけ
  • fluent/command/fluentd.rb は fluent/log.rb, fluent/env.rb, fluent/version.rbfluent/supervisor.rb を読み込んで Fluent::Supervisor#start を実行する
  • fluent/log.rb は自前の便利ロガーっぽいもの
  • fluent/env.rb は設定ファイルのパスとかポート番号とかの初期値を定数に入れてるだけ
  • fluent/version.rb はバージョン番号だけ
  • fluent/supervisor.rb が fluentd の本体部分
    • Fluent::Supervisor#initialize はコマンドラインオプションを保持してロガーを作ってる
    • Fluent::Supervisor#start は fluent/load.rb を読んで必要ならばデーモン化したあとメインループに入る
    • fluent/load.rb は依存するサードパーティのライブラリなどを一括して require してる。こういうスタイルのコードは初めて読んだけど require が分散してないのはある程度の規模のプログラムになるとわかりやすくていいかもしれない。 cool.io など使ってるのでイベント駆動で動いてるのかなーなど眺めてるだけで楽しい。
    • install_supervisor_signal_handlers はシグナルをトラップしてる。実際はこのあと読む supervise メソッドのなかで fork してて (子をメインプロセスと呼ぶ) メインプロセスにシグナルを送り直して、 INT TERM の場合は終了フラグ @finished を立てるので start のなかの until @finished メインループを抜ける。つまり子を殺して親も死ぬのできれいにシャットダウンする。
    • supervise メソッドは基本的に fork してるだけ。必要ならばデーモン化する。なぜか Process.daemon を呼ばず自前で STDIN STDOUT STDERR を閉じたりしてる。子プロセスは main_process を実行して、親は子が終了するまで待つ (Process.waitpid)
    • main_process は渡されたブロックを実行する。このブロックは supervise メソッドに渡されたもので、 start のなかに実際のブロックのコードがある。いろいろメソッドを実行してる。あとで掘り下げる。あと main_process の仕事は例外をキャッチしてロガーにログを流してるだけ。
    • start のなかの supervise に渡すブロック、に戻ると、いろいろやってる。順に追っていく。
      • read_config は設定ファイルを読んでるだけ
      • change_privilege は子のメインプロセスのほうの実行ユーザー・グループを変更してるだけ (supervise に渡されるブロックの中のコードは fork した子プロセスで実行されることに注意)
      • init_engine は Fluent::Engine.init したあと、プラグインを読み込んだりしてる。 Fluent::Engine はあとで読む。
      • install_main_process_signal_handlers は子のメインプロセスでもシグナルをトラップしてる。 USR1 を受け取ると Fluent::Engine.flush! してる。これが、 USR1 シグナルを送るとバッファの内容を吐き出す、という根拠のようだ。これまでで TimeSlicedOutput などは一切出てきてないので、 USR1 を受け取ってもバッファの内容を吐き出さないというのは flush! メソッドが呼ばれたあとの各プラグインでの実装に依存する振る舞いだと考えられる。
      • run_configure は Fluent::Engine.parse_config を実行してるだけ。 read_config はパースしてる様子がなくて、単にファイルを read してるだけだったけど、実際のパースと解釈はあとでやっているということらしい。
      • finish_daemonize は start_daemonize とセットで読むべきだったので両方いま読む。
        • start_daemonize はお行儀の良いデーモンプロセスの作り方という感じで、リンク先にある通りで二度 fork してる。 start_daemonize は親プロセスのほうで実行されることに注意。つまりデーモンにするオプションを指定した場合は、マスタープロセスが二度 fork してデーモン化したあとで、子プロセスをさらに fork する。
        • finish_daemonize は逆に子プロセスのほうで実行される。これは、うーん、なにやってるんだろう、 supervise のなかの fork してる下で、親プロセスのほうで実行される if @daemonize && @wait_daemonize_pipe_w ; end のところとほぼ同じで、自信ないけど、 fork した子は親と同じ STDIN STDOUT STDERR を共有するので改めて閉じなおしてるんだと思う (デーモンプロセスの子もデーモンであるべきなので?)
      • そして run_engine は、 Fluent::Engine.run を実行してる。 Fluend::Engine は日を改めるとして、ここだけ先回りしちゃうと、 Coolio::Loop のイベントループを回してる。ので、 fluentd は正常起動してるあいだはずっと run_engine が走ってる、という感じなんだと思う。
      • その下に exit 0 とあるけど、ここにどういう条件で来るのかは run_engine の終了条件などを知らないといけないので、また今度。

この先イベント駆動とか Mutex とか難しそうなのがひかえてるけどがんばります。

余談: pkill -USR1 -f fluentd すると

2012-02-09 01:34:48 +0900: fluent/supervisor.rb:294:block in install_main_process_signal_handlers: force flushing buffered events
2012-02-09 01:34:48 +0900: fluent/supervisor.rb:294:block in install_main_process_signal_handlers: force flushing buffered events

という風に flush したっぽいログが二回出ていてなんでかなーと不思議だったのだけど、子プロセスが受け取って一回、親プロセスが子プロセスに送り直してもう一回で二回出てるわけですね (ps でみると親も子も $0 は同じっぽい) こういう実用上はどうでもいいトリビアに詳しくなれるのもソースコードリーディングのひそかな楽しみですね。