LoginSignup
30
7

More than 1 year has passed since last update.

CloudWatch Logs Insights 集計クエリ入門

Last updated at Posted at 2020-12-10

AWS CloudWatch Logs をご利用のみなさん、CloudWatch Logs Insights は利用していますか?
自分は CloudWatch Logs の検索記法に慣れていたのもあり、Logs Insights の記法を学習する元気がいまいち起きず、初めの方は filter @message =~ "hoge" みたいなクエリしか使っていませんでした (このクエリは今もよく使います :joy: )。

しかしながら、Saved Query 対応などもきっかけに、ここ 1 年くらいで結構 Logs Inshigts の集計クエリを活用する場面も増えたので、集計クエリの使い方のチュートリアルのような記事にまとめてみます。

以下、簡単な API アクセスログみたいなものを想定して、ログデータの集計というシーンにおけるクエリ例やちょっとしたテクニックを紹介していきます。

あるフィールドの値でグルーピングして集計したい

例: 応答 status 値ごとのログ件数をカウントする

まずは非常に基本的な stats コマンドの利用例です。
以下のように status に HTTP status を持つログから、 status の値ごとの発生件数をカウントします。

{"status": 200}

次のクエリで実現できます。

stats count(*) by status

以下のような結果が得られます。

status count(*)
200 15
400 3

一定時間単位のデータを集計したい

例: 15分ごとのログ件数をカウントする

これもサンプルクエリにもあるくらいの bin 関数を利用した stats の例です。
同様に status に HTTP status を持つログから、 15 分ごとの 200 応答件数をカウントします。

filter status = 200
| stats count(*) by bin(15m)

以下のような結果が得られます。

bin(15m) count(*)
2020-12-01 15:15:00.000 19
2020-12-01 15:00:00.000 35
2020-12-01 14:45:00.000 32
2020-12-01 14:30:00.000 72

テクニック: filter をせずに条件付きのカウントをしたい

さて、上記の例では先に status = 200 で filter してから集計を行っていました。
これを filter を用いずに行うにはどうすると良いでしょうか。

これは boolean が 0, 1 であることを利用することで、以下のように表現できます。
後述しますが、このテクニックは複数の集計値を扱う場合に有用になってきます。

stats sum(status = 200) by bin(15m)

また、フィールドとして定義した条件式を利用することもできます。

fields status = 200 as is_200
| sum(is_200) by bin(15m)

今の簡単な例では大していいことはありませんが、
複雑な条件を扱う場合や、条件式を再利用する場合などに見通しのよいクエリを書くのに役立ちます。

テクニック: JST で bin(1d) したい

デイリーの集計で利用する bin(1d) は UTC 基準で集約されます。
それで困らないシーンも多いとは思いますが、きっちり日本時間で集計したいこともあると思います。

bin 関数のオプションや @timestamp のタイムゾーン変換を行う関数は現状ありませんが、
@timestamp は Unix timestamp なので、これに直接整数を足して時間操作を行うことができます。

以下のように手動での時間操作と date_floor 関数を利用することで JST 版の bin(1d) と正味同じ挙動を実現できます。

date_floor(@timestamp + 9 * 60 * 60 * 1000, 1d)

あるフィールドの値 × 一定時間単位でグルーピングして集計したい

例: 15分ごとの応答 status 値ごとのログ件数をカウントする

これまでの stats コマンドの利用を組み合わせた例です。
同様に status に HTTP status を持つログから、 15 分ごとの status ごとの発生件数をカウントします。

stats count(*) by status, bin(15m)

以下のような結果が得られます。

status bin(15m) count(*)
400 2020-12-01 15:15:00.000 1
400 2020-12-01 15:00:00.000 4
400 2020-12-01 14:45:00.000 3
400 2020-12-01 14:30:00.000 7
200 2020-12-01 15:15:00.000 19
200 2020-12-01 15:00:00.000 35
200 2020-12-01 14:45:00.000 32
200 2020-12-01 14:30:00.000 72

表示結果の調整をしたい

ちょっとデータの次元が増えると表の並べ方を調整したくなります。
sort コマンドや display コマンド、 as キーワードなどを活用できます。

例えば上記の表を以下のように調整してみます。

  • 一番左の列を時間にする
  • 時間 -> status (desc) の辞書順に並べる
  • カウントの列名は total_count にする
stats count(*) as total_count by status, bin(15m) as bin_15m
| sort bin_15m, status desc
| display bin_15m, status, total_count

以下のような結果が得られます。

bin_15m status total_count
2020-12-01 15:00:00.000 400 4
2020-12-01 15:00:00.000 200 35
2020-12-01 15:15:00.000 400 1
2020-12-01 15:15:00.000 200 19
2020-12-01 14:30:00.000 400 7
2020-12-01 14:30:00.000 200 72
2020-12-01 14:45:00.000 400 3
2020-12-01 14:45:00.000 200 32

複数項目の集計をしたい

例: 応答時間の傾向について、複数の条件 (avg, p95, etc...) で集計する

先ほどの組み合わせでは stats コマンドの by キーワードの後ろを増やすことで、グルーピングの基準を追加しました。
stats コマンドの by キーワードの手前の集計値を増やすことで、複数の集計項目を取り扱うことができます。

{"response_time": 15}

上のような response_time の値をもつログから

  • 平均応答時間
  • p95 応答時間
  • 1000ms を超えた応答の数
  • 1000ms を超えた応答の数の割合

を1クエリで集計します。

stats count(*) as total,
  avg(response_time) as response_avg,
  pct(response_time, 95) as response_p95,
  sum(response_time >= 1000) as over_1s_count
| display response_avg, response_p95, over_1s_count, (over_1s_count / total * 100) as over_1s_rate

sum(response_time >= 1000) の部分は条件付きカウントを利用しています。
仮に filter コマンドで response_time が大きいログだけに絞ってしまうと、count(*) as total で取れる値が 「全体の応答の数」ではなく「response_time が大きい応答の数」になってしまい、全体の応答数などとの比較ができなくなります。

以下のような結果が得られます。

response_avg response_p95 over_1s_count over_1s_rate
14.9973 20.3021 3 0.3166

グループごとに複数項目の集計をしたい

例: パスごとの応答時間の傾向について、複数の条件 (avg, p95, etc...) で集計する

上記のクエリにグルーピングも追加してみます。
以下のようなログからパスでグルーピングして、パスごとのレイテンシ状況を集計します。

{"response_time": 15, "path":"/hoge"}

先ほどからほとんど変わらず、 by キーワードの追加と display の追加で実現できます。

stats count(*) as total,
  avg(response_time) as response_avg,
  pct(response_time, 95) as response_p95,
  sum(response_time >= 1000) as over_1s_count by path
| display path, response_avg, response_p95, over_1s_count, (over_1s_count / total * 100) as over_1s_rate

以下のような結果が得られます。

path response_avg response_p95 over_1s_count over_1s_rate
/hoge 14.9973 20.3021 3 0.3166
/fuga 50.0011 80.3232 12 1.2345

sort コマンドや limit コマンドも利用することでパフォーマンスが悪いパスの一覧を得ることができます。
その他にも以下のような応用も考えられそうです。

  • status をグルーピングに追加してパス & status ごとの応答時間傾向を観測する
  • status のカウンターを集計項目に追加してパスごとの応答時間傾向 + status 傾向を観測する
  • 特定 path で filter した上で bin グルーピングを使って特定 API の時系列での変化状況を観測する
  • @logStream でグルーピングしてタスクやインスタンスごとのレイテンシ状況を観測する

おわりに

比較的シンプルな使い方の延長で説明してきましたが、このくらいの知識でも集計クエリを活用できそうなシーンはだいぶ増えるのではないかと思います。

日々の運用で発生するログ調査においても、絞り込みだけでなく集計も活用することでより俯瞰的な調査を行えるようになると思います。
この記事が「クエリよくわかんないしあんまりつかってないなー :thinking: 」という方などの参考になればと思います。

30
7
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
30
7