CloudWatch Logs メトリクスフィルターは 継続的にデフォルト値をメトリクスに発行しているわけではない

メトリクスフィルターがメトリクスに値を発行するのは、フィルターパターンに一致するにせよしないにせよ、ログイベントが発生した場合のみであるということを改めて知ったという話です。デフォルト値を設定した時の挙動を抑えておきましょう。

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

コンバンハ、千葉(幸)です。

CloudWatch Logs ロググループには、メトリクスフィルターと呼ばれる仕組みを設定することができます。メトリクスフィルターでは、特定のフィルターパターンを定義しておくことで、条件に合致した場合にメトリクス宛に値をパブリッシュ(発行)させることができます。メトリクスに対してCloudWatch アラームを設定することで、キーワード監視の仕組みを実現することできます。

メトリクスフィルターが値を発行する際の挙動について勘違いしていた部分があるので書きます。

目次

先に結論

  • メトリクスフィルターがメトリクスに対して値を発行するのはロググループにログイベントが発生した場合のみである
  • デフォルト値は「発生したログイベントに対して評価を行った結果、合致しなかった」場合に発行されるものである
  • ログの出力が途切れる場合、メトリクスの値は欠損することになる

メトリクスフィルターの概念

メトリクスフィルターとは何かをおさらいしましょう。ドキュメントの言葉をそのまま借りると、以下の5要素が存在します。

  • フィルターパターン
  • メトリクス名
  • メトリクス名前空間
  • メトリクス値
  • デフォルト値

ログデータの検索およびフィルタリング

(ちなみに冒頭に以下の記述があるのですが、ドキュメントの記載の流れでそうなっているだけで、CloudWatch Logs エージェントによるものに限らずロググループであればなんでも設定可能です。)

CloudWatch Logs エージェントがAmazon CloudWatch へのログデータの発行を開始した後、1 つ以上のメトリクスフィルターを作成して、ログデータの検索およびフィルタリングを開始できます。

メトリクスフィルターのイメージとしては以下の通りです。左から順に見ていきましょう。

ロググループには1個以上のログストリームが作成され、いずれかのログストリームにログイベントが記録されます。

ロググループに対して、メトリクスフィルターを設定することが可能です。ログストリームの単位ではなく、あくまでロググループの単位です。一つのロググループに対して、2つ以上のメトリクスフィルターを設定することも可能です。

メトリクスフィルターにはフィルターパターンを定義します。例えば「ERRORという文字列を含むかどうか」というものです。フィルターパターンに合致した場合、メトリクスに対して値をパブリッシュさせることができます。メトリクスというくくりの中で、どのメトリクス名前空間のどのメトリクス名に対して値をパブリッシュするかを定義することができます。

さらには、条件に合致した場合に発行する値(メトリクス値)と合致しない場合に発行する値(デフォルト値)を選択することが可能です。例えば合致する場合には「1」を、合致しない場合には「0」を発行するとしましょう。発行先のメトリクス名に対して「特定の期間内で検出された値が0より大きい」というアラームを設定すれば、ログに対するキーワード監視が実現できます。

なお、一意のメトリクスを定義するための概念としてディメンションと呼ばれるものもあるのですが、メトリクスフィルターにより発行される場合にはディメンションを定義することができません。

メトリクスフィルターのデフォルト値の挙動

今回の肝になる部分です。ドキュメントには以下の記載があります。

一致するログが見つからなかった期間中にメトリクスフィルターに報告された値。この値を 0 に設定することで、データは毎秒報告され、データがない期間がある「むらがある」メトリクスを回避できます。

念のため、英語も確認しておきましょう。

The value reported to the metric filter during a period when no matching logs are found. By setting this to 0, you ensure that data is reported during every period, preventing "spotty" metrics with periods of no data.

文章の冒頭部分の受け取り方がなかなか難しいですが、「データは毎秒報告され、データがない期間がある「むらがある」メトリクスを回避できます」という部分が気になります。デフォルト値を設定しておけば、いついかなる時も継続的にメトリクスに対して値が発行され、「データなし」の期間が発生しないという挙動になるのかと捉えていました。実際はそうではありませんでした。

実機で確認してみる

ロググループに対してメトリクスフィルターを設定します。このロググループは手動で実行するLambdaの実行ログが出力される宛先で、継続的にログが発生するものではありません。作成。

フィルター名は「test-filter」とし、パラメータには以下を設定しました。ログイベントに「Error」という文字列が含まれている場合に「1」を、それ以外は「0」を発行する挙動です。

項目
フィルターパターン Error
メトリクス名 test-function-error-count
メトリクス名前空間 CWLogs
メトリクス値 1
デフォルト値 0

設定後、ログイベントが発生すれば、メトリクスに値がカウントされます。(私はそれに気づかずにひたすら待ち続けていました。)明示的にログを出力させてみます。「0」が記録されました。

CloudWatch アラームの設定

このメトリクスに対してアラームをセットします。1分間隔でメトリクスの値を確認し、0より大きい値が検出されたらアラーム状態に遷移させるものです。

出来上がったアラームは以下の通り。

アラームのステータスは「データ不足」になります。作成直後の一時的なものではありません。ログイベントが発生しない限り、メトリクスに対して「1」も「0」も発行されないため、「データ不足」が続きます。

フィルターに合致しないログイベントを発生させる

Lambdaを実行してロググループにログを出力させます。フィルターパターンで定義している「Error」は含まないログです。メトリクスフィルターによりデフォルト値の「0」が発行されるため、アラームは「OK」状態に遷移します。

初回の発行と今回の発行の実際のログは以下のようになっています。それぞれ3行に渡ってログイベントが記録されています。

メトリクスから、統計を「サンプル数」に切り替えて確認してみると、それぞれのタイミングでメトリクスの値が「3」が記録されています。(グラフ描画上では線でつながっていますが、3が記録され続けたわけではありません。)

ログイベントが発生しないとメトリクスには何も値が発行されないため、再びアラームのステータスは「データ不足」に遷移します。

フィルターに合致するログイベントを発生させる

Lambdaをわざとエラーが起こるようにして実行し、ロググループに「Error」の文字列を含むログイベントを発生させます。4行分ログが出力され、そのうち1行に「Error」が含まれます。(2行目の先頭にすべて大文字のERRORが含まれていますが、フィルターパターンでは大文字小文字が区別されるため、そこに反応したわけではありません。画像には写っていませんが末尾にErrorが記録されています。なぜ写さなかったのか。)

メトリクスフィルターによりメトリクスに「1」が発行されるため、アラームのステータスは「アラーム状態」に遷移します。

メトリクスのサンプル数には「4」が記録されました。ログイベントごとに「0,1,0,0」が発行されたということでしょう。

このあとログイベントが発生しなければ、再びアラームは「データ不足」に遷移します。

欠落データに対する処理の仕方を変更する

メトリクスに対する値の発行、およびアラームのステータス遷移については上記で確認したような挙動となります。ドキュメントで見た『データがない期間がある「むらがある」メトリクスを回避』できるというのは、まさにこういったケースで『アラームが「データ不足」にならない』ということを指しているのかと思っていましたが、そうではないようです。

上記の状態でもキーワード監視の挙動には影響がないですが、通常時が「データ不足」では納まりが悪いという場合もあります。その場合には、アラームにおける欠落データの処理の仕方を変更することで回避できます。「欠落データを適性(しきい値を超えていない)として処理」を選択すれば、メトリクスに値が発行されていない場合でもアラームのステータスは「OK」になります。

終わりに

メトリクスフィルターのデフォルト値の挙動について確認しました。ドキュメントを読んで「こういった挙動になるのかな」と想像したものと差異があったので、やはり実際の動作確認をしてみることが大事だということを痛感しました。

同じような受け取り方をした方の助けになれば幸いです。

以上、千葉(幸)が東京からお送りしました。

追記

改めていろんなドキュメントを漁った結果、まさに以下に記載がありました。

メトリクスフィルターが、ログイベントで一致するいずれかの用語、語句、または値を見つけた場合、メトリクス値に指定された量だけ CloudWatch メトリクスのカウントを増分します。メトリクス値は 1 分ごとに集計され、報告されます。

1 分の間にログが取り込まれても一致が見つからない場合は、デフォルト値に設定された値 (存在する場合) が報告されます。ただし、1 分の間に取り込まれたログイベントがない場合は、値は報告されません。

デフォルト値を指定すると、その値が 0 の場合でも、データはより頻繁に報告されるので、一致が見つからない場合にむらがあるメトリクスを避けるのに役立ちます。

たとえば、2 つのレコードを公開し、メトリクス値は 1 で、デフォルト値は 0 のロググループがあるとします。最初の 1 分で両方のログレコードで一致が見つかった場合、その分のメトリクス値は 2 になります。次の 1 分で発行されるログレコードに一致する値がない場合、デフォルト値の 0 が両方のログレコードに使用され、その 1 分のメトリクス値は 0 になります。

デフォルト値を指定しない場合、一致するパターンが見つからない期間についてはデータは報告されません。

一致が見つかった場合のメトリクス値の変更方法の設定

あくまで、ログが取り込まれている範囲内でむらのあるメトリクスを避けられるものだと理解しました。

一方で、また別の箇所では以下のような記述も発見しました。

9.[デフォルト値] に「0」と入力し、[フィルターの作成] を選択します。デフォルト値を指定すると、ログイベントが発生しない期間でもデータが報告され、データが存在しないことがある、むらのあるメトリクスを回避できます。

例: ログイベントのカウント

前述のものとは異なる記述に見えます。ドキュメントを参照する際は、何が正しいかを見極めながら、かつできる限り実機で検証しながら受け止める姿勢が必要ですね。