CloudWatch Logs Insightsのparseコマンドを使っていて、微妙にフォーマットの異なるログからデータを抽出しようとして、ちょっと困ったことがあったのでメモしておく。
[parseコマンドの基本]
parseコマンドの使い方は、こちらの公式サイトに例がある。
CloudWatch Logsに次のようなログがあるとする。
user=alice, method:find_item, latency := 123ms
user=bob, method:find_item, latency := 234ms
user=charlie, method:delete_item, latency := 345ms
これに対して、次のようなクエリを書いたとする。
parse @message "user=*, method:*, latency := *" as @user, @method, @latency
| stats avg(@latency) by @method, @user
すると、次のような表形式で結果を得ることができる。
| @user | @method | @latency |
| alice | find_item | 123ms |
| bob | find_item | 234ms |
| charlie | delete_item | 345ms |
[微妙にフォーマットの異なるログの問題]
先ほどの例のように、対象のログのフォーマットが全て同じであればparseコマンドは問題なく動作する。しかし、アプリからのログが常にそのような綺麗な形で出力されてくるとは限らない😭。
AWS Lambda関数がランタイムが出力するログを例に見ていく。Lambda関数の実行が終了したとき、次のようなログが出力される。
REPORT RequestId: bee11f7d-6ac6-4767-8157-d3964bcefe7c Duration: 250.23 ms Billed Duration: 251 ms Memory Size: 512 MB Max Memory Used: 42 MB Init Duration: 121.40 ms
しかし、Lambda関数のインスタンスが再利用された場合には*1、次のようなログが出力される。
REPORT RequestId: 47b29888-af90-4c16-a0de-2506bef8d399 Duration: 122.06 ms Billed Duration: 123 ms Memory Size: 512 MB Max Memory Used: 43 MB
初回実行の場合には、末尾にInit Duration: 121.40 msのようなログが追加されているが、再実行の場合にはこの部分がないため、ログのフォーマットが異なっている。
これらのログに対して、parse @message "Max Memory Used: *" as @maxMemoryというクエリを実行してMax Memory Usedの値を取得しようとすると、次のような結果になってしまう。
| @maxMemory |
| 42 MB Init Duration: 121.40 ms |
| 43 MB |
そこで、parse @message "Max Memory Used: *Init Duration: *" as @maxMemory, @initDurationのようなクエリでInit Durationの値もまとめてパースしようとすると、次のような結果になってしまう。
| @maxMemory | @initDuration |
| 42 MB | 121.40 ms |
2つ目のレコードの方は、Init Duration:に相当する部分がないため、パースに失敗してしまう。
[複数回parseする]
実はCloudWatch Logs Insightsのparseコマンドは1つのクエリの中で複数回利用できる*2。
なので、以下のようなクエリを実行する。
parse @message "Max Memory Used: * " as @maxMemory
| parse @message "Init Duration: * " as @initDuration
そうすると、以下のような結果が得られる。
| @maxMemory | @initDuration |
| 42 | 121.40 |
| 43 |
もっと増やすこともできる。
parse @message "Duration: * " as @duration
| parse @message "Billed Duration: * " as @billedDuration
| parse @message "Max Memory Used: * " as @maxMemory
| parse @message "Init Duration: * " as @initDuration
| @duration | @billedDuration | @maxMemory | @initDuration |
| 250.23 | 251 | 42 | 121.40 |
| 122.06 | 123 | 43 |
[まとめ]
- CloudWatch Logs Insightsではログの一部をparseコマンドで抽出できる
- 複数のフィールドを抽出する時に、対象のログのレコードによって存在しないフィールドがある場合、1回のparseコマンドではデータを抽出できないレコードがある
- parseコマンドを複数回繋げることで、フィールド数が異なるログでも正しくデータを抽出できる
