Skip to content

time.Now() slow on High Sierra #22601

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.

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

Closed
donovanhide opened this issue Nov 6, 2017 · 5 comments
Closed

time.Now() slow on High Sierra #22601

donovanhide opened this issue Nov 6, 2017 · 5 comments

Comments

@donovanhide
Copy link
Contributor

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

go1.9.2 darwin/amd64

Does this issue reproduce with the latest release?

Yes

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

OS X 10.13 High Sierra

What did you do?

Call time.Now() frequently in latency sensitive code to measure time delay between receipt of network message and final processing of message.

What did you expect to see?

Similar pprof results on OS X and linux.

What did you see instead?

time.now() dominates in pprof profiles when run on OS X, but not on linux.

(pprof) list time.now
Total: 840ms
ROUTINE ======================== time.now in /usr/local/Cellar/go/1.9.2/libexec/src/runtime/sys_darwin_amd64.s
     250ms      250ms (flat, cum) 29.76% of Total
         .          .    212:   MOVQ    SP, DI
         .          .    213:   MOVQ    $0, SI
         .          .    214:   MOVQ    $0, DX  // required as of Sierra; Issue 16570
         .          .    215:   MOVL    $(0x2000000+116), AX // gettimeofday
         .          .    216:   SYSCALL
     250ms      250ms    217:   CMPQ    AX, $0
         .          .    218:   JNE     inreg
         .          .    219:   MOVQ    0(SP), AX
         .          .    220:   MOVL    8(SP), DX
         .          .    221:inreg:
         .          .    222:   // sec is in AX, usec in DX

Seems like the fallback to the syscall happens. Not sure how to prevent this from occurring

@rasky
Copy link
Member

rasky commented Nov 6, 2017

Duplicate of #22037.

This has been fixed on Go tip (will be 1.10), and was decided not to backport it to 1.9.2 because we didn't have any evidence that the loss of nanosecond precision was affecting real-world code. Nor we thought that the increase in execution time was going to impact real-world users.

/cc @rsc

@bradfitz
Copy link
Contributor

bradfitz commented Nov 6, 2017

@rasky, thanks. I'll close this. @donovanhide, we can reopen to discuss backport if you think it's a concern.

@bradfitz bradfitz closed this as completed Nov 6, 2017
@donovanhide
Copy link
Contributor Author

@rasky @bradfitz Sorry, hadn't initially read #22037 carefully enough to see that the fix had been postponed. I guess I am a real world user with real world code, but I can just run tip on OS X if that is easier.

@rasky
Copy link
Member

rasky commented Nov 6, 2017

@donovanhide it would be great if you could confirm that tip fixes for you, thanks

@donovanhide
Copy link
Contributor Author

donovanhide commented Nov 6, 2017

Can confirm, with:

$ go version
go version devel +37b056948d Mon Nov 6 18:23:51 2017 +0000 darwin/amd64

time.now() no longer shows up in pprof profiles at all on High Sierra.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants