Stowage/go
2
0
Fork 0
mirror of https://github.com/golang/go.git synced 2025-12-08 06:10:04 +00:00
Code Issues Projects Releases Packages Wiki Activity

testing: reformat test chatty output

Browse source 
In #24929, we decided to stream chatty test output. It looks like,

foo_test.go:138: TestFoo/sub-1: hello from subtest 1
foo_test.go:138: TestFoo/sub-2: hello from subtest 2

In this CL, we refactor the output to be grouped by === CONT lines, preserving
the old test-file-before-log-line behavior:

=== CONT TestFoo/sub-1
    foo_test.go:138 hello from subtest 1
=== CONT TestFoo/sub-2
    foo_test.go:138 hello from subtest 2

This should remove a layer of verbosity from tests, and make it easier to group
together related lines. It also returns to a more familiar format (the
pre-streaming format), whilst still preserving the streaming feature.

Fixes #38458

Change-Id: Iaef94c580d69cdd541b2ef055aa004f50d72d078
Reviewed-on: https://go-review.googlesource.com/c/go/+/229085
Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Bryan C. Mills <bcmills@google.com>
Reviewed-by: Andrew Bonventre <andybons@golang.org>
This commit is contained in:
Jean de Klerk 2020-05-04 14:06:34 -06:00
parent c847589ad0
commit 0a90ecad07
11 changed files with 374 additions and 88 deletions
Download patch file Download diff file Expand all files Collapse all files

81
src/testing/testing.go
View file

@ -325,6 +325,7 @@ var (
cpuListStr *string
parallel *int
testlog *string
printer *testPrinter
haveExamples bool // are there examples?
@ -334,6 +335,49 @@ var (
numFailed uint32 // number of test failures
)
type testPrinter struct {
chatty bool
lastNameMu sync.Mutex // guards lastName
lastName string // last printed test name in chatty mode
}
func newTestPrinter(chatty bool) *testPrinter {
return &testPrinter{
chatty: chatty,
}
}
func (p *testPrinter) Print(testName, out string) {
p.Fprint(os.Stdout, testName, out)
}
func (p *testPrinter) Fprint(w io.Writer, testName, out string) {
if !p.chatty || strings.HasPrefix(out, "--- PASS") || strings.HasPrefix(out, "--- FAIL") {
fmt.Fprint(w, out)
return
}
p.lastNameMu.Lock()
defer p.lastNameMu.Unlock()
if strings.HasPrefix(out, "=== CONT") || strings.HasPrefix(out, "=== RUN") {
p.lastName = testName
fmt.Fprint(w, out)
return
}
if p.lastName == "" {
p.lastName = testName
} else if p.lastName != testName {
// Always printed as-is, with 0 decoration or indentation. So, we skip
// printing to w.
fmt.Printf("=== CONT %s\n", testName)
p.lastName = testName
}
fmt.Fprint(w, out)
}
// The maximum number of stack frames to go through when skipping helper functions for
// the purpose of decorating log messages.
const maxStackLen = 50
@ -354,10 +398,11 @@ type common struct {
cleanupPc []uintptr // The stack trace at the point where Cleanup was called.
chatty bool // A copy of the chatty flag.
bench bool // Whether the current test is a benchmark.
finished bool // Test function has completed.
hasSub int32 // written atomically
raceErrors int // number of races detected during test
runner string // function name of tRunner running the test
hasSub int32 // Written atomically.
raceErrors int // Number of races detected during test.
runner string // Function name of tRunner running the test.
parent *common
level int // Nesting depth of test or benchmark.
@ -496,9 +541,6 @@ func (c *common) decorate(s string, skip int) string {
buf := new(strings.Builder)
// Every line is indented at least 4 spaces.
buf.WriteString(" ")
if c.chatty {
fmt.Fprintf(buf, "%s: ", c.name)
}
fmt.Fprintf(buf, "%s:%d: ", file, line)
lines := strings.Split(s, "\n")
if l := len(lines); l > 1 && lines[l-1] == "" {
@ -517,12 +559,12 @@ func (c *common) decorate(s string, skip int) string {
// flushToParent writes c.output to the parent after first writing the header
// with the given format and arguments.
func (c *common) flushToParent(format string, args ...interface{}) {
func (c *common) flushToParent(testName, format string, args ...interface{}) {
p := c.parent
p.mu.Lock()
defer p.mu.Unlock()
fmt.Fprintf(p.w, format, args...)
printer.Fprint(p.w, testName, fmt.Sprintf(format, args...))
c.mu.Lock()
defer c.mu.Unlock()
@ -697,7 +739,14 @@ func (c *common) logDepth(s string, depth int) {
panic("Log in goroutine after " + c.name + " has completed")
} else {
if c.chatty {
fmt.Print(c.decorate(s, depth+1))
if c.bench {
// Benchmarks don't print === CONT, so we should skip the test
// printer and just print straight to stdout.
fmt.Print(c.decorate(s, depth+1))
} else {
printer.Print(c.name, c.decorate(s, depth+1))
}
return
}
c.output = append(c.output, c.decorate(s, depth+1)...)
@ -942,7 +991,7 @@ func (t *T) Parallel() {
for ; root.parent != nil; root = root.parent {
}
root.mu.Lock()
fmt.Fprintf(root.w, "=== CONT %s\n", t.name)
printer.Fprint(root.w, t.name, fmt.Sprintf("=== CONT %s\n", t.name))
root.mu.Unlock()
}
@ -1001,7 +1050,7 @@ func tRunner(t *T, fn func(t *T)) {
root.duration += time.Since(root.start)
d := root.duration
root.mu.Unlock()
root.flushToParent("--- FAIL: %s (%s)\n", root.name, fmtDuration(d))
root.flushToParent(root.name, "--- FAIL: %s (%s)\n", root.name, fmtDuration(d))
if r := root.parent.runCleanup(recoverAndReturnPanic); r != nil {
fmt.Fprintf(root.parent.w, "cleanup panicked with %v", r)
}
@ -1100,7 +1149,7 @@ func (t *T) Run(name string, f func(t *T)) bool {
for ; root.parent != nil; root = root.parent {
}
root.mu.Lock()
fmt.Fprintf(root.w, "=== RUN %s\n", t.name)
printer.Fprint(root.w, t.name, fmt.Sprintf("=== RUN %s\n", t.name))
root.mu.Unlock()
}
// Instead of reducing the running count of this test before calling the
@ -1266,6 +1315,8 @@ func (m *M) Run() (code int) {
flag.Parse()
}
printer = newTestPrinter(Verbose())
if *parallel < 1 {
fmt.Fprintln(os.Stderr, "testing: -parallel can only be given a positive integer")
flag.Usage()
@ -1309,12 +1360,12 @@ func (t *T) report() {
dstr := fmtDuration(t.duration)
format := "--- %s: %s (%s)\n"
if t.Failed() {
t.flushToParent(format, "FAIL", t.name, dstr)
t.flushToParent(t.name, format, "FAIL", t.name, dstr)
} else if t.chatty {
if t.Skipped() {
t.flushToParent(format, "SKIP", t.name, dstr)
t.flushToParent(t.name, format, "SKIP", t.name, dstr)
} else {
t.flushToParent(format, "PASS", t.name, dstr)
t.flushToParent(t.name, format, "PASS", t.name, dstr)
}
}
}