LoginSignup
17
4

More than 1 year has passed since last update.

@task4233

Git にコミットされない魔法のデバッグ用ロガーを開発してきた

Last updated at Posted at 2022-03-29

こんにちは。taskです。

先日、メルカリ主催の「Online Spring Internship for Gophers 2022」に参加してきました。

このイベントでは、募集要項に書かれている通り、Go1.18で新しく入る型パラメタ（ジェネリクス）、Fuzzing、Workspaceについて学んだ上で、参加者各自がGo1.18の新機能を用いたツールを開発しました。

私はそこでアイデアや設計などのサポートをしていただき、Git にコミットされないデバッグ用ロガーである dl を開発しました。この記事では開発の背景や使い方、仕組みについて紹介します。

このロガーの特徴は以下の3つです。

  1. Git にコミットされないGoのデバッグ用ロガー
  2. 既存の logr.Logger 構造体も利用可能
  3. 1コマンドで環境構築可能

デモ動画もあるので貼っておきます。

delog_ja

開発した経緯

開発の発端は、冒頭でも触れたメルカリの短期インターンシップでした。その過程で静的解析について知見が得られたため、今回のロガーの開発に至りました。

このロガーの目的は、デバッグログの消し忘れを機械的に無くすことです。

そもそも、開発者は想定外の挙動に出くわした時にデバッグのために次のようなログを仕込むことが多いと思います。

目的 仕込まれるログ
対象変数の値を確認するため fmt.Fprintf(os.Stderr, "%#v\n", targetVariable)
対象変数の型を確認するため fmt.Fprintf(os.Stderr, "%T\n", targetVariable)
その箇所は実行されているか確認するため fmt.Fprintf(os.Stderr, "passed!")

しかし、こういったログを仕込んで当初の問題を解決してから、仕込んだログを消し忘れてコミットした経験がある方もいるのではないでしょうか？最悪の場合、そのコードがリリースされることすらあります。

開発者がこのようなヒューマンエラーを減らすことはできても撲滅することは難しいと考え、この問題を機械の力で解決しようと考えました。

使い方

dl は Go1.17 以下のバージョン用(v1)と Go1.18 以上のバージョン用(v2)の2つを提供しています。これらの違いは、ジェネリクスを使っているか否かです。とはいえ、大半のユースケースが logr.Logger の機能を使うと思っているので、Go1.17以下でも困ることはあまりないと思います。

インストール方法は下記の通り、たった1つのコマンドで完了します。

Go <=1.17

go install github.com/task4233/dl/cmd/dl@v1
dl init .

Go 1.18+

go install github.com/task4233/dl/v2/cmd/dl@main
dl init .

あとは、何も考えずに開発するだけです。Git にコミットする時には対象のログがコミットから消えています。

logr.Logger の導入

最近は Go のためのロガーとして logr を採用している開発者も多いのではないでしょうか？

冒頭に書いた通り、dl は logr の宣言時に一緒に dl.NewLogger を呼び出すことで手軽に導入できます。サンプルとして、logr に対応している zapr を dl 導入する例を置いておきます。

Playground

package main

import (
	"fmt"

	"github.com/go-logr/logr"
	"github.com/go-logr/zapr"
	"go.uber.org/zap"

	"github.com/task4233/dl/v2"
)

func main() {
	// 既存の zapr 用設定
	// ref: https://github.com/go-logr/zapr#usage
	var log logr.Logger

	zapLog, err := zap.NewDevelopment()
	if err != nil {
		panic(fmt.Sprintf("who watches the watchmen (%v)?", err))
	}
	log = zapr.NewLogger(zapLog)

	log.Info("Logr in action!", "the answer", 42)

	// dl に導入する
	// ref: https://pkg.go.dev/github.com/task4233/dl/v2#NewLogger
	dl := dl.NewLogger(&log)
	dl.Info("コミットされないログ", "the answer", 42)

	// Output:
	// 2009-11-10T23:00:00.000Z	INFO	sandbox2860739875/prog.go:24	Logr in action!	{"the answer": 42}
	// 2009-11-10T23:00:00.000Z	INFO	sandbox2860739875/prog.go:29	コミットされないログ	{"the answer": 42}
}

dl の内部構造

dl は、Git Hooks と Go の 構文解析ツールを利用して、コミット前にロガーの記述を全て削除し、コミット後に元のファイルを復元することで実現されています。

コミット時の処理の流れは以下の通りです。

  1. 開発者が $ git commit を実行する
  2. .git/hooks/pre-commit に書かれた $ dl clean によって、既存プログラムの一時保存とdlに関する記述記述削除が行われる
  3. dlに関する記述が削除されたファイルがコミットされる
  4. .git/hooks/post-commit に書かれた $ dl restore によって、dlに関する記述が削除される前のファイルが復元される

この流れから分かる通り、 .git/hooks/pre-commit はコミット前に、 .git/hooks/post-commit はコミット後に実行されるスクリプトです。このスクリプトによって、コミットされないロガーが実現されています。

Git Hooks に関しては、公式のドキュメントが参考になりました。

ここからは、更にロガーの記述が削除される仕組みについて深堀りしていきます。

削除機構と静的解析

ロガーの記述削除には、Go の静的解析の機能を利用しています。

「えっ、別にプログラム内で文字列検索して該当箇所を削除すれば良くない？」などと思った方がいるかもしれません。しかし、文字列検索して削除する方法ではログが削除されてからコミットされたプログラムが正常に動作しなくなる可能性があるのでダメです。その点で静的解析は優秀で、 Decl を丸ごと削除することで文法的に問題のないブロックの消し方をしてくれます。

嬉しいことに Go は静的解析に必要なライブラリを言語側が提供しているので、それを利用します。詳しくは、tenntenn さんのスライドをご覧ください。

こちらに書かれているように静的解析のフェーズは、

  • 構文解析
  • 型チェック
  • 静的単一代入形式(SSA)
  • ポインタ解析

などがあり、これらは目的に応じて使い分ける必要があります。

例えば、Go1.18 で話題に上がっているジェネリクスに関する型推論結果を得たい場合、2つ目の型チェックで取得することができます。逆にいえば、1つ目の構文解析のみでは型推論に関する情報は得ることができません。

今回の目的はロガーを削除することなので、一部のエッジケースを除き構文解析のみで事足ります。そのため、構文解析に必要な

  • go/ast パッケージ
  • go/parser パッケージ
  • go/format パッケージ
  • x/tools/go/ast/astutil パッケージ

あたりを利用します。

構文解析をするときに重要な概念が、言語の意味に関係ない情報を取り除き、意味に関係ある情報のみを抽象した木構造であるAST(Abstract Syntax Tree): 抽象構文木です。詳しくは、tenntennさんのスライドを参照してください。

Go の go/ast パッケージはこの木を表現するためのパッケージです。下記の通り、 go/parser パッケージの関数を用いて AST を取得することができます。

Playground

     0  *ast.File {
     1  .  Package: 1:1
     2  .  Name: *ast.Ident {
     3  .  .  NamePos: 1:9
     4  .  .  Name: "greeting"
     5  .  }
     6  .  Decls: []ast.Decl (len = 2) {
     7  .  .  0: *ast.GenDecl {
     8  .  .  .  TokPos: 3:1
     9  .  .  .  Tok: import
    10  .  .  .  Lparen: -
    11  .  .  .  Specs: []ast.Spec (len = 1) {
    12  .  .  .  .  0: *ast.ImportSpec {
    13  .  .  .  .  .  Path: *ast.BasicLit {
    14  .  .  .  .  .  .  ValuePos: 3:8
    15  .  .  .  .  .  .  Kind: STRING
    16  .  .  .  .  .  .  Value: "\"fmt\""
    17  .  .  .  .  .  }
    18  .  .  .  .  .  EndPos: -
    19  .  .  .  .  }
    20  .  .  .  }
    21  .  .  .  Rparen: -
    22  .  .  }
    23  .  .  1: *ast.FuncDecl {
    24  .  .  .  Name: *ast.Ident {
    25  .  .  .  .  NamePos: 5:6
    26  .  .  .  .  Name: "Hi"
    27  .  .  .  .  Obj: *ast.Object {
    28  .  .  .  .  .  Kind: func
    29  .  .  .  .  .  Name: "Hi"
    30  .  .  .  .  .  Decl: *(obj @ 23)
    31  .  .  .  .  }
    32  .  .  .  }
    33  .  .  .  Type: *ast.FuncType {
    34  .  .  .  .  Func: 5:1
    35  .  .  .  .  Params: *ast.FieldList {
    36  .  .  .  .  .  Opening: 5:8
    37  .  .  .  .  .  List: []*ast.Field (len = 1) {
    38  .  .  .  .  .  .  0: *ast.Field {
    39  .  .  .  .  .  .  .  Names: []*ast.Ident (len = 1) {
    40  .  .  .  .  .  .  .  .  0: *ast.Ident {
    41  .  .  .  .  .  .  .  .  .  NamePos: 5:9
    42  .  .  .  .  .  .  .  .  .  Name: "name"
    43  .  .  .  .  .  .  .  .  .  Obj: *ast.Object {
    44  .  .  .  .  .  .  .  .  .  .  Kind: var
    45  .  .  .  .  .  .  .  .  .  .  Name: "name"
    46  .  .  .  .  .  .  .  .  .  .  Decl: *(obj @ 38)
    47  .  .  .  .  .  .  .  .  .  }
    48  .  .  .  .  .  .  .  .  }
    49  .  .  .  .  .  .  .  }
    50  .  .  .  .  .  .  .  Type: *ast.Ident {
    51  .  .  .  .  .  .  .  .  NamePos: 5:14
    52  .  .  .  .  .  .  .  .  Name: "string"
    53  .  .  .  .  .  .  .  }
    54  .  .  .  .  .  .  }
    55  .  .  .  .  .  }
    56  .  .  .  .  .  Closing: 5:20
    57  .  .  .  .  }
    58  .  .  .  }
    59  .  .  .  Body: *ast.BlockStmt {
    60  .  .  .  .  Lbrace: 5:22
    61  .  .  .  .  List: []ast.Stmt (len = 1) {
    62  .  .  .  .  .  0: *ast.ExprStmt {
    63  .  .  .  .  .  .  X: *ast.CallExpr {
    64  .  .  .  .  .  .  .  Fun: *ast.SelectorExpr {
    65  .  .  .  .  .  .  .  .  X: *ast.Ident {
    66  .  .  .  .  .  .  .  .  .  NamePos: 6:2
    67  .  .  .  .  .  .  .  .  .  Name: "fmt"
    68  .  .  .  .  .  .  .  .  }
    69  .  .  .  .  .  .  .  .  Sel: *ast.Ident {
    70  .  .  .  .  .  .  .  .  .  NamePos: 6:6
    71  .  .  .  .  .  .  .  .  .  Name: "Printf"
    72  .  .  .  .  .  .  .  .  }
    73  .  .  .  .  .  .  .  }
    74  .  .  .  .  .  .  .  Lparen: 6:12
    75  .  .  .  .  .  .  .  Args: []ast.Expr (len = 2) {
    76  .  .  .  .  .  .  .  .  0: *ast.BasicLit {
    77  .  .  .  .  .  .  .  .  .  ValuePos: 6:13
    78  .  .  .  .  .  .  .  .  .  Kind: STRING
    79  .  .  .  .  .  .  .  .  .  Value: "\"Hi, %s\\n\""
    80  .  .  .  .  .  .  .  .  }
    81  .  .  .  .  .  .  .  .  1: *ast.Ident {
    82  .  .  .  .  .  .  .  .  .  NamePos: 6:25
    83  .  .  .  .  .  .  .  .  .  Name: "name"
    84  .  .  .  .  .  .  .  .  .  Obj: *(obj @ 43)
    85  .  .  .  .  .  .  .  .  }
    86  .  .  .  .  .  .  .  }
    87  .  .  .  .  .  .  .  Ellipsis: -
    88  .  .  .  .  .  .  .  Rparen: 6:29
    89  .  .  .  .  .  .  }
    90  .  .  .  .  .  }
    91  .  .  .  .  }
    92  .  .  .  .  Rbrace: 7:1
    93  .  .  .  }
    94  .  .  }
    95  .  }
    96  .  Scope: *ast.Scope {
    97  .  .  Objects: map[string]*ast.Object (len = 1) {
    98  .  .  .  "Hi": *(obj @ 27)
    99  .  .  }
   100  .  }
   101  .  Imports: []*ast.ImportSpec (len = 1) {
   102  .  .  0: *(obj @ 12)
   103  .  }
   104  .  Unresolved: []*ast.Ident (len = 2) {
   105  .  .  0: *(obj @ 50)
   106  .  .  1: *(obj @ 65)
   107  .  }
   108  }

今回のツールにおける目的は、import 文の削除と dl パッケージを利用している関数呼び出し削除の2つです。これらはいずれも Decls に含まれており、対象の decl を除去すれば良いです。

ただし、何も考えずに対象の decl をスライスから除去してしまうと、コメントの位置がおかしくなるという問題がありました。

そこで、Stack Overflow の回答にあるように astutil を利用することで解決しました。

おわりに

今回は、メルカリの「Online Spring Internship for Gophers 2022」に参加して、デバッグ用途に特化したロガーを開発してみました。開発に至るまでの議論やフィードバックについて、tenntennさんはじめ、他のメンターさんと参加者、そして友人に助力いただきました。本当にありがとうございました！

そして、今回のロガーは導入のしやすさも意識して作ったので、よかったらぜひ使ってみてください！
GitHub および GoDoc に利用例も載っているので、使い方に困ることはないと思います。
そして、もしよければ Star もください :bow:

また、エッジケース的なバグも潜んでいると思うので、もしバグが起きた場合は GitHub Issue や Twitter で報告していただけると非常にありがたいです :pray:

17
4
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
17
4