t.Log()直到测试完成后才会显示,因此如果您试图调试挂起或执行不良的测试,似乎需要使用fmt。
是的:包括Go 1.13(2019年8月)之前都是这样。
这是在golang.org的24929期
Consider the following (silly) automated tests:
func TestFoo(t *testing.T) {
t.Parallel()
for i := 0; i < 15; i++ {
t.Logf("%d", i)
time.Sleep(3 * time.Second)
}
}
func TestBar(t *testing.T) {
t.Parallel()
for i := 0; i < 15; i++ {
t.Logf("%d", i)
time.Sleep(2 * time.Second)
}
}
func TestBaz(t *testing.T) {
t.Parallel()
for i := 0; i < 15; i++ {
t.Logf("%d", i)
time.Sleep(1 * time.Second)
}
}
If I run go test -v, I get no log output until all of TestFoo is done, then no output until all of TestBar is done, and again no more output until all of TestBaz is done.
This is fine if the tests are working, but if there is some sort of bug, there are a few cases where buffering log output is problematic:
When iterating locally, I want to be able to make a change, run my tests, see what's happening in the logs immediately to understand what's going on, hit CTRL+C to shut the test down early if necessary, make another change, re-run the tests, and so on.
If TestFoo is slow (e.g., it's an integration test), I get no log output until the very end of the test. This significantly slows down iteration.
If TestFoo has a bug that causes it to hang and never complete, I'd get no log output whatsoever. In these cases, t.Log and t.Logf are of no use at all.
This makes debugging very difficult.
Moreover, not only do I get no log output, but if the test hangs too long, either the Go test timeout kills the test after 10 minutes, or if I increase that timeout, many CI servers will also kill off tests if there is no log output after a certain amount of time (e.g., 10 minutes in CircleCI).
So now my tests are killed and I have nothing in the logs to tell me what happened.
但(可能)Go 1.14(2020年Q1): CL 127120
测试:流日志输出在详细模式
现在的输出是:
=== RUN TestFoo
=== PAUSE TestFoo
=== RUN TestBar
=== PAUSE TestBar
=== RUN TestBaz
=== PAUSE TestBaz
=== CONT TestFoo
=== CONT TestBaz
main_test.go:30: 0
=== CONT TestFoo
main_test.go:12: 0
=== CONT TestBar
main_test.go:21: 0
=== CONT TestBaz
main_test.go:30: 1
main_test.go:30: 2
=== CONT TestBar
main_test.go:21: 1
=== CONT TestFoo
main_test.go:12: 1
=== CONT TestBaz
main_test.go:30: 3
main_test.go:30: 4
=== CONT TestBar
main_test.go:21: 2
=== CONT TestBaz
main_test.go:30: 5
=== CONT TestFoo
main_test.go:12: 2
=== CONT TestBar
main_test.go:21: 3
=== CONT TestBaz
main_test.go:30: 6
main_test.go:30: 7
=== CONT TestBar
main_test.go:21: 4
=== CONT TestBaz
main_test.go:30: 8
=== CONT TestFoo
main_test.go:12: 3
=== CONT TestBaz
main_test.go:30: 9
=== CONT TestBar
main_test.go:21: 5
=== CONT TestBaz
main_test.go:30: 10
main_test.go:30: 11
=== CONT TestFoo
main_test.go:12: 4
=== CONT TestBar
main_test.go:21: 6
=== CONT TestBaz
main_test.go:30: 12
main_test.go:30: 13
=== CONT TestBar
main_test.go:21: 7
=== CONT TestBaz
main_test.go:30: 14
=== CONT TestFoo
main_test.go:12: 5
--- PASS: TestBaz (15.01s)
=== CONT TestBar
main_test.go:21: 8
=== CONT TestFoo
main_test.go:12: 6
=== CONT TestBar
main_test.go:21: 9
main_test.go:21: 10
=== CONT TestFoo
main_test.go:12: 7
=== CONT TestBar
main_test.go:21: 11
=== CONT TestFoo
main_test.go:12: 8
=== CONT TestBar
main_test.go:21: 12
main_test.go:21: 13
=== CONT TestFoo
main_test.go:12: 9
=== CONT TestBar
main_test.go:21: 14
=== CONT TestFoo
main_test.go:12: 10
--- PASS: TestBar (30.01s)
=== CONT TestFoo
main_test.go:12: 11
main_test.go:12: 12
main_test.go:12: 13
main_test.go:12: 14
--- PASS: TestFoo (45.02s)
PASS
ok command-line-arguments 45.022s
它确实在Go 1.14中,正如Dave Cheney在“Go test -v流输出”中所证明的那样:
在Go 1.14中,Go test -v将在t.Log输出发生时进行流处理,而不是将其保存到测试运行结束。
下Go 1.14的fmt。Println和t.Log行是交错的,而不是等待测试完成,这表明当使用go test -v时,测试输出是流的。
根据戴夫的说法,优点是:
对于在测试失败时经常长时间重试的集成风格测试来说,这是一个很大的生活质量改进。
流化t.Log输出将帮助Gophers调试这些测试失败,而不必等到整个测试超时才能接收它们的输出。