Merge pull request openshift#16817 from smarterclayton/parse_test_data

Automatic merge from submit-queue (batch tested with PRs 16068, 16817).

Correctly parse nested go tests

Use a stateful parser approach to process each section of the test
output independently. Correctly handles nested tests and nested output
and puts any stdout/err into the SystemOut field of the generated test
result.

Note: this breaks --suite=nested, but was not able to find any users.

@liggitt @stevekuznetsov tests are updated but want to soak this a bit

Author: openshift-merge-robot

test/integration/runner/runner_test.go

@@ -84,14 +84,17 @@ func executeTests(t *testing.T, dir, packageName string, maxRetries int) {
 		if testing.Verbose() {
 			t.Logf("compiling %s", packageName)
 		}
-		cmd := exec.Command("go", "test", packageName, "-i", "-c", binaryName)
+		binaryPath, err = filepath.Abs(binaryName)
+		if err != nil {
+			t.Fatal(err)
+		}
+		cmd := exec.Command("go", "test", packageName, "-i", "-c", binaryPath)
 		if testing.Verbose() {
 			cmd.Args = append(cmd.Args, "-test.v")
 		}
 		if out, err := cmd.CombinedOutput(); err != nil {
 			t.Fatal(string(out))
 		}
-		binaryPath = "." + string(filepath.Separator) + binaryName
 	}
 
 	// run all the nested tests
@@ -162,17 +165,50 @@ func runSingleTest(t *testing.T, dir, binaryPath, name string) error {
 	out, err := cmd.CombinedOutput()
 	if err != nil {
 		if len(out) != 0 {
-			return fmt.Errorf(string(out))
+			return fmt.Errorf(splitSingleGoTestOutput(string(out)))
 		}
 		return err
 	}
 
 	if testing.Verbose() {
-		t.Log(string(out))
+		// show the last 20k output from the run only
+		if len(out) > 20000 {
+			out = out[len(out)-20000:]
+		}
+		t.Log(splitSingleGoTestOutput(string(out)))
 	}
 	return nil
 }
 
+var (
+	testStartPattern = regexp.MustCompile(`(?m:^=== RUN.*$)`)
+	testSplitPattern = regexp.MustCompile(`(?m:^--- (PASS|FAIL):.*$)`)
+	testEndPattern   = regexp.MustCompile(`(?m:^(PASS|FAIL)$)`)
+)
+
+// splitSingleGoTestOutput takes the output of a single go test run and places a divider token (=== OUTPUT)
+// between the system output (shown between '=== RUN' and '--- PASS') and the test output (t.Log/t.Error
+// between '--- PASS' and the final 'PASS|FAIL' line). go test does not capture system output correctly for
+// parallel jobs, so we can't guarantee a program parsing the test output can get at system output without
+// this approach.
+func splitSingleGoTestOutput(out string) string {
+	if match := testStartPattern.FindStringIndex(out); len(match) == 2 {
+		out = out[match[1]:]
+	}
+	var log string
+	if match := testSplitPattern.FindStringIndex(out); len(match) == 2 {
+		log = out[match[1]:]
+		out = out[:match[0]]
+	}
+	if match := testEndPattern.FindStringIndex(log); len(match) == 2 {
+		log = log[:match[0]]
+	}
+	if len(log) > 0 {
+		return log + "\n=== OUTPUT\n" + out
+	}
+	return "\n=== OUTPUT\n" + out
+}
+
 func without(all []string, value string) []string {
 	var result []string
 	for i := 0; i < len(all); i++ {

tools/junitreport/pkg/api/test_suite.go

@@ -19,12 +19,15 @@ func (t *TestSuite) AddProperty(name, value string) {
 func (t *TestSuite) AddTestCase(testCase *TestCase) {
 	t.NumTests += 1
 
-	if testCase.SkipMessage != nil {
+	switch {
+	case testCase.SkipMessage != nil:
 		t.NumSkipped += 1
-	}
-
-	if testCase.FailureOutput != nil {
+	case testCase.FailureOutput != nil:
 		t.NumFailed += 1
+	default:
+		// we do not preserve output on tests that are not failures or skips
+		testCase.SystemOut = ""
+		testCase.SystemErr = ""
 	}
 
 	t.Duration += testCase.Duration

tools/junitreport/pkg/parser/gotest/data_parser.go

@@ -6,97 +6,82 @@ import (
 	"github.com/openshift/origin/tools/junitreport/pkg/api"
 )
 
-func newTestDataParser() testDataParser {
-	return testDataParser{
-		// testStartPattern matches the line in verbose `go test` output that marks the declaration of a test.
-		// The first submatch of this regex is the name of the test
-		testStartPattern: regexp.MustCompile(`=== RUN\s+([^/]+)$`),
+// testStartPattern matches the line in verbose `go test` output that marks the declaration of a test.
+// The first submatch of this regex is the name of the test
+var testStartPattern = regexp.MustCompile(`^=== RUN\s+([^\s]+)$`)
 
-		// testResultPattern matches the line in verbose `go test` output that marks the result of a test.
-		// The first submatch of this regex is the result of the test (PASS, FAIL, or SKIP)
-		// The second submatch of this regex is the name of the test
-		// The third submatch of this regex is the time taken in seconds for the test to finish
-		testResultPattern: regexp.MustCompile(`--- (PASS|FAIL|SKIP):\s+([^/]+)\s+\((\d+\.\d+)(s| seconds)\)`),
-	}
-}
-
-type testDataParser struct {
-	testStartPattern  *regexp.Regexp
-	testResultPattern *regexp.Regexp
-}
-
-// MarksBeginning determines if the line marks the beginning of a test case
-func (p *testDataParser) MarksBeginning(line string) bool {
-	return p.testStartPattern.MatchString(line)
-}
-
-// ExtractName extracts the name of the test case from test output line
-func (p *testDataParser) ExtractName(line string) (string, bool) {
-	if matches := p.testStartPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[1]) > 0 {
+// ExtractRun identifies the start of a test output section.
+func ExtractRun(line string) (string, bool) {
+	if matches := testStartPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[1]) > 0 {
 		return matches[1], true
 	}
-
-	if matches := p.testResultPattern.FindStringSubmatch(line); len(matches) > 2 && len(matches[2]) > 0 {
-		return matches[2], true
-	}
-
 	return "", false
 }
 
-// ExtractResult extracts the test result from a test output line
-func (p *testDataParser) ExtractResult(line string) (api.TestResult, bool) {
-	if matches := p.testResultPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[1]) > 0 {
-		switch matches[1] {
+// testResultPattern matches the line in verbose `go test` output that marks the result of a test.
+// The first submatch of this regex is the result of the test (PASS, FAIL, or SKIP)
+// The second submatch of this regex is the name of the test
+// The third submatch of this regex is the time taken in seconds for the test to finish
+var testResultPattern = regexp.MustCompile(`^(\s*)--- (PASS|FAIL|SKIP):\s+([^\s]+)\s+\((\d+\.\d+)(s| seconds)\)$`)
+
+// ExtractResult extracts the test result from a test output line. Depth is measured as the leading whitespace
+// for the line multiplied by four, which is used to identify output from nested Go subtests.
+func ExtractResult(line string) (r api.TestResult, name string, depth int, duration string, ok bool) {
+	if matches := testResultPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[2]) > 0 {
+		switch matches[2] {
 		case "PASS":
-			return api.TestResultPass, true
+			r = api.TestResultPass
 		case "SKIP":
-			return api.TestResultSkip, true
+			r = api.TestResultSkip
 		case "FAIL":
-			return api.TestResultFail, true
+			r = api.TestResultFail
+		default:
+			return "", "", 0, "", false
 		}
+		name = matches[3]
+		duration = matches[4] + "s"
+		depth = len(matches[1]) / 4
+		ok = true
+		return
 	}
-	return "", false
-}
-
-// ExtractDuration extracts the test duration from a test output line
-func (p *testDataParser) ExtractDuration(line string) (string, bool) {
-	if matches := p.testResultPattern.FindStringSubmatch(line); len(matches) > 3 && len(matches[3]) > 0 {
-		return matches[3] + "s", true
-	}
-	return "", false
+	return "", "", 0, "", false
 }
 
-func newTestSuiteDataParser() testSuiteDataParser {
-	return testSuiteDataParser{
-		// coverageOutputPattern matches coverage output on a single line.
-		// The first submatch of this regex is the percent coverage
-		coverageOutputPattern: regexp.MustCompile(`coverage:\s+(\d+\.\d+)\% of statements`),
+// testOutputPattern captures a line with leading whitespace.
+var testOutputPattern = regexp.MustCompile(`^(\s*)(.*)$`)
 
-		// packageResultPattern matches the `go test` output for the end of a package.
-		// The first submatch of this regex matches the result of the test (ok or FAIL)
-		// The second submatch of this regex matches the name of the package
-		// The third submatch of this regex matches the time taken in seconds for tests in the package to finish
-		// The sixth (optional) submatch of this regex is the percent coverage
-		packageResultPattern: regexp.MustCompile(`(ok|FAIL)\s+(.+)[\s\t]+(\d+\.\d+(s| seconds))([\s\t]+coverage:\s+(\d+\.\d+)\% of statements)?`),
+// ExtractOutput captures a line of output indented by whitespace and returns
+// the output, the indentation depth (4 spaces is the canonical indentation used by go test),
+// and whether the match was successful.
+func ExtractOutput(line string) (string, int, bool) {
+	if matches := testOutputPattern.FindStringSubmatch(line); len(matches) > 1 {
+		return matches[2], len(matches[1]) / 4, true
 	}
+	return "", 0, false
 }
 
-type testSuiteDataParser struct {
-	coverageOutputPattern *regexp.Regexp
-	packageResultPattern  *regexp.Regexp
-}
-
-// ExtractName extracts the name of the test suite from a test output line
-func (p *testSuiteDataParser) ExtractName(line string) (string, bool) {
-	if matches := p.packageResultPattern.FindStringSubmatch(line); len(matches) > 2 && len(matches[2]) > 0 {
-		return matches[2], true
+// coverageOutputPattern matches coverage output on a single line.
+// The first submatch of this regex is the percent coverage
+var coverageOutputPattern = regexp.MustCompile(`coverage:\s+(\d+\.\d+)\% of statements`)
+
+// packageResultPattern matches the `go test` output for the end of a package.
+// The first submatch of this regex matches the result of the test (ok or FAIL)
+// The second submatch of this regex matches the name of the package
+// The third submatch of this regex matches the time taken in seconds for tests in the package to finish
+// The sixth (optional) submatch of this regex is the percent coverage
+var packageResultPattern = regexp.MustCompile(`^(ok|FAIL)\s+(.+)[\s\t]+(\d+\.\d+(s| seconds))([\s\t]+coverage:\s+(\d+\.\d+)\% of statements)?$`)
+
+// ExtractPackage extracts the name of the test suite from a test package line.
+func ExtractPackage(line string) (name string, duration string, coverage string, ok bool) {
+	if matches := packageResultPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[2]) > 0 {
+		return matches[2], matches[3], matches[5], true
 	}
-	return "", false
+	return "", "", "", false
 }
 
 // ExtractDuration extracts the package duration from a test output line
-func (p *testSuiteDataParser) ExtractDuration(line string) (string, bool) {
-	if resultMatches := p.packageResultPattern.FindStringSubmatch(line); len(resultMatches) > 3 && len(resultMatches[3]) > 0 {
+func ExtractDuration(line string) (string, bool) {
+	if resultMatches := packageResultPattern.FindStringSubmatch(line); len(resultMatches) > 3 && len(resultMatches[3]) > 0 {
 		return resultMatches[3], true
 	}
 	return "", false
@@ -107,24 +92,19 @@ const (
 )
 
 // ExtractProperties extracts any metadata properties of the test suite from a test output line
-func (p *testSuiteDataParser) ExtractProperties(line string) (map[string]string, bool) {
+func ExtractProperties(line string) (map[string]string, bool) {
 	// the only test suite properties that Go testing can create are coverage values, which can either
 	// be present on their own line or in the package result line
-	if matches := p.coverageOutputPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[1]) > 0 {
+	if matches := coverageOutputPattern.FindStringSubmatch(line); len(matches) > 1 && len(matches[1]) > 0 {
 		return map[string]string{
 			coveragePropertyName: matches[1],
 		}, true
 	}
 
-	if resultMatches := p.packageResultPattern.FindStringSubmatch(line); len(resultMatches) > 6 && len(resultMatches[6]) > 0 {
+	if resultMatches := packageResultPattern.FindStringSubmatch(line); len(resultMatches) > 6 && len(resultMatches[6]) > 0 {
 		return map[string]string{
 			coveragePropertyName: resultMatches[6],
 		}, true
 	}
 	return map[string]string{}, false
 }
-
-// MarksCompletion determines if the line marks the completion of a test suite
-func (p *testSuiteDataParser) MarksCompletion(line string) bool {
-	return p.packageResultPattern.MatchString(line)
-}