Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

runtime/trace: generated timestamps have a jump in them #15102

Closed
mbertschler opened this issue Apr 4, 2016 · 6 comments
Closed

runtime/trace: generated timestamps have a jump in them #15102

mbertschler opened this issue Apr 4, 2016 · 6 comments
Labels
FrozenDueToAge
Milestone
Go1.7

Comments

@mbertschler
Copy link

I discovered a problem with a trace file that was generated on a linux/arm device (Beaglebone Black ARMv7). The program was cross-compiled on my laptop go version go1.6 darwin/amd64 with GOOS=linux GOARCH=arm GOARM=7.

I generated the trace file with runtime/trace packages Start/Stop functions.
Then I transfered the file to my laptop and ran go tool trace. Web browser opened, but when clicking on something it produced the error failed to parse trace: time stamps out of order.
The check that produces this error is here: internal/trace/parser.go

I modified the source code to print the index and timestamps of the relevant events in the tracefile:

index= 1191701   ev.Ts=  147573700100
index= 1191702   ev.Ts=  147573703108
index= 1191703   ev.Ts=  147573707524
index= 1191704   ev.Ts=  147573711028
index= 1191705   ev.Ts=  147573735572
index= 1191706   ev.Ts=  147573865188
index= 1191707   ev.Ts=  147573867444
index= 1191708   ev.Ts=  147573888900
index= 1191709   ev.Ts=  147573893780
index= 1191710   ev.Ts= -147573193487
index= 1191711   ev.Ts= -147573190607
index= 1191712   ev.Ts= -147573186191
index= 1191713   ev.Ts= -147573182815
index= 1191714   ev.Ts= -147573158159
index= 1191715   ev.Ts= -147573029439
index= 1191716   ev.Ts= -147573027279
index= 1191717   ev.Ts= -147573005983
index= 1191718   ev.Ts= -147573001071
index= 1191719   ev.Ts= -147572190527

This is the tracefile: trace_1.zip
Do you also need the code? It is <200LOC but dependent on 32bit Linux system calls.

So except one jump, that looks like just the switch of the sign, everything is consistent.
I was not able to reproduce this. What could have happened here?
@bradfitz bradfitz added this to the Go1.7 milestone Apr 7, 2016
@dvyukov
Copy link
Member

dvyukov commented Apr 7, 2016

Please try the following patch:

diff --git a/src/runtime/os_linux_arm.go b/src/runtime/os_linux_arm.go
index 8fdfb58..f483b33 100644
--- a/src/runtime/os_linux_arm.go
+++ b/src/runtime/os_linux_arm.go
@@ -71,5 +71,5 @@ func cputicks() int64 {
        // Currently cputicks() is used in blocking profiler and to seed fastrand1().
        // nanotime() is a poor approximation of CPU ticks that is enough for the profiler.
        // randomNumber provides better seeding of fastrand1.
-       return nanotime() + int64(randomNumber)
+       return nanotime()// + int64(randomNumber)
 }

@dvyukov
Copy link
Member

dvyukov commented Apr 7, 2016

Or you are not able to reproduce it at all? If so, I guess it is it.

@minux
Copy link
Member

minux commented Apr 7, 2016 via email

@dvyukov
Copy link
Member

dvyukov commented Apr 8, 2016

@minux I meant that maybe randomNumber causes cputicks overflow, and then overflow somehow causes the jump. But randomNumber is int32, so it should not cause int64 overflow.

@gopherbot
Copy link

CL https://golang.org/cl/21730 mentions this issue.

@mbertschler
Copy link
Author

@dvyukov I just tried my "corrupted" file again and with your change it works!
It also makes sense why the *1e9 causes the int64 to overflow here.

ev.Ts = (ev.Ts - minTs) * 1e9 / ticksPerSec

@tv42 tv42 mentioned this issue Aug 16, 2016
Closed
@golang golang locked and limited conversation to collaborators Apr 13, 2017
@rsc rsc unassigned dvyukov Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
Go1.7
Development

No branches or pull requests
5 participants
@bradfitz @minux @dvyukov @mbertschler @gopherbot