[go] runtime: skip printlock when output goes to a goroutine buffer

1 view

Skip to first unread message

Gerrit Bot (Gerrit)

unread,

Aug 9, 2026, 9:25:02 PM (9 hours ago) Aug 9

to goph...@pubsubhelper.golang.org, David Teather, golang-co...@googlegroups.com

Gerrit Bot has uploaded the change for review

Commit message

runtime: skip printlock when output goes to a goroutine buffer

runtime.Stack prints its traceback through the print* machinery, which
takes printlock, which acquires the process-global debuglock. Stack
diverts its output into the calling goroutine's own writebuf, so the
lock protects nothing and concurrent callers serialize for no reason.

Return early from printlock and printunlock when gp.writebuf is non-nil
and the M is not dying. writebuf is non-nil only for runtime.Stack and a
few runtime tests, so ordinary print output still takes the lock. The
dying check is needed because gwrite ignores writebuf once the M is
dying and writes to stderr, which is shared.

Also move recordForPanic in gwrite below the writebuf check. It takes
printlock itself and mutates the global printBacklog, so two concurrent
Stack calls would otherwise race on it, invisibly to the race detector
since runtime packages are built NoInstrument. Stack output therefore no
longer reaches printBacklog. A traceback is larger than the 512-byte
buffer, so debug.Stack from recovery middleware was already overwriting
the print output leading up to a crash.

Traceback, panic and fatal error output are unchanged. Three benchmarks
and three tests are added, one of which fails if the recordForPanic move
is dropped.

goos: darwin
goarch: arm64
pkg: runtime
cpu: Apple M2 Pro
                 │     old      │                 new                 │
                 │    sec/op    │   sec/op     vs base                │
Stack-10           1140.5n ± 1%   709.3n ± 1%  -37.81% (p=0.000 n=20)
StackParallel-10   1689.5n ± 3%   110.1n ± 2%  -93.48% (p=0.000 n=20)
StackAll-10         64.72µ ± 7%   54.71µ ± 1%  -15.46% (p=0.000 n=20)
geomean             4.996µ        1.623µ       -67.52%

StackParallel used to get slower as procs were added, 936n at one up to
1682n at eight. It now runs 631n down to 109n. B/op and allocs/op are
unchanged.

Fixes #56400

Change-Id: I21e20cdab5971d2c9f62dfd0a03909c9463e1de6

GitHub-Last-Rev: 576943ce779a2cf42a299879295878f4813b629a

GitHub-Pull-Request: golang/go#80807

Change diff

diff --git a/src/runtime/export_test.go b/src/runtime/export_test.go
index ae5c516..cab12bc 100644
--- a/src/runtime/export_test.go
+++ b/src/runtime/export_test.go
@@ -2102,6 +2102,15 @@
 	return string(buf)
 }
 
+// PrintBacklog returns a copy of the runtime's print backlog.
+func PrintBacklog() []byte {
+	b := make([]byte, len(printBacklog))
+	printlock()
+	copy(b, printBacklog[:])
+	printunlock()
+	return b
+}
+
 // DumpPrint returns the output of print(v).
 func DumpPrint[T any](v T) string {
 	gp := getg()
diff --git a/src/runtime/print.go b/src/runtime/print.go
index 3abdf17..8283359 100644
--- a/src/runtime/print.go
+++ b/src/runtime/print.go
@@ -67,7 +67,14 @@
 // For both these reasons, let a thread acquire the printlock 'recursively'.
 
 func printlock() {
-	mp := getg().m
+	gp := getg()
+	if gp.writebuf != nil && gp.m.dying == 0 {
+		// Output is being diverted into this goroutine's own buffer
+		// (see gwrite), so there is nothing shared to protect. Once
+		// the M is dying gwrite writes to stderr instead, so keep the lock.
+		return
+	}
+	mp := gp.m
 	mp.locks++ // do not reschedule between printlock++ and lock(&debuglock).
 	mp.printlock++
 	if mp.printlock == 1 {
@@ -77,7 +84,11 @@
 }
 
 func printunlock() {
-	mp := getg().m
+	gp := getg()
+	if gp.writebuf != nil && gp.m.dying == 0 {
+		return
+	}
+	mp := gp.m
 	mp.printlock--
 	if mp.printlock == 0 {
 		unlock(&debuglock)
@@ -90,7 +101,6 @@
 	if len(b) == 0 {
 		return
 	}
-	recordForPanic(b)
 	gp := getg()
 	// Don't use the writebuf if gp.m is dying. We want anything
 	// written through gwrite to appear in the terminal rather
@@ -98,6 +108,7 @@
 	// Note that we can't just clear writebuf in the gp.m.dying case
 	// because a panic isn't allowed to have any write barriers.
 	if gp == nil || gp.writebuf == nil || gp.m.dying > 0 {
+		recordForPanic(b)
 		writeErr(b)
 		return
 	}
diff --git a/src/runtime/print_test.go b/src/runtime/print_test.go
index cfc27ed..1229df4 100644
--- a/src/runtime/print_test.go
+++ b/src/runtime/print_test.go
@@ -5,11 +5,131 @@
 package runtime_test
 
 import (
+	"bytes"
 	"math"
 	"runtime"
+	"strconv"
+	"strings"
+	"sync"
 	"testing"
 )
 
+// printlock is skipped while a goroutine's output is diverted into its own
+// writebuf, so exercise that path from several goroutines at once and check
+// that each one still gets exactly its own output.
+func TestPrintConcurrentWritebuf(t *testing.T) {
+	const goroutines = 8
+	const iters = 200
+
+	var wg sync.WaitGroup
+	for g := range goroutines {
+		wg.Add(1)
+		go func() {
+			defer wg.Done()
+			for i := range iters {
+				v := g*iters + i
+				if got, want := runtime.DumpPrint(v), strconv.Itoa(v); got != want {
+					t.Errorf("DumpPrint(%d) = %q, want %q", v, got, want)
+					return
+				}
+			}
+		}()
+	}
+	wg.Wait()
+}
+
+// Stack writes through the same path. Concurrent callers asking only for
+// their own stack must each get one well-formed traceback.
+func TestStackConcurrent(t *testing.T) {
+	const goroutines = 8
+	const iters = 50
+
+	var wg sync.WaitGroup
+	for range goroutines {
+		wg.Add(1)
+		go func() {
+			defer wg.Done()
+			buf := make([]byte, 8192)
+			for range iters {
+				s := string(buf[:runtime.Stack(buf, false)])
+				if !strings.HasPrefix(s, "goroutine ") {
+					t.Errorf("Stack does not begin with %q: %.64q", "goroutine ", s)
+					return
+				}
+				if n := strings.Count(s, "\ngoroutine "); n != 0 {
+					t.Errorf("Stack(all=false) reported %d other goroutines:\n%s", n, s)
+					return
+				}
+				if !strings.Contains(s, "runtime_test.TestStackConcurrent") {
+					t.Errorf("Stack is missing its own frame:\n%s", s)
+					return
+				}
+			}
+		}()
+	}
+	wg.Wait()
+}
+
+// Diverted output must not reach the print backlog, which is a global that
+// recordForPanic maintains under printlock. If it did, concurrent Stack calls
+// would race on it, and each call would also overwrite the crash context the
+// backlog exists to preserve.
+func TestStackLeavesPrintBacklogAlone(t *testing.T) {
+	var wg sync.WaitGroup
+	for range 8 {
+		wg.Add(1)
+		go func() {
+			defer wg.Done()
+			buf := make([]byte, 8192)
+			for range 50 {
+				runtime.Stack(buf, false)
+				runtime.DumpPrint(12345)
+			}
+		}()
+	}
+	wg.Wait()
+
+	// Look for text only a traceback produces.
+	backlog := runtime.PrintBacklog()
+	for _, marker := range []string{"TestStackLeavesPrintBacklogAlone", "goroutine "} {
+		if bytes.Contains(backlog, []byte(marker)) {
+			t.Errorf("print backlog contains traceback text %q:\n%s",
+				marker, bytes.Trim(backlog, "\x00"))
+		}
+	}
+}
+
+func BenchmarkStack(b *testing.B) {
+	buf := make([]byte, 8192)
+	for b.Loop() {
+		runtime.Stack(buf, false)
+	}
+}
+
+func BenchmarkStackParallel(b *testing.B) {
+	b.RunParallel(func(pb *testing.PB) {
+		buf := make([]byte, 8192)
+		for pb.Next() {
+			runtime.Stack(buf, false)
+		}
+	})
+}
+
+func BenchmarkStackAll(b *testing.B) {
+	var wg sync.WaitGroup
+	stop := make(chan struct{})
+	for range 32 {
+		wg.Add(1)
+		go func() { defer wg.Done(); <-stop }()
+	}
+	buf := make([]byte, 1<<16)
+	for b.Loop() {
+		runtime.Stack(buf, true)
+	}
+	close(stop)
+	wg.Wait()
+}
+
 func FuzzPrintFloat64(f *testing.F) {
 	f.Add(math.SmallestNonzeroFloat64)
 	f.Add(math.MaxFloat64)

Change information

Files:

M src/runtime/export_test.go
M src/runtime/print.go
M src/runtime/print_test.go

Change size: M

Delta: 3 files changed, 143 insertions(+), 3 deletions(-)

Open in Gerrit

Related details

Attention set is empty

Submit Requirements:

Code-Review
No-Unresolved-Comments
Review-Enforcement
TryBots-Pass

Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings.

Gerrit

unsatisfied_requirement

satisfied_requirement

open

diffy

Emmanuel Odeke (Gerrit)

unread,

1:10 AM (5 hours ago) 1:10 AM

to David Teather, Gerrit Bot, goph...@pubsubhelper.golang.org, Keith Randall, Austin Clements, Michael Knyszek, Michael Pratt, Ian Lance Taylor, golang-co...@googlegroups.com

Attention needed from Austin Clements, Ian Lance Taylor, Keith Randall, Michael Knyszek and Michael Pratt

Emmanuel Odeke voted Commit-Queue+1

Commit-Queue

Open in Gerrit

Related details

Attention is currently required from:

Austin Clements
Ian Lance Taylor
Keith Randall
Michael Knyszek
Michael Pratt

Submit Requirements:

Code-Review
No-Unresolved-Comments
Review-Enforcement
TryBots-Pass

Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings.

Gerrit

unsatisfied_requirement

satisfied_requirement

open

diffy

Reply all

Reply to author

Forward

0 new messages