[dev.garbage] cmd/gc, runtime: add locks around print statements
Now each C printf, Go print, or Go println is guaranteed
not to be interleaved with other calls of those functions.
This should help when debugging concurrent failures.
LGTM=rlh
R=rlh
CC=golang-codereviews
https://golang.org/cl/169120043
diff --git a/src/cmd/gc/builtin.c b/src/cmd/gc/builtin.c
index bd3fca1..aeeaded 100644
--- a/src/cmd/gc/builtin.c
+++ b/src/cmd/gc/builtin.c
@@ -24,6 +24,8 @@
"func @\"\".printslice (? any)\n"
"func @\"\".printnl ()\n"
"func @\"\".printsp ()\n"
+ "func @\"\".printlock ()\n"
+ "func @\"\".printunlock ()\n"
"func @\"\".concatstring2 (? string, ? string) (? string)\n"
"func @\"\".concatstring3 (? string, ? string, ? string) (? string)\n"
"func @\"\".concatstring4 (? string, ? string, ? string, ? string) (? string)\n"
diff --git a/src/cmd/gc/go.h b/src/cmd/gc/go.h
index 965a055..cc59041 100644
--- a/src/cmd/gc/go.h
+++ b/src/cmd/gc/go.h
@@ -1464,6 +1464,7 @@
void walkexpr(Node **np, NodeList **init);
void walkexprlist(NodeList *l, NodeList **init);
void walkexprlistsafe(NodeList *l, NodeList **init);
+void walkexprlistcheap(NodeList *l, NodeList **init);
void walkstmt(Node **np);
void walkstmtlist(NodeList *l);
Node* conv(Node*, Type*);
diff --git a/src/cmd/gc/runtime.go b/src/cmd/gc/runtime.go
index 38bf6ab..c600771 100644
--- a/src/cmd/gc/runtime.go
+++ b/src/cmd/gc/runtime.go
@@ -36,6 +36,8 @@
func printslice(any)
func printnl()
func printsp()
+func printlock()
+func printunlock()
func concatstring2(string, string) string
func concatstring3(string, string, string) string
diff --git a/src/cmd/gc/walk.c b/src/cmd/gc/walk.c
index 7b502eb..38bed1e 100644
--- a/src/cmd/gc/walk.c
+++ b/src/cmd/gc/walk.c
@@ -364,6 +364,15 @@
}
void
+walkexprlistcheap(NodeList *l, NodeList **init)
+{
+ for(; l; l=l->next) {
+ l->n = cheapexpr(l->n, init);
+ walkexpr(&l->n, init);
+ }
+}
+
+void
walkexpr(Node **np, NodeList **init)
{
Node *r, *l, *var, *a;
@@ -1773,6 +1782,11 @@
calls = nil;
notfirst = 0;
+ // Hoist all the argument evaluation up before the lock.
+ walkexprlistcheap(all, init);
+
+ calls = list(calls, mkcall("printlock", T, init));
+
for(l=all; l; l=l->next) {
if(notfirst) {
calls = list(calls, mkcall("printsp", T, init));
@@ -1853,6 +1867,9 @@
if(op == OPRINTN)
calls = list(calls, mkcall("printnl", T, nil));
+
+ calls = list(calls, mkcall("printunlock", T, init));
+
typechecklist(calls, Etop);
walkexprlist(calls, init);
diff --git a/src/runtime/print1.go b/src/runtime/print1.go
index 8f82688..3d812bd 100644
--- a/src/runtime/print1.go
+++ b/src/runtime/print1.go
@@ -41,7 +41,31 @@
gp.writebuf = nil
}
-//var debuglock mutex
+var debuglock mutex
+
+// The compiler emits calls to printlock and printunlock around
+// the multiple calls that implement a single Go print or println
+// statement. Some of the print helpers (printsp, for example)
+// call print recursively. There is also the problem of a crash
+// happening during the print routines and needing to acquire
+// the print lock to print information about the crash.
+// For both these reasons, let a thread acquire the printlock 'recursively'.
+
+func printlock() {
+ mp := getg().m
+ mp.printlock++
+ if mp.printlock == 1 {
+ lock(&debuglock)
+ }
+}
+
+func printunlock() {
+ mp := getg().m
+ mp.printlock--
+ if mp.printlock == 0 {
+ unlock(&debuglock)
+ }
+}
// write to goroutine-local buffer if diverting output,
// or else standard error.
@@ -80,7 +104,7 @@
// Very simple printf. Only for debugging prints.
// Do not add to this without checking with Rob.
func vprintf(str string, arg unsafe.Pointer) {
- //lock(&debuglock);
+ printlock()
s := bytes(str)
start := 0
@@ -160,7 +184,7 @@
gwrite(s[start:i])
}
- //unlock(&debuglock);
+ printunlock()
}
func printpc(p unsafe.Pointer) {
diff --git a/src/runtime/runtime.h b/src/runtime/runtime.h
index 6a02ef1..ee86f2d 100644
--- a/src/runtime/runtime.h
+++ b/src/runtime/runtime.h
@@ -345,6 +345,7 @@
int32 helpgc;
bool spinning; // M is out of work and is actively looking for work
bool blocked; // M is blocked on a Note
+ int8 printlock;
uint32 fastrand;
uint64 ncgocall; // number of cgo calls in total
int32 ncgo; // number of cgo calls currently in progress
diff --git a/test/live.go b/test/live.go
index f15bb74..55a1bd3 100644
--- a/test/live.go
+++ b/test/live.go
@@ -9,20 +9,39 @@
package main
+func printnl()
+
+//go:noescape
+func printpointer(**int)
+
+//go:noescape
+func printintpointer(*int)
+
+//go:noescape
+func printstringpointer(*string)
+
+//go:noescape
+func printstring(string)
+
+//go:noescape
+func printbytepointer(*byte)
+
+func printint(int)
+
func f1() {
var x *int
- print(&x) // ERROR "live at call to printpointer: x$"
- print(&x) // ERROR "live at call to printpointer: x$"
+ printpointer(&x) // ERROR "live at call to printpointer: x$"
+ printpointer(&x) // ERROR "live at call to printpointer: x$"
}
func f2(b bool) {
if b {
- print(0) // nothing live here
+ printint(0) // nothing live here
return
}
var x *int
- print(&x) // ERROR "live at call to printpointer: x$"
- print(&x) // ERROR "live at call to printpointer: x$"
+ printpointer(&x) // ERROR "live at call to printpointer: x$"
+ printpointer(&x) // ERROR "live at call to printpointer: x$"
}
func f3(b bool) {
@@ -30,22 +49,22 @@
// live throughout the function, to avoid being poisoned
// in GODEBUG=gcdead=1 mode.
- print(0) // ERROR "live at call to printint: x y$"
+ printint(0) // ERROR "live at call to printint: x y$"
if b == false {
- print(0) // ERROR "live at call to printint: x y$"
+ printint(0) // ERROR "live at call to printint: x y$"
return
}
if b {
var x *int
- print(&x) // ERROR "live at call to printpointer: x y$"
- print(&x) // ERROR "live at call to printpointer: x y$"
+ printpointer(&x) // ERROR "live at call to printpointer: x y$"
+ printpointer(&x) // ERROR "live at call to printpointer: x y$"
} else {
var y *int
- print(&y) // ERROR "live at call to printpointer: x y$"
- print(&y) // ERROR "live at call to printpointer: x y$"
+ printpointer(&y) // ERROR "live at call to printpointer: x y$"
+ printpointer(&y) // ERROR "live at call to printpointer: x y$"
}
- print(0) // ERROR "live at call to printint: x y$" "x \(type \*int\) is ambiguously live" "y \(type \*int\) is ambiguously live"
+ printint(0) // ERROR "live at call to printint: x y$" "x \(type \*int\) is ambiguously live" "y \(type \*int\) is ambiguously live"
}
// The old algorithm treated x as live on all code that
@@ -56,20 +75,20 @@
func f4(b1, b2 bool) { // x not live here
if b2 {
- print(0) // x not live here
+ printint(0) // x not live here
return
}
var z **int
x := new(int)
*x = 42
z = &x
- print(**z) // ERROR "live at call to printint: x z$"
+ printint(**z) // ERROR "live at call to printint: x z$"
if b2 {
- print(1) // ERROR "live at call to printint: x$"
+ printint(1) // ERROR "live at call to printint: x$"
return
}
for {
- print(**z) // ERROR "live at call to printint: x z$"
+ printint(**z) // ERROR "live at call to printint: x z$"
}
}
@@ -84,7 +103,7 @@
*y = 54
z = &y
}
- print(**z) // ERROR "live at call to printint: x y$" "x \(type \*int\) is ambiguously live" "y \(type \*int\) is ambiguously live"
+ printint(**z) // ERROR "live at call to printint: x y$" "x \(type \*int\) is ambiguously live" "y \(type \*int\) is ambiguously live"
}
// confusion about the _ result used to cause spurious "live at entry to f6: _".
@@ -155,8 +174,8 @@
// At this point p is dead: the code here cannot
// get to the bottom of the function.
// This used to have a spurious "live at call to printint: p".
- print(1) // nothing live here!
- select { // ERROR "live at call to newselect: autotmp" "live at call to selectgo: autotmp"
+ printint(1) // nothing live here!
+ select { // ERROR "live at call to newselect: autotmp" "live at call to selectgo: autotmp"
case <-c: // ERROR "live at call to selectrecv: autotmp"
return nil
case <-c: // ERROR "live at call to selectrecv: autotmp"
@@ -172,8 +191,8 @@
if b {
// Unlike previous, the cases in this select fall through,
// so we can get to the println, so p is not dead.
- print(1) // ERROR "live at call to printint: p"
- select { // ERROR "live at call to newselect: autotmp.* p" "live at call to selectgo: autotmp.* p"
+ printint(1) // ERROR "live at call to printint: p"
+ select { // ERROR "live at call to newselect: autotmp.* p" "live at call to selectgo: autotmp.* p"
case <-c: // ERROR "live at call to selectrecv: autotmp.* p"
case <-c: // ERROR "live at call to selectrecv: autotmp.* p"
}
@@ -209,7 +228,7 @@
func f14() {
x := g14()
- print(&x) // ERROR "live at call to printpointer: x"
+ printstringpointer(&x) // ERROR "live at call to printstringpointer: x"
}
func g14() string
@@ -217,8 +236,8 @@
func f15() {
var x string
_ = &x
- x = g15() // ERROR "live at call to g15: x"
- print(x) // ERROR "live at call to printstring: x"
+ x = g15() // ERROR "live at call to g15: x"
+ printstring(x) // ERROR "live at call to printstring: x"
}
func g15() string
@@ -282,7 +301,7 @@
}
z = m2[g18()] // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
z = m2[g18()] // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- print(z)
+ printbytepointer(z)
}
var ch chan *byte
@@ -296,7 +315,7 @@
}
z = <-ch // ERROR "live at call to chanrecv1: autotmp_[0-9]+$"
z = <-ch // ERROR "live at call to chanrecv1: autotmp_[0-9]+$"
- print(z)
+ printbytepointer(z)
}
func f20() {
@@ -316,7 +335,7 @@
}
z = m2[[2]string{"x", "y"}] // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
z = m2[[2]string{"x", "y"}] // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- print(z)
+ printbytepointer(z)
}
func f23() {
@@ -328,7 +347,8 @@
}
z, ok = m2[[2]string{"x", "y"}] // ERROR "live at call to mapaccess2: autotmp_[0-9]+$"
z, ok = m2[[2]string{"x", "y"}] // ERROR "live at call to mapaccess2: autotmp_[0-9]+$"
- print(z, ok)
+ printbytepointer(z)
+ print(ok)
}
func f24() {
@@ -350,8 +370,8 @@
}
var x string
_ = &x
- x = g15() // ERROR "live at call to g15: x"
- print(x) // ERROR "live at call to printstring: x"
+ x = g15() // ERROR "live at call to g15: x"
+ printstring(x) // ERROR "live at call to printstring: x"
} // ERROR "live at call to deferreturn: x"
func g25()
@@ -366,7 +386,7 @@
}
print26((*int)(nil), (*int)(nil), (*int)(nil)) // ERROR "live at call to print26: autotmp_[0-9]+$"
print26((*int)(nil), (*int)(nil), (*int)(nil)) // ERROR "live at call to print26: autotmp_[0-9]+$"
- println()
+ printnl()
}
//go:noescape
@@ -381,7 +401,7 @@
}
call27(func() { x++ }) // ERROR "live at call to call27: autotmp_[0-9]+$"
call27(func() { x++ }) // ERROR "live at call to call27: autotmp_[0-9]+$"
- println()
+ printnl()
}
// but defer does escape to later execution in the function
@@ -392,7 +412,7 @@
defer call27(func() { x++ }) // ERROR "live at call to deferproc: autotmp_[0-9]+$" "live at call to deferreturn: autotmp_[0-9]+$"
}
defer call27(func() { x++ }) // ERROR "live at call to deferproc: autotmp_[0-9]+ autotmp_[0-9]+$" "live at call to deferreturn: autotmp_[0-9]+ autotmp_[0-9]+$" "ambiguously live"
- println() // ERROR "live at call to printnl: autotmp_[0-9]+ autotmp_[0-9]+$"
+ printnl() // ERROR "live at call to printnl: autotmp_[0-9]+ autotmp_[0-9]+$"
} // ERROR "live at call to deferreturn: autotmp_[0-9]+ autotmp_[0-9]+$"
// and newproc (go) escapes to the heap
@@ -403,7 +423,7 @@
go call27(func() { x++ }) // ERROR "live at call to newobject: &x" "live at call to newproc: &x$"
}
go call27(func() { x++ }) // ERROR "live at call to newobject: &x"
- println()
+ printnl()
}
//go:noescape
@@ -415,10 +435,10 @@
func f28(b bool) {
if b {
- print(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
+ printstring(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
}
- print(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
- print(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
+ printstring(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
+ printstring(s1 + s2 + s3 + s4 + s5 + s6 + s7 + s8 + s9 + s10) // ERROR "live at call to concatstrings: autotmp_[0-9]+$" "live at call to printstring: autotmp_[0-9]+$"
}
// map iterator should die on end of range loop
@@ -426,14 +446,14 @@
func f29(b bool) {
if b {
for k := range m { // ERROR "live at call to mapiterinit: autotmp_[0-9]+$" "live at call to mapiternext: autotmp_[0-9]+$"
- print(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
+ printstring(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
}
}
for k := range m { // ERROR "live at call to mapiterinit: autotmp_[0-9]+$" "live at call to mapiternext: autotmp_[0-9]+$"
- print(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
+ printstring(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
}
for k := range m { // ERROR "live at call to mapiterinit: autotmp_[0-9]+$" "live at call to mapiternext: autotmp_[0-9]+$"
- print(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
+ printstring(k) // ERROR "live at call to printstring: autotmp_[0-9]+$"
}
}
@@ -446,14 +466,14 @@
// the copy of ptrarr and the internal iterator pointer.
if b {
for _, p := range ptrarr {
- print(p) // ERROR "live at call to printpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
+ printintpointer(p) // ERROR "live at call to printintpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
}
}
for _, p := range ptrarr {
- print(p) // ERROR "live at call to printpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
+ printintpointer(p) // ERROR "live at call to printintpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
}
for _, p := range ptrarr {
- print(p) // ERROR "live at call to printpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
+ printintpointer(p) // ERROR "live at call to printintpointer: autotmp_[0-9]+ autotmp_[0-9]+$"
}
}
@@ -503,44 +523,44 @@
func f33() {
if m33[nil] == 0 { // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- println()
+ printnl()
return
} else {
- println()
+ printnl()
}
- println()
+ printnl()
}
func f34() {
if m33[nil] == 0 { // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- println()
+ printnl()
return
}
- println()
+ printnl()
}
func f35() {
if m33[nil] == 0 && m33[nil] == 0 { // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- println()
+ printnl()
return
}
- println()
+ printnl()
}
func f36() {
if m33[nil] == 0 || m33[nil] == 0 { // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- println()
+ printnl()
return
}
- println()
+ printnl()
}
func f37() {
if (m33[nil] == 0 || m33[nil] == 0) && m33[nil] == 0 { // ERROR "live at call to mapaccess1: autotmp_[0-9]+$"
- println()
+ printnl()
return
}
- println()
+ printnl()
}
// select temps should disappear in the case bodies
@@ -558,44 +578,44 @@
if b {
select { // ERROR "live at call"
case <-fc38(): // ERROR "live at call"
- println()
+ printnl()
case fc38() <- *fi38(1): // ERROR "live at call"
- println()
+ printnl()
case *fi38(2) = <-fc38(): // ERROR "live at call"
- println()
+ printnl()
case *fi38(3), *fb38() = <-fc38(): // ERROR "live at call"
- println()
+ printnl()
}
- println()
+ printnl()
}
- println()
+ printnl()
}
// issue 8097: mishandling of x = x during return.
func f39() (x []int) {
x = []int{1}
- println() // ERROR "live at call to printnl: x"
+ printnl() // ERROR "live at call to printnl: x"
return x
}
func f39a() (x []int) {
x = []int{1}
- println() // ERROR "live at call to printnl: x"
+ printnl() // ERROR "live at call to printnl: x"
return
}
func f39b() (x [10]*int) {
x = [10]*int{}
x[0] = new(int) // ERROR "live at call to newobject: x"
- println() // ERROR "live at call to printnl: x"
+ printnl() // ERROR "live at call to printnl: x"
return x
}
func f39c() (x [10]*int) {
x = [10]*int{}
x[0] = new(int) // ERROR "live at call to newobject: x"
- println() // ERROR "live at call to printnl: x"
+ printnl() // ERROR "live at call to printnl: x"
return
}
@@ -614,7 +634,7 @@
func bad40() {
t := newT40()
- println()
+ printnl()
_ = t
}
@@ -622,6 +642,6 @@
ret := T40{}
ret.m = make(map[int]int) // ERROR "live at call to makemap: ret"
t := &ret
- println() // ERROR "live at call to printnl: ret"
+ printnl() // ERROR "live at call to printnl: ret"
_ = t
}
diff --git a/test/live2.go b/test/live2.go
index ef6ad99..1bd0af2 100644
--- a/test/live2.go
+++ b/test/live2.go
@@ -12,6 +12,8 @@
// issue 8142: lost 'addrtaken' bit on inlined variables.
// no inlining in this test, so just checking that non-inlined works.
+func printnl()
+
type T40 struct {
m map[int]int
}
@@ -24,7 +26,7 @@
func bad40() {
t := newT40() // ERROR "live at call to makemap: ret"
- println() // ERROR "live at call to printnl: ret"
+ printnl() // ERROR "live at call to printnl: ret"
_ = t
}
@@ -32,6 +34,6 @@
ret := T40{}
ret.m = make(map[int]int) // ERROR "live at call to makemap: ret"
t := &ret
- println() // ERROR "live at call to printnl: ret"
+ printnl() // ERROR "live at call to printnl: ret"
_ = t
}
