qbit/go
1
0
Fork 0
mirror of https://github.com/golang/go synced 2024-11-19 21:04:43 -07:00
Code Releases Activity

cmd/trace: exclude threads in syscall on behalf of runtime

Browse Source 
The number of threads in syscall presented by execution tracer's
trace view includes not only the threads calling system calls on behalf
of user created goroutines, but also those running on behalf of system
goroutines.

When the number of such system goroutines was small, the graph was
useful when examining where a program was saturating the CPU.
But as more and more system goroutines are invloved the graph became
less useful for the purpose - for example, after golang.org/cl/34784,
the timer goroutines dominate in the graph with large P
because the runtime creates per-P timer goroutines.

This change excludes the threads in syscall on behalf of runtime (system
goroutines) from the visualization. Alternatively, I could visualize the
count of such threads in a separate counter but in the same graph.
Given that many other debug endpoints (e.g. /debug/pprof/goroutine) hide
the system goroutines, including them in the same graph can confuse users.

Update #22574

Change-Id: If758cd6b9ed0596fde9a471e846b93246580b9d5
Reviewed-on: https://go-review.googlesource.com/81315
Reviewed-by: Austin Clements <austin@google.com>
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
This commit is contained in:
Hana Kim 2017-11-30 18:51:04 -05:00 committed by Hyang-Ah Hana Kim
parent 7b57e21a07
commit 662938850b
1 changed files with 32 additions and 13 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

35
src/cmd/trace/trace.go
View File

@ -287,8 +287,9 @@ type heapStats struct {
}
type threadStats struct {
insyscall uint64
prunning uint64
insyscallRuntime uint64 // system goroutine in syscall
insyscall uint64 // user goroutine in syscall
prunning uint64 // thread running P
}
type frameNode struct {
@ -311,6 +312,7 @@ const (
type gInfo struct {
state gState // current state
name string // name chosen for this goroutine at first EvGoStart
isSystemG bool
start *trace.Event // most recent EvGoStart
markAssist *trace.Event // if non-nil, the mark assist currently running.
}
@ -391,6 +393,7 @@ func generateTrace(params *traceParams) (ViewerData, error) {
ctx.gstates[newState]++
info.state = newState
}
for _, ev := range ctx.events {
// Handle state transitions before we filter out events.
switch ev.Type {
@ -398,10 +401,12 @@ func generateTrace(params *traceParams) (ViewerData, error) {
setGState(ev, ev.G, gRunnable, gRunning)
info := getGInfo(ev.G)
if info.name == "" {
if len(ev.Stk) > 0 {
info.name = fmt.Sprintf("G%v %s", ev.G, ev.Stk[0].Fn)
} else {
if len(ev.Stk) == 0 {
info.name = fmt.Sprintf("G%v", ev.G)
} else {
fname := ev.Stk[0].Fn
info.name = fmt.Sprintf("G%v %s", ev.G, fname)
info.isSystemG = strings.HasPrefix(fname, "runtime.") && fname != "runtime.main"
}
}
info.start = ev
@ -419,10 +424,18 @@ func generateTrace(params *traceParams) (ViewerData, error) {
setGState(ev, ev.Args[0], gWaiting, gRunnable)
case trace.EvGoSysExit:
setGState(ev, ev.G, gWaiting, gRunnable)
if getGInfo(ev.G).isSystemG {
ctx.threadStats.insyscallRuntime--
} else {
ctx.threadStats.insyscall--
}
case trace.EvGoSysBlock:
setGState(ev, ev.G, gRunning, gWaiting)
if getGInfo(ev.G).isSystemG {
ctx.threadStats.insyscallRuntime++
} else {
ctx.threadStats.insyscall++
}
case trace.EvGoSched, trace.EvGoPreempt:
setGState(ev, ev.G, gRunning, gRunnable)
case trace.EvGoStop,
@ -440,7 +453,11 @@ func generateTrace(params *traceParams) (ViewerData, error) {
case trace.EvGoInSyscall:
// Cancel out the effect of EvGoCreate at the beginning.
setGState(ev, ev.G, gRunnable, gWaiting)
if getGInfo(ev.G).isSystemG {
ctx.threadStats.insyscallRuntime++
} else {
ctx.threadStats.insyscall++
}
case trace.EvHeapAlloc:
ctx.heapStats.heapAlloc = ev.Args[0]
case trace.EvNextGC:
@ -449,8 +466,8 @@ func generateTrace(params *traceParams) (ViewerData, error) {
if setGStateErr != nil {
return ctx.data, setGStateErr
}
if ctx.gstates[gRunnable] < 0 || ctx.gstates[gRunning] < 0 || ctx.threadStats.insyscall < 0 {
return ctx.data, fmt.Errorf("invalid state after processing %v: runnable=%d running=%d insyscall=%d", ev, ctx.gstates[gRunnable], ctx.gstates[gRunning], ctx.threadStats.insyscall)
if ctx.gstates[gRunnable] < 0 || ctx.gstates[gRunning] < 0 || ctx.threadStats.insyscall < 0 || ctx.threadStats.insyscallRuntime < 0 {
return ctx.data, fmt.Errorf("invalid state after processing %v: runnable=%d running=%d insyscall=%d insyscallRuntime=%d", ev, ctx.gstates[gRunnable], ctx.gstates[gRunning], ctx.threadStats.insyscall, ctx.threadStats.insyscallRuntime)
}
// Ignore events that are from uninteresting goroutines
@ -663,7 +680,9 @@ func (ctx *traceContext) emitThreadCounters(ev *trace.Event) {
if ctx.prevThreadStats == ctx.threadStats {
return
}
ctx.emit(&ViewerEvent{Name: "Threads", Phase: "C", Time: ctx.time(ev), Pid: 1, Arg: &threadCountersArg{ctx.threadStats.prunning, ctx.threadStats.insyscall}})
ctx.emit(&ViewerEvent{Name: "Threads", Phase: "C", Time: ctx.time(ev), Pid: 1, Arg: &threadCountersArg{
Running: ctx.threadStats.prunning,
InSyscall: ctx.threadStats.insyscall}})
ctx.prevThreadStats = ctx.threadStats
}