From 9f9b95bb59176d4b9e381265ea49a8fe15a5f3c1 Mon Sep 17 00:00:00 2001 From: Austin Clements Date: Mon, 23 Nov 2015 11:29:56 -0500 Subject: [release-branch.go1.5] runtime: improve stack barrier debugging This improves stack barrier debugging messages in various ways: 1) Rather than printing only the remaining stack barriers (of which there may be none, which isn't very useful), print all of the G's stack barriers with a marker at the position the stack itself has unwound to and a marker at the problematic stack barrier (where applicable). 2) Rather than crashing if we encounter a stack barrier when there are no more stkbar entries, print the same debug message we would if we had encountered a stack barrier at an unexpected location. Hopefully this will help with debugging #12528. Change-Id: I2e6fe6a778e0d36dd8ef30afd4c33d5d94731262 Reviewed-on: https://go-review.googlesource.com/17147 Reviewed-by: Rick Hudson Reviewed-by: Russ Cox Reviewed-on: https://go-review.googlesource.com/17193 Run-TryBot: Austin Clements TryBot-Result: Gobot Gobot --- src/runtime/mgcmark.go | 28 ++++++++++++++++++++++------ src/runtime/traceback.go | 16 +++++++++------- 2 files changed, 31 insertions(+), 13 deletions(-) diff --git a/src/runtime/mgcmark.go b/src/runtime/mgcmark.go index ac93e16606..151a8bd9a5 100644 --- a/src/runtime/mgcmark.go +++ b/src/runtime/mgcmark.go @@ -608,22 +608,36 @@ func gcRemoveStackBarrier(gp *g, stkbar stkbar) { printlock() print("at *", hex(stkbar.savedLRPtr), " expected stack barrier PC ", hex(stackBarrierPC), ", found ", hex(val), ", goid=", gp.goid, "\n") print("gp.stkbar=") - gcPrintStkbars(gp.stkbar) - print(", gp.stkbarPos=", gp.stkbarPos, ", gp.stack=[", hex(gp.stack.lo), ",", hex(gp.stack.hi), ")\n") + gcPrintStkbars(gp, -1) + print(", gp.stack=[", hex(gp.stack.lo), ",", hex(gp.stack.hi), ")\n") throw("stack barrier lost") } *lrPtr = uintreg(stkbar.savedLRVal) } -// gcPrintStkbars prints a []stkbar for debugging. -func gcPrintStkbars(stkbar []stkbar) { +// gcPrintStkbars prints the stack barriers of gp for debugging. It +// places a "@@@" marker at gp.stkbarPos. If marker >= 0, it will also +// place a "==>" marker before the marker'th entry. +func gcPrintStkbars(gp *g, marker int) { print("[") - for i, s := range stkbar { + for i, s := range gp.stkbar { if i > 0 { print(" ") } + if i == int(gp.stkbarPos) { + print("@@@ ") + } + if i == marker { + print("==> ") + } print("*", hex(s.savedLRPtr), "=", hex(s.savedLRVal)) } + if int(gp.stkbarPos) == len(gp.stkbar) { + print(" @@@") + } + if marker == len(gp.stkbar) { + print(" ==>") + } print("]") } @@ -648,7 +662,9 @@ func gcUnwindBarriers(gp *g, sp uintptr) { gcUnlockStackBarriers(gp) if debugStackBarrier && gp.stkbarPos != before { print("skip barriers below ", hex(sp), " in goid=", gp.goid, ": ") - gcPrintStkbars(gp.stkbar[before:gp.stkbarPos]) + // We skipped barriers between the "==>" marker + // (before) and the "@@@" marker (gp.stkbarPos). + gcPrintStkbars(gp, int(before)) print("\n") } } diff --git a/src/runtime/traceback.go b/src/runtime/traceback.go index 8f27ba4d66..fa13713637 100644 --- a/src/runtime/traceback.go +++ b/src/runtime/traceback.go @@ -142,7 +142,8 @@ func gentraceback(pc0, sp0, lr0 uintptr, gp *g, skip int, pcbuf *uintptr, max in // Fix up returns to the stack barrier by fetching the // original return PC from gp.stkbar. - stkbar := gp.stkbar[gp.stkbarPos:] + stkbarG := gp + stkbar := stkbarG.stkbar[stkbarG.stkbarPos:] if pc0 == ^uintptr(0) && sp0 == ^uintptr(0) { // Signal to fetch saved values from gp. if gp.syscallsp != 0 { @@ -206,8 +207,8 @@ func gentraceback(pc0, sp0, lr0 uintptr, gp *g, skip int, pcbuf *uintptr, max in stkbarPos = gp.stkbarPos - 1 } else { printlock() - print("runtime: failed to unwind through stackBarrier at SP ", hex(sp0), " index ", gp.stkbarPos, "; ") - gcPrintStkbars(gp.stkbar) + print("runtime: failed to unwind through stackBarrier at SP ", hex(sp0), "; ") + gcPrintStkbars(gp, int(gp.stkbarPos)) print("\n") throw("inconsistent state in stackBarrier") } @@ -244,7 +245,8 @@ func gentraceback(pc0, sp0, lr0 uintptr, gp *g, skip int, pcbuf *uintptr, max in sp := frame.sp if flags&_TraceJumpStack != 0 && f.entry == systemstackPC && gp == g.m.g0 && gp.m.curg != nil { sp = gp.m.curg.sched.sp - stkbar = gp.m.curg.stkbar[gp.m.curg.stkbarPos:] + stkbarG = gp.m.curg + stkbar = stkbarG.stkbar[stkbarG.stkbarPos:] } frame.fp = sp + uintptr(funcspdelta(f, frame.pc)) if !usesLR { @@ -282,9 +284,9 @@ func gentraceback(pc0, sp0, lr0 uintptr, gp *g, skip int, pcbuf *uintptr, max in } if frame.lr == stackBarrierPC { // Recover original PC. - if stkbar[0].savedLRPtr != lrPtr { + if len(stkbar) == 0 || stkbar[0].savedLRPtr != lrPtr { print("found next stack barrier at ", hex(lrPtr), "; expected ") - gcPrintStkbars(stkbar) + gcPrintStkbars(stkbarG, len(stkbarG.stkbar)-len(stkbar)) print("\n") throw("missed stack barrier") } @@ -504,7 +506,7 @@ func gentraceback(pc0, sp0, lr0 uintptr, gp *g, skip int, pcbuf *uintptr, max in if callback != nil && n < max && len(stkbar) > 0 { print("runtime: g", gp.goid, ": leftover stack barriers ") - gcPrintStkbars(stkbar) + gcPrintStkbars(stkbarG, len(stkbarG.stkbar)-len(stkbar)) print("\n") throw("traceback has leftover stack barriers") } -- cgit v1.2.3-54-g00ecf