36

What is the correct way to precisely measure a time duration in Go? Most application just use the standard time package and the following approach:

var startTime = time.Now()
doSomeHardWork()
var duration = time.Since(startTime) // or: time.Now() - startTime

However, time.Now() returns the current system time, which leads to two flaws:

  1. If the system time is changed during the measurement (for example due to a time zone change (DST) or a leap second), the resulting duration is also wrong.
  2. The system time can tick deliberately faster or slower than the real time. This always happens when the operating system synchronizes the internal clock with NTP time servers (which might happen several times an hour!)

    From MSDN:

    [The time service] adjusts the local clock rate to allow it to converge toward the correct time. If the time difference between the local clock and the [accurate time sample] is too large to correct by adjusting the local clock rate, the time service sets the local clock to the correct time.

If the system time changes (either manually or due to DST), it might be possible to detect the invalid duration and discard it. But if the system clock ticks e.g. 10% faster to synchronize with world-time, it is practically impossible to detect. That's intended behaviour and how the system clock is designed.

For that reason, most other languages offer a dedicated API for measuring durations:

What is the correct way to precisely measure execution time in Go?

peterSO
  • 158,998
  • 31
  • 281
  • 276
maja
  • 17,250
  • 17
  • 82
  • 125
  • Technically `performance.now()` is a DOM feature, not JavaScript. If you're running JS e.g. on a server you'll have some other API. – OrangeDog Aug 21 '17 at 16:15
  • 1
    If you're trying to profile the performance of some code, it's often useful to use CPU performance counters to measure time in core clock cycles, rather than wall-clock time, so CPU frequency-scaling makes less difference. (This makes sense if it's CPU-bound, not memory-bound (since memory frequency usually stays constant), and definitely not I/O bound.) Perf counters can also help you find *why* it takes the time it does, e.g. cache misses vs. branch mispredicts vs. high latency long dependency chains vs. actually maxing out CPU front-end or execution-unit throughput. – Peter Cordes Aug 21 '17 at 16:52
  • e.g. on Linux `perf record ./a.out`, then `perf report`. – Peter Cordes Aug 21 '17 at 16:53

3 Answers3

46

Package time

Monotonic Clocks

Operating systems provide both a “wall clock,” which is subject to changes for clock synchronization, and a “monotonic clock,” which is not. The general rule is that the wall clock is for telling time and the monotonic clock is for measuring time. Rather than split the API, in this package the Time returned by time.Now contains both a wall clock reading and a monotonic clock reading; later time-telling operations use the wall clock reading, but later time-measuring operations, specifically comparisons and subtractions, use the monotonic clock reading.

For example, this code always computes a positive elapsed time of approximately 20 milliseconds, even if the wall clock is changed during the operation being timed:

start := time.Now()
... operation that takes 20 milliseconds ...
t := time.Now()
elapsed := t.Sub(start)

Other idioms, such as time.Since(start), time.Until(deadline), and time.Now().Before(deadline), are similarly robust against wall clock resets.

Starting with Go 1.9 (released August 24, 2017), Go uses a monotonic clock for durations.

See Proposal: Monotonic Elapsed Time Measurements in Go.

peterSO
  • 158,998
  • 31
  • 281
  • 276
  • 3
    That is a pretty genious API design. Much better than providing a separate function and relying on the programmer to chose the right one (which many don't). – maja Aug 21 '17 at 07:28
  • @maja: I have added a link to the design document (proposal). – peterSO Aug 21 '17 at 07:36
  • 4
    Doesn't this mean that if `a` and `b` are times, it's possible for `b - a + a != b`? – Dan Aug 24 '17 at 12:25
  • 2
    Instead of `elapsed := t.Sub(start)` you can use `elapsed := time.Since(start)` an skip the second call to `Now()` – Jobu Nov 08 '21 at 18:52
8

This is available in Go 1.9 (August 2017) with monotonic clocks, you won't have to do anything special to benefit from it:

https://tip.golang.org/pkg/time/#hdr-Monotonic_Clocks

Operating systems provide both a “wall clock,” which is subject to changes for clock synchronization, and a “monotonic clock,” which is not. The general rule is that the wall clock is for telling time and the monotonic clock is for measuring time. Rather than split the API, in this package the Time returned by time.Now contains both a wall clock reading and a monotonic clock reading; later time-telling operations use the wall clock reading, but later time-measuring operations, specifically comparisons and subtractions, use the monotonic clock reading.

For example, this code always computes a positive elapsed time of approximately 20 milliseconds, even if the wall clock is changed during the operation being timed:

start := time.Now()
... operation that takes 20 milliseconds ...
t := time.Now()
elapsed := t.Sub(start)

Other idioms, such as time.Since(start), time.Until(deadline), and time.Now().Before(deadline), are similarly robust against wall clock resets.

This change to the time pkg was triggered by this issue, which prompted this proposal for change from Russ Cox:

Comparison and subtraction of times observed by time.Now can return incorrect results if the system wall clock is reset between the two observations. We propose to extend the time.Time representation to hold an additional monotonic clock reading for use in those calculations. Among other benefits, this should make it impossible for a basic elapsed time measurement using time.Now and time.Since to report a negative duration or other result not grounded in reality.

Kenny Grant
  • 9,360
  • 2
  • 33
  • 47
6

For Go 1.8 and before, the correct timing function is not inside the time package, but instead in the runtime package:

func nanotime() int64

In order to correctly measure execution time, the following procedure should be used:

var startTime = runtime.nanotime()
doSomeHardWork()
var duration = runtime.nanotime() - startTime

Unfortunately, the method itself is not documented very well. It emerged in this issue after a long discussion if it was really neccessary. For Go 1.9 and newer, refer to Kenny Grant's answer.

maja
  • 17,250
  • 17
  • 82
  • 125
  • 1
    runtime.nanotime() is not exported An example is here https://github.com/gavv/monotime/blob/master/monotime.go Pay attention to //go:linkname – Larytet Sep 14 '18 at 21:57