Lambda PowerToolsとCW Logs Insightsがいいぞ！

## はじめに

この記事は、[ミロゴス Advent Calendar 2022](https://qiita.com/advent-calendar/2022/milogos) 20日目の記事です。

Lambda のログを CloudWatch Logs で見ている。けれども、調査時にログの検索がし辛いと感じたり、そのログからとある値を集計したい要件があったりするかと思います。
このような場合に対して CW Logs には CW Logs Insights が 用意されています。

本記事では CW Logs Insights を使ったログ検索のクエリの一例を記載します。
また、CW Logs に 構造化ログの形で出力できるPython のライブラリ、aws-lambda-powertools を使うことで CW Logs Insights がどう便利になるのかを紹介します。

対象者としては下記のような方を対象としています。

- Lambda を使ってるが CW Logs の検索に辛さを感じている。
- CW Logs のログから抽出し集計をするスクリプトを作っている。

### CloudWatch Logs Insights について

CW Logs のログデータをクエリによって検索、分析できる機能です。
独特なコマンドがいくつかありますが、下記のようなクエリを書くだけで簡単に検索できます。

```xquery
fields @timestamp, @message
| sort @timestamp desc
| limit 20
```

https://docs.aws.amazon.com/ja_jp/AmazonCloudWatch/latest/logs/AnalyzingLogData.html

### AWS Lambda PowerTools について

Lambda はデフォルトとして CW Logs にログ出力するため、外部サービスを使う以外には CW Logs にログ集約されているかと思います。
CW Logs では通常の 1 行で表示されるログ以外に、JSON 形式の構造化ログも利用できます。

![構造化ログの例](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/67099cb8-adb9-491a-1a8d-ad72c32ba60b.png)


PowerTools は構造化ログ以外に、トレースやカスタムメトリクスなどをベストプラクティスの形で実装するためのライブラリです。
Python には AWS Lambda Powertools for Python があり、他に TypeScript や Java、.NET にもそれぞれ提供されています。

- AWS Lambda Powertools for Python
  - https://awslabs.github.io/aws-lambda-powertools-python/
- AWS Lambda Powertools for TypeScript
  - https://awslabs.github.io/aws-lambda-powertools-typescript/
- AWS Lambda Powertools for Java
  - https://awslabs.github.io/aws-lambda-powertools-java/
- Lambda Powertools .NET
  - https://awslabs.github.io/aws-lambda-powertools-dotnet/

各リファレンスを見るとわかりますが、特に Python 版は様々な機能を持っています。そのため、Lambda で Python を使うのであれば基本的に利用するのが良いかと思います。

## 相性の良さを見てみる

### Lambda

まずは、PowerTools を使った時に表示されるLambdaのログです。

赤枠が PowerTools を使ったログ出力、青枠が logging モジュールを使ったログ出力になります。
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/3bc16745-f1c2-4945-4f22-0abee3442d58.png)

下記にログ出力したプログラムの一部を記載します。

```python
    test_object = {"hoge": "Hello World", "count": random.randint(10, 99)}

    # PowerToolsを使ったログ出力
    powertools_logger = Logger()
    powertools_logger.info(test_object)

    # Pythonのloggingモジュールを使ったログ出力
    import logging
    logger = logging.getLogger()
    logger.setLevel(logging.INFO)
    logger.info(test_object)
```


logging モジュールは 1 行に表示される形で、サンプルでは2 要素の辞書型の出力のためまだ確認しやすいですが、さらに要素が多くなるとより見づらくなります。

PowerTools を使ったログは構造化されており、info メソッドに渡した値以外に`level`や`timestamp`まで表示されています。
辞書型の`test_object`変数もフォーマットがかかることで見やすくなっているのが見てとれるかと思います。

#### さらにログをわかりやすくする

```python
powertools_logger = Logger(
    location="[%(name)s - %(filename)s] %(funcName)s:%(lineno)d"
)
```

上記は私が PowerTools を使う際に追加している設定です。
Lambda で使うファイルが 1 ファイルのみで済む場合は問題ありませんが、複数のファイルがある場合にどこのファイルのログなのかはデフォルトの設定では表示されません。
そこで私はログから該当箇所を判別しやすいように`location`にログフォーマットを渡しています。

下記がその実際の CW のログです。
赤線を引いている箇所が追加されています。
ログ名やファイル名、関数名と行番号まで表示できており、どこでこのログが出力されたのか一目で判断できます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/c8518f6b-4ec7-1c00-bc07-3d7cf7fd9972.png)

### CW Logs Insights

PowerTools を使うことで簡単に構造化ログが出力できました。
構造化ログを使うメリットの一つとして、Logs Insights でクエリの指定がしやすくなるという点があります。

例えば、INFO ログのみを表示したい場合、下記のようなクエリになります。

```xquery
fields @timestamp, @message, hoge, count as cnt
| sort @timestamp desc
| filter @message like /(?i)INFO/
```
(?i)は大文字小文字関係なく検索をかけます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/7a00ca20-1f4d-0f06-e5f7-dfac9d6acb03.png)

しかし、例えば DEBUG ログに`information`のような`info`が入った単語の出力があると、それもクエリ結果に引っかかってしまいます。

これに対して、もし PowerTools で構造化ログを出力しているなら下記のように書くことができます。

```xquery
fields @timestamp, @message, message.hoge, message.count as cnt
| sort @timestamp desc
| filter level = 'INFO'
```

ログレベルを INFO に指定する形なので、他のログレベルのログが検索結果に出てくることはありません。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/e2bf2a27-8d0d-b1c3-5a0b-00319343a318.png)

## なぜできるのか

なぜ、構造化ログを使っていると`filter level = 'INFO'`のような形が書けるのでしょうか。
それは下記のレコードを見るとわかります。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/77b863f9-3210-2236-2258-970937f47050.png)

`@message` に JSON の形で宣言されている値は、`level`や`message.count`のような形でデフォルトのフィールド（`@message`や`@log`など）と同じように宣言されています。

そのため、クエリ結果のフィールド部分にも`message.hoge`と言った形で指定でき、数値であれば下記のように集計することもできます。

```xquery
# 5分ごとにmessage.countの値を合算して出力
stats sum(message.count) by bin(5m)
| sort @timestamp desc
| filter level = 'INFO'
```

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/224198/106c6999-77c3-a8ae-ff10-baf1f0557663.png)

他の集計のクエリは下記に記載があります。
https://docs.aws.amazon.com/ja_jp/AmazonCloudWatch/latest/logs/CWL_QuerySyntax.html#CWL_QuerySyntax-alias

## まとめ

PowerToolsの機能を使うことで構造化ログを簡単に設定しました。
また、構造化ログのおかげで CW Logs Insights でログの調査や集計が簡単になるような例を紹介しました。

CW Logs Insights には構造化ログ以外にも非常に便利な機能がいくつもあります。
AWS のオンラインイベントでも紹介されています。

https://aws.amazon.com/jp/blogs/news/update-divedeep-series-24/

ぜひ、Lambda 関数の開発で使うようにしてみてください。