概要

go test -json(および go tool test2json)が出力する "Action":"output" イベントに、
任意の新フィールド "OutputType" が追加された。値は次のいずれかを取る。

• error — (*testing.T).Error/Errorf/Fatal/Fatalf が出力したテキストの先頭行
• error-continue — その直前の error 行に続く、同一エラーの継続行
• frame — === RUN や --- FAIL: のようなテスト実行フレーミング行(既に他のイベントでより直接的に表現されている)
• (空文字列) — 上記に当てはまらない通常の出力(t.Log など)

これにより、CI システムがテスト失敗のサマリーを構築する際に、大量のログ出力の中から
本当に重要な失敗理由(t.Error/t.Fatal が出した行)だけを機械的に取り出せるようになる。
詳細はcmd/test2json helpを参照。

導入経緯

golang/go#62728 で提案された。提案の動機は、
go test -json の出力だけでは (*testing.T).Error{,f}/Fatal{,f} によるログと、それ以外の
一般的なログ出力(t.Log など)を区別できず、LUCI のような CI システムがテスト失敗の
サマリーを構築しにくいという課題だった。「失敗直前の最後の行を使う」といったヒューリスティックは、
t.Error の後にさらにログが続くケースや、クラッシュ・パニックでスタックトレースが最後に
出力されるケースで信頼できないことが指摘された。

議論では、当初提案されていた真偽値フィールド "Error" の代わりに、フレーミング行も含めて
種別を表現できる文字列フィールド "OutputType"(error/error-continue/frame)へと設計が
発展した。また、エラーテキストの区切りに使う新しい制御文字(既存のフレーミング用マーカー
^V (0x16) に加えて ^O/^N)の選定や、それらのマーカー自体がテスト出力中に現れた場合の
エスケープ方法についても議論された。ランタイムパニックやクラッシュの扱いについては議論の末、
「testing パッケージ自身が recover して re-panic するケースのみ error としてタグ付けし、
プロセスをクラッシュさせる他 goroutine のパニックまでは対象にしない」という方針で決着した。
提案は 2023-09 に proposal review meeting の active 入りし、その後 likely accept を経て accepted
となった。

議論のハイライト

• 当初案の真偽値 "Error" フィールドから、フレーミング行も表現できる "OutputType" 文字列
  フィールド(error/error-continue/frame)への設計変更が提案・合意された。
• エラー区切りの制御文字は ^N(shift out)/^O(shift in)が候補に挙がったが、実装では
  最終的に ^O を開始・^N を終了マーカーとして採用し、^[(escape)でマーカー文字自体の
  エスケープにも対応した。
• 複数回の t.Error 呼び出しをどう区別するかという懸念に対し、それぞれが独立した
  ^O...^N シーケンスとして出力されることで対応する設計になった。
• ランタイムパニック・クラッシュの扱いは議論が分かれたが、testing パッケージが自身で
  recover して re-panic する範囲に限定する方針で決着した。

使用例

go test -json の出力を消費する CI 側のツールを想定した例。

Before

package main

import (
	"bufio"
	"encoding/json"
	"fmt"
	"os"
)

type TestEvent struct {
	Action string
	Test   string
	Output string
}

func main() {
	scanner := bufio.NewScanner(os.Stdin)
	var lastOutput string
	for scanner.Scan() {
		var e TestEvent
		if err := json.Unmarshal(scanner.Bytes(), &e); err != nil {
			continue
		}
		if e.Action == "output" {
			// ヒューリスティック: 失敗直前の最後の行を
			// もっともらしい失敗理由とみなす。
			lastOutput = e.Output
		}
		if e.Action == "fail" {
			fmt.Printf("%s failed, likely reason: %s", e.Test, lastOutput)
		}
	}
}

After

package main

import (
	"bufio"
	"encoding/json"
	"fmt"
	"os"
	"strings"
)

type TestEvent struct {
	Action     string
	Test       string
	Output     string
	OutputType string
}

func main() {
	scanner := bufio.NewScanner(os.Stdin)
	var errText strings.Builder
	for scanner.Scan() {
		var e TestEvent
		if err := json.Unmarshal(scanner.Bytes(), &e); err != nil {
			continue
		}
		if e.Action == "output" && (e.OutputType == "error" || e.OutputType == "error-continue") {
			// t.Error/t.Fatal が出力した行だけを蓄積する。
			errText.WriteString(e.Output)
		}
		if e.Action == "fail" {
			fmt.Printf("%s failed, reason:\n%s", e.Test, errText.String())
			errText.Reset()
		}
	}
}

移行時の注意

OutputType は既存の "output" イベントに追加された任意フィールドであり、既存のフィールド
(Output など)の意味やイベントの並びは変わらない。フィールドを参照しない既存の JSON
コンシューマは変更なしに動作し続ける。

実装解説

cmd/internal/test2json パッケージの Converter.writeOutputEvent
(test2json.go;l=425)
が、出力バイト列中の制御文字 ^O(markErrBegin)/^N(markErrEnd)/^[(markEscape)を
走査し、^O と ^N に挟まれた区間を OutputType: "error" の出力イベントとして、それに続く
同一エラーの後続行(次の ^O が来るまで)を OutputType: "error-continue" として分割して
書き出す。すでにテスト実行フレーミング中(writeFramingで
isFraming がセットされている間)の出力は OutputType: "frame" になる。

送信側の testing パッケージでは、outputWriter.writeLine
(testing.go;l=1255)
が errBegin/errEnd の各行について ^O/^N を前後に付与する。この errBegin/errEnd は
common.log
(testing.go;l=1112)
に渡される isErr 引数に由来し、Error/Errorf/Fatal/Fatalf は isErr=true で、
Log/Logf/Skip/Skipf は isErr=false で c.log を呼び出す
(testing.go;l=1347-1372)。
出力中に既存のマーカー文字が偶然含まれる場合は escapeMarkers
(testing.go;l=1292)
が ^[ でエスケープしてから書き出す。