Extra Ms may lead to the "no consistent ordering of events possible" error when parsing trace file with cgo enabled, since:
1. The gs in the extra Ms may be in `_Gdead` status while starting trace by invoking `runtime.StartTrace`,
2. and these gs will trigger `traceEvGoSysExit` events in `runtime.exitsyscall` when invoking go functions from c,
3. then, the events of those gs are under non-consistent ordering, due to missing the previous events.
Add two events, `traceEvGoCreate` and `traceEvGoInSyscall`, in `runtime.StartTrace`, will make the trace parser happy.
Fixes #29707
Change-Id: I2fd9d1713cda22f0ddb36efe1ab351f88da10881
GitHub-Last-Rev:
7bbfddb81b70041250e3c59ce53bea44f7afd2c3
GitHub-Pull-Request: golang/go#54974
Reviewed-on: https://go-review.googlesource.com/c/go/+/429858
Run-TryBot: Michael Pratt <mpratt@google.com>
Reviewed-by: Michael Pratt <mpratt@google.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
Run-TryBot: xie cui <
523516579@qq.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Auto-Submit: Michael Pratt <mpratt@google.com>
gs[g.ID] = g
case EvGoStart, EvGoStartLabel:
g := gs[ev.G]
- if g.PC == 0 {
+ if g.PC == 0 && len(ev.Stk) > 0 {
g.PC = ev.Stk[0].PC
g.Name = ev.Stk[0].Fn
}
func IsSystemGoroutine(entryFn string) bool {
// This mimics runtime.isSystemGoroutine as closely as
// possible.
- return entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
+ // Also, locked g in extra M (with empty entryFn) is system goroutine.
+ return entryFn == "" || entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
}
t.Fatalf("want %s, got %s\n", want, output)
}
}
+
+func TestCgoTraceParser(t *testing.T) {
+ // Test issue 29707.
+ switch runtime.GOOS {
+ case "plan9", "windows":
+ t.Skipf("no pthreads on %s", runtime.GOOS)
+ }
+ output := runTestProg(t, "testprogcgo", "CgoTraceParser")
+ want := "OK\n"
+ if output != want {
+ t.Fatalf("want %s, got %s\n", want, output)
+ }
+}
+
+func TestCgoTraceParserWithOneProc(t *testing.T) {
+ // Test issue 29707.
+ switch runtime.GOOS {
+ case "plan9", "windows":
+ t.Skipf("no pthreads on %s", runtime.GOOS)
+ }
+ output := runTestProg(t, "testprogcgo", "CgoTraceParser", "GOMAXPROCS=1")
+ want := "OK\n"
+ if output != want {
+ t.Fatalf("GOMAXPROCS=1, want %s, got %s\n", want, output)
+ }
+}
casgstatus(gp, _Gidle, _Gdead)
gp.m = mp
mp.curg = gp
+ mp.isextra = true
mp.lockedInt++
mp.lockedg.set(gp)
gp.lockedm.set(mp)
gp.goid = sched.goidgen.Add(1)
+ gp.sysblocktraced = true
if raceenabled {
gp.racectx = racegostart(abi.FuncPCABIInternal(newextram) + sys.PCQuantum)
}
+ if trace.enabled {
+ // Trigger two trace events for the locked g in the extra m,
+ // since the next event of the g will be traceEvGoSysExit in exitsyscall,
+ // while calling from C thread to Go.
+ traceGoCreate(gp, 0) // no start pc
+ gp.traceseq++
+ traceEvent(traceEvGoInSyscall, -1, gp.goid)
+ }
// put on allg for garbage collector
allgadd(gp)
newSigstack bool // minit on C thread called sigaltstack
printlock int8
incgo bool // m is executing a cgo call
+ isextra bool // m is an extra m
freeWait uint32 // if == 0, safe to free g0 and delete m (atomic)
fastrand uint64
needextram bool
--- /dev/null
+// Copyright 2011 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+//go:build !plan9 && !windows
+// +build !plan9,!windows
+
+// This is for issue #29707
+
+package main
+
+/*
+#include <pthread.h>
+
+extern void* callbackTraceParser(void*);
+typedef void* (*cbTraceParser)(void*);
+
+static void testCallbackTraceParser(cbTraceParser cb) {
+ pthread_t thread_id;
+ pthread_create(&thread_id, NULL, cb, NULL);
+ pthread_join(thread_id, NULL);
+}
+*/
+import "C"
+
+import (
+ "bytes"
+ "fmt"
+ traceparser "internal/trace"
+ "runtime/trace"
+ "time"
+ "unsafe"
+)
+
+func init() {
+ register("CgoTraceParser", CgoTraceParser)
+}
+
+//export callbackTraceParser
+func callbackTraceParser(unsafe.Pointer) unsafe.Pointer {
+ time.Sleep(time.Millisecond)
+ return nil
+}
+
+func CgoTraceParser() {
+ buf := new(bytes.Buffer)
+
+ trace.Start(buf)
+ C.testCallbackTraceParser(C.cbTraceParser(C.callbackTraceParser))
+ trace.Stop()
+
+ _, err := traceparser.Parse(buf, "")
+ if err != nil {
+ fmt.Println("Parse error: ", err)
+ } else {
+ fmt.Println("OK")
+ }
+}
if status == _Gsyscall {
gp.traceseq++
traceEvent(traceEvGoInSyscall, -1, gp.goid)
+ } else if status == _Gdead && gp.m != nil && gp.m.isextra {
+ // Trigger two trace events for the dead g in the extra m,
+ // since the next event of the g will be traceEvGoSysExit in exitsyscall,
+ // while calling from C thread to Go.
+ gp.traceseq = 0
+ gp.tracelastp = getg().m.p
+ // +PCQuantum because traceFrameForPC expects return PCs and subtracts PCQuantum.
+ id := trace.stackTab.put([]uintptr{startPCforTrace(0) + sys.PCQuantum}) // no start pc
+ traceEvent(traceEvGoCreate, -1, gp.goid, uint64(id), stackID)
+ gp.traceseq++
+ traceEvent(traceEvGoInSyscall, -1, gp.goid)
} else {
gp.sysblocktraced = false
}
func startPCforTrace(pc uintptr) uintptr {
f := findfunc(pc)
if !f.valid() {
- return pc // should not happen, but don't care
+ return pc // may happen for locked g in extra M since its pc is 0.
}
w := funcdata(f, _FUNCDATA_WrapInfo)
if w == nil {