Slide 1

Slide 1 text

slogによる構造化ログの実装と CloudWatch Logs Insightsでの利用 golang.tokyo #38 https://golangtokyo.connpass.com/event/348079/

Slide 2

Slide 2 text

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

Slide 3

Slide 3 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 3 Special Thanks to ● 同僚のdiskymgさんに大きなご貢献をいただきました ○ 初期の調査 ○ slog導入の決定 ○ 実装方法の壁打ち ○ etc. ● 大変お世話になりました!!! https://github.com/diskymg

Slide 4

Slide 4 text

サマリ

Slide 5

Slide 5 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 5 この発表でお話しすること ● 自社プロダクトのgoのログ実装をslogに統一しました ● ログ項目を再設計しました ○ API, CMD, DBそれぞれで一貫性のあるログ項目 ● slogを実装する上で学んだ知見をご紹介します ○ contextにloggerを格納しない実装 ■ 独自ハンドラーにより、逆にcontextからログ項目を取り出す ○ テストハンドラーを実装し、出力の内容を検証 ■ 各ログをbytes.Bufferに記録 ○ その他 ■ cobraに独自のmiddlewareを実装

Slide 6

Slide 6 text

現状と課題

Slide 7

Slide 7 text

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を用いる

Slide 8

Slide 8 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 8 課題:中途半端な構造化ログの導入 ● API ○ zerologを用いて構造化ログ自体は実装されていた ■ gin middlewareで設定し、リクエスト内容のログに利用 ■ エラー時にはエラー情報やレスポンス情報を付与して分析に活用していた ■ zerologとは? ● Json出力に特化した、シンプルかつ高速なロガー ○ contextにzerologを格納しているが、通常のログ出力にはほとんど利用さ れていなかった ○ 一部でlogパッケージやfmt.Println等の利用も散見された

Slide 9

Slide 9 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 9 課題:中途半端な構造化ログの導入 ● CMD ○ 構造化ログの利用はなく、fmt.FPrintf()が多用されていた ○ テストの実装 ■ 標準出力/エラー出力の書き出し先を外部から注入して出力内容を検証し ていた

Slide 10

Slide 10 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 10 課題:中途半端な構造化ログの導入 ● DB ○ gorm/logger+zerologを用いて構造化ログ自体は実装されていた ■ gorm/loggerインターフェースを実装し、ロガーにzerologを指定 ■ contextからrequest_id等を取り出して、項目に設定 ■ gorm/loggerとは? ● gorm標準のロガー ● インターフェースを実装することで、柔軟な制御が可能 ○ ただし、db取得時にdb.WithContext()メソッドが呼ばれずに、ctxから必 要情報が取り出せていない場面が散見された

Slide 11

Slide 11 text

改善方針

Slide 12

Slide 12 text

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を格納しなくて良いのでは?

Slide 13

Slide 13 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 13 ログ項目を再設計する ● API/CMD/DBで一貫性を持つように、ログ項目を再設計する ○ 共通 ■ 共通で必要な項目 ○ API ■ 共通から継承した項目 ■ APIに必要な項目 ○ CMD ■ 共通から継承した項目 ■ CMDに必要な項目 ○ DB: ■ API/CMDから継承した項目 ■ DBに必要な項目

Slide 14

Slide 14 text

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

Slide 15

Slide 15 text

実装詳細

Slide 16

Slide 16 text

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を実行

Slide 17

Slide 17 text

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付き) }

Slide 18

Slide 18 text

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) } } }

Slide 19

Slide 19 text

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)

Slide 20

Slide 20 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 20 テスト ● リファクタ前のCMD ○ 構造化ログの利用はなく、fmt.FPrintf()が多用されていた ○ テストの実装 ■ 標準出力/エラー出力の書き出し先を外部から注入して、 出力内容を検証していた

Slide 21

Slide 21 text

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にコードを公開しました

Slide 22

Slide 22 text

ログの利用

Slide 23

Slide 23 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 23 ログの利用 ● API/CMD/DBで一貫した項目を持つ構造化ログの実装ができた ● CloudWatch Logs Insightsにおける構造化の恩恵 ■ SQLライクなクエリが書けるため、様々な絞り込みや集計が可能 ■ 構造化により、上記がより簡単に実現可能 ■ テキストの状態だと自分でパースを頑張る必要がある ● 最後に実際の利用例を紹介します

Slide 24

Slide 24 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 24 request_idでの絞り込み fields @timestamp, path, msg | sort @timestamp desc | filter request_id like /hogehoge/

Slide 25

Slide 25 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 25 command_idでの絞り込み fields @timestamp, command_name, msg | sort @timestamp desc | filter command_id like /hogehoge/

Slide 26

Slide 26 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 26 user_agentの集計 filter type = "access" | stats count(*) as count by user_agent | order by count desc

Slide 27

Slide 27 text

最後に

Slide 28

Slide 28 text

Copyright © ENECHANGE Ltd. All Rights Reserved. | 28 エンジニアを募集しています! We are currently hiring GREEN ENGINEERS !!!