go: cmd/trace: "failed to parse trace: no consistent ordering of events possible"

What version of Go are you using (`go version`)?

$ go version
go version go1.11.4 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (`go env`)?

go env Output

$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/256dpi/Library/Caches/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/256dpi/Development/Go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/Cellar/go/1.11.4/libexec"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.11.4/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/mj/lp3r462x6tqfd4v_93bvh65h0000gn/T/go-build000614795=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I ran a network intensive go program (closed source) with a fairly light workload.

What did you expect to see?

I expect to be able to obtain a trace profile and explore it with the viewer program.

What did you see instead?

After obtaining the profile with wget -O trace.out "http://localhost:6060/debug/pprof/trace?seconds=10". When running go tool trace trace.out I received:

2019/01/12 12:37:26 Parsing trace...
failed to parse trace: no consistent ordering of events possible

About this issue

Original URL
State: closed
Created 5 years ago
Reactions: 2
Comments: 28 (14 by maintainers)

Commits related to this issue

runtime: synchronize StartTrace and StopTrace with sysmon Currently sysmon is not stopped when the world is stopped, which is in general a difficult thing to do. The result of this is that when traci... — committed to golang/go by mknyszek 4 years ago

Most upvoted comments

For anyone who’s interested in investigating this, I am attaching a trace from the program @AlexRouSg posted. trace.out in the attached repro.zip file was generated with go test -trace=trace.out.

This trace parsing failed because of an unexpected GoSysExit event at offset 48 (almost at the beginning of the trace) This is unexpected - there was no preceding event with the goroutine 17 before this event. We usually expect a GoInSyscall if the goroutine was in syscall. See https://github.com/golang/go/blob/c847589ad06a1acfcceaac7b230c0d5a826caab8/src/runtime/trace.go#L207-L213.

I suspect the code path that should trigger GoInSyscall events for all goroutines in syscall was broken. https://github.com/golang/go/blob/c847589ad06a1acfcceaac7b230c0d5a826caab8/src/runtime/trace.go#L239

I couldn’t find the corresponding stack info (stack id: 0) in the trace, so don’t know what goroutine this is either. 😦

cc runtime people: @dvyukov @aclements @mknyszek @ianlancetaylor

hyangah on Sep 10, 2020

I use curl http://addr:port/debug/pprof/trace to get the trace file, and get the same error. by my test, if my program is in a high concurrency state, the trace file will be parsed failed with the error, if my program is idle, the trace file will be ok.

nejisama on Jul 16, 2021

I have to add, I was testing a binary that was linked with C code (CGO). Is it possible that tracing does not work properly in CGO builds?

256dpi on Jan 15, 2019