📋 Goのユニットテストのログを綺麗に保つ方法：失敗した入力のみをログ出力する 🔗

Goでユニットテスト（特にテーブル駆動テスト）を書く際、標準のグローバルな log パッケージに出力を行う関数があると、ターミナルがあっという間に散らかってしまいます。

10個以上のテストケースがあり、そのうち1つだけが失敗した場合でも、エラーを見つけるために成功したすべてのケースのログ出力をスクロールしなければなりません。このノイズはデバッグを遅らせ、テスト結果の可読性を大きく損ないます。

よくあるシナリオを見ていきながら、ログをキャプチャしてテストが失敗したときだけ出力するように改善する方法を確認しましょう。

📑 目次 🔗

🔊 問題点：ノイズの多いテスト出力 🔗

例えば、入力値と最終的な計算結果をログに出力するシンプルな関数があるとします。

package add

import (
	"log"
)

func add(x, y int) int {
	log.Printf("add %d %d", x, y)
	res := x + y
	log.Printf("add %d %d = %d", x, y, res)
	return res
}

ここで、3つのケースを持つ標準的なテーブル駆動ユニットテストを書きます（最後の1つは意図的に失敗するように設計しています）。

package add

import (
	"testing"
)

func TestAdd(t *testing.T) {
	inputs := []struct {
		x    int
		y    int
		want int
	}{
		{x: 1, y: 2, want: 3},
		{x: 3, y: 2, want: 5},
		{x: 4, y: 5, want: 0}, // Intentionally failing case
	}

	for _, in := range inputs {
		got := add(in.x, in.y)
		if in.want != got {
			t.Errorf("add %d %d got %d want %d", in.x, in.y, got, in.want)
		}
	}
}

go test を実行すると、最後に失敗が表示される前に、成功したすべての入力のログが出力されてしまいます。

$ go test
2020/09/05 09:01:25 add 1 2
2020/09/05 09:01:25 add 1 2 = 3
2020/09/05 09:01:25 add 3 2
2020/09/05 09:01:25 add 3 2 = 5
2020/09/05 09:01:25 add 4 5
2020/09/05 09:01:25 add 4 5 = 9
--- FAIL: TestAdd (0.00s)
    add_test.go:28: add 4 5 got 9 want 0
FAIL
exit status 1

🛠️ 解決策：依存性の注入（DI）とバッファ 🔗

失敗した入力によって生成されたログだけを確認できれば、はるかに見やすくなります。これは、関数にロガーを渡し（依存性の注入）、テスト中はログを一時的なバッファに書き込むことで実現できます。

まず、*log.Logger を受け取るように関数を更新しましょう。

package add

import "log"

func add(logger *log.Logger, x, y int) int {
	logger.Printf("add %d %d", x, y)
	res := x + y
	logger.Printf("add %d %d = %d", x, y, res)
	return res
}

次に、テストを更新します。テストケースのループごとに新しい bytes.Buffer を作成し、そこに新しいロガーを紐付けます。テストが成功すれば、バッファはそのまま破棄されます。テストが失敗した場合のみ、エラーメッセージと一緒にバッファの内容を出力します！

(注：Goでテーブル駆動のサブテストを実行する際のイディオムである t.Run を使うようにテストもアップグレードしています)。

package add

import (
	"bytes"
	"log"
	"testing"
)

func TestAdd(t *testing.T) {
	inputs := []struct {
		name string
		x    int
		y    int
		want int
	}{
		{name: "1+2", x: 1, y: 2, want: 3},
		{name: "3+2", x: 3, y: 2, want: 5},
		{name: "4+5", x: 4, y: 5, want: 0}, // Intentionally failing case
	}

	for _, in := range inputs {
		t.Run(in.name, func(t *testing.T) {
			// 1. Create a buffer to capture the logs
			var buf bytes.Buffer
			
			// 2. Create a new logger that writes to the buffer
			logger := log.New(&buf, "", log.LstdFlags)
			
			// 3. Pass the custom logger into our function
			got := add(logger, in.x, in.y)
			
			if in.want != got {
				// 4. Print the buffer contents ONLY if the test fails
				t.Errorf("got %d want %d\n\nExecution Logs:\n%s", got, in.want, buf.String())
			}
		})
	}
}

✨ クリーンな出力結果 🔗

これでテストを実行すると、出力は驚くほどクリーンになり、次のアクションが明確になります。失敗に関連するログだけが表示されます。

$ go test
--- FAIL: TestAdd (0.00s)
    --- FAIL: TestAdd/4+5 (0.00s)
        add_test.go:35: got 9 want 0
            
            Execution Logs:
            2020/09/05 09:22:48 add 4 5
            2020/09/05 09:22:48 add 4 5 = 9
            
FAIL
exit status 1

関数をグローバルロガーから切り離すことで、コードの柔軟性が高まり、テストスイートは静かになり、デバッグの速度が劇的に向上します。

📚 無料電子書籍をダウンロード 🔗

カウエの生き方のオフライン版を入手しましょう——🍏 健康、💰 富、❤️ 愛、🧘 意味を最適化するための実践ガイドです。

📬 ニュースレターを購読する 🔗

新しいエッセイ、本の要約、より良く生きるための実践ガイドを公開した際にお知らせします。スパムはありません——いつでも配信停止できます。

💬 コメントとディスカッション 🔗

質問、ご意見、提案はありますか？ぜひ下であなたの考えを共有してください。コメント欄は GitHub Discussions（広告なし・スパムなし）を利用しています——下の GitHub でサインイン をクリックしてコメントやリアクションを残してください（無料の GitHub アカウントは1分未満で作成できます）。

免責事項：当サイトのコンテンツは情報提供および教育のみを目的としており、医療、心理、金融、投資、税務、または法律上の助言を構成するものではありません。ここに掲載されている考え、キュレーション、意見はすべて私個人のものであり、雇用主の見解を代表するものではありません。書籍、講演、記事の要約は独立した教育的な解説であり、それぞれの著者の知的財産です。編集、フォーマット、要約の補助としてAIツールを使用する場合がありますが、正確性を期すよう努めているものの誤りが含まれる可能性があります。プライバシー：当サイトでは、任意のニュースレター購読（follow.it）、コメント機能（giscus / GitHub Discussions）、および埋め込みメディア（YouTube）に外部サービスを利用しており、これらのサービスはそれぞれのプライバシーポリシーに従って訪問者のIPアドレスやCookieを処理する場合があります。