Skip to content

Commit

Permalink
Workaround for a race in test2json with test timeout
Browse files Browse the repository at this point in the history 
See golang/go/issues/57305
  • Loading branch information
@dnephin
dnephin committed Jan 8, 2023
1 parent 31e54cf commit 2fe7769
Show file tree
Hide file tree
Showing 5 changed files with 110 additions and 5 deletions.
3 changes: 0 additions & 3 deletions .project/golangci-lint.yml
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,4 @@
linters-settings:
gocyclo:
min-complexity: 12
goconst:
min-len: 2
min-occurrences: 4
Expand Down Expand Up @@ -33,7 +31,6 @@ linters:
- errcheck
- gocognit
- goconst
- gocyclo
- gofmt
- goimports
- gosimple
Expand Down
19 changes: 17 additions & 2 deletions testjson/execution.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,11 @@ type Package struct {
// shuffleSeed is the seed used to shuffle the tests. The value is set when
// tests are run with -shuffle
shuffleSeed string

// testTimeoutPanicInTest stores the name of a test that received the panic
// output caused by a test timeout. This is necessary to work around a race
// condition in test2json. See https://github.com/golang/go/issues/57305.
testTimeoutPanicInTest string
}

// Result returns if the package passed, failed, or was skipped because there
Expand Down Expand Up @@ -398,6 +403,14 @@ func (p *Package) addTestEvent(event TestEvent) {

switch event.Action {
case ActionOutput, ActionBench:
if strings.HasPrefix(event.Output, "panic: test timed out") {
p.testTimeoutPanicInTest = event.Test
}
if p.testTimeoutPanicInTest == event.Test {
p.addOutput(0, event.Output)
return
}

tc := p.running[event.Test]
p.addOutput(tc.ID, event.Output)
return
Expand Down Expand Up @@ -491,8 +504,10 @@ func (e *Execution) Failed() []TestCase {
for _, name := range sortedKeys(e.packages) {
pkg := e.packages[name]

// Add package-level failure output if there were no failed tests.
if pkg.TestMainFailed() {
// Add package-level failure output if there were no failed tests, or
// if the test timeout was reached (because we now have to store that
// output on the package).
if pkg.TestMainFailed() || pkg.testTimeoutPanicInTest != "" {
failed = append(failed, TestCase{Package: name})
}
failed = append(failed, pkg.Failed...)
Expand Down
17 changes: 17 additions & 0 deletions testjson/summary_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"testing"
"time"

"gotest.tools/gotestsum/internal/text"
"gotest.tools/v3/assert"
"gotest.tools/v3/golden"
)
Expand Down Expand Up @@ -319,3 +320,19 @@ func scanConfigFromGolden(filename string) func(t *testing.T) ScanConfig {
return ScanConfig{Stdout: bytes.NewReader(golden.Get(t, filename))}
}
}

func TestSummary_TestTimeoutPanicRace(t *testing.T) {
source := golden.Get(t, "input/go-test-json-panic-race.out")
cfg := ScanConfig{
Stdout: bytes.NewReader(source),
Handler: &captureHandler{},
}
exec, err := ScanTestOutput(cfg)
assert.NilError(t, err)

out := new(bytes.Buffer)
PrintSummary(out, exec, SummarizeAll)

actual := text.ProcessLines(t, out, text.OpRemoveSummaryLineElapsedTime)
golden.Assert(t, actual, "summary/test-timeout-panic-race")
}
39 changes: 39 additions & 0 deletions testjson/testdata/input/go-test-json-panic-race.out
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
{"Time":"2022-12-14T09:49:01.562401799Z","Action":"start","Package":"github.com/mafredri/test"}
{"Time":"2022-12-14T09:49:01.569546938Z","Action":"run","Package":"github.com/mafredri/test","Test":"TestHello"}
{"Time":"2022-12-14T09:49:01.569700427Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"=== RUN TestHello\n"}
{"Time":"2022-12-14T09:49:02.569759117Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":" main_test.go:11: Hello\n"}
{"Time":"2022-12-14T09:49:02.56982657Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"--- PASS: TestHello (1.00s)\n"}
{"Time":"2022-12-14T09:49:02.572963923Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"panic: test timed out after 1s\n"}
{"Time":"2022-12-14T09:49:02.572982687Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"running tests:\n"}
{"Time":"2022-12-14T09:49:02.572992095Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\tTestHello (1s)\n"}
{"Time":"2022-12-14T09:49:02.573000907Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\n"}
{"Time":"2022-12-14T09:49:02.573019868Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"goroutine 33 [running]:\n"}
{"Time":"2022-12-14T09:49:02.573029067Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.(*M).startAlarm.func1()\n"}
{"Time":"2022-12-14T09:49:02.573038878Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2240 +0x3b9\n"}
{"Time":"2022-12-14T09:49:02.573064315Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"created by time.goFunc\n"}
{"Time":"2022-12-14T09:49:02.573079975Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/time/sleep.go:176 +0x32\n"}
{"Time":"2022-12-14T09:49:02.573097493Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\n"}
{"Time":"2022-12-14T09:49:02.573119064Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"goroutine 1 [runnable]:\n"}
{"Time":"2022-12-14T09:49:02.573141104Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.(*T).Run(0xc000083040, {0x5be88c?, 0x4ce6c5?}, 0x6072a0)\n"}
{"Time":"2022-12-14T09:49:02.573162696Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1629 +0x405\n"}
{"Time":"2022-12-14T09:49:02.573178743Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.runTests.func1(0x7438e0?)\n"}
{"Time":"2022-12-14T09:49:02.573203585Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2035 +0x45\n"}
{"Time":"2022-12-14T09:49:02.57321895Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.tRunner(0xc000083040, 0xc00025fc88)\n"}
{"Time":"2022-12-14T09:49:02.573239542Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1575 +0x10b\n"}
{"Time":"2022-12-14T09:49:02.573342015Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.runTests(0xc0000c0500?, {0x739320, 0x2, 0x2}, {0x0?, 0x100c0000ab938?, 0x743080?})\n"}
{"Time":"2022-12-14T09:49:02.573376752Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2033 +0x489\n"}
{"Time":"2022-12-14T09:49:02.573403856Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"testing.(*M).Run(0xc0000c0500)\n"}
{"Time":"2022-12-14T09:49:02.573433691Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1905 +0x63a\n"}
{"Time":"2022-12-14T09:49:02.573456763Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"main.main()\n"}
{"Time":"2022-12-14T09:49:02.573483156Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t_testmain.go:49 +0x1aa\n"}
{"Time":"2022-12-14T09:49:02.573503088Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\n"}
{"Time":"2022-12-14T09:49:02.573520911Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"goroutine 20 [runnable]:\n"}
{"Time":"2022-12-14T09:49:02.573539195Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"runtime.goexit1()\n"}
{"Time":"2022-12-14T09:49:02.573576101Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/runtime/proc.go:3616 +0x54\n"}
{"Time":"2022-12-14T09:49:02.573596375Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"runtime.goexit()\n"}
{"Time":"2022-12-14T09:49:02.573620424Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/runtime/asm_amd64.s:1599 +0x6\n"}
{"Time":"2022-12-14T09:49:02.573637148Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"created by testing.(*T).Run\n"}
{"Time":"2022-12-14T09:49:02.573690092Z","Action":"output","Package":"github.com/mafredri/test","Test":"TestHello","Output":"\t/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1628 +0x3ea\n"}
{"Time":"2022-12-14T09:49:02.574702109Z","Action":"pass","Package":"github.com/mafredri/test","Test":"TestHello","Elapsed":1}
{"Time":"2022-12-14T09:49:02.57473959Z","Action":"output","Package":"github.com/mafredri/test","Output":"FAIL\tgithub.com/mafredri/test\t1.012s\n"}
{"Time":"2022-12-14T09:49:02.574754586Z","Action":"fail","Package":"github.com/mafredri/test","Elapsed":1.012}
37 changes: 37 additions & 0 deletions testjson/testdata/summary/test-timeout-panic-race
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@

=== Failed
=== FAIL: github.com/mafredri/test (0.00s)
panic: test timed out after 1s
running tests:
TestHello (1s)

goroutine 33 [running]:
testing.(*M).startAlarm.func1()
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2240 +0x3b9
created by time.goFunc
/home/mafredri/sdk/go1.20rc1/src/time/sleep.go:176 +0x32

goroutine 1 [runnable]:
testing.(*T).Run(0xc000083040, {0x5be88c?, 0x4ce6c5?}, 0x6072a0)
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1629 +0x405
testing.runTests.func1(0x7438e0?)
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2035 +0x45
testing.tRunner(0xc000083040, 0xc00025fc88)
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1575 +0x10b
testing.runTests(0xc0000c0500?, {0x739320, 0x2, 0x2}, {0x0?, 0x100c0000ab938?, 0x743080?})
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:2033 +0x489
testing.(*M).Run(0xc0000c0500)
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1905 +0x63a
main.main()
_testmain.go:49 +0x1aa

goroutine 20 [runnable]:
runtime.goexit1()
/home/mafredri/sdk/go1.20rc1/src/runtime/proc.go:3616 +0x54
runtime.goexit()
/home/mafredri/sdk/go1.20rc1/src/runtime/asm_amd64.s:1599 +0x6
created by testing.(*T).Run
/home/mafredri/sdk/go1.20rc1/src/testing/testing.go:1628 +0x3ea
FAIL github.com/mafredri/test 1.012s

DONE 1 tests, 1 failure

0 comments on commit 2fe7769

Please sign in to comment.