From: Dmitry Vyukov Date: Mon, 8 Aug 2016 13:41:18 +0000 (+0200) Subject: internal/trace: fix analysis of EvGoWaiting/EvGoInSyscall events X-Git-Tag: go1.8beta1~1767 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=a50f9859bd15784d047875624c9fa91ce69bd85b;p=gostls13.git internal/trace: fix analysis of EvGoWaiting/EvGoInSyscall events When tracing is started in the middle of program execution, we already have a number of runnable goroutines and a number of blocked/in syscall goroutines. In order to reflect these goroutines in the trace, we emit EvGoCreate for all existing goroutines. Then for blocked/in syscall goroutines we additionally emit EvGoWaiting/EvGoInSyscall events. These events don't reset g.ev during trace analysis. So next EvGoStart finds g.ev set to the previous EvGoCreate. As the result time between EvGoCreate and EvGoStart is accounted as scheduler latency. While in reality it is blocking/syscall time. Properly reset g.ev for EvGoWaiting/EvGoInSyscall events. Change-Id: I0615ba31ed7567600a0667ebb27458481da73adb Reviewed-on: https://go-review.googlesource.com/25572 Reviewed-by: Hyang-Ah Hana Kim --- diff --git a/src/internal/trace/parser.go b/src/internal/trace/parser.go index c31517f683..b1fc17ac58 100644 --- a/src/internal/trace/parser.go +++ b/src/internal/trace/parser.go @@ -581,11 +581,13 @@ func postProcessTrace(ver int, events []*Event) error { return fmt.Errorf("g %v is not runnable before EvGoWaiting (offset %v, time %v)", ev.G, ev.Off, ev.Ts) } g.state = gWaiting + g.ev = ev case EvGoInSyscall: if g.state != gRunnable { return fmt.Errorf("g %v is not runnable before EvGoInSyscall (offset %v, time %v)", ev.G, ev.Off, ev.Ts) } g.state = gWaiting + g.ev = ev case EvGoCreate: if err := checkRunning(p, g, ev, true); err != nil { return err