Cherry-pick #22541 to 7.x: Run unit and integration tests with gotestsum

[urso]

Cherry-pick of PR #22541 to 7.x branch. Original message:

• Enhancement

What does this PR do?

The PR introduces gotestsum to drive the go based unit and integration tests. This is meant as replacement for github.com/jstemmer/go-junit-report, which seems to be unmaintained for a while.

Only the GoTest mage helper is modified to use gotestsum instead of go-junit-reporter. In addition to the change we add unit tests for GoTest that do run actual tests. The output of these helper-tests is captured and validated against known regular expressions.

Why is it important?

We use go-junit-reporter in order to create a xunit like report that is uploaded after the tests have finished. Unfortunately the project seems to be unmaintained for at least a year.

We discovered that we have a few issues with our test output. For example lines have been missing, wrong tests have been marked as failed (on panic in a leaked go-routine), or failed tests have not been reported at all. The new unit tests try to cover most cases that have not been reported correctly, in order to validate that the change actually fixes reporting.

goroutinepanic handling

This one might be a little flaky. But it seems that a 'badly' scheduled unmanaged go-routine can bring down and flag unrelated tests. The stack trace in the failed test actually matches the original test that did spawn the go-routine.

We did try to reproduce the issue by running 2 tests. The first test creates a go-routine that sleeps for 2 seconds and finally panics. The second tests waits for 5 seconds. Depending on the order the test is run we did see the second test to be marked as "Failed". A sample output using go-junit-reporter shows false_positive_failure as failed:

Package: github.com/elastic/beats/v7/filebeat/placeholder/goroutinepanic

[2020-11-11T14:33:13.939Z] Test:    TestWrongPanic

[2020-11-11T14:33:13.939Z] ----

[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/goroutinepanic

[2020-11-11T14:33:13.939Z] Test:    TestWrongPanic/setup_failing_go-routine

[2020-11-11T14:33:13.939Z] ----

[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/goroutinepanic

[2020-11-11T14:33:13.939Z] Test:    TestWrongPanic/false_positive_failure

[2020-11-11T14:33:13.939Z] /var/lib/jenkins/workspace/Beats_beats_PR-22541/.gvm/versions/go1.14.7.linux.amd64/src/testing/testing.go:654 +0x11a

[2020-11-11T14:33:13.939Z] /var/lib/jenkins/workspace/Beats_beats_PR-22541/.gvm/versions/go1.14.7.linux.amd64/src/testing/testing.go:676 +0x2b

[2020-11-11T14:33:13.939Z] /var/lib/jenkins/workspace/Beats_beats_PR-22541/.gvm/versions/go1.14.7.linux.amd64/src/testing/testing.go:766 +0x78

[2020-11-11T14:33:13.939Z] /var/lib/jenkins/workspace/Beats_beats_PR-22541/src/github.com/elastic/beats/filebeat/placeholder/goroutinepanic/run_test.go:12 +0x76

[2020-11-11T14:33:13.939Z] /var/lib/jenkins/workspace/Beats_beats_PR-22541/src/github.com/elastic/beats/filebeat/placeholder/goroutinepanic/run_test.go:10 +0x3f

Unfortunately the problem is not solved by switching to gotestsum (or running go test). Here it is up to us to ensure we never leak go-routines when a test returns. For example in auditbeat we found tests like:

go func() {
  err := create files
  if err != nil { panic }
}()

wait and validate files (max 30s wait)

The tests did fail (especially on windows) and the go routine did bring down another unrelated test.

testify assert output missing

We use the testify package for validation. The package adds a newline before the actual report. Unfortunately the assert output was missing from all test output in jenkins. We finally tracked down the problem to go-junit-reporter "eating" our test output.

We did create some failing sample tests in order debug the issue. The expected output was:

--- FAIL: TestSimpleAssertFails (0.00s)
    run_test.go:11: 
        	Error Trace:	run_test.go:11
        	Error:      	Should be true
        	Test:       	TestSimpleAssertFails
--- FAIL: TestSimpleAssertWithMessage (0.00s)
    run_test.go:15: 
        	Error Trace:	run_test.go:15
        	Error:      	Should be true
        	Test:       	TestSimpleAssertWithMessage
        	Messages:   	My message
--- FAIL: TestSimpleAssertWithMessagef (0.00s)
    run_test.go:19: 
        	Error Trace:	run_test.go:19
        	Error:      	Should be true
        	Test:       	TestSimpleAssertWithMessagef
        	Messages:   	My message with arguments: 42
--- FAIL: TestSimpleRequireFails (0.00s)
    run_test.go:23: 
        	Error Trace:	run_test.go:23
        	Error:      	Should be true
        	Test:       	TestSimpleRequireFails
--- FAIL: TestSimpleRequireWithMessage (0.00s)
    run_test.go:27: 
        	Error Trace:	run_test.go:27
        	Error:      	Should be true
        	Test:       	TestSimpleRequireWithMessage
        	Messages:   	My message
--- FAIL: TestSimpleRequireWithMessagef (0.00s)
    run_test.go:31: 
        	Error Trace:	run_test.go:31
        	Error:      	Should be true
        	Test:       	TestSimpleRequireWithMessagef
        	Messages:   	My message with arguments: 42
--- FAIL: TestFailEqualMaps (0.00s)
    run_test.go:50: 
        	Error Trace:	run_test.go:50
        	Error:      	Not equal: 
        	            	expected: map[string]interface {}{"a":1, "b":true, "c":"test", "e":map[string]interface {}{"x":"y"}}
        	            	actual  : map[string]interface {}{"a":42, "b":false, "c":"test"}
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,8 +1,5 @@
        	            	-(map[string]interface {}) (len=4) {
        	            	- (string) (len=1) "a": (int) 1,
        	            	- (string) (len=1) "b": (bool) true,
        	            	- (string) (len=1) "c": (string) (len=4) "test",
        	            	- (string) (len=1) "e": (map[string]interface {}) (len=1) {
        	            	-  (string) (len=1) "x": (string) (len=1) "y"
        	            	- }
        	            	+(map[string]interface {}) (len=3) {
        	            	+ (string) (len=1) "a": (int) 42,
        	            	+ (string) (len=1) "b": (bool) false,
        	            	+ (string) (len=1) "c": (string) (len=4) "test"
        	            	 }
        	Test:       	TestFailEqualMaps
FAIL
exit status 1

Unfortunately the actual output was missing the failed assertions:

[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleAssertFails
[2020-11-11T14:33:13.939Z]     run_test.go:11: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleAssertWithMessage
[2020-11-11T14:33:13.939Z]     run_test.go:15: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleAssertWithMessagef
[2020-11-11T14:33:13.939Z]     run_test.go:19: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleRequireFails
[2020-11-11T14:33:13.939Z]     run_test.go:23: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleRequireWithMessage
[2020-11-11T14:33:13.939Z]     run_test.go:27: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestSimpleRequireWithMessagef
[2020-11-11T14:33:13.939Z]     run_test.go:31: 
[2020-11-11T14:33:13.939Z] ----
[2020-11-11T14:33:13.939Z] Package: github.com/elastic/beats/v7/filebeat/placeholder/withassert
[2020-11-11T14:33:13.939Z] Test:    TestFailEqualMaps
[2020-11-11T14:33:13.939Z]     run_test.go:50: 
[2020-11-11T14:33:13.939Z] ----

The new unit tests for GoTest show that the problem is solved by gotestsum

Checklist

• My code follows the style guidelines of this project
• I have commented my code, particularly in hard-to-understand areas
  - [ ] I have made corresponding changes to the documentation
  - [ ] I have made corresponding change to the default configuration files
• I have added tests that prove my fix is effective or that my feature works
  - [ ] I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

How to test this PR locally

make test and the different mage testing commands will use gotestsum now.

Limitations

Tests must not print directly or indirectly to stdout/stdout. The go test -json command does not mark a test as passed/failed in that case, which will subsequently mark the test as failed (unknown state) in the junit report. The test run itself succeeds, though.

Related issues

• Closes Test output of go tests is not printed in CI #21685

[elasticmachine]

Pinging @elastic/integrations-services (Team:Services)

[elasticmachine]

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

• Build Cause: Pull request #23512 opened

• • Start Time: 2021-01-14T16:06:01.582+0000

• Duration: 93 min 5 sec

• Commit: 37dc89a

Test stats 🧪

Test	Results
Failed	0
Passed	17343
Skipped	1372
Total	18715

💚 Flaky test report

Tests succeeded.

Expand to view the summary

Test stats 🧪

Test	Results
Failed	0
Passed	17343
Skipped	1372
Total	18715