おまえらのSidekiq(OSS) + logrotateでUSR2を使う認識は改めたほうが良い

はじめに

すんません。タイトルは若干釣りです。

Ateam cyma Advent Calendar 2019 の8日目は 株式会社エイチームライフスタイル CTO の @tsutorm が担当します！

実はcymaもちょっと見てるんだよ！

おまえらのSidekiq + logrotateでUSR2を使う認識は改めたほうが良い

背景

cymaはもともとPHPで実装されていましたが、2019/02にリプレイスを行い、現在はモノリシックなRailsアプリケーションとして実装されています。

非同期処理はセオリー通りActiveJobを軸に、当初 :async モードを利用して実装されていましたが、非同期ジョブの動作担保をより確実に行うため、2019/08頃より :sidekiq モードを利用するよう変更しました。

そんな2019/09に、Sidekiq 6.0がリリースされ、当時まだcymaのRailsバージョンは5.1, Sidekiqも5系だったということもあり、Rails5.2, 6.0を踏まえた事前調査がてら、Wikiをなんとなく読んでいたところからお話は始まります。

USR2の記述が変わってる？

Sidekiq <6.0 used USR2 for logfile maintenance. This functionality has been removed in 6.0.

🤔こんな事書いてあったか？

おぉ。ごっそり変わってますね。要約すると、

• USR2シグナルの利用は 6.0 で削除される
• Sidekiq Enterpriseではローリングリスタートとして引き続き利用できる

とのこと。なるほど。
Loggingに The Sidekiq process logs only to STDOUT. This is the way modern daemons should work. ともあるように、Sidekiq自体がログファイルに対して責任を追う時代は終わりました。

Sidekiq 5.xの時点でもSTDOUTをリダイレクトしているケースはreopenしない

一応おもしろいんで実装も確認しておこうと思ってソースを追ってみた所、

tag:v5.2.7/lib/sidekiq/cli.rb#L154

      'USR2' => ->(cli) {
        if Sidekiq.options[:logfile]
          Sidekiq.logger.info "Received USR2, reopening log file"
          Sidekiq::Logging.reopen_logs
        end
      },

🤔 logfileオプション使ってないとそもそも何もしないぞ・・・

ということは、bundle exec sidekiq > log/sidekiq.log みたいなコードだと、USR2送っても何もしないんだーへー。なるほど・・・

しかし一般の認識は・・・

Google で sidekiq log とかで検索すると、前提条件の話も特になく、とにかくUSR2 + logrotate の話がいっぱいひっとするお・・・

みんな！このままじゃ、bump upリリースで事故るよ！！！

じゃぁどうすれば？

cymaでは、標準出力からログファイルに出力する形式を取っていて、且つ一旦ファイルに吐いてから CloudWatch Logsエージェントを利用して転送していたこともあり、EC2上に残ったファイルのローテションにはlogrotatedを引き続き利用していました。

ゆくゆくバージョンも上げていくと思うので、USR2を現段階で使わないけど、ちゃんとログのローテートもできるようなlogrotateにしなければ。
ということもあって、以下のような感じにUpdate

(中略)
    copytruncate
    prerotate
      pid=/app/cyma/tmp/pids/sidekiq.pid
      test -s $pid && kill -TSTP "$(cat $pid)"
      sleep 1
    endscript
    lastaction
      pid=/app/cyma/tmp/pids/sidekiq.pid
      test -s $pid && kill -TERM "$(cat $pid)"
      systemctl start sidekiq.service
    endscript
}

• prerotate時点でTSTPシグナルを利用して新規ジョブの流入をカット。ジョブ終了に概ね掛かりそうな秒数(ここでは1秒)分待機
• copytruncateを利用してログファイルのローテーションを実行することでFDの切り替えを考慮しなくてもオッケーにする
• lastaction時点でTERMシグナルでプロセスを一旦終了させ、再起動

てな感じにしてみました。

うーん。早くコンテナ化して、そもそもlogrotateとか言わなくても良いようにしたい。

まとめ

• Sidekiq への USR2 シグナルは v6.0 以降、log の reopen として機能しない
• 標準出力経由でログを吐いている場合、そもそも v5.x の時点でも USR2 は reopen もしない
• ちゃんとドキュメントを読もう
• Sidekiq Enterpriseを使ってたらこんな面倒な事しなくてもUSR2で引き続きよさげ

終わりに

Ateam cyma Advent Calendar 2019 の 8日目、いかがでしたでしょうか。
9日目は @sumiita が アナログデザインの強さ について記事を書かれるそうですので、お楽しみに！

株式会社エイチームでは、一緒に働けるチャレンジ精神旺盛な仲間を募集しています。

エンジニアとしての働き方に興味を持たれた方はcymaのQiita Jobsをご覧ください。

そのほかの職種は、エイチームグループ採用サイトをご覧ください。