Skip to content

Commit

Permalink
Workaround test2json bug causing missing test output
Browse files Browse the repository at this point in the history 
See golang/go#29755.

If a test fails, and there is no test output (other than framing), then
print all the test output for the entire test case.

This won't fix the issue if the test which failed had some output, but
well behaved tests generally shouldn't non-failure message output, so
hopefully this case is rare.
  • Loading branch information
@dnephin
dnephin committed Apr 19, 2020
1 parent 50427ef commit aa9ed6b
Show file tree
Hide file tree
Showing 6 changed files with 133 additions and 6 deletions.
2 changes: 1 addition & 1 deletion internal/junitxml/testdata/junitxml-report.golden
View file
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@
<failure message="Failed" type="">=== RUN TestNestedWithFailure/c&#xA; --- FAIL: TestNestedWithFailure/c (0.00s)&#xA; &#x9;stub_test.go:65: failed&#xA;</failure>
</testcase>
<testcase classname="github.com/gotestyourself/gotestyourself/testjson/internal/stub" name="TestNestedWithFailure" time="0.000000">
<failure message="Failed" type="">=== RUN TestNestedWithFailure&#xA;--- FAIL: TestNestedWithFailure (0.00s)&#xA;</failure>
<failure message="Failed" type="">=== RUN TestNestedWithFailure&#xA;--- FAIL: TestNestedWithFailure (0.00s)&#xA;=== RUN TestNestedWithFailure/a&#xA; --- PASS: TestNestedWithFailure/a (0.00s)&#xA;=== RUN TestNestedWithFailure/a/sub&#xA; --- PASS: TestNestedWithFailure/a/sub (0.00s)&#xA;=== RUN TestNestedWithFailure/b&#xA; --- PASS: TestNestedWithFailure/b (0.00s)&#xA;=== RUN TestNestedWithFailure/b/sub&#xA; --- PASS: TestNestedWithFailure/b/sub (0.00s)&#xA;=== RUN TestNestedWithFailure/c&#xA; --- FAIL: TestNestedWithFailure/c (0.00s)&#xA; &#x9;stub_test.go:65: failed&#xA;=== RUN TestNestedWithFailure/d&#xA; --- PASS: TestNestedWithFailure/d (0.00s)&#xA;=== RUN TestNestedWithFailure/d/sub&#xA; --- PASS: TestNestedWithFailure/d/sub (0.00s)&#xA;</failure>
</testcase>
<testcase classname="github.com/gotestyourself/gotestyourself/testjson/internal/stub" name="TestSkipped" time="0.000000">
<skipped message="=== RUN TestSkipped&#xA;--- SKIP: TestSkipped (0.00s)&#xA;&#x9;stub_test.go:26: &#xA;"></skipped>
Expand Down
40 changes: 35 additions & 5 deletions testjson/execution.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -109,8 +109,36 @@ func (p Package) TestCases() []TestCase {

// Output returns the full test output for a test.
func (p Package) Output(test string) string {
return strings.Join(p.OutputLines(test), "")
}

// OutputLines returns the full test output for a test as a slice of strings.
//
// As a workaround for test output being attributed to the wrong subtest, if
// the requested test output only contains framing lines (ex: --- FAIL: ),
// then all output for the root test is returned.
// See https://github.com/golang/go/issues/29755.
func (p Package) OutputLines(test string) []string {
root, sub := splitTestName(test)
return strings.Join(p.output[root][sub], "")
lines := p.output[root][sub]
// every test will have 2 framing lines, === RUN, and --- {PASS,FAIL}
if len(lines) > 2 {
return lines
}
result := make([]string, 0, len(p.output[root])*2)
for _, sub := range testNamesSorted(p.output[root]) {
result = append(result, p.output[root][sub]...)
}
return result
}

func testNamesSorted(subs map[string][]string) []string {
names := make([]string, 0, len(subs))
for name := range subs {
names = append(names, name)
}
sort.Strings(names)
return names
}

func (p Package) addOutput(test string, output string) {
Expand All @@ -120,7 +148,6 @@ func (p Package) addOutput(test string, output string) {
}
// TODO: limit size of buffered test output
p.output[root][sub] = append(p.output[root][sub], output)

}

// splitTestName into root test name and any subtest names.
Expand Down Expand Up @@ -228,10 +255,13 @@ func isCachedOutput(output string) bool {
return strings.Contains(output, "\t(cached)")
}

// OutputLines returns the full test output for a test as an array of lines.
// OutputLines returns the full test output for a test as an slice of lines.
// This function is a convenient wrapper around Package.OutputLines() to
// support the hiding of output in the summary.
//
// See Package.OutLines() for more details.
func (e *Execution) OutputLines(pkg, test string) []string {
root, sub := splitTestName(test)
return e.packages[pkg].output[root][sub]
return e.packages[pkg].OutputLines(test)
}

// Package returns the Package by name.
Expand Down
46 changes: 46 additions & 0 deletions testjson/execution_test.go
View file
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
package testjson

import (
"bytes"
"testing"
"time"

"github.com/google/go-cmp/cmp"
"gotest.tools/v3/assert"
"gotest.tools/v3/golden"
)

func TestPackage_Elapsed(t *testing.T) {
Expand Down Expand Up @@ -45,3 +47,47 @@ func TestExecution_Add_PackageCoverage(t *testing.T) {
}

var cmpPackage = cmp.AllowUnexported(Package{})

func TestExecution_OutputLines_WithMisattributedOutput(t *testing.T) {
exec, err := ScanTestOutput(ScanConfig{
Stdout: bytes.NewReader(golden.Get(t, "go-test-json-misattributed.out")),
Stderr: bytes.NewBuffer(nil),
Handler: noopHandler{},
})
assert.NilError(t, err)

expected := []string{
"=== RUN TestOutputWithSubtest\n",
"--- FAIL: TestOutputWithSubtest (0.00s)\n",
"=== RUN TestOutputWithSubtest/sub_test\n",
" --- PASS: TestOutputWithSubtest/sub_test (0.00s)\n",
" foo_test.go:9: output from sub test\n",
" foo_test.go:11: more output from sub test\n",
" foo_test.go:16: more output from sub test\n",
"=== RUN TestOutputWithSubtest/sub_test/sub2\n",
" --- PASS: TestOutputWithSubtest/sub_test/sub2 (0.00s)\n",
" foo_test.go:14: output from sub2 test\n",
" foo_test.go:22: output from root test\n",
" foo_test.go:27: output from root test\n",
"=== RUN TestOutputWithSubtest/sub_test2\n",
" --- PASS: TestOutputWithSubtest/sub_test2 (0.00s)\n",
" foo_test.go:21: output from sub test2\n",
" foo_test.go:23: more output from sub test2\n",
" foo_test.go:28: more output from sub test2\n",
"=== RUN TestOutputWithSubtest/sub_test2/sub2\n",
" --- PASS: TestOutputWithSubtest/sub_test2/sub2 (0.00s)\n",
" foo_test.go:26: output from sub2 test\n",
" foo_test.go:32: output after sub test\n",
}
assert.DeepEqual(t, exec.Package("").OutputLines("TestOutputWithSubtest"), expected)
}

type noopHandler struct{}

func (s noopHandler) Event(TestEvent, *Execution) error {
return nil
}

func (s noopHandler) Err(string) error {
return nil
}
1 change: 1 addition & 0 deletions testjson/internal/nested/nested_test.go
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
package testjson
35 changes: 35 additions & 0 deletions testjson/testdata/go-test-json-misattributed.out
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
{"Action":"run","Test":"TestOutputWithSubtest"}
{"Action":"output","Test":"TestOutputWithSubtest","Output":"=== RUN TestOutputWithSubtest\n"}
{"Action":"run","Test":"TestOutputWithSubtest/sub_test"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test","Output":"=== RUN TestOutputWithSubtest/sub_test\n"}
{"Action":"run","Test":"TestOutputWithSubtest/sub_test/sub2"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test/sub2","Output":"=== RUN TestOutputWithSubtest/sub_test/sub2\n"}
{"Action":"run","Test":"TestOutputWithSubtest/sub_test2"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2","Output":"=== RUN TestOutputWithSubtest/sub_test2\n"}
{"Action":"run","Test":"TestOutputWithSubtest/sub_test2/sub2"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2/sub2","Output":"=== RUN TestOutputWithSubtest/sub_test2/sub2\n"}
{"Action":"output","Test":"TestOutputWithSubtest","Output":"--- FAIL: TestOutputWithSubtest (0.00s)\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test","Output":" --- PASS: TestOutputWithSubtest/sub_test (0.00s)\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test","Output":" foo_test.go:9: output from sub test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test","Output":" foo_test.go:11: more output from sub test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test","Output":" foo_test.go:16: more output from sub test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test/sub2","Output":" --- PASS: TestOutputWithSubtest/sub_test/sub2 (0.00s)\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test/sub2","Output":" foo_test.go:14: output from sub2 test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test/sub2","Output":" foo_test.go:22: output from root test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test/sub2","Output":" foo_test.go:27: output from root test\n"}
{"Action":"pass","Test":"TestOutputWithSubtest/sub_test/sub2"}
{"Action":"pass","Test":"TestOutputWithSubtest/sub_test"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2","Output":" --- PASS: TestOutputWithSubtest/sub_test2 (0.00s)\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2","Output":" foo_test.go:21: output from sub test2\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2","Output":" foo_test.go:23: more output from sub test2\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2","Output":" foo_test.go:28: more output from sub test2\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2/sub2","Output":" --- PASS: TestOutputWithSubtest/sub_test2/sub2 (0.00s)\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2/sub2","Output":" foo_test.go:26: output from sub2 test\n"}
{"Action":"output","Test":"TestOutputWithSubtest/sub_test2/sub2","Output":" foo_test.go:32: output after sub test\n"}
{"Action":"pass","Test":"TestOutputWithSubtest/sub_test2/sub2"}
{"Action":"pass","Test":"TestOutputWithSubtest/sub_test2"}
{"Action":"fail","Test":"TestOutputWithSubtest"}
{"Action":"output","Output":"FAIL\n"}
{"Action":"output","Output":"FAIL\tgotest.tools/gotestsum/foo\t0.001s\n"}
{"Action":"output","Output":"FAIL\n"}
{"Action":"fail"}
15 changes: 15 additions & 0 deletions testjson/testdata/short-verbose-format.out
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,21 @@ PASS testjson/internal/stub.TestNestedWithFailure/d/sub (0.00s)
PASS testjson/internal/stub.TestNestedWithFailure/d (0.00s)
=== RUN TestNestedWithFailure
--- FAIL: TestNestedWithFailure (0.00s)
=== RUN TestNestedWithFailure/a
--- PASS: TestNestedWithFailure/a (0.00s)
=== RUN TestNestedWithFailure/a/sub
--- PASS: TestNestedWithFailure/a/sub (0.00s)
=== RUN TestNestedWithFailure/b
--- PASS: TestNestedWithFailure/b (0.00s)
=== RUN TestNestedWithFailure/b/sub
--- PASS: TestNestedWithFailure/b/sub (0.00s)
=== RUN TestNestedWithFailure/c
--- FAIL: TestNestedWithFailure/c (0.00s)
stub_test.go:65: failed
=== RUN TestNestedWithFailure/d
--- PASS: TestNestedWithFailure/d (0.00s)
=== RUN TestNestedWithFailure/d/sub
--- PASS: TestNestedWithFailure/d/sub (0.00s)
FAIL testjson/internal/stub.TestNestedWithFailure (0.00s)
PASS testjson/internal/stub.TestNestedSuccess/a/sub (0.00s)
PASS testjson/internal/stub.TestNestedSuccess/a (0.00s)
Expand Down

0 comments on commit aa9ed6b

Please sign in to comment.