From: Daniel Martí Date: Tue, 21 Jan 2020 10:21:17 +0000 (+0000) Subject: cmd/go: make Script/test_regexps less flaky under load X-Git-Tag: go1.14rc1~78 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=8689ea6a4a2aa33b90bfbcf5076bfff0b6fdcaed;p=gostls13.git cmd/go: make Script/test_regexps less flaky under load With the command below, I was able to reproduce failures within the first 50 or so runs: go test -c -o test && stress -p 32 ./test -test.run Script/test_regexp When printing the full failure output, we'd see: BenchmarkX BenchmarkX: x_test.go:13: LOG: X running N=1 BenchmarkX/Y BenchmarkX/Y: x_test.go:15: LOG: Y running N=1 BenchmarkX/Y: x_test.go:15: LOG: Y running N=100 BenchmarkX/Y: x_test.go:15: LOG: Y running N=10000 BenchmarkX/Y: x_test.go:15: LOG: Y running N=1000000 BenchmarkX/Y: x_test.go:15: LOG: Y running N=100000000 BenchmarkX/Y: x_test.go:15: LOG: Y running N=1000000000 BenchmarkX/Y 1000000000 0.000050 ns/op BenchmarkX/Y: x_test.go:15: LOG: Y running N=1 BenchmarkX/Y: x_test.go:15: LOG: Y running N=30 BenchmarkX/Y: x_test.go:15: LOG: Y running N=1207 BenchmarkX/Y: x_test.go:15: LOG: Y running N=120700 BenchmarkX/Y: x_test.go:15: LOG: Y running N=12070000 BenchmarkX/Y: x_test.go:15: LOG: Y running N=1000000000 BenchmarkX/Y 1000000000 0.000715 ns/op In other words, the N values aren't required to be exact. It seems like they are cut short if the machine is under stress. That's the exact scenario we reproduce above, since I used -p=32 on my laptop with only 4 real CPU cores. First, don't require each line to be present. Instead, use patterns that span multiple lines, so that we can just match the first and last N= lines. Second, don't require the last N= lines to be exact; simply require them to have a reasonably large number of digits. Fixes #36664. Change-Id: I7a9818f1a07099fa6482a26da2ac5cbea0f8ab30 Reviewed-on: https://go-review.googlesource.com/c/go/+/215578 Run-TryBot: Bryan C. Mills Reviewed-by: Bryan C. Mills Reviewed-by: Daniel Martí TryBot-Result: Gobot Gobot --- diff --git a/src/cmd/go/testdata/script/test_regexps.txt b/src/cmd/go/testdata/script/test_regexps.txt index 020b8dd579..39dedbf06f 100644 --- a/src/cmd/go/testdata/script/test_regexps.txt +++ b/src/cmd/go/testdata/script/test_regexps.txt @@ -2,31 +2,38 @@ go test -cpu=1 -run=X/Y -bench=X/Y -count=2 -v testregexp # Test the following: -# TestX is run, twice +# TestX is run, twice stdout -count=2 '^=== RUN TestX$' stdout -count=2 '^ TestX: x_test.go:6: LOG: X running$' -# TestX/Y is run, twice +# TestX/Y is run, twice stdout -count=2 '^=== RUN TestX/Y$' stdout -count=2 '^ TestX/Y: x_test.go:8: LOG: Y running$' -# TestXX is run, twice +# TestXX is run, twice stdout -count=2 '^=== RUN TestXX$' stdout -count=2 '^ TestXX: z_test.go:10: LOG: XX running' -# TestZ is not run +# TestZ is not run ! stdout '^=== RUN TestZ$' -# BenchmarkX is run but only with N=1, once -stdout -count=1 '^ BenchmarkX: x_test.go:13: LOG: X running N=1$' -! stdout '^ BenchmarkX: x_test.go:13: LOG: X running N=10$' +# BenchmarkX is run with N=1 once, only to discover what sub-benchmarks it has, +# and should not print a final summary line. +stdout -count=1 '^\s+BenchmarkX: x_test.go:13: LOG: X running N=1$' +! stdout '^\s+BenchmarkX: x_test.go:13: LOG: X running N=\d\d+' +! stdout 'BenchmarkX\s+\d+' -# BenchmarkXX is run but only with N=1, once -stdout -count=1 '^ BenchmarkXX: z_test.go:18: LOG: XX running N=1$' -! stdout '^ BenchmarkXX: z_test.go:18: LOG: XX running N=10$' +# Same for BenchmarkXX. +stdout -count=1 '^\s+BenchmarkXX: z_test.go:18: LOG: XX running N=1$' +! stdout '^\s+BenchmarkXX: z_test.go:18: LOG: XX running N=\d\d+' +! stdout 'BenchmarkXX\s+\d+' -# BenchmarkX/Y is run in full, twice -stdout -count=2 ' BenchmarkX/Y: x_test.go:15: LOG: Y running N=1\n BenchmarkX/Y: x_test.go:15: LOG: Y running N=100\n BenchmarkX/Y: x_test.go:15: LOG: Y running N=10000\n BenchmarkX/Y: x_test.go:15: LOG: Y running N=1000000\n BenchmarkX/Y: x_test.go:15: LOG: Y running N=100000000\n BenchmarkX/Y: x_test.go:15: LOG: Y running N=1000000000' +# BenchmarkX/Y is run in full twice due to -count=2. +# "Run in full" means that it runs for approximately the default benchtime, +# but may cap out at N=1e9. +# We don't actually care what the final iteration count is, but it should be +# a large number, and the last iteration count prints right before the results. +stdout -count=2 '^\s+BenchmarkX/Y: x_test.go:15: LOG: Y running N=[1-9]\d{4,}\nBenchmarkX/Y\s+\d+' -- testregexp/x_test.go -- package x @@ -65,4 +72,4 @@ func BenchmarkZ(b *testing.B) { func BenchmarkXX(b *testing.B) { b.Logf("LOG: XX running N=%d", b.N) -} \ No newline at end of file +}