diff --git a/src/cmd/trace/trace.go b/src/cmd/trace/trace.go index 7670d330e1..26548fa9de 100644 --- a/src/cmd/trace/trace.go +++ b/src/cmd/trace/trace.go @@ -371,11 +371,15 @@ func generateTrace(params *traceParams) (ViewerData, error) { case trace.EvGCSweepStart: ctx.emitSlice(ev, "SWEEP") case trace.EvGCSweepDone: - case trace.EvGoStart: + case trace.EvGoStart, trace.EvGoStartLabel: ctx.grunnable-- ctx.grunning++ ctx.emitGoroutineCounters(ev) - ctx.emitSlice(ev, gnames[ev.G]) + if ev.Type == trace.EvGoStartLabel { + ctx.emitSlice(ev, ev.SArgs[0]) + } else { + ctx.emitSlice(ev, gnames[ev.G]) + } case trace.EvGoCreate: ctx.gcount++ ctx.grunnable++ diff --git a/src/internal/trace/goroutines.go b/src/internal/trace/goroutines.go index f8673e20bc..f02c7eb91b 100644 --- a/src/internal/trace/goroutines.go +++ b/src/internal/trace/goroutines.go @@ -48,7 +48,7 @@ func GoroutineStats(events []*Event) map[uint64]*GDesc { g := &GDesc{ID: ev.Args[0], CreationTime: ev.Ts, gdesc: new(gdesc)} g.blockSchedTime = ev.Ts gs[g.ID] = g - case EvGoStart: + case EvGoStart, EvGoStartLabel: g := gs[ev.G] if g.PC == 0 { g.PC = ev.Stk[0].PC diff --git a/src/internal/trace/order.go b/src/internal/trace/order.go index 8ca2da52aa..4b788147d1 100644 --- a/src/internal/trace/order.go +++ b/src/internal/trace/order.go @@ -150,7 +150,7 @@ func stateTransition(ev *Event) (g uint64, init, next gState) { g = ev.G init = gState{1, gRunnable} next = gState{2, gWaiting} - case EvGoStart: + case EvGoStart, EvGoStartLabel: g = ev.G init = gState{ev.Args[1], gRunnable} next = gState{ev.Args[1] + 1, gRunning} diff --git a/src/internal/trace/parser.go b/src/internal/trace/parser.go index fa62eccf72..3110d6341f 100644 --- a/src/internal/trace/parser.go +++ b/src/internal/trace/parser.go @@ -28,12 +28,13 @@ type Event struct { StkID uint64 // unique stack ID Stk []*Frame // stack trace (can be empty) Args [3]uint64 // event-type-specific arguments + SArgs []string // event-type-specific string args // linked event (can be nil), depends on event type: // for GCStart: the GCStop // for GCScanStart: the GCScanDone // for GCSweepStart: the GCSweepDone // for GoCreate: first GoStart of the created goroutine - // for GoStart: the associated GoEnd, GoBlock or other blocking event + // for GoStart/GoStartLabel: the associated GoEnd, GoBlock or other blocking event // for GoSched/GoPreempt: the next GoStart // for GoBlock and other blocking events: the unblock event // for GoUnblock: the associated GoStart @@ -126,7 +127,7 @@ func readTrace(r io.Reader) (ver int, events []rawEvent, strings map[uint64]stri return } switch ver { - case 1005, 1007: + case 1005, 1007, 1008: break default: err = fmt.Errorf("unsupported trace file version %v.%v (update Go toolchain) %v", ver/1000, ver%1000, ver) @@ -363,9 +364,12 @@ func parseEvents(ver int, rawEvents []rawEvent, strings map[uint64]string) (even } } switch raw.typ { - case EvGoStart, EvGoStartLocal: + case EvGoStart, EvGoStartLocal, EvGoStartLabel: lastG = e.Args[0] e.G = lastG + if raw.typ == EvGoStartLabel { + e.SArgs = []string{strings[e.Args[2]]} + } case EvGCStart, EvGCDone, EvGCScanStart, EvGCScanDone: e.G = 0 case EvGoEnd, EvGoStop, EvGoSched, EvGoPreempt, @@ -599,7 +603,7 @@ func postProcessTrace(ver int, events []*Event) error { return fmt.Errorf("g %v already exists (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts) } gs[ev.Args[0]] = gdesc{state: gRunnable, ev: ev, evCreate: ev} - case EvGoStart: + case EvGoStart, EvGoStartLabel: if g.state != gRunnable { return fmt.Errorf("g %v is not runnable before start (offset %v, time %v)", ev.G, ev.Off, ev.Ts) } @@ -890,7 +894,8 @@ const ( EvGoStartLocal = 38 // goroutine starts running on the same P as the last event [timestamp, goroutine id] EvGoUnblockLocal = 39 // goroutine is unblocked on the same P as the last event [timestamp, goroutine id, stack] EvGoSysExitLocal = 40 // syscall exit on the same P as the last event [timestamp, goroutine id, real timestamp] - EvCount = 41 + EvGoStartLabel = 41 // goroutine starts running with label [timestamp, goroutine id, seq, label string id] + EvCount = 42 ) var EventDescriptions = [EvCount]struct { @@ -940,4 +945,5 @@ var EventDescriptions = [EvCount]struct { EvGoStartLocal: {"GoStartLocal", 1007, false, []string{"g"}}, EvGoUnblockLocal: {"GoUnblockLocal", 1007, true, []string{"g"}}, EvGoSysExitLocal: {"GoSysExitLocal", 1007, false, []string{"g", "ts"}}, + EvGoStartLabel: {"GoStartLabel", 1008, false, []string{"g", "seq", "label"}}, } diff --git a/src/internal/trace/testdata/http_1_7_good b/src/internal/trace/testdata/http_1_7_good new file mode 100644 index 0000000000..b0e318e9a4 Binary files /dev/null and b/src/internal/trace/testdata/http_1_7_good differ diff --git a/src/internal/trace/testdata/stress_1_7_good b/src/internal/trace/testdata/stress_1_7_good new file mode 100644 index 0000000000..b4d927de34 Binary files /dev/null and b/src/internal/trace/testdata/stress_1_7_good differ diff --git a/src/internal/trace/testdata/stress_start_stop_1_7_good b/src/internal/trace/testdata/stress_start_stop_1_7_good new file mode 100644 index 0000000000..c23ed7dc08 Binary files /dev/null and b/src/internal/trace/testdata/stress_start_stop_1_7_good differ diff --git a/src/runtime/mgc.go b/src/runtime/mgc.go index 37a3554d0d..0e3a4e4f15 100644 --- a/src/runtime/mgc.go +++ b/src/runtime/mgc.go @@ -311,6 +311,14 @@ const ( gcMarkWorkerIdleMode ) +// gcMarkWorkerModeStrings are the strings labels of gcMarkWorkerModes +// to use in execution traces. +var gcMarkWorkerModeStrings = [...]string{ + "GC (dedicated)", + "GC (fractional)", + "GC (idle)", +} + // gcController implements the GC pacing controller that determines // when to trigger concurrent garbage collection and how much marking // work to do in mutator assists and background marking. diff --git a/src/runtime/trace.go b/src/runtime/trace.go index d75019dd62..0bb529ea9d 100644 --- a/src/runtime/trace.go +++ b/src/runtime/trace.go @@ -60,7 +60,8 @@ const ( traceEvGoStartLocal = 38 // goroutine starts running on the same P as the last event [timestamp, goroutine id] traceEvGoUnblockLocal = 39 // goroutine is unblocked on the same P as the last event [timestamp, goroutine id, stack] traceEvGoSysExitLocal = 40 // syscall exit on the same P as the last event [timestamp, goroutine id, real timestamp] - traceEvCount = 41 + traceEvGoStartLabel = 41 // goroutine starts running with label [timestamp, goroutine id, seq, label string id] + traceEvCount = 42 ) const ( @@ -116,11 +117,16 @@ var trace struct { stackTab traceStackTable // maps stack traces to unique ids // Dictionary for traceEvString. - // Currently this is used only for func/file:line info after tracing session, - // so we assume single-threaded access. + // + // Currently this is used only at trace setup and for + // func/file:line info after tracing session, so we assume + // single-threaded access. strings map[string]uint64 stringSeq uint64 + // markWorkerLabels maps gcMarkWorkerMode to string ID. + markWorkerLabels [len(gcMarkWorkerModeStrings)]uint64 + bufLock mutex // protects buf buf traceBufPtr // global trace buffer, used when running without a p } @@ -232,6 +238,18 @@ func StartTrace() error { _g_.m.startingtrace = false trace.enabled = true + // Register runtime goroutine labels. + _, pid, bufp := traceAcquireBuffer() + buf := (*bufp).ptr() + if buf == nil { + buf = traceFlush(0).ptr() + (*bufp).set(buf) + } + for i, label := range gcMarkWorkerModeStrings[:] { + trace.markWorkerLabels[i], buf = traceString(buf, label) + } + traceReleaseBuffer(pid) + unlock(&trace.bufLock) startTheWorld() @@ -361,7 +379,7 @@ func ReadTrace() []byte { trace.headerWritten = true trace.lockOwner = nil unlock(&trace.lock) - return []byte("go 1.7 trace\x00\x00\x00\x00") + return []byte("go 1.8 trace\x00\x00\x00\x00") } // Wait for new data. if trace.fullHead == 0 && !trace.shutdown { @@ -932,7 +950,9 @@ func traceGoStart() { _g_ := getg().m.curg _p_ := _g_.m.p _g_.traceseq++ - if _g_.tracelastp == _p_ { + if _g_ == _p_.ptr().gcBgMarkWorker.ptr() { + traceEvent(traceEvGoStartLabel, -1, uint64(_g_.goid), _g_.traceseq, trace.markWorkerLabels[_p_.ptr().gcMarkWorkerMode]) + } else if _g_.tracelastp == _p_ { traceEvent(traceEvGoStartLocal, -1, uint64(_g_.goid)) } else { _g_.tracelastp = _p_