[インデックス 17952] ファイルの概要

このコミットは、Go言語のテスト実行ツールである test/run.go の出力を、標準の go test -v コマンドの出力形式に合わせるための変更です。これにより、テスト結果、特に各テストの実行時間をより視覚的に把握しやすくなり、パフォーマンスのボトルネックを特定するのに役立ちます。

コミット

commit de8549dfd36bc46ca9c10903dad6e504e1444a86
Author: Russ Cox <rsc@golang.org>
Date:   Tue Dec 10 14:02:42 2013 -0500

    test/run: make -v output look like go test output

    Among other things, it makes it easier to scan to
    see what is slow.

    R=golang-dev, bradfitz
    CC=golang-dev
    https://golang.org/cl/40040044

GitHub上でのコミットページへのリンク

https://github.com/golang/go/commit/de8549dfd36bc46ca9c10903dad6e504e1444a86

元コミット内容

test/run: make -v output look like go test output

このコミットは、test/run ツールが生成する詳細な（-v フラグによる）出力を、Go言語の標準テストコマンド go test -v の出力形式に合わせることを目的としています。これにより、特に実行時間の長いテストを特定しやすくなります。

変更の背景

Go言語のプロジェクトでは、標準の go test コマンドがテストの実行と結果の表示に広く使われています。go test -v オプションを使用すると、各テストの実行状況と完了ステータス、そして実行時間が詳細に表示されます。この形式は、開発者がテストの進捗を追跡し、特に実行に時間がかかっているテスト（いわゆる「遅いテスト」）を特定する上で非常に有用です。

test/run.go は、Goプロジェクト自体のテストスイートを実行するためのカスタムツールであると考えられます。標準の go test とは異なる独自の出力形式を持っていたため、テスト結果の分析や、パフォーマンスのボトルネック特定において、標準ツールとの一貫性が欠けていました。

このコミットの背景には、test/run.go の出力を go test -v の出力形式に統一することで、開発者が慣れ親しんだ形式でテスト結果を効率的に分析できるようにするという意図があります。特に、各テストの実行時間を明確に表示することで、どのテストが遅いのかを一目で把握できるようにし、テストスイート全体のパフォーマンス改善に繋げることが狙いです。

前提知識の解説

`go test` コマンドと `-v` オプション

go test はGo言語に組み込まれているテスト実行ツールです。Goのソースコード内に記述されたテスト関数（TestXxx という命名規則に従う関数）を自動的に発見し、実行します。

go test (通常モード): デフォルトでは、各パッケージのテストが成功したか失敗したかの概要のみを表示します。失敗したテストについては詳細なエラーメッセージが表示されますが、成功した個々のテストについては表示されません。
go test -v (verboseモード): -v (verbose) フラグを付けると、より詳細な出力が得られます。このモードでは、各テスト関数が実行されるたびにその名前とステータス（PASS または FAIL）、そして実行にかかった時間が表示されます。この詳細な出力は、テストの進行状況をリアルタイムで確認したり、特定のテストがなぜ遅いのか、あるいはなぜ失敗したのかをデバッグする際に非常に役立ちます。

go test -v の典型的な出力形式は以下のようになります。

=== RUN   TestExample
--- PASS: TestExample (0.00s)
=== RUN   TestAnother
--- FAIL: TestAnother (0.01s)
    example_test.go:10: Some error message
PASS
ok      example_package 0.020s

このコミットは、test/run.go というカスタムテストランナーが、この go test -v の出力形式を模倣するように変更するものです。

`test/run.go` の役割

test/run.go は、Go言語の標準ライブラリやツールチェーン自体のテストを実行するために使われる、Goプロジェクト内部のカスタムテストハーネスです。これは、通常の go test コマンドではカバーしきれない、より複雑なテストシナリオや、特定の環境設定が必要なテストを実行するために設計されています。

このファイルは、Goのソースツリーの test/ ディレクトリに存在し、GoのビルドシステムやCI/CDパイプラインの一部として利用されます。このツールは、Goの様々なコンポーネント（コンパイラ、ランタイム、標準ライブラリなど）に対する広範なテストスイートを実行し、その結果を収集・報告する役割を担っています。

このコミット以前は、test/run.go の出力形式が go test -v とは異なっていたため、開発者は異なる出力形式に慣れる必要がありました。この変更により、Goプロジェクトのテスト結果の可読性と分析効率が向上します。

技術的詳細

このコミットの技術的な変更は、主に test/run.go ファイル内のテスト結果の処理と出力ロジックに集中しています。

time パッケージのインポート:
- テストの実行時間を計測するために、Goの標準ライブラリである time パッケージが新しくインポートされました。
test 構造体への dt フィールド追加:
- 各テストの実行時間を保持するために、test 構造体に dt time.Duration という新しいフィールドが追加されました。time.Duration 型は、時間の長さをナノ秒単位で表す型で、Goで時間計測を行う際によく使用されます。
test.run() メソッドでの時間計測:
- test 構造体の run() メソッドは、個々のテストを実行するロジックを含んでいます。このメソッドの冒頭で start := time.Now() を呼び出してテスト開始時刻を記録し、defer 関数内で t.dt = time.Since(start) を呼び出してテストの実行時間を計算し、dt フィールドに格納するように変更されました。defer を使用することで、run() メソッドが終了する直前（エラーが発生した場合でも）に必ず実行時間が記録されることが保証されます。
main() 関数での出力ロジックの変更:
- main() 関数内のテスト結果を処理するループが大幅に変更されました。
- ステータス管理の導入: 各テストのステータスを status 変数（"ok ", "skip", "FAIL"）で管理するようになりました。これにより、出力形式をより細かく制御できるようになります。
- スキップされたテストの扱い: スキップされたテスト (skipError) の処理が改善され、予期せぬスキップの場合には FAIL ステータスとして扱われるようになりました。また、スキップされたテストの出力は、go test -v と同様に、特定の条件（*verbose または *showSkips が設定されていない場合）で抑制されるようになりました。
- エラー文字列とステータスの分離: 以前は errStr でエラーとスキップの両方の状態を表現していましたが、status 変数と errStr を分離することで、より明確な状態管理が可能になりました。
- 実行時間のフォーマット: dt := fmt.Sprintf("%.3fs", test.dt.Seconds()) を使用して、実行時間を小数点以下3桁までの秒数形式（例: 0.123s）にフォーマットするようになりました。これは go test -v の出力形式と一致します。
- 出力形式の統一:
  - 失敗したテスト (FAIL): go test が失敗したテストに対して出力する形式（# go run run.go -- <test_path>\n<error_message>\nFAIL\t<test_name>\t<duration>）に合わせるように fmt.Printf の呼び出しが変更されました。
  - 成功したテスト (ok) およびスキップされたテスト (skip): go test -v が成功したテストやスキップされたテストに対して出力する形式（<status>\t<test_name>\t<duration>）に合わせるように fmt.Printf の呼び出しが変更されました。これにより、各テストのステータス、名前、実行時間がタブ区切りで表示されるようになります。

これらの変更により、test/run.go の出力は、標準の go test -v コマンドの出力と視覚的にほぼ同じになり、開発者がテスト結果をより効率的に分析できるようになりました。特に、実行時間の表示は、テストスイートのパフォーマンスプロファイリングに直接貢献します。

コアとなるコードの変更箇所

--- a/test/run.go
+++ b/test/run.go
@@ -27,6 +27,7 @@ import (
 	"sort"
 	"strconv"
 	"strings"
+"time"
 	"unicode"
 )
 
@@ -114,28 +115,39 @@ func main() {
 	failed := false
 	resCount := map[string]int{}
 	for _, test := range tests {
-		<-test.donec
-		_, isSkip := test.err.(skipError)
-		errStr := "pass"
+		<-test.donec		
+		status := "ok  "
+		errStr := ""
+		if _, isSkip := test.err.(skipError); isSkip {
+			status = "skip"
+			test.err = nil
+			if !skipOkay[path.Join(test.dir, test.gofile)] {
+				errStr = "unexpected skip for " + path.Join(test.dir, test.gofile) + ": " + errStr
+				status = "FAIL"
+			}
+		}
 	if test.err != nil {
+			status = "FAIL"
 		errStr = test.err.Error()
-		if !isSkip {
-			failed = true
-		}
 	}
-	if isSkip && !skipOkay[path.Join(test.dir, test.gofile)] {
-		errStr = "unexpected skip for " + path.Join(test.dir, test.gofile) + ": " + errStr
-		isSkip = false
+	if status == "FAIL" {
 		failed = true
 	}
-	resCount[errStr]++
-	if isSkip && !*verbose && !*showSkips {
+	resCount[status]++
+	if status == "skip" && !*verbose && !*showSkips {
+		continue
+	}
+	dt := fmt.Sprintf("%.3fs", test.dt.Seconds())
+	if status == "FAIL" {
+		fmt.Printf("# go run run.go -- %s\\n%s\\nFAIL\\t%s\\t%s\\n",
+			path.Join(test.dir, test.gofile),
+			errStr, test.goFileName(), dt)
 		continue
 	}
-	if !*verbose && test.err == nil {
+	if !*verbose {
 		continue
 	}
-	fmt.Printf("# go run run.go -- %s\\n%-20s %-20s: %s\\n", path.Join(test.dir, test.gofile), test.action, test.goFileName(), errStr)
+	fmt.Printf("%s\\t%s\\t%s\\n", status, test.goFileName(), dt)
 	}
  
  if *summary {
@@ -207,7 +219,8 @@ func check(err error) {
 type test struct {
 	dir, gofile string
 	donec       chan bool // closed when done
-
+	dt time.Duration
+	
 	src    string
 	action string // "compile", "build", etc.
 
@@ -379,7 +392,11 @@ func init() { checkShouldTest() }\
 
 // run runs a test.
 func (t *test) run() {
-	defer close(t.donec)
+	start := time.Now()
+	defer func() {
+		t.dt = time.Since(start)
+		close(t.donec)
+	}()
 
 	srcBytes, err := ioutil.ReadFile(t.goFileName())
 	if err != nil {

コアとなるコードの解説

このコミットの主要な変更は、test/run.go ファイル内の以下の3つのセクションに集中しています。

import 文の変更:
- import ブロックに time パッケージが追加されました。これは、テストの実行時間を計測するために必要です。
test 構造体の変更:
- type test struct { ... } の定義に、dt time.Duration という新しいフィールドが追加されました。このフィールドは、各テストの実行にかかった時間を time.Duration 型で保持するために使用されます。
test.run() メソッドの変更:
- func (t *test) run() { ... } メソッドは、個々のテストを実行するロジックを含んでいます。
- 以前は defer close(t.donec) のみでしたが、変更後は start := time.Now() でテスト開始時刻を記録し、defer 関数内で t.dt = time.Since(start) を呼び出してテストの実行時間を計算し、t.dt フィールドに格納するように変更されました。これにより、テストが完了した際にその実行時間が正確に記録されるようになります。
main() 関数のテスト結果処理ループの変更:
- func main() { ... } 内の for _, test := range tests { ... } ループが、テスト結果の出力形式を調整するために大幅に修正されました。
- ステータス判定ロジックの変更:
  - 以前は errStr と isSkip で状態を管理していましたが、新しく status 変数（"ok ", "skip", "FAIL"）を導入し、より明確にテストの最終状態を表現するようになりました。
  - スキップされたテスト (skipError) の処理が洗練され、skipOkay マップに基づいて予期せぬスキップを FAIL として扱うロジックが追加されました。
- resCount の集計方法の変更:
  - 以前は resCount[errStr]++ でエラー文字列ごとに集計していましたが、変更後は resCount[status]++ となり、ok, skip, FAIL といったステータスごとに集計するようになりました。
- 出力抑制ロジックの変更:
  - if isSkip && !*verbose && !*showSkips { continue } が if status == "skip" && !*verbose && !*showSkips { continue } に変更され、スキップされたテストの出力抑制が status 変数に基づいて行われるようになりました。
  - if !*verbose && test.err == nil { continue } が if !*verbose { continue } に変更され、verboseモードでない場合の出力抑制が簡略化されました。
- 出力形式の変更:
  - 最も重要な変更は fmt.Printf の呼び出しです。
  - 失敗したテストの場合 (status == "FAIL"):
```
fmt.Printf("# go run run.go -- %s\\n%s\\nFAIL\\t%s\\t%s\\n",
    path.Join(test.dir, test.gofile),
    errStr, test.goFileName(), dt)
```
    この形式は、go test がテスト失敗時に出力する形式を模倣しており、テストのパス、エラーメッセージ、FAIL ステータス、テスト名、そして実行時間を表示します。
  - 成功またはスキップされたテストの場合 (!*verbose でない場合):
```
fmt.Printf("%s\\t%s\\t%s\\n", status, test.goFileName(), dt)
```
    この形式は、go test -v が成功またはスキップされたテストに対して出力する形式を模倣しており、ステータス (ok または skip)、テスト名、そして実行時間をタブ区切りで表示します。dt は fmt.Sprintf("%.3fs", test.dt.Seconds()) によって「0.123s」のような形式にフォーマットされます。

これらの変更により、test/run.go の出力は、標準の go test -v コマンドの出力とほぼ同じになり、開発者がテスト結果をより効率的に分析し、特に実行時間の長いテストを容易に特定できるようになりました。

参考にした情報源リンク

go test -v の出力形式に関するWeb検索結果 (Google Web Search Toolによる)
Go言語のソースコード (特に src/cmd/go/test.go や src/testing/testing.go など、go test の実装に関連するファイル)
Go言語のコミット履歴とコードレビューシステム (Gerrit)

comemo