Flip GO_TEST_WRAP_TESTV default

[sluongng]

In https://github.com/bazelbuild/rules_go/issues/2364, it was established that GO_TEST_WRAP_TESTV will be opt-in instead of opt-out. The main reason was --test_output=errors output will contain more verbose outputs of successful test cases being mixed among failed test cases.

For example

> cat main_test.go
package main

import "testing"

func TestHelloWorld(t *testing.T) {
}

func TestHelloWorld2(t *testing.T) {
}

func TestHelloWorld3(t *testing.T) {
}

func TestHelloWorld4(t *testing.T) {
}

func TestHelloWorld5(t *testing.T) {
    t.Fatal("blah")
}

> bazel 2>/dev/null test :all --test_env=GO_TEST_WRAP_TESTV=1
==================== Test output for //:a_test:
=== RUN   TestHelloWorld
--- PASS: TestHelloWorld (0.00s)
=== RUN   TestHelloWorld2
--- PASS: TestHelloWorld2 (0.00s)
=== RUN   TestHelloWorld3
--- PASS: TestHelloWorld3 (0.00s)
=== RUN   TestHelloWorld4
--- PASS: TestHelloWorld4 (0.00s)
=== RUN   TestHelloWorld5
    main_test.go:18: blah
--- FAIL: TestHelloWorld5 (0.00s)
FAIL
================================================================================
//:a_test                                                                FAILED in 0.0s
  /private/var/tmp/_bazel_sluongng/f16739de4a8438c42e8aba41e8e74b32/execroot/_main/bazel-out/darwin_arm64-fastbuild/testlogs/a_test/test.log

Executed 1 out of 1 test: 1 fails locally.
exit 3

> bazel 2>/dev/null test :all --test_env=GO_TEST_WRAP_TESTV=0
==================== Test output for //:a_test:
--- FAIL: TestHelloWorld5 (0.00s)
    main_test.go:18: blah
FAIL
================================================================================
//:a_test                                                                FAILED in 0.0s
  /private/var/tmp/_bazel_sluongng/f16739de4a8438c42e8aba41e8e74b32/execroot/_main/bazel-out/darwin_arm64-fastbuild/testlogs/a_test/test.log

Executed 1 out of 1 test: 1 fails locally.
exit 3

However, I think we should flip this to opt-out instead of opt-in. The reasons are:

1. --test_output=errors is not the default in Bazel. To make it a default, the user would have to set it in a custom .bazelrc file, and in there, the opt-out could be set accordingly to achieve desired outputs.

2. In the happy case where all tests succeed, the test.xml file will be created by parsing the verbose output. Currently, because of the default non-verbose output, the test.xml file is relatively empty and useless. However, with verbose output, each test func would be converted to a testcase in the XML, decorated with execution time to aid test performance investigation. This is especially potent when used with BES service that could help analyze these XMLs overtime.

3. Big test targets could be sharded to reduce the amount of func included in each shard. Note that Bazel does cap the maximum shard count to 25 to help promote smaller targets/packages. With the addition of https://github.com/bazelbuild/bazel-gazelle/pull/1597, user would now have more ways to reduce their go_test target size

So I think a modest change like this

diff --git a/go/tools/bzltestutil/wrap.go b/go/tools/bzltestutil/wrap.go
index 511768c8..c3ccbf75 100644
--- a/go/tools/bzltestutil/wrap.go
+++ b/go/tools/bzltestutil/wrap.go
@@ -61,7 +61,7 @@ func shouldAddTestV() bool {
                }
                return wrap
        }
-       return false
+       return true
 }

would help improve new users' experience while still allowing power users to optionally opt-out with --test_env=GO_TEST_WRAP_TESTV=0

[sluongng]

@fmeum @linzhp This is pretty much an RFC. I discovered this recently when digging through why go_test is rendered on BuildBuddy UI differently from other rules.

Here is the before verbose enabled

and here is the after test verbose enabled

I think for many of our customers who are using rules_go, this small improvement could be a BIG deal.

I could send a simple PR if I could get the current maintainers to agree on this issue.

[linzhp]

--test_output=errors and GO_TEST_WRAP_TESTV=1 are independent. Even without --test_output=errors, when a test fail, people will have to open the test.log to see what's going on. GO_TEST_WRAP_TESTV=1 is too verbose for most cases, local dev or CI, terminal output or test.log. This makes it even worse on CI jobs that runs thousands of tests from one shard, especially with RBE. In fact, we only set GO_TEST_WRAP_TESTV in a job that is detecting flaky tests, which needs to analyze test.xml. As test.xml is meant to be read by a program, it's easy for that program to set GO_TEST_WRAP_TESTV too.

So I agree with @robbertvanginkel that GO_TEST_WRAP_TESTV=0 is a better default. BuildBuddy UI does make the test result look nicer with GO_TEST_WRAP_TESTV=1, but you can set it by default from BuildBuddy UI, right?

[sluongng]

I think there is a discoverability problem with GO_TEST_WRAP_TESTV though. It took me quite some digging to find this config knob and I think we have plenty of customers who would want it enabled.

CI jobs that runs thousands of tests from one shard

😱. I guess it's fine if the tests are relatively fast themselves.

but you can set it by default from BuildBuddy UI, right?

The default still needs to be set either on the test rule or on the .bazelrc config. I strongly believe that this could be quite beneficial for use cases outside of BuildBuddy as well. Knowing how much time is spent on each test func in a target is valuable for development purposes.

[fmeum]

Could we have both? Always specify test.v in the wrapper and use the output to populate the XML file, but by default filter out most lines.

I could see this becoming a problem with test cases that execute in parallel though as their outputs may mix.

[sluongng]

I like your idea @fmeum

We could potentially filter these out ourselves from the test log? 🤔

=== RUN   TestHelloWorld
--- PASS: TestHelloWorld (0.00s)
=== RUN   TestHelloWorld2
--- PASS: TestHelloWorld2 (0.00s)
=== RUN   TestHelloWorld3
--- PASS: TestHelloWorld3 (0.00s)
=== RUN   TestHelloWorld4
--- PASS: TestHelloWorld4 (0.00s)
=== RUN   TestHelloWorld5

The ordering here

    main_test.go:18: blah
--- FAIL: TestHelloWorld5 (0.00s)
FAIL

is slightly different from

--- FAIL: TestHelloWorld5 (0.00s)
    main_test.go:18: blah
FAIL

though.

I could see this becoming a problem with test cases that execute in parallel though as their outputs may mix.

I think these should be funneled through Go's testing package already, and if it's not, then it would make not much of a difference here?

[linzhp]

The default still needs to be set either on the test rule or on the .bazelrc config.

The way we do it is to have this in the default .bazelrc:

test --test_output=errors
try-import %workspace%/.ci.bazelrc

So people will see the test errors on local machines and most CI jobs. Different CI jobs populate different .ci.bazelrc. For the jobs that need test.xml, they can either run with --test_env=GO_TEST_WRAP_TESTV=1 or put that in .ci.bazelrc.