Skip to content

Instantly share code, notes, and snippets.

@nirui
Created May 24, 2018 03:03
Show Gist options
  • Save nirui/82608ab20e5aac3bd3c1eb5a8f78d23c to your computer and use it in GitHub Desktop.
Save nirui/82608ab20e5aac3bd3c1eb5a8f78d23c to your computer and use it in GitHub Desktop.
package main
import (
"testing"
"time"
)
func BenchmarkTimeNow(b *testing.B) {
for i := 0; i < b.N; i++ {
time.Now()
}
}
// goos: linux
// goarch: amd64
// BenchmarkTimeNow-2 500000 3758 ns/op
@nirui
Copy link
Author

nirui commented May 24, 2018

Also tested on Go 1.10.2 tarball downloaded directly from Golang website. It still slow but the profile information is differ.

> export GOROOT=/tmp/go1.10.2
> export PATH=/tmp/go1.10.2/bin
> go version
go version go1.10.2 linux/amd64

> go test -bench . -cpuprofile cpu.out
goos: linux
goarch: amd64
BenchmarkTimeNow-2   	  500000	      3632 ns/op
PASS
ok  	_/tmp/test	2.009s

> go tool pprof test.test cpu.out 
File: test.test
Type: cpu
Time: May 24, 2018 at 10:44pm (CST)
Duration: 2s, Total samples = 1.86s (92.86%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 1.86s, 100% of 1.86s total
      flat  flat%   sum%        cum   cum%
     1.76s 94.62% 94.62%      1.76s 94.62%  runtime._ExternalCode
     0.04s  2.15% 96.77%      0.04s  2.15%  runtime.nanotime
     0.04s  2.15% 98.92%      0.07s  3.76%  time.now
     0.01s  0.54% 99.46%      0.08s  4.30%  _/tmp/test.BenchmarkTimeNow
     0.01s  0.54%   100%      0.01s  0.54%  runtime.walltime
         0     0%   100%      1.78s 95.70%  runtime._System
         0     0%   100%      0.08s  4.30%  testing.(*B).launch
         0     0%   100%      0.08s  4.30%  testing.(*B).runN
         0     0%   100%      0.07s  3.76%  time.Now
(pprof) list time.Now
Total: 1.86s
ROUTINE ======================== time.Now in /tmp/go1.10.2/src/time/time.go
         0       70ms (flat, cum)  3.76% of Total
         .          .   1039:// Provided by package runtime.
         .          .   1040:func now() (sec int64, nsec int32, mono int64)
         .          .   1041:
         .          .   1042:// Now returns the current local time.
         .          .   1043:func Now() Time {
         .       70ms   1044:	sec, nsec, mono := now()
         .          .   1045:	sec += unixToInternal - minWall
         .          .   1046:	if uint64(sec)>>33 != 0 {
         .          .   1047:		return Time{uint64(nsec), sec + minWall, Local}
         .          .   1048:	}
         .          .   1049:	return Time{hasMonotonic | uint64(sec)<<nsecShift | uint64(nsec), mono, Local}
(pprof) list time.now
Total: 1.86s
ROUTINE ======================== time.now in /tmp/go1.10.2/src/runtime/timestub.go
      40ms       70ms (flat, cum)  3.76% of Total
         .          .     14:
         .          .     15:func walltime() (sec int64, nsec int32)
         .          .     16:
         .          .     17://go:linkname time_now time.now
         .          .     18:func time_now() (sec int64, nsec int32, mono int64) {
      20ms       20ms     19:	sec, nsec = walltime()
      20ms       50ms     20:	return sec, nsec, nanotime() - startNano
         .          .     21:}
(pprof) 

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment