Lambda + Go + CloudWatch Log での Structured Logging
なんか最近自分が見ている界隈でログの話が盛り上がってる気がする (GAE SE 2nd Gen)
GKE や GAE については、すでに以下の様な記事が出ているのでそちらを見ていただけるのがいいと思いますし、 Structured Logging の利点についてもまとまっていると思います。
StackDriver Logging における、 Structured Logging はとてもいいもので、僕も GAE を初めて使ったときには感動しました。
一方で、 AWS を使い始めたときに困ったのもログでした。
見やすいログ、調査しやすいログってとても重要なのにもかかわらず、AWS での標準のログでは従来のシンプルなログの出し方になってて、
要するに Debug("aaa") とすると、一行の aaa ってログが吐き出されるだけになっています。
そこで CloudWatch Log において StackDriver Logging のように出力するにはどうすればいいだろう。ってことで作ったのが GitHub - hixi-hyi/logone-lambda-go になります。 今回は Lambda 特化にしています。(仕事においては GAE FE Ruby 用だったり Fargate Go 用の同等のライブラリを社内で作って使ったりしています)
CloudWatch Log においては、何かしらのアノテーションを元にログをまとめ上げるという、効率の良い Log の収集方法はありません。 そこで、本モジュールにおいては、 ログを一旦メモリにためて、Lambda の終了時に JSON を組み立てて出力することにしています。 README の Caution にも書いてありますが、大きなシステムで使う際には注意してください。
システムによっては少し気にするポイントがあることは欠点*1ですが、それを考えたとしても非常に使いやすいログになると思っています。
使い方については
logone-lambda-go/example の実装と logone-lambda-go#outputs のアウトプットイメージを見てもらうのが早いと思いますが、例えば以下のようなことが可能になります。
{ $.runtime.elapsed >= 1000 }で 1sec 以上かかったのログを取り出す{ $.runtime.severity = "CRITICAL" }で CRITICAL のログが出力されているものを取り出す{ $.runtime.tags.aws-sdk-error >= 1 }で Tag: aws-sdk-error が発生したものを取り出す
CloudWatch Log よりも見やすくなった CloudWatch Log Insight でも同様のことができますし、Log Insight の集計関数を使うことによって該当時間内にどれだけ何が起こったということを調べることも楽になります。
例えば fields @message | filter runtime.severity = "CRITICAL" | stats count(*) とすれば CRITICAL ログが吐き出されたイベントの数がわかります。
ということで、是非使ってもらえればと。
*1:メモリ使用量、同時に標準出力ができるログサイズ、panic 時の処理など
