Amazon CloudWatch Logs に出力するログは JSON 形式だと分析が楽になるかもしれない話

2022.12.18Update

南川

この記事は、ニフティグループ Advent Calendar 2022 18日目の記事です。

はじめに

基幹システムグループサービスインフラチームの南川です。

普段はユーザーサインアップやシングルサインオン、顧客管理システム等の開発や運用を担当しています。

今回は、 Amazon CloudWatch Logs に出力するログの形式について説明します。

Amazon CloudWatch Logs

Amazon CloudWatch Logs は、 AWS リソースや AWS 上で実行するアプリケーションからのログファイルをモニタリング、保存、アクセスできるサービスです。

CloudWatch Logs に出力するログ形式

結論から言うと JSON 形式にしておくと、検索や分析する際に楽です。

今回はチャットツールのログを例として、ログが JSON 形式でない場合と JSON 形式である場合でどのような違いがあるかを取り上げます。

例：チャットツールのログ (JSON 形式でない場合)

まず、ログとして出力されるデータは以下のようになっています。先頭にログのレベル、その後ろにログのメッセージが記載されています。

[INFO] Taro posted "hoge" from 1.2.3.4

[INFO] Jiro posted "fuga" from 5.6.7.8

[INFO] Taro posted "piyo" from 1.2.3.4

[INFO] Jiro posted "hello" from 9.10.11.12

[ERROR] Saburo couldn't post from 1.1.1.1

投稿成功時 (1-4行目)
- INFO レベルで「<ユーザー名> posted “<本文>” from <IPアドレス>」
エラー発生時 (5行目)
- ERROR レベルで「<ユーザー名> <エラーメッセージ> from <IPアドレス>」

CloudWatch Logs にこれらのログを出力すると以下のようになります。

CloudWatch Logs に出力されたこれらのログは、 CloudWatch Logs Insights を用いて検索・分析することができます。

CloudWatch Logs Insights でログを検索、分析する

CloudWatch Logs Insights では、クエリを使ってログデータを検索・分析・データの抽出ができます。

それでは、先ほどの CloudWatch Logs に出力したログに対して、 CloudWatch Logs Insights でデータを抽出してみます。

例：ログイベントを取得する

まずは、簡単な例として最新20件のログイベントのタイムスタンプとメッセージを新しい順で取得するクエリを実行します。クエリとその実行結果は以下の通りです。

fields @timestamp, @message

| sort @timestamp desc

| limit 20

下部の実行結果にはCloudWatch Logsに出力されたログのタイムスタンプとメッセージが表示されています。クエリは複数のコマンドで構成されており、それぞれのコマンドがパイプ文字 (|) で区切られています。クエリ内で使えるコマンドについては、 CloudWatch Logs Insights のクエリ構文を参照してください。今回はこのクエリで使われているコマンドについて簡単に説明します。

1	fields @timestamp, @message

1行目の fields コマンドは、クエリ結果の特定のフィールドを表示するコマンドです。例のクエリでは @timestamp と @message の値をクエリ結果に表示するようにしています。このコマンドで指定できるフィールドはサポートされるログと検出されるフィールドを参照してください。

1	sort @timestamp desc

2行目の sort コマンドは、特定のフィールドについてソートするコマンドです。例のクエリでは @timestamp について降順 (desc) ソートしています。

limit 20

3行目の limit コマンドは、クエリで返すログイベントの上限数を指定するコマンドです。例のクエリでは検索結果 (ログイベントの数) を20件まで返すように指定しています。

例：投稿に成功したログイベントの投稿者名とメッセージとIPアドレスを取得する

次に、投稿に成功したイベントを抽出し、そのイベントの投稿者名とメッセージとIPアドレスを表示するクエリを実行します。クエリとその実行結果は以下の通りです。投稿者名、メッセージ、IPアドレスはそれぞれ userName, body, ipAddress フィールドに格納されています。

fields @message

| parse @message "[*] *" as loggingType, loggingMessage

| filter loggingType = "INFO"

| filter loggingMessage like /\w+ posted ".*" from \d+\.\d+\.\d+\.\d+/

| parse loggingMessage "* posted \"*\" from *" as userName, body, ipAddress

| display @message, loggingType, loggingMessage, userName, body, ipAddress

1 2	parse @message "[] " as loggingType, loggingMessage parse loggingMessage "* posted \"\" from " as userName, body, ipAddress

2,5行目の parse コマンドは、フィールドの値からでデータを抽出し、クエリ (後続のコマンド) で使える一時的なフィールドを作成するコマンドです。例の2行目のクエリでは、 @message において "[*] *" の各 * に該当する値が as の後ろの各フィールド (1つ目の * の箇所は loggingType 、2つ目の * の箇所は loggingMessage) に格納されます。例えば、 @message が「[INFO] Taro posted "hoge" from 1.2.3.4」の場合、 loggingType は「INFO」、 loggingMessage は「Taro posted "hoge" from 1.2.3.4」となります。

1 2	filter loggingType = "INFO" filter loggingMessage like /\w+ posted ".*" from \d+\.\d+\.\d+\.\d+/

3,4行目の filter コマンドは、1つ以上の条件を満たすイベントを取得するコマンドです。例のクエリでは、 loggingType の値が “INFO” であるイベント（3行目）と、 loggingMessage の値が「 \w+ posted ".*" from \d+\.\d+\.\d+\.\d+ 」というパターンの正規表現にマッチしているイベント（4行目）を取得しています（4行目の filter コマンドが無くても投稿成功イベントを抽出できなくはないですが、正規表現でも判定できる例として追加しています）。

1	display @message, loggingType, loggingMessage, userName, body, ipAddress

5行目の display コマンドは、クエリ結果の特定のフィールドを表示するコマンドです。例のクエリではカンマ区切りで列挙されたフィールド (@message, loggingType, loggingMessage, userName, body, ipAddress) の値を表示しています。

このように、ログを構造化 (JSON 形式で記述) していない場合、ログから投稿文、投稿者名、IPアドレスを抽出するために5,6行程度のクエリを書く必要があります。

ログを JSON 形式で構造化する

先ほどのログを JSON 形式で構造化してみます。構造化した一例は以下の通りです。

{"level":"INFO","user_name":"Taro","body":"hoge","ip_address":"1.2.3.4"}

{"level":"INFO","user_name":"Jiro","body":"fuga","ip_address":"5.6.7.8"}

{"level":"INFO","user_name":"Taro","body":"piyo","ip_address":"1.2.3.4"}

{"level":"INFO","user_name":"Jiro","body":"hello","ip_address":"9.10.11.12"}

{"level":"ERROR","user_name":"Saburo","body":"couldn't post","ip_address":"1.1.1.1"}

CloudWatch Logs にこれらのログを出力すると以下のようになります。

この構造化されたログから、先ほどと同様の投稿者名とメッセージとIPアドレスを取得するクエリを書くと以下のようになります。投稿者名、メッセージ、IPアドレスはそれぞれ user_name, body, ip_address フィールドに格納されています。

1 2	fields @message, level, user_name, body, ip_address \| filter level = "INFO"

ログの本文 (@message) が JSON 形式である場合、 parse コマンド不要で JSON フィールドの値を、キー名を指定して参照することができます。これにより、構造化されていない時に比べ、クエリの行数を削減することができました。

また、ネストが深く複雑な JSON でも、ドット表記を使用して JSON フィールドにアクセスすることも可能です。
参考：サポートされるログと検出されるフィールド – Amazon CloudWatch Logs

構造化ログのデメリット

ログを JSON 形式で出力する場合、構造化されていない時に比べ、ログのサイズが大きくなる傾向があります。また、 CloudWatch Logs では、ログの取り込み、保管、分析によって 1 GB ごとに料金が発生します。つまり、 JSON 形式でログ出力すると、 JSON形式で出力されていない時に比べて、 CloudWatch Logs のコストがかかることがあります。

JSON 形式でログを出力する際は、すべてのデータをログ出力するのではなく、必要なデータを取捨選択するなどの工夫が必要です。

おわりに

今回は CloudWatch Logs のログ形式について書きました。CloudWatch Logs に格納するログは JSON 形式 (構造化ログ) にしたほうが、 Logs Insights のクエリが簡潔になり、検索・分析・データ抽出が楽になります。しかし、ログサイズの肥大化に伴い、コストが増えることもあるので、不必要なデータは出力しないなどの工夫が必要です。皆さんも AWS 上にアプリケーションをデプロイする際は、ログ形式を JSON にすることを検討してみてください。

明日は、 yt_glaceon さんの担当です。
お楽しみに！