🪓

Cargo Lambda のログを JSON(Bunyan format) で出力する

に公開

内容

出力するログのフォーマットは JSON で出力すると便利なことが多い。
CloudWatchLogs なら Subscription filter を使って一定以上の Log Level のもののみを転送して通知するなどがやりやすいためである。

Bunyan format

{
  "v": 0,
  "name": "lambda",
  "msg": "information",
  "level": 30,
  "hostname": "Workstation",
  "pid": 4574,
  "time": "2025-04-20T17:21:57.31645104Z",
  "target": "lambda::handler",
  "line": 36,
  "file": "src/handler.rs"
}

ここでは Rust (Cargo Lambda) のログを Bunyan format で出力するように設定するやり方を記す。

使うのは tracing-bunyan-formatter というクレートである。

https://crates.io/crates/tracing-bunyan-formatter

Cargo Lambda のデフォルトのログ出力

cargo lambda init で作成するとデフォルトのログが出力されるようになってはいる。
ログレベル次第だとは思うがログレベルをみたり他の情報をみるには少し見にくいし、ログの分析にも少し扱いずらそうである。

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/4cd8abe69d2f4ac67382fc6066d94d25c274538e/src/main.rs#L5

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/4cd8abe69d2f4ac67382fc6066d94d25c274538e/src/handler.rs#L21

lambda_http::tracing::init_default_subscriber();
lambda_http::tracing::info!("information");

サンプルは lambda http なので watch して curl すれば実行できる。

cargo lambda watch

# 別タブから
curl http://localhost:9000/?log=info
curl http://localhost:9000/?log=warn
curl http://localhost:9000/?log=err
# curl http://localhost:9000/?log=panic

CWL などでも見たことがあるログが出ている。

INFO Lambda runtime invoke{requestId="d7f2cd28-5af6-49d5-92c8-1ad57b0a2357" xrayTraceId="Root=1-68053309-1dda0493af9111783fa5ffea;Parent=b46f7da2d955fd3e;Sampled=1"}: information

tracing-bunyan-formatter

設定

bunyan format を使うために以下のクレートを追加する。

cargo add \
  tracing \
  tracing-bunyan-formatter \
  tracing-subscriber

以下のように設定する。

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/bda307af6c7b7007ba85000e85ed3e51a1b24243/src/main.rs#L8-L18

ログが多い

上記の設定をすると lambda の Runtime のメッセージや hyper のログなどがすべて出るようになる。

それに JSON を確認してもらうとわかるが msg のキーに [LAMBDA RUNTIME INVOKE - EVENT] と細かいメッセージが出てくる。
これはわかりにくいので消したい。

{
  "v": 0,
  "name": "lambda",
  "msg": "[LAMBDA RUNTIME INVOKE - EVENT] information",
  "level": 30,
  "hostname": "Workstation",
  "pid": 4203,
  "time": "2025-04-20T15:19:32.133469183Z",
  "target": "lambda::handler",
  "line": 21,
  "file": "src/handler.rs",
  "requestId": "2f7a46dd-a83d-437f-ba4f-7872134f5d1b",
  "xrayTraceId": "Root=1-68051084-86a8c3c4beb90e7854b1ed7d;Parent=95c87aa30e621259;Sampled=1"
}

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/21da98ea0ab6c1fbd005d850ab3172c1db1ae28c/src/main.rs#L12-L24

環境変数 RUST_LOG からログレベルを設定できるようにする。

[LAMBDA RUNTIME INVOKE - EVENT] は消したいので

.add_directive("lambda_runtime=warn".parse().unwrap());

としている。

これで info レベルのログは出力されなくなるため、[LAMBDA RUNTIME INVOKE - EVENT] などの冗長なメッセージを抑制できる。

ただ残念ながら [LAMBDA RUNTIME INVOKE - START] などのメッセージも出なくなるので自分で tracing::info! したほうがいいかもしれない。

また RUST_LOG から取らなくても

tracing_subscriber::filter::EnvFilter::try_from_default_env()

を使うこともできるのだが RUST_LOG が未定義だったりすると何も出力しなくなるのでサンプルでは明示的に

std::env::var("RUST_LOG")

をしたり、

.filter(|a| !a.is_empty())

で空文字ならデフォルトに流せるようにしている。

おまけ panic

panic したときも同じようなメッセージが流れるように hook しておく。

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/126199f1492bd1fe7c17974f9c0f0224156bc6dd/src/main.rs#L9-L16

Runtime のエラーと被るのでそちらのほうは表示されないように無効化しておく。

https://github.com/Creanciel/ZennCargoLambdaBunyan/blob/126199f1492bd1fe7c17974f9c0f0224156bc6dd/src/main.rs#L30

まとめ

これですっきりとしたログ環境になったはずである。
出力されたログを上手く収集して、通知できるように設定できるといいのではなかろうか。

Discussion