はじめに
AWS SDK for Go v2 を使って CLI ツールなどを開発していると、内部で呼ばれる SDK のロギングもきちんとやってみようという謎のモチベーションがときどき湧いてきますよね。
オプションでログレベルを渡すように設計し、それに応じてログ出力をいい感じに整えたいですが、どうせなら SDK のログも同じフォーマットで出力したいものです。特にデバッグ時には、アプリのログなのか SDK のログなのかが一見してわかるようになっているとトラブルシューティングが捗りそうです。今回はこれを実装してみます。
概要
SDK に対してカスタムロガーを渡さない場合は logging.StandardLogger が呼ばれます。このロガーが簡素な出力を行い、アプリ側で定義したロガーとフォーマットが異なって出力されるためモヤモヤするというのが今回の痒いところになります。このためカスタムロガーを設定することになりますが、どちらから出力されたのかを識別するための情報もほしいところです。
SDK はデフォルトではほとんどログを出力しないため、通常は特に気にする必要はありません。ただし SDK のデバッグログを出力したい場合などは大量のログが出るため「ログの出し方をもっと統一したいなぁ」となりました。これに対する解決策ですが、以下の流れで見通しよく実装できました。
- 埋め込みを使ってアプリ用と SDK 用でそれぞれ同じ内容のロガーを作る
- それぞれのロガーにはどちらのログかを判別できる情報 (label) を設定する
- SDK 用のロガーは
logging.Loggerインターフェースを実装する - それぞれ呼び出す
実装
アプリ用と SDK 用でそれぞれロガーを作る
今回は以下のように log/slog でベーシックなロガーを作ります。アプリ用か SDK 用かを識別するために label を出力するようにしました。label=App のように表示されます。
// newLogger creates a new base logger used by AppLogger and SDKLogger.
func newLogger(w io.Writer, level slog.Leveler, label string) *slog.Logger {
opts := &slog.HandlerOptions{
Level: level,
}
l := slog.New(slog.NewTextHandler(w, opts))
l = l.With(slog.String("label", label))
return l
}
次にこれをアプリ用、SDK 用それぞれのロガーに埋め込みます。アプリ用は log/slog のロガーをラップしているだけです。
// AppLogger is a logger for the application.
type AppLogger struct {
*slog.Logger
}
// NewAppLogger creates a new logger for the application.
func NewAppLogger(w io.Writer, level slog.Leveler, label string) *AppLogger {
l := newLogger(w, level, label)
return &AppLogger{l}
}
SDK 用も同様に、この時点ではラップしているだけです。
// SDKLogger is a logger for the AWS SDK. This implemented the logging.Logger interface.
// See: https://github.com/aws/smithy-go/blob/main/logging/logger.go
type SDKLogger struct {
*slog.Logger
}
// NewSDKLogger creates a new logger for AWS SDK.
func NewSDKLogger(w io.Writer, level slog.Leveler, label string) *SDKLogger {
l := newLogger(w, level, label)
return &SDKLogger{l}
}
logging.Logger インターフェースを実装する
これだけだと SDKLogger をカスタムロガーとして SDK に渡せないため、Logf を実装する必要があります。logging.Classification には WARN と DEBUG しかないので、これらを switch 文で振り分けて SDKLogger の各メソッドを単純に実行しています。
// Logf logs a message with formatting.
func (l *SDKLogger) Logf(classification logging.Classification, format string, v ...any) {
s := fmt.Sprintf(format, v...)
switch classification {
case logging.Warn:
l.Warn(s)
case logging.Debug:
l.Debug(s)
default:
l.Info(s)
}
}
呼び出す
あとはアプリの中で適切に呼び出すだけです。ロガーの渡し方については公式ドキュメントを参照してください。例えば以下のような形になるでしょうか。
func main() {
ctx := context.Background()
// Writer を定義する
w := os.Stderr
// ログレベルを定義する
level := slog.LevelDebug
// 各ロガーを定義する
appLogger := log.NewAppLogger(w, level, "App")
sdkLogger := log.NewSDKLogger(w, level, "SDK")
cfg, err := config.LoadDefaultConfig(ctx,
// SDK Config に SDK 用ロガーを渡す
config.WithLogger(sdkLogger),
// SDK Config にログモードを渡す
// 今回はレスポンスだけ出す
config.WithClientLogMode(aws.LogResponse),
)
// SDK Config からクライアントを作る
// 今回は例として S3 のクライアントを作る
client := s3.NewFromConfig(cfg)
// なんらかの処理を実行してログを出力する
out, err := client.ListBuckets(ctx, &s3.ListBucketsInput{})
if err != nil {
panic(err)
}
for _, bucket := range out.Buckets {
appLogger.Info(aws.ToString(bucket.Name))
}
}
これを実行してみると、以下のような出力が得られます。今回は標準のテキストハンドラを使っており、メッセージがエスケープされるなどコンソール向けではないですが、統一的なフォーマットでログが表示されていることがわかります。label 属性で App, SDK のどちらが出力したものかも識別できます (見づらいですが、右にスクロールしていただくと label=SDK となっています)
$ go run main.go time=2025-03-20T19:31:23.506+09:00 level=DEBUG msg="Response\nHTTP/1.1 200 OK\r\nTransfer-Encoding: chunked\r\nContent-Type: application/xml\r\nDate: Thu, 20 Mar 2025 10:31:24 GMT\r\nServer: AmazonS3\r\nX-Amz-Id-2: XXXX\r\nX-Amz-Request-Id: XXXX\r\n\r\n" label=SDK time=2025-03-20T19:31:23.507+09:00 level=INFO msg=abc-bucket label=App time=2025-03-20T19:31:23.507+09:00 level=INFO msg=cdk-hnb659fds-assets-000000000000-ap-northeast-1 label=App time=2025-03-20T19:31:23.507+09:00 level=INFO msg=cf-templates-111111111111-ap-northeast-1 label=App
汎用化してみた
完全に自分用ですが、github.com/charmbracelet/log というサードパーティー製のロガーをラップする形で、今回紹介した内容をパッケージ化しています。
これを使うことで以下のような出力を得ることができます (拙作の llcm のログです)
おわりに
最後に紹介した自分用のラッパーはミニマム構成で割と気に入っているのですが、今後はやはり Go の標準ライブラリである log/slog で、この文脈でも使える自前のハンドラを書いてみたいと思います。
簡単30秒