slogによる構造化ログの実装とCloudWatch Logs Insightsでの利用

ENECHANGEのGoではzerologによるログの構造化を行っていますが、中途半端な状態です。 これをslogに切り替えて整備し、 CloudWatch Logs Insightsで調査するまでの過程を改善しました。その中で学んだ知見や具体的な実装について、簡単に共有していきます。

Transcript

1. slogによる構造化ログの実装と CloudWatch Logs Insightsでの利用 golang.tokyo #38 https://golangtokyo.connpass.com/event/348079/
2. Copyright © ENECHANGE Ltd. All Rights Reserved. | 2 自己紹介 Ryuya Ishibashi ENECHANGE株式会社で働いてます • 2022/04 - 2023/03 ◦ Railsエンジニアとして、電気料金シミュレーションの API開発を中心にお仕事していました • 2023/04 - ←いまここ ◦ Go・インフラエンジニアとして、EVsmartを中心に お仕事しています EVsmartとは？ • EVの充電器検索、充電スタンド・スポット口コミサイト • 上記POIデータのAPI提供 (@RubyKaigi2022) X / GitHub
3. Copyright © ENECHANGE Ltd. All Rights Reserved. | 3 Special Thanks to • 同僚のdiskymgさんに大きなご貢献をいただきました ◦ 初期の調査 ◦ slog導入の決定 ◦ 実装方法の壁打ち ◦ etc. • 大変お世話になりました！！！ https://github.com/diskymg
4. サマリ
5. Copyright © ENECHANGE Ltd. All Rights Reserved. | 5 この発表でお話しすること • 自社プロダクトのgoのログ実装をslogに統一しました • ログ項目を再設計しました ◦ API, CMD, DBそれぞれで一貫性のあるログ項目 • slogを実装する上で学んだ知見をご紹介します ◦ contextにloggerを格納しない実装 ▪ 独自ハンドラーにより、逆にcontextからログ項目を取り出す ◦ テストハンドラーを実装し、出力の内容を検証 ▪ 各ログをbytes.Bufferに記録 ◦ その他 ▪ cobraに独自のmiddlewareを実装
6. 現状と課題
7. Copyright © ENECHANGE Ltd. All Rights Reserved. | 7 現状の構成 • API ◦ gin/gorm による実装 ◦ AWS ECS on Fargateでホスト • CMD ◦ cobraによる実装 ◦ AWS ECSのスケジュールされたタスクで実行 • ログ ◦ AWS FireLensとKinesis Data Firehoseで送信 ▪ 標準出力とエラー出力が送信対象 ◦ 保存先はCloudWatchとS3 ◦ ログ分析にはCloudWatch Logs Insightsを用いる
8. Copyright © ENECHANGE Ltd. All Rights Reserved. | 8 課題：中途半端な構造化ログの導入 • API ◦ zerologを用いて構造化ログ自体は実装されていた ▪ gin middlewareで設定し、リクエスト内容のログに利用 ▪ エラー時にはエラー情報やレスポンス情報を付与して分析に活用していた ▪ zerologとは？ • Json出力に特化した、シンプルかつ高速なロガー ◦ contextにzerologを格納しているが、通常のログ出力にはほとんど利用さ れていなかった ◦ 一部でlogパッケージやfmt.Println等の利用も散見された
9. Copyright © ENECHANGE Ltd. All Rights Reserved. | 9 課題：中途半端な構造化ログの導入 • CMD ◦ 構造化ログの利用はなく、fmt.FPrintf()が多用されていた ◦ テストの実装 ▪ 標準出力/エラー出力の書き出し先を外部から注入して出力内容を検証し ていた
10. Copyright © ENECHANGE Ltd. All Rights Reserved. | 10 課題：中途半端な構造化ログの導入 • DB ◦ gorm/logger+zerologを用いて構造化ログ自体は実装されていた ▪ gorm/loggerインターフェースを実装し、ロガーにzerologを指定 ▪ contextからrequest_id等を取り出して、項目に設定 ▪ gorm/loggerとは？ • gorm標準のロガー • インターフェースを実装することで、柔軟な制御が可能 ◦ ただし、db取得時にdb.WithContext()メソッドが呼ばれずに、ctxから必 要情報が取り出せていない場面が散見された
11. 改善方針
12. Copyright © ENECHANGE Ltd. All Rights Reserved. | 12 logをslogに統一する • logをslogに統一する ◦ zerolog, log, fmt.Println, fmt.FPrintf()を廃止 ◦ 原則slogの利用に統一する ◦ slogとは？ ▪ Go 1.21で標準ライブラリーに加わった ▪ context.Context 型を標準でサポートしており、 Handler でコンテキスト情報を利用できる • → contextにlogを格納しなくて良いのでは？
13. Copyright © ENECHANGE Ltd. All Rights Reserved. | 13 ログ項目を再設計する • API/CMD/DBで一貫性を持つように、ログ項目を再設計する ◦ 共通 ▪ 共通で必要な項目 ◦ API ▪ 共通から継承した項目 ▪ APIに必要な項目 ◦ CMD ▪ 共通から継承した項目 ▪ CMDに必要な項目 ◦ DB: ▪ API/CMDから継承した項目 ▪ DBに必要な項目
14. Copyright © ENECHANGE Ltd. All Rights Reserved. | 14 slogのメソッドをcontext付きで呼び出す • 独自ハンドラを作成し、contextから指定の項目を取り出してログ項目に追加 • slogは最初に一度作成してslog.SetDefault()すれば良い ◦ context毎にログインスタンスを管理する必要がなくなる • コンテキスト付きでslogのメソッドを呼ぶ ◦ 例) slog.InfoContext(ctx, “hogehoge”) 参考にさせていただいた記事 Go言語のloggerをDefault1つで済ませる方法：slog Handlerが contextの中身を見てよしなにするパターン https://blog.arthur1.dev/entry/2024/05/18/212731
15. 実装詳細
16. Copyright © ENECHANGE Ltd. All Rights Reserved. | 16 • 指定の項目をcontextから取り出す 独自ハンドラーを実装する var keys = []string{ "user_id", "request_id", "command_name", "command_id", } type LogHandler struct { slog.Handler } func (h *LogHandler) Handle(ctx context.Context, r slog.Record) error { for _, key := range keys { if v := ctx.Value(key); v != nil { r.AddAttrs(slog.Attr{Key: string(key), Value: slog.AnyValue(v)}) // 指定keyがあれば属性に設定 } } return h.Handler.Handle(ctx, r) } 初期化 • mainで初期化する func main() { config.Init() logger.Init(config.GetConfig()) db.Init() h := &LogHandler{ // 独自Handler Handler: slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ Level: logLevel, AddSource: true, }), } slog.SetDefault(slog.New(h)) // デ フォルトに設定 • 初期化に独自ハンドラーを利用する • slog.SetDefaultを実行
17. Copyright © ENECHANGE Ltd. All Rights Reserved. | 17 • DB接続時、独自ロガーにデ フォルトのslogを渡す 初期化 - DB l := NewLogger( glogger.Config{ SlowThreshold: time.Second, LogLevel: logLevel, Colorful: true, }, slog.Default(), // デフォルトのslogを 渡す ) dbMs, err = gorm.Open(sqlserver.Open(dsn), &gorm.Config{ Logger: l, CreateBatchSize: 100, }) • gorm/logger interfaceを満たし、 slogを利用する独自ロガーを作成 type DBLogger struct { log *slog.Logger // slogを利用 gLogger.Config } // gorm/loggerを満たす var _ gLogger.Interface = &DBLogger{} func NewLogger(config gLogger.Config, logger *slog.Logger) gLogger.Interface { return &DBLogger{ log: logger, Config: config, } } func (l DBLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) { sql, _ := fc() l.log.InfoContext(ctx, sql) // slogを利用（context付き） }
18. Copyright © ENECHANGE Ltd. All Rights Reserved. | 18 contextへの項目設定 • API ◦ gin middlewareで、contextに必要な項目を設定 • CMD ◦ cobra middleware (自作)でcontextに必要な項目を設定 ▪ gistにコードを公開しました func CommandContextMiddleware() CommandMiddleware { return func(next func(cmd *cobra.Command, args []string) error) func(cmd *cobra.Command, args []string) error { return func(cmd *cobra.Command, args []string) error { ctx := cmd.Context() ctx = context.WithValue(ctx, commandIDKey, xid.New().String()) // command_idを設定 ctx = context.WithValue(ctx, commandNameKey, cmd.CommandPath()) // command_nameを設定 ctx = context.WithValue(ctx, logTypeKey, enums.LogTypeCommand) // log_typeを設定 cmd.SetContext(ctx) return next(cmd, args) } } }
19. Copyright © ENECHANGE Ltd. All Rights Reserved. | 19 利用 • 前提 ◦ 各関数はctxを引数に持つ • コンテキスト付きでslogのメソッドを呼ぶ ◦ slog.InfoContext(ctx, “hoge”) ◦ slog.WarnContext(ctx, “hoge”) ◦ slog.ErrorContext(ctx, “hoge”) • DB取得時にコンテキストを付与する ◦ dbMs := db.GetSqlServ().WithContext(ctx)
20. Copyright © ENECHANGE Ltd. All Rights Reserved. | 20 テスト • リファクタ前のCMD ◦ 構造化ログの利用はなく、fmt.FPrintf()が多用されていた ◦ テストの実装 ▪ 標準出力/エラー出力の書き出し先を外部から注入して、 出力内容を検証していた
21. Copyright © ENECHANGE Ltd. All Rights Reserved. | 21 テスト • テストハンドラーを用意し、出力の内容を書き出す ◦ slog.Handlerインターフェースを満たすTestHandlerを実装 ◦ TestHandlerは、ログをbytes.Bufferに記録 ◦ テストの最初でテストハンドラーを初期化し、ロギングに利用 ◦ テスト用のヘルパーメソッドを利用して出力内容を検証 ▪ 例) • func (h *TestHandler) IsLogMessageEmpty(level LogLevel) bool • func (h *TestHandler) IsLogMessageEqual(level LogLevel, message string) bool • func (h *TestHandler) IsLogMessageMatchingPattern(level LogLevel, pattern *regexp.Regexp) bool ◦ gistにコードを公開しました
22. ログの利用
23. Copyright © ENECHANGE Ltd. All Rights Reserved. | 23 ログの利用 • API/CMD/DBで一貫した項目を持つ構造化ログの実装ができた • CloudWatch Logs Insightsにおける構造化の恩恵 ▪ SQLライクなクエリが書けるため、様々な絞り込みや集計が可能 ▪ 構造化により、上記がより簡単に実現可能 ▪ テキストの状態だと自分でパースを頑張る必要がある • 最後に実際の利用例を紹介します
24. Copyright © ENECHANGE Ltd. All Rights Reserved. | 24 request_idでの絞り込み fields @timestamp, path, msg | sort @timestamp desc | filter request_id like /hogehoge/
25. Copyright © ENECHANGE Ltd. All Rights Reserved. | 25 command_idでの絞り込み fields @timestamp, command_name, msg | sort @timestamp desc | filter command_id like /hogehoge/
26. Copyright © ENECHANGE Ltd. All Rights Reserved. | 26 user_agentの集計 filter type = "access" | stats count(*) as count by user_agent | order by count desc
27. 最後に
28. Copyright © ENECHANGE Ltd. All Rights Reserved. | 28 エンジニアを募集しています！ We are currently hiring GREEN ENGINEERS !!!