Skip to content

Commit

Permalink
runtime/traceback: support tracking goroutine ancestor tracebacks wit…
Browse files Browse the repository at this point in the history
…h GODEBUG="tracebackancestors=N"

Currently, collecting a stack trace via runtime.Stack captures the stack for the
immediately running goroutines. This change extends those tracebacks to include
the tracebacks of their ancestors. This is done with a low memory cost and only
utilized when debug option tracebackancestors is set to a value greater than 0.

Resolves golang#22289

Change-Id: I527b0af222bb3c757c7fd30363e889cec51d8f45
  • Loading branch information
edaniels committed Apr 4, 2018
1 parent 00c8e14 commit 88aaf7b
Show file tree
Hide file tree
Showing 5 changed files with 144 additions and 29 deletions.
6 changes: 6 additions & 0 deletions src/runtime/extern.go
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,12 @@ It is a comma-separated list of name=val pairs setting these named variables:
schedtrace: setting schedtrace=X causes the scheduler to emit a single line to standard
error every X milliseconds, summarizing the scheduler state.
tracebackancestors: setting tracebackancestors=N adds traceback information for goroutines
and their ancestor's tracebacks. This extends the information returned by runtime.Stack.
Ancestor's goroutine ids will refer to the id of the goroutine at the time of creation;
there may exist a new goroutine with the same id. N represents the depth of ancestry
to follow per goroutine. Setting it to 0 will store no ancestry info.
The net and net/http packages also refer to debugging variables in GODEBUG.
See the documentation for those packages for details.
Expand Down
33 changes: 31 additions & 2 deletions src/runtime/proc.go
Original file line number Diff line number Diff line change
Expand Up @@ -3224,16 +3224,17 @@ func malg(stacksize int32) *g {
//go:nosplit
func newproc(siz int32, fn *funcval) {
argp := add(unsafe.Pointer(&fn), sys.PtrSize)
gp := getg()
pc := getcallerpc()
systemstack(func() {
newproc1(fn, (*uint8)(argp), siz, pc)
newproc1(fn, (*uint8)(argp), siz, gp, pc)
})
}

// Create a new g running fn with narg bytes of arguments starting
// at argp. callerpc is the address of the go statement that created
// this. The new g is put on the queue of g's waiting to run.
func newproc1(fn *funcval, argp *uint8, narg int32, callerpc uintptr) {
func newproc1(fn *funcval, argp *uint8, narg int32, callergp *g, callerpc uintptr) {
_g_ := getg()

if fn == nil {
Expand Down Expand Up @@ -3301,6 +3302,7 @@ func newproc1(fn *funcval, argp *uint8, narg int32, callerpc uintptr) {
newg.sched.g = guintptr(unsafe.Pointer(newg))
gostartcallfn(&newg.sched, fn)
newg.gopc = callerpc
newg.ancestors = capturecallerinfo(callergp)
newg.startpc = fn.fn
if _g_.m.curg != nil {
newg.labels = _g_.m.curg.labels
Expand Down Expand Up @@ -3338,6 +3340,33 @@ func newproc1(fn *funcval, argp *uint8, narg int32, callerpc uintptr) {
}
}

// capturecallerinfo copies previous ancestors of the given caller g and
// includes infor for the current caller into a new set of tracebacks for
// a g being created.
func capturecallerinfo(callergp *g) []ancestorInfo {
// Copy all prior info, except for the root goroutine (goid 0).
if debug.tracebackancestors <= 0 || callergp.goid == 0 {
return nil
}
ancestorstocopy := int32(len(callergp.ancestors))
if ancestorstocopy+1 > debug.tracebackancestors {
ancestorstocopy = debug.tracebackancestors - 1
}
ancestors := make([]ancestorInfo, ancestorstocopy+1)
copy(ancestors[1:], callergp.ancestors[:ancestorstocopy])

var pcs [_TracebackMaxFrames]uintptr
npcs := gcallers(callergp, 0, pcs[:])
ipcs := make([]uintptr, npcs)
copy(ipcs, pcs[:npcs])
ancestors[0] = ancestorInfo{
pcs: ipcs,
goid: callergp.goid,
gopc: callergp.gopc,
}
return ancestors
}

// Put on gfree list.
// If local list is too long, transfer a batch to the global list.
func gfput(_p_ *p, gp *g) {
Expand Down
30 changes: 16 additions & 14 deletions src/runtime/runtime1.go
Original file line number Diff line number Diff line change
Expand Up @@ -314,20 +314,21 @@ type dbgVar struct {
// existing int var for that value, which may
// already have an initial value.
var debug struct {
allocfreetrace int32
cgocheck int32
efence int32
gccheckmark int32
gcpacertrace int32
gcshrinkstackoff int32
gcrescanstacks int32
gcstoptheworld int32
gctrace int32
invalidptr int32
sbrk int32
scavenge int32
scheddetail int32
schedtrace int32
allocfreetrace int32
cgocheck int32
efence int32
gccheckmark int32
gcpacertrace int32
gcshrinkstackoff int32
gcrescanstacks int32
gcstoptheworld int32
gctrace int32
invalidptr int32
sbrk int32
scavenge int32
scheddetail int32
schedtrace int32
tracebackancestors int32
}

var dbgvars = []dbgVar{
Expand All @@ -345,6 +346,7 @@ var dbgvars = []dbgVar{
{"scavenge", &debug.scavenge},
{"scheddetail", &debug.scheddetail},
{"schedtrace", &debug.schedtrace},
{"tracebackancestors", &debug.tracebackancestors},
}

func parsedebugvars() {
Expand Down
13 changes: 11 additions & 2 deletions src/runtime/runtime2.go
Original file line number Diff line number Diff line change
Expand Up @@ -378,8 +378,9 @@ type g struct {
sigcode0 uintptr
sigcode1 uintptr
sigpc uintptr
gopc uintptr // pc of go statement that created this goroutine
startpc uintptr // pc of goroutine function
gopc uintptr // pc of go statement that created this goroutine
ancestors []ancestorInfo // ancestor information goroutine(s) that created this goroutine
startpc uintptr // pc of goroutine function
racectx uintptr
waiting *sudog // sudog structures this g is waiting on (that have a valid elem ptr); in lock order
cgoCtxt []uintptr // cgo traceback context
Expand Down Expand Up @@ -743,6 +744,14 @@ type stkframe struct {
argmap *bitvector // force use of this argmap
}

// ancestorInfo details information about a goroutine that
// was an ancestor of another goroutine.
type ancestorInfo struct {
pcs []uintptr // pcs from the stack of this goroutine
goid int64 // goroutine id of this goroutine; original goroutine possibly dead
gopc uintptr // pc of go statement that created this goroutine
}

const (
_TraceRuntimeFrames = 1 << iota // include frames for internal runtime functions.
_TraceTrap // the initial PC, SP are from a trap, not a return PC from a call
Expand Down
91 changes: 80 additions & 11 deletions src/runtime/traceback.go
Original file line number Diff line number Diff line change
Expand Up @@ -627,18 +627,22 @@ func printcreatedby(gp *g) {
pc := gp.gopc
f := findfunc(pc)
if f.valid() && showframe(f, gp, false, false) && gp.goid != 1 {
print("created by ", funcname(f), "\n")
tracepc := pc // back up to CALL instruction for funcline.
if pc > f.entry {
tracepc -= sys.PCQuantum
}
file, line := funcline(f, tracepc)
print("\t", file, ":", line)
if pc > f.entry {
print(" +", hex(pc-f.entry))
}
print("\n")
printcreatedby1(f, pc)
}
}

func printcreatedby1(f funcInfo, pc uintptr) {
print("created by ", funcname(f), "\n")
tracepc := pc // back up to CALL instruction for funcline.
if pc > f.entry {
tracepc -= sys.PCQuantum
}
file, line := funcline(f, tracepc)
print("\t", file, ":", line)
if pc > f.entry {
print(" +", hex(pc-f.entry))
}
print("\n")
}

func traceback(pc, sp, lr uintptr, gp *g) {
Expand Down Expand Up @@ -689,6 +693,67 @@ func traceback1(pc, sp, lr uintptr, gp *g, flags uint) {
print("...additional frames elided...\n")
}
printcreatedby(gp)

for _, ancestor := range gp.ancestors {
printAncestorTraceback(ancestor)
}
}

// printAncestorTraceback prints the traceback of the given ancestor.
func printAncestorTraceback(ancestor ancestorInfo) {
print("[originating from goroutine ", ancestor.goid, "]:\n")
elideWrapper := false
for fidx, pc := range ancestor.pcs {
f := findfunc(pc) // f previously validated
if showfuncinfo(f, fidx == 0, elideWrapper && fidx != 0) {
elideWrapper = printAncestorTracebackFuncInfo(f, pc)
}
}
if len(ancestor.pcs) == _TracebackMaxFrames {
print("...additional frames elided...\n")
}
// Show what created goroutine, except main goroutine (goid 1).
f := findfunc(ancestor.gopc)
if f.valid() && showfuncinfo(f, false, false) && ancestor.goid != 1 {
printcreatedby1(f, ancestor.gopc)
}
}

// printAncestorTraceback prints the given function info at a given pc
// within an ancestor traceback. The precision of this info is reduced
// due to only have access to the pcs at the time of the caller
// goroutine being created.
func printAncestorTracebackFuncInfo(f funcInfo, pc uintptr) bool {
tracepc := pc // back up to CALL instruction for funcline.
if pc > f.entry {
tracepc -= sys.PCQuantum
}
file, line := funcline(f, tracepc)
inldata := funcdata(f, _FUNCDATA_InlTree)
if inldata != nil {
inltree := (*[1 << 20]inlinedCall)(inldata)
ix := pcdatavalue(f, _PCDATA_InlTreeIndex, tracepc, nil)
for ix != -1 {
name := funcnameFromNameoff(f, inltree[ix].func_)
print(name, "(...)\n")
print("\t", file, ":", line, "\n")

file = funcfile(f, inltree[ix].file)
line = inltree[ix].line
ix = inltree[ix].parent
}
}
name := funcname(f)
if name == "runtime.gopanic" {
name = "panic"
}
print(name, "(...)\n")
print("\t", file, ":", line)
if pc > f.entry {
print(" +", hex(pc-f.entry))
}
print("\n")
return elideWrapperCalling(name)
}

func callers(skip int, pcbuf []uintptr) int {
Expand All @@ -711,6 +776,10 @@ func showframe(f funcInfo, gp *g, firstFrame, elideWrapper bool) bool {
if g.m.throwing > 0 && gp != nil && (gp == g.m.curg || gp == g.m.caughtsig.ptr()) {
return true
}
return showfuncinfo(f, firstFrame, elideWrapper)
}

func showfuncinfo(f funcInfo, firstFrame, elideWrapper bool) bool {
level, _, _ := gotraceback()
if level > 1 {
// Show all frames.
Expand Down

0 comments on commit 88aaf7b

Please sign in to comment.