#なぜ書くのか
実務スタートしてから本日でまる１ヶ月が経ちました。
同期と協力し、一つの機能をリリースし、正常に稼働させることに成功しました。
しかし実は一度、本番環境で処理を完了できないという不具合を起こしてしまいました。
2度と同じことを起こさないための備忘録としアウトプットさせていただきます。
#なぜ起きたのか
簡単に言えば「無限ループ」に陥ったことが原因です。
Sidekiq上で走っているジョブを監視するという機能で、ジョブがダブったり喪失したりするのを検知しSlackにアラートを出すというのが、今回の実装内容でした。
まずぶち当たったのが、
・予定から実行
・実行中から予定
この双方の行き来のタイミングでジョブを取得してチェックに入ってしまうと、度々エラーとして検知してしまうということです。
行き来のスピードは１秒から最大５秒ほどのラグがありました（ローカル環境でのチェックでは）。
そのタイミングで新機能の監視用のジョブが動いてしまうと、正常にジョブが動いていたとしてもエラーとして検知してしまうということです。
これに対し私が行った対策は
ジョブを取得する際にループを回し、10回取得する中で５秒の「sleep」もかけて全てのデータが同じであれば次の処理に渡す
というものでした。これがよくありませんでした、、、。
#どう改善したのか
本番環境では、３０秒度に走り、１０秒ほどで、処理を終えるという、予定と実行を目まぐるしく動き回る、それはそれは元気なジョブが動いていました。
ループを回す中で取得するにも、取得だけで50秒以上かかるので（わざとそうしていたのですが）、永遠に10回の取得の中で得られるデータが同じになることはないという原因で無限ループになっていたのです。
修正の際にはまず、全てのデータが同じになるまでループを回すと言うのをやめました。
しかし取得はきちんとふるいにかけなければ、Slackのアラートをめちゃくちゃ鳴らすことになってしまうのはわかっていました。
そこで、ループの上限を決め、得られたデータの中で一番多かったデータを次の処理へ渡す仕様へと変更しました。
#省略
def sidekiq_logs_arr_in
consistency_check_sidekiq_logs = []
#以前はwhile文とredoを使っていたが明確な上限を定めた
50.times do
queues = []
# 予定から実行、実行から予定に移るタイミングにばらつきがあるために、sleepを使って回避
sleep 2
#Sidekiq上のジョブを取得
Sidekiq::Workers.new.each { |_process_id, _thread_id, job| queues << job["queue"] }
Sidekiq::ScheduledSet.new.each { |job| queues << job["queue"] }
queues = queues.sort
consistency_check_sidekiq_logs << queues
end
#最終的にカウントでループの中で一番多いデータを返す
consistency_check_sidekiq_logs.max_by { |x| consistency_check_sidekiq_logs.count x }
end
#省略
こうすることで、この後の処理の際に、正常時にも例外を吐いてしまうと言うことはなくなり、元気なジョブがいようとも、整合性の取れたログを取得することができるようになりました。
#今後どうするか
まず特定の条件を満たさなければ、やり直すと言う処理をなるべくループ処理の中で行わないようにします。
上限を決め、どんなことがあっても、どんな状況であれ抜けられるループを組むと言うのはめちゃくちゃ大切なことなのだなと痛感しました...。
無限ループを本番環境で起こしてしまうのは会社に大損害を与える可能性もあるために今後は本当に気をつけます。