cmd/trace: dump thread id on proc start

Augment ProcStart events with OS thread id.
This helps in scheduler locality analysis.

Change-Id: I93fea75d3072cf68de66110d0b59d07101badcb5
Reviewed-on: https://go-review.googlesource.com/7302
Reviewed-by: Keith Randall <khr@golang.org>

diff --git a/src/cmd/trace/trace.go b/src/cmd/trace/trace.go
index 41a56b92bb00ad9b5eb5ccc5f91249506e38e8e8..a572ed8f282f7936367854cc088f0e8be3c1b570 100644 (file)
--- a/src/cmd/trace/trace.go
+++ b/src/cmd/trace/trace.go
@@ -391,7 +391,14 @@ func (ctx *traceContext) emitThreadCounters(ev *trace.Event) {
 }
 
 func (ctx *traceContext) emitInstant(ev *trace.Event, name string) {
-       ctx.emit(&ViewerEvent{Name: name, Phase: "I", Scope: "t", Time: ctx.time(ev), Tid: ctx.proc(ev), Stack: ctx.stack(ev.Stk)})
+       var arg interface{}
+       if ev.Type == trace.EvProcStart {
+               type Arg struct {
+                       ThreadID uint64
+               }
+               arg = &Arg{ev.Args[0]}
+       }
+       ctx.emit(&ViewerEvent{Name: name, Phase: "I", Scope: "t", Time: ctx.time(ev), Tid: ctx.proc(ev), Stack: ctx.stack(ev.Stk), Arg: arg})
 }
 
 func (ctx *traceContext) emitArrow(ev *trace.Event, name string) {

diff --git a/src/internal/trace/parser.go b/src/internal/trace/parser.go
index 4e5f534d4cd2a1b235415298180ccf9238555124..44a2e66cfe9f0c70525b01dd0a0c336df900f56c 100644 (file)
--- a/src/internal/trace/parser.go
+++ b/src/internal/trace/parser.go
@@ -584,7 +584,7 @@ const (
        EvFrequency      = 2  // contains tracer timer frequency [frequency (ticks per second)]
        EvStack          = 3  // stack [stack id, number of PCs, array of PCs]
        EvGomaxprocs     = 4  // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id]
-       EvProcStart      = 5  // start of P [timestamp]
+       EvProcStart      = 5  // start of P [timestamp, thread id]
        EvProcStop       = 6  // stop of P [timestamp]
        EvGCStart        = 7  // GC start [timestamp, stack id]
        EvGCDone         = 8  // GC done [timestamp]
@@ -628,7 +628,7 @@ var EventDescriptions = [EvCount]struct {
        EvFrequency:      {"Frequency", false, []string{"freq"}},
        EvStack:          {"Stack", false, []string{"id", "siz"}},
        EvGomaxprocs:     {"Gomaxprocs", true, []string{"procs"}},
-       EvProcStart:      {"ProcStart", false, []string{}},
+       EvProcStart:      {"ProcStart", false, []string{"thread"}},
        EvProcStop:       {"ProcStop", false, []string{}},
        EvGCStart:        {"GCStart", true, []string{}},
        EvGCDone:         {"GCDone", false, []string{}},

diff --git a/src/runtime/pprof/trace_test.go b/src/runtime/pprof/trace_test.go
index efec9a6ba29efed33b8d64e3867a99ca70dcc71f..c57f4b8db17ff16f64a9b38106e4fcbbfedba7a4 100644 (file)
--- a/src/runtime/pprof/trace_test.go
+++ b/src/runtime/pprof/trace_test.go
@@ -101,7 +101,7 @@ func TestTraceStress(t *testing.T) {
                <-done
                wg.Done()
        }()
-       time.Sleep(time.Millisecond)
+       time.Sleep(time.Millisecond) // give the goroutine above time to block
 
        buf := new(bytes.Buffer)
        if err := StartTrace(buf); err != nil {
@@ -109,6 +109,7 @@ func TestTraceStress(t *testing.T) {
        }
 
        procs := runtime.GOMAXPROCS(10)
+       time.Sleep(50 * time.Millisecond) // test proc stop/start events
 
        go func() {
                runtime.LockOSThread()

diff --git a/src/runtime/trace.go b/src/runtime/trace.go
index ea35343552b0b8cb1ddb31d336afc97f78f220b1..eb3ceb2f38050288c39765b8f45898c44340c723 100644 (file)
--- a/src/runtime/trace.go
+++ b/src/runtime/trace.go
@@ -21,7 +21,7 @@ const (
        traceEvFrequency      = 2  // contains tracer timer frequency [frequency (ticks per second)]
        traceEvStack          = 3  // stack [stack id, number of PCs, array of PCs]
        traceEvGomaxprocs     = 4  // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id]
-       traceEvProcStart      = 5  // start of P [timestamp]
+       traceEvProcStart      = 5  // start of P [timestamp, thread id]
        traceEvProcStop       = 6  // stop of P [timestamp]
        traceEvGCStart        = 7  // GC start [timestamp, stack id]
        traceEvGCDone         = 8  // GC done [timestamp]
@@ -716,7 +716,7 @@ func traceGomaxprocs(procs int32) {
 }
 
 func traceProcStart() {
-       traceEvent(traceEvProcStart, -1)
+       traceEvent(traceEvProcStart, -1, uint64(getg().m.id))
 }
 
 func traceProcStop(pp *p) {