From 9c89923266a372e9357dc3296b6c53bb931dd4a9 Mon Sep 17 00:00:00 2001 From: Austin Clements Date: Mon, 5 Nov 2018 12:36:42 -0500 Subject: [PATCH] runtime: deflake TestTracebackAncestors TestTracebackAncestors has a ~0.1% chance of failing with more goroutines in the traceback than expected. This happens because there's a window between each goroutine starting its child and that goroutine actually exiting. The test captures its own stack trace after everything is "done", but if this happens during that window, it will include the goroutine that's in the process of being torn down. Here's an example of such a failure: https://build.golang.org/log/fad10d0625295eb79fa879f53b8b32b9d0596af8 This CL fixes this by recording the goroutines that are expected to exit and removing them from the stack trace. With this fix, this test passed 15,000 times with no failures. Change-Id: I71e7c6282987a15e8b74188b9c585aa2ca97cbcd Reviewed-on: https://go-review.googlesource.com/c/147517 Run-TryBot: Austin Clements TryBot-Result: Gobot Gobot Reviewed-by: Ian Lance Taylor --- .../testdata/testprog/traceback_ancestors.go | 56 +++++++++++++++++-- 1 file changed, 51 insertions(+), 5 deletions(-) diff --git a/src/runtime/testdata/testprog/traceback_ancestors.go b/src/runtime/testdata/testprog/traceback_ancestors.go index fe57c1c157..0ee402c4bd 100644 --- a/src/runtime/testdata/testprog/traceback_ancestors.go +++ b/src/runtime/testdata/testprog/traceback_ancestors.go @@ -5,8 +5,10 @@ package main import ( + "bytes" "fmt" "runtime" + "strings" ) func init() { @@ -18,25 +20,50 @@ const numFrames = 2 func TracebackAncestors() { w := make(chan struct{}) - recurseThenCallGo(w, numGoroutines, numFrames) + recurseThenCallGo(w, numGoroutines, numFrames, true) <-w printStack() close(w) } +var ignoreGoroutines = make(map[string]bool) + func printStack() { buf := make([]byte, 1024) for { n := runtime.Stack(buf, true) if n < len(buf) { - fmt.Print(string(buf[:n])) + tb := string(buf[:n]) + + // Delete any ignored goroutines, if present. + pos := 0 + for pos < len(tb) { + next := pos + strings.Index(tb[pos:], "\n\n") + if next < pos { + next = len(tb) + } else { + next += len("\n\n") + } + + if strings.HasPrefix(tb[pos:], "goroutine ") { + id := tb[pos+len("goroutine "):] + id = id[:strings.IndexByte(id, ' ')] + if ignoreGoroutines[id] { + tb = tb[:pos] + tb[next:] + next = pos + } + } + pos = next + } + + fmt.Print(tb) return } buf = make([]byte, 2*len(buf)) } } -func recurseThenCallGo(w chan struct{}, frames int, goroutines int) { +func recurseThenCallGo(w chan struct{}, frames int, goroutines int, main bool) { if frames == 0 { // Signal to TracebackAncestors that we are done recursing and starting goroutines. w <- struct{}{} @@ -44,10 +71,29 @@ func recurseThenCallGo(w chan struct{}, frames int, goroutines int) { return } if goroutines == 0 { + // Record which goroutine this is so we can ignore it + // in the traceback if it hasn't finished exiting by + // the time we printStack. + if !main { + ignoreGoroutines[goroutineID()] = true + } + // Start the next goroutine now that there are no more recursions left // for this current goroutine. - go recurseThenCallGo(w, frames-1, numFrames) + go recurseThenCallGo(w, frames-1, numFrames, false) return } - recurseThenCallGo(w, frames, goroutines-1) + recurseThenCallGo(w, frames, goroutines-1, main) +} + +func goroutineID() string { + buf := make([]byte, 128) + runtime.Stack(buf, false) + const prefix = "goroutine " + if !bytes.HasPrefix(buf, []byte(prefix)) { + panic(fmt.Sprintf("expected %q at beginning of traceback:\n%s", prefix, buf)) + } + buf = buf[len(prefix):] + n := bytes.IndexByte(buf, ' ') + return string(buf[:n]) } -- 2.50.0