Deep dive into log/slog package

Go Conference mini 2023 Winter IN KYOTOでの登壇資料になります

Transcript

1. Deep dive into log/slog package Pana@Go Conference mini 2023 Winter IN KYOTO
2. 本日のトークの内容 • 自己紹介 • log/slogパッケージの概要 • 基本的なAPI • パフォーマンスに関して
3. 自己紹介 • 宮鼻 (Pana) • 株式会社SODAでWebエンジニア ◦ 2年くらいGoを書いている ◦ Zennに記事を書いている • 好き ◦ コーヒー ☕ ◦ つけ麺 • GitHub ◦ k3forx
4. 本日話すこと/話さないこと • 話すこと ◦ log/slogが実装/導入された背景や目的 ◦ 公開されているAPIの概要/内部のアーキテクチャ ◦ パフォーマンス観点での詳細な実装/設計 • 話さないこと ◦ log/slogのAPIの詳細な使い方 ◦ Webアプリケーションとの連携
5. log/slogパッケージの概要
6. log/slogパッケージとは • Go1.21のリリースで開発された構造化ログのための標準ライブラリ ◦ 現時点 (2023/11時点) ではテキスト形式とJSON形式での出力をサポートしてい る • 他のロギングパッケージは？ ◦ logrus, zap, zerologなど色々ある
7. なぜlog/slogパッケージが開発された？ • 色々なパッケージが開発された結果 ◦ 巨大なアプリケーションでは依存関係を通して様々なロギングパッケージに依存し ている • 何を解決したかった？ ◦ ログを統一的に扱えるようできる ◦ ユーザーがカスタマイズ可能な ”バックエンド” を定義した ◦ 将来的に色々なロギングパッケージがこの “バックエンド” を受け付ける (実装す る) ようになることを期待 ◦ より高品質なバックエンドを作成するためにGoのコミュニティが協力し合える ◦ 詳細は Proposal: Structured Logging#what-does-success-look-like に記載があ る
8. 基本的なアーキテクチャ • Logger構造体 ◦ ユーザー (開発者) から呼ばれる関数を定義 ◦ Record構造体を生成しHandlerにわたす • Record構造体 ◦ ログの内容を構造体として保持する • Handlerインターフェイス ◦ Record構造体を受け取り処理する
9. 基本的なAPI (使い方)
10. Infoメソッドをみてみる Output: • time, levelが出力 (デフォルト) • 第一引数はmsgのvalueとして出力 (デフォルト) • その後の引数はkey-valueとして出力 (なくても良い) ソースの位置の出力有 無などが設定できる
11. 内部の構造を見てみる 1. Record構造体を生成 + argsを追加 2. Hanlderインターフェイスに 渡す ログレベル
12. 同じ情報を固定で出力させる Output: • Withメソッドを使えば同じメッセージを出力できる
13. 同じような情報をまとめて出力 Output: • WithGroupメソッドを使えば、オプションのkey-valueをまとめて出力できる
14. パフォーマンスに関して
15. 随所に現れるパフォーマンスを意識した設計 • log/slogでいうパフォーマンスとは？ ◦ 主にメモリアロケーションのこと ◦ つまり、メモリのアロケーションをできるだけ少なくしている
16. どこに現れるか？ • 色々な構造体/インターフェイス/型に現れている！！ ◦ Logger構造体 ◦ Handlerインターフェイス ◦ Record構造体 ▪ Add関数 ◦ Attr (Value) 構造体 ◦ etc…
17. どこに現れるか？ • 色々な構造体/インターフェイスに現れている！！ ◦ Logger構造体 ◦ Handlerインターフェイス ◦ Record構造体 ⭐ ▪ Add関数 ⭐ ◦ Attr (Value) 構造体 ⭐ ◦ etc…
18. 関数の呼び出し (インライン展開) • インライン展開とは？ ◦ 関数を呼び出す側に呼び出される側の関数のコードを展開し、関 数への制御転送をしないようにする方法。これにより関数呼び出し に伴うオーバーヘッドを削減する (Wikipediaより抜粋) • コンパイラがいい感じにインライン展開してくれる • インライン展開できるかどうかは細かい条件がある ◦ https://github.com/golang/go/wiki/CompilerOptimizations#fun ction-inlining
19. 関数の呼び出し (直接 vs 間接) • 試してみる • ビルドの最適化オプションを有効化
20. 関数の呼び出し (直接 vs 間接) • 試してみる • 実行ファイルを逆アセンブルする
21. 関数の呼び出し (直接 vs 間接) • インターフェイス経由でのメソッド呼び出しはインライン展開されない場 合がある (されることもある) ◦ 関数呼び出しにオーバーヘッドが生じるのでパフォーマンスに影響 する可能性がある • log/slogではどこで意識されているのか？ ◦ Loggerはインターフェイスではなく構造体 になっている ▪ 呼び出し側でインターフェイスによる間接的なメソッド呼び出し にならないようにしている ◦ Infoメソッドなどはインターフェイス経由ではなく直接呼び出せる よ うになっている
22. Logger構造体のパフォーマンスメモ ✍ インライン展開されるようにインターフェースで はなく構造体として定義されている
23. Handlerインターフェイス Handleメソッド以外はパフォーマンス (最適 化) のためのメソッド
24. Handlerインターフェイス (Enabledメソッド) メソッドの最初に呼ばれる →早期リターン
25. Enabledメソッドのパフォーマンスメモ ✍ 無駄にログを出力しないように関数の一番最初 に呼ばれるようになっている
26. Handlerインターフェイス (WithAttrsメソッド) • WithAttrメソッドは引数のattrsを[]byteに変換した後、新しいHandler を生成する ◦ Handlerは内部にhandlerStateを持つ ◦ bufの型の*buffer.Bufferは実際には[]byte型 • さらに[]byteはsync.Poolを使用
27. sync.Poolとは？ • GoDocをみてみる ◦ 「... Pool’s purpose is to cache allocated but unused items for later reuse, relieving pressure on the garbage collector. …」
28. sync.Poolとは？ • GoDocをみてみる ◦ 「プールの目的は、割り当てられたが未使用のアイテムをキャッシュ し、後で再利用することで、ガベージ・コレクターの負担を軽減する ことである。」 • → 一時的に何かしらの値を保持して後で使いたい時 /確保のコス トが高いものをあらかじめに用意しておきたい時に便利 • log/slogパッケージ以外では、fmtパッケージやencoding/jsonパッケー ジでも使用されている • パフォーマンスに関するベンチマーク等の話はたくさん記事が出ている のでここでは割愛
29. sync.Poolの基本的な使い方 • GoDocのExampleをみてみる 1. 再利用したいアイテムを定義 2. アイテムを利用したい場合は Get メソッドを呼ぶ 3. アイテムを更新した後は Putメ ソッドを呼ぶ
30. log/slogパッケージではどう使われているか？ • 実装 Freeメソッドで空にした後に Putメ ソッドを呼ぶ ある程度大きい初期化を行うことで appendによるメモリの再確保を避け る
31. log/slogパッケージではどう使われているか？ Handleメソッドでは書き込む内容を bufにつめ て、出力したのちにFreeメソッドを呼ぶ → bufは常に空に初期化される WithAttrsメソッドでは引数のattrsをbufにつ めて、新しいhandlerを返すような処理 → 元々のHandlerに影響を出さずに、引数 のattrsを高速に出力できるような仕組み
32. WithAttrsメソッドのパフォーマンスメモ ✍ • sync.Poolを使うことによって Handlerのメソッド を呼ぶたびに都度メモリを確保しないようになっ ている • 引数のattrsはbufに保存され、新しい Handler ではその保存された bufを内部的に保持してい る
33. Record構造体 (Addメソッド) anyの可変長引数をAttrに 変換してる
34. Attr構造体 (Value構造体) uint64とanyのみでGoの型を表現 している
35. こう思いました... Valueフィールドの型はanyだとダメなのか？
36. 結論は... Valueの方がanyより少しだけメモリ効率が良い →文字列 (string型) を例に考えてみる
37. (おさらい) Goにおけるany型とstring型
38. stringをanyで表現しようとすると... stringへのポインタ (anyが持つ)　＋　byteへのポインタ (stringが持つ)
39. Value構造体でのstringの表現を見てみる 文字列の長さ byteへのポインタ anyの場合
40. Value構造体でのstringの表現を見てみる 文字列の長さ byteへのポインタ Valueの場合
41. Attr (Value) 構造体のパフォーマンスメモ ✍ Value構造体を定義することで anyをそのまま扱う より少しだけメモリ効率が良い設計になっている
42. Record構造体 (Addメソッド) なんかちょっと複雑なことをやってい るように見える...なぜ？
43. Record構造体 最初に長さ5の配列が初期化される
44. Record構造体 (Addメソッド) 最初 (nFront=0, len(r.Front)=5) は初期化済みの5つの配列にAttrを 詰める 配列が埋まったあとは、残りの argsを (Attr単位で) カウントして、最初にそ の容量を確保している (appendによる 再確保はない)
45. なぜ nAttrsInline = 5となっているのか？ A. zapを使っているコードを調べたところ9割くらいのロガーが5個の key-valueを出力していた (https://youtu.be/8rnI2xLrdeM?si=oCuKdvPQcrW08dXF から)
46. Record構造体のAdd関数のパフォーマンスメモ ✍ • zapの使い方から使用される key-valueペアの個 数を調査していた • 最初にその個数分のメモリだけ初期化し、追加 でメモリの再確保が可能な限り起きないように なっていた (起きたとしても 1回)
47. まとめ
48. log/slogパッケージまとめ • 構造化ログを生成する初の標準パッケージ • パフォーマンスについて色々な工夫が見られた ◦ メモリのアロケーションを何回も行わない工夫が見られた • 突き詰めて実装コードを読んでみると、意外と難しいことはやっていない ように思えた ◦ Goの言語仕様をきちんと理解した上の設計/実装になっていた • Logger構造体やHandlerインターフェイスのパフォーマンスに関する調 査は後日ブログで公開予定
49. ありがとうございました