Goのデバッグ用ロガーの開発を通して得た デバッグとgoパッケージに関する知見/Knowledge by given implementation of logger for debug

[Elevator Pitch]

Goでデバッグをする場合, 基本的にはDelve, GDB, ロギングの3択になります. DelveやGDBによるデバッグは便利ですが複数の変数情報を高速に得ることは困難であり, この用途にはロギングが適しています. しかし, デバッグ用に追加したロギング用のコードを消し忘れ, 実行速度の低下や業務用のコードにおける機密情報のログ出力等の問題を引き起こす可能性があります. これらの問題に対処するべく, 私はGoの静的解析および動的解析によって変数情報等を表示可能で, コミット時に自動的に削除されるデバッグ用のロガーdlを開発しました. 本セッションでは, 前述したGoにおける3種類のデバッグ方法の利点および欠点ならびにdlの開発を通して得たgo/ast等のgoパッケージに関する知見をご紹介します.

[Main Description]

開発において, 想定外の挙動をした際にデバッグをした経験がある方は多いのではないでしょうか? Goでデバッグをする場合, 基本的にはDelve[1], GDB[2], ロギングの3択になります. Delve[1]はサードパーティー製のGo用デバッガであり, 実行時の変数やスタック情報の表示や上書き, goroutineの情報取得等ができます. また, リモードデバッグを有効にすることで, VS CodeやGoLandなどのエディタやIDEに組み込んでGUI上でデバッグすることもできるため, 開発時に重宝します. GDB[2]はDelve[1]と似たデバッガで, gef[5]やpeda[4], pwndbg[6]等のGDBスクリプトにより, 低レイヤを対象としたデバッグを円滑に行うことができます. しかし, Go Blogの記事[3]に記載されているように, Goプログラムの構造を理解していないため誤った結果を表示する場合もあります. また, Delve[1]やGDB[2]はある1点の状態を詳しく得ることは得意ですが, 複数の変数情報等をまとめて高速に得ることは不得手です. したがって, 手軽に複数の変数情報等をまとめて高速に得る用途にはロギングが適しています.

Goのロギングには, builtinパッケージのpanic, print, println, fmtパッケージやlogパッケージの各種関数およびメソッド, サードパーティー製のglog[7], Logrus[8], zap[9]等のロガーが利用できます. また, logr[10]が提供するinterfaceを満たすロガーを利用することで, それぞれのロガーを手軽に切り替えることもできます. これにより, Delve[1]やGDB[2]と違い, 複数の変数情報等をまとめて高速に得ることができます. しかし, デバッグ用に追加したロギング用のコードを消し忘れ, 実行速度の低下や業務用のコードにおける機密情報のログ出力等の問題を引き起こす可能性があります. 実際に, 私もインターンシップ先のリポジトリに対して余分なロギング用のコードを追加し, レビュー漏れで本番コードに紛れ込んでしまった経験があります．

そこで, 私はGoの静的解析と動的解析によって変数情報等を表示でき，コミット時に自動的に削除されるデバッグ用のロガーdl( https://github.com/task4233/dl )を開発しました. Design Docsはこちら( http://bit.ly/3XGdtyF )です. dlは変数とその型情報, 変数が利用されているコードの行数を表示する機能とコミット時に自動的に削除される機能を提供します. これらの機能は, Goのgo/token, go/parser, go/astパッケージ等を用いた静的解析やruntimeパッケージを用いた動的解析を活用することで実現しています. また, dlは前述したlogrのinterfaceを満たしているロガーであればラップすることができ, 既存のロガーを変更することなく容易に導入することができます. 私が調査した中では, これらの機能を全て備えたロガーは他に存在しませんでした(2023/01/30現在).

本セッションでは, 前述したGoにおける3種類のデバッグ方法の利点および欠点ならびにdlの開発を通して得たgo/ast等のgoパッケージに関する知見をご紹介します. 過去のGo ConferenceでGDB[2]に関する講演[11]がありましたが, これとは異なる切り口の内容なので差分はあると考えています.

[1] go-delve/delve: https://github.com/go-delve/delve

[2] GDB: The GNU Project Debugger: https://www.sourceware.org/gdb/

[3] Debugging Go Code with GDB: https://go.dev/doc/gdb

[4] hugsy/gef: https://github.com/hugsy/gef

[5] longld/peda: https://github.com/longld/peda

[6] pwndbg/pwndbg: https://github.com/pwndbg/pwndbg

[7] golang/glog: https://github.com/golang/glog

[8] Sirupsen/logrus: https://github.com/Sirupsen/logrus

[9] uber-go/zap: https://github.com/uber-go/zap/

[10] go-logr/logr: https://github.com/go-logr/logr

[11] Debugging Go Code with GDB:https://speakerdeck.com/kaneshin/debugging-go-code-with-gdb

Transcript

1. Goのデバッグ用ロガーの開発を通して得た デバッグとgoパッケージに関する知見 Go Conference 2023 2023/06/02 Takashi Mima(@task4233)
2. Takashi Mima(@task4233) 所属 ・株式会社メルカリ(Identity Platform) 興味分野 ・バックエンド 　・Go(Contribution/Go Conference) ・セキュリティ 　・CTF(SECCON Beginners) 　・セキュリティ・ミニキャンプ in 三重 2023 講師 ほか ・Twitter: @task4233 ・Portfolio: task4233.dev 2
3. Goでデバッグする際に 何を使いますか？👀 3
4. Delve?GDB?ロギング？ 他の何か？🧐 4
5. 本発表で共有する2つのこと 1. Goにおける3種類のデバッグ方法 2. 自作したロガーの開発に用いられているgoパッケージ ・デバッガの詳しい使い方 ・GODEBUG等の環境変数を用いたデバッグ 5 本発表で共有しないこと
6. 3種類のデバッグ方法 Delve GDB ロギング 👍 ・大半のGoプログラム 　のデバッグに利用可能 ・Goに特化しており、 　GDBよりも正確な結果 　が得られる ・Cgoやランタイムの 　デバッグに利用可能 ・機能拡張が豊富 ・Pythonスクリプトで 　処理を自動化可能 ・手軽(学習コスト低) ・複数の変数の状態を 　まとめて確認可能 ・手動のデバッガ操作 　よりも高速 🤔 ・単一の状態でしか情報 　を取得できない ・単一の状態でしか情報 　を取得できない ・ビルド時のフラグを 　設定する必要がある ・ログの埋め込み/ 　消し忘れが起き得る ・実行速度の低下 6
7. Delve: Goに特化したサードパーティー製のデバッガ 目標 ・Go用のシンプルでフル機能を備えたデバッグツールの提供 Delveが適する場面 ・ビルドされたGoプログラムをデバッグする場合の大半 ・Goのランタイムやデータ構造、式を理解しているため 実装 ・github.com/go-delve/delve 7
8. Goクイズ: 次のプログラム実行時に表示されるのは？🤔 package main import "fmt" type T struct{ N int } func main() { ts := []T{{N: 1}, {N: 3}, {N: 5}} minT := &T{N: 10000} for _, t := range ts { if t.N < minT.N { minT = &t } } fmt.Println(minT.N) } 8 1⃣ 1 2⃣ 5 3⃣ 10000 4⃣ 未定義 Playground: go.dev/play/p/rkeWSeUx4pm
9. Goクイズ: 次のプログラム実行時に表示されるのは？🤔 package main import "fmt" type T struct{ N int } func main() { ts := []T{{N: 1}, {N: 3}, {N: 5}} minT := &T{N: 10000} for _, t := range ts { if t.N < minT.N { minT = &t } } fmt.Println(minT.N) } 9 1⃣ 1 2⃣ 5 3⃣ 10000 4⃣ 未定義 Playground: go.dev/play/p/rkeWSeUx4pm
10. GDB: Goに限らず普遍的に使えるデバッガ 用途 ・プログラム実行中の内部情報の把握 ・クラッシュした際のメモリやスタックの状態の把握 GDBが適する場面 ・Cgoコードやランタイム自体のデバッグをする場合 参考リンク ・https://sourceware.org/git/binutils-gdb.git ・https://go.dev/doc/gdb 10
11. GDB: 低レイヤのデバッグ 拡張スクリプト ・Go用拡張: go/src/runtime/runtime-gdb.py ・peda: https://github.com/longld/peda ・gef: https://github.com/hugsy/gef 11
12. ロギング: プログラムの変数等の情報出力 ロギングが適する場面 ・複数の変数情報を手軽にまとめて出力したい場合 利用できるもの ・builtin関数のpanic, print, println ・fmt, log, x/exp/slog ・glog, logrus, zap ・logr.Logger interface 12
13. 3種類のデバッグ方法 Delve GDB ロギング 👍 ・大半のGoプログラム 　のデバッグに利用可能 ・Goに特化しており、 　GDBよりも正確な結果 　が得られる ・Cgoやランタイムの 　デバッグに利用可能 ・機能拡張が豊富 ・Pythonスクリプトで 　処理を自動化可能 ・手軽(学習コスト低) ・複数の変数の状態を 　まとめて確認可能 ・手動のデバッガ操作 　よりも高速 🤔 ・単一の状態でしか情報 　を取得できない ・単一の状態でしか情報 　を取得できない ・ビルド時のフラグを 　設定する必要がある ・ログの埋め込み/ 　消し忘れが起き得る ・実行速度の低下 13
14. 3種類のデバッグ方法 Delve GDB ロギング 👍 ・大半のGoプログラム 　のデバッグに利用可能 ・Goに特化しており、 　GDBよりも正確な結果 　が得られる ・Cgoやランタイムの 　デバッグに利用可能 ・機能拡張が豊富 ・Pythonスクリプトで 　処理を自動化可能 ・手軽(学習コスト低) ・複数の変数の状態を 　まとめて確認可能 ・手動のデバッガ操作 　よりも高速 🤔 ・単一の状態でしか情報 　を取得できない ・単一の状態でしか情報 　を取得できない ・ビルド時のフラグを 　設定する必要がある ・ログの埋め込み/ 　消し忘れが起き得る ・実行速度の低下 14
15. こんな経験はありませんか？ ・テストがうまく動かない... ・プログラムが謎の挙動をする → ログを仕込む！ ・対象変数の値は何？ 　log.Printf(“%#v”, targetVariable) ・対象変数の型は何？ 　log.Printf(“%T”, targetVariable) ・そもそも、その箇所は実行されている？ 　log.Printf(“passed!”) → 仕込んだログを消し忘れて commit & push (& release)... 15
16. 人はデバッグ時に余計なことを考えたくない ・デバッグ後、ログを仕込んだ場所を忘れがち →コミット時にロギング部分を全て消すロガーを開発すれば 　良いのでは？🤔 16
17. デバッグ用ロガーのdlを開発しました 仕組み ・コミット前後のGit Hooksでロギング部分を削除・復元 ・ロガーの削除・復元はGoの静的解析により実現 実装 ・https://github.com/task4233/dl 紹介記事 ・Git にコミットされない魔法のデバッグ用ロガーを開発 　してきた - Qiita 17
18. バグらせずにロガー部分を削除する技術 静的解析をする ・プログラムを実行せずにGoのコードを解析すること ・詳しくは tenntennさんの14. 静的解析とコード生成 に 字句解析→構文解析→型チェックの順に行われる ・今回、型情報は必要ないので構文解析のフェーズまで(コード) ・構文解析までするとAST(抽象構文木)が得られる ・型チェックまですると型情報が得られる 18
19. AST(抽象構文木)とは 言語の意味に関係のある情報のみを取り出した木 ・return 1, nil は Return Statements 19 ReturnStmt Expr (1) Expr (nil) Results ＝
20. dlで利用されているgoパッケージと用途 20 パッケージ名 用途 該当部分 go/token 字句解析(Go Code→tokens) コード go/parser 構文解析(tokens→AST) コード (x/tools/) go/ast ASTの関連操作 コード go/format AST操作後の整形 コード
21. ASTからロガーの呼び出しを削除するために 言語仕様に沿って呼び出され得る箇所を考える ・ロガーの定義は func Info[T any](v T) (int, error) 　→Expression Expressionが入る場所は？ ・Expression Statements(例: dl.Info(1) ) ・Assignment Statements(例: n, err := dl.Info(1) ) ・Return Statements(例: return dl.Info(1) ) など 21
22. ASTからロガーの呼び出しを削除するために 該当部分をASTから発見する ・Expression Statementsを見つけたい時は以下のように ・見つけた後に、該当部分を削除する 22
23. まとめ 3種類のデバッグ方法(Delve, GDB, ロギング) ・得手不得手がある ・目的にあった方法を選択できると良い goパッケージ(go/ast, go/tokenなど) ・静的解析のためのパッケージ ・ASTや型情報等を得ることができる ・興味のある方はツール自作も！ 23 ありがとうございました！