こちらは
の6日目です。
Azureを始めとしたクラウドでインフラをTerraformなどを活用しながら構築・運用しているエンジニアですが、今年に入ってからNew Relicに入門しました。
直近はAzure Monitorを使っていて、そちらではKQLというクエリ言語でグラフやアラートを書いていたんですが、
NRQLが大枠ではKQLと近いようなクエリ言語だったので特に違和感なくNew Relicを使い始められました。
APMやSynthetic MonitoringといったNew Relicならではの機能を始め、豊富なメニューから様々な情報が得られてグラフやダッシュボード、SLI/SLO、そしてアラートに利用できるのがとても良い感じです。
アラートについては色々カスタマイズ性できるのですが・・・カスタマイズ性の高さ故にキチンと要件に合わせて設定しないと「思った通りに動かない！」ということに繋がったので共有したいと思います。
TL;DR
- Alert ConditionのStreaming Methodのデフォルト（推奨）はEvent flow
- Event flowは常にデータが流れてくるモノ向けで、デイリーバッチのように散発的で実行頻度が低いデータには向かない
- バッチをアラートにする場合はEvent timerないしCadenceを設定すべし
何があったのか？
WebシステムをAKS（Azure Kubernetes Service）で構築しており、その中に1日1回動くデイリーバッチをCronJobとして実装しているのですが、対抗システムの仕様変更によってデイリーバッチが何日かに一回程度エラーが発生するようになってしまいました。
バッチのエラーの監視については
- KubernetesのJobステータスによる監視
- エージェントで転送したログのエラー監視
の2つを行っており、1.のアラートの発報によって気づきました。
対抗システムの想定外の変更ということもあって、バッチの処理内容を変更するまで度々アラートが発生してしまうのでアラートを無効化しました。
その後も度々バッチはコケていて、まあ既知の問題だしアラートは無効化しているから問題ないか…と思い過ごしそうになりましたが、
なんでエラーログは出ているはずなのに無効化していない２.のログ監視のアラートが出てないんだ？？？となり、調査を開始しました。
調査
調査と言ってもどこが怪しいかの検討がついていなかったので、見えるところから見ていくスタイルで調査していきました。
ログの確認
ログのエラー監視は特定のentity.nameのログでログレベルがErrorのものがあったらアラートを発報する、というよくあるログ監視にしている認識でした。
New RelicのログテーブルでNRQLを叩いたりAKSのPodの生ログを見ても、数日に一回程度のペースでErrorレベルのログが出力していました。
Errorログはしっかり出ているのに何故アラートがならないのか…？と疑問が深まる限りでした。
他のエラーログとの比較
（良いことではないですが）都合よく度々エラーログ検知のアラートが上がっているアプリがあったので、設定を見比べてみることにしました。
NRQLは概ね同じものだったんですが、Signal behaviorのところを見比べてみると
アラートが出ていた方のSignal behavior
アラートが出てない方のSignal behavior
Timer/Delayという表記の違いもありましたが、Streaming MethodがEvent timerとEvent flowと違うものが設定されているのが一番の違いでは？と考え、New Relicの設定の意味を調べました。
Streaming Method - Event flowとEvent timerの違い
Event timerやEvent flowといった具体的なキーワードで調べてみると色々情報が出てきました。
ちなみにNew Relicを使い始めた頃に一通りの説明をしてもらっていたのですが、まさに「難しくてよく分からないな…？」となっていた部分でした。
これらの記事でもしっかり書かれていたのでお恥ずかしいことですが、まとめると、
Azureなど各種プラットフォームのメトリクスや常にある程度のアクセスがあるWebページのログのように、常にデータが流れ続けるものにはEvent flow（New Relicアラートのデフォルト）は向いていますが、
デイリーバッチのログのように発生間隔が大きいデータには向かず、
Event timerもしくはCadenceにするべきとのことでした。
完全に理解した！というわけではないですが私の理解では、
Event flowでは、Window durationの期間が終わってDelayの時間が経過後にさらに後続のデータを受信したタイミングで集計・評価が行われて、しきい値を超えていたらアラートを発報するという形のようです。
上記の公式ドキュメント等に図などもあるのでご確認ください。
上記の例ですと、バッチは深夜1時に動くので、1:00-1:01が評価期間になります。より厳密にはバッチが走って最初のログが出力され、それがNew Relicに取り込めたタイミングから1分間、というほうが正確なようですが一旦理解しやすいように1:00-1:01にします。
そして2分間のDelayがあって1:03以降に何かしらのログが流れればそのタイミングがアラートを発報する、ということになります。
しかしこのバッチは概ね1:00-1:01の一分間のうちに処理が終わってしまい、次にログが出るのは24時間後になるので、Event flowの仕様によって後続データを65分以上受信しない場合は未集計データとして破棄されてしまったようです。
つまりWindow Duration期間内に処理が完了してしまうバッチではEvent flowでは基本的にアラートが発報しない！ということだと思います。
1時間間隔のバッチであれば65分後の破棄より前にギリギリアラートは発報するわけですが、処理から1時間後にアラート発報なのでやはり不適切ですね…
一方、Event timerの場合は、後続データの有無に関わらずDelayの時間が終わった瞬間にアラートが発報するので、今回のケースでもキチンとアラートは発報することを検証環境で確認できました。
ちなみにCadenceは従来の一般的なアラート方式で、データが流入したタイミングなどは考慮せずにNew RelicのシステムクロックでWindow Durationの間のデータを集計してDelayの後に発報するという形式で、
私達が期待していた挙動はこちらに近かったと思います。
まとめ
今回は、 - ログ以外の方法でもアラートを設定していてエラーに気づけた - 他にきちんと機能している同等のアラート設定があって比較することができた
以上のような都合のよい状況だったので大きな問題にはなりませんでしたが、これらがなかったらエラーを見逃していたと思うと中々ゾッとしますね…
個人的には、Event flowがデフォルト・推奨として設定されている理由として記載されていた、
ほとんどの場合、この集計方法の方が、遅延によるデータの取りこぼしが少なく、検出までの時間が短縮されると考えられるためです。
という文言が未だに腹落ちしていなかったりするので、もう少しNew Relicへの理解を深めたいと思っています。
