t.Log()
pojawi się dopiero po zakończeniu testu, więc jeśli próbujesz zdebugować test, który się zawiesza lub działa źle, wydaje się, że musisz go użyć fmt
.
Tak: tak było do wersji Go 1.13 (sierpień 2019) włącznie.
I tak było w golang.org
numerze 24929
Rozważ następujące (głupie) testy automatyczne:
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)
}
}
Jeśli uruchomię go test -v
, nie otrzymuję danych wyjściowych, dopóki wszystko nie TestFoo
zostanie wykonane , a następnie żadnych danych wyjściowych, dopóki wszystko nie TestBar
zostanie wykonane, i znowu żadnych danych wyjściowych, dopóki wszystko nie TestBaz
zostanie wykonane.
Jest to w porządku, jeśli testy działają, ale jeśli jest jakiś błąd, jest kilka przypadków, w których buforowanie danych wyjściowych dziennika jest problematyczne:
- Podczas iteracji lokalnej chcę mieć możliwość wprowadzenia zmiany, uruchomienia testów, natychmiastowego sprawdzenia, co się dzieje w dziennikach, aby zrozumieć, co się dzieje, nacisnąć CTRL + C, aby w razie potrzeby zakończyć test wcześniej, wprowadzić kolejną zmianę, ponownie uruchomić testy i tak dalej.
Jeśli TestFoo
jest powolny (np. Jest to test integracji), żadne dane wyjściowe dziennika nie są wyświetlane aż do samego końca testu. To znacznie spowalnia iterację.
- Jeśli
TestFoo
ma błąd, który powoduje, że się zawiesza i nigdy się nie kończy, nie otrzymywałbym żadnego wyjścia dziennika. W tych przypadkach, t.Log
i t.Logf
nie mają zastosowania w ogóle.
To sprawia, że debugowanie jest bardzo trudne.
- Co więcej, nie tylko nie otrzymuję danych wyjściowych dziennika, ale jeśli test zawiesza się zbyt długo, limit czasu testu Go zabija test po 10 minutach lub jeśli zwiększę ten limit czasu, wiele serwerów CI również wyłącza testy, jeśli nie ma logować dane wyjściowe po określonym czasie (np. 10 minut w CircleCI).
Więc teraz moje testy są zakończone i nie mam nic w dziennikach, aby powiedzieć mi, co się stało.
Ale dla (prawdopodobnie) Go 1.14 (Q1 2020): CL 127120
testowanie: przesyłanie danych wyjściowych dziennika w trybie szczegółowym
Wynik to teraz:
=== RUN TestFoo
=== PAUSE TestFoo
=== RUN TestBar
=== PAUSE TestBar
=== RUN TestGaz
=== PAUSE TestGaz
=== CONT TestFoo
TestFoo: main_test.go:14: hello from foo
=== CONT TestGaz
=== CONT TestBar
TestGaz: main_test.go:38: hello from gaz
TestBar: main_test.go:26: hello from bar
TestFoo: main_test.go:14: hello from foo
TestBar: main_test.go:26: hello from bar
TestGaz: main_test.go:38: hello from gaz
TestFoo: main_test.go:14: hello from foo
TestGaz: main_test.go:38: hello from gaz
TestBar: main_test.go:26: hello from bar
TestFoo: main_test.go:14: hello from foo
TestGaz: main_test.go:38: hello from gaz
TestBar: main_test.go:26: hello from bar
TestGaz: main_test.go:38: hello from gaz
TestFoo: main_test.go:14: hello from foo
TestBar: main_test.go:26: hello from bar
--- PASS: TestFoo (1.00s)
--- PASS: TestGaz (1.00s)
--- PASS: TestBar (1.00s)
PASS
ok dummy/streaming-test 1.022s
Rzeczywiście tak jest w Go 1.14, jak potwierdza Dave Cheney w „ go test -v
transmisji strumieniowej ”:
W Go 1.14, go test -v
będzie przesyłać strumieniowo t.Log
dane wyjściowe tak, jak to się dzieje, zamiast gromadzić je do końca przebiegu testowego .
W Go 1.14 linie fmt.Println
i t.Log
są przeplatane , zamiast czekać na zakończenie testu, co pokazuje, że wyjście testu jest przesyłane strumieniowo, gdy go test -v
jest używane.
Zaleta, według Dave'a:
Jest to duża poprawa jakości życia w przypadku testów w stylu integracji, które często są ponawiane przez długie okresy, gdy test kończy się niepowodzeniem.
Strumieniowe przesyłanie t.Log
danych pomoże Świstakom debugować te niepowodzenia testów bez konieczności czekania, aż upłynie cały czas testu, aby otrzymać wynik.