runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds #11222

laboger · 2015-06-15T18:12:54Z

libgo/runtime/go-nanotime.c calls gettimeofday which only provides microsecond precision, not the nanosecond precision that is documented for Time.

Here is a testcase that demonstrates the problem. I built it using gccgo from the latest gcc5 branch, and I can see the libgo code for go-nanotime.c is the same in trunk so would expect the same behavior there. The problem occurs on ppc64le and x86 with gccgo; did not try ppc64 but would expect that behavior there too. Problem does not occur with golang.

package main

import (
        "fmt"
        "time"
)

const (
        defaultTimeOut = 30
)

func abort(start time.Time, timeOff time.Duration) bool {
        since := time.Since(start)
        now := time.Now()
        fmt.Printf("start: %s since: %d now: %s\n", start.String(), since, now.String())
        return timeOff.Nanoseconds()+time.Since(start).Nanoseconds() > (time.Duration(defaultTimeOut) * time.Second).Nanoseconds()
}

func main() {
        cases := []struct {
                timeOff  time.Duration
                expAbort bool
        }{
                {time.Duration(1), false},
                {time.Duration(2), false},
                {time.Duration(10), false},
                {time.Duration(30), true},
                {time.Duration(40), true},
        }

        for _, c := range cases {
                s := c.timeOff * time.Second
                if a := abort(time.Now(), s); a != c.expAbort {
                        fmt.Printf("Duration %v, expected %v, was %v\n", c.timeOff, s, a)
                }
        }

}

start: 2015-06-15 13:09:04.675845 -0500 CDT since: 7000 now: 2015-06-15 13:09:04.675856 -0500 CDT
start: 2015-06-15 13:09:04.676307 -0500 CDT since: 0 now: 2015-06-15 13:09:04.676307 -0500 CDT
start: 2015-06-15 13:09:04.67633 -0500 CDT since: 0 now: 2015-06-15 13:09:04.676331 -0500 CDT
start: 2015-06-15 13:09:04.676351 -0500 CDT since: 1000 now: 2015-06-15 13:09:04.676352 -0500 CDT
start: 2015-06-15 13:09:04.676373 -0500 CDT since: 0 now: 2015-06-15 13:09:04.676374 -0500 CDT

The value of 0 occurs intermittently for the "since" value in the output due to the lack of precision.

Could clock_gettime be called instead to get nanosecond precision?

The text was updated successfully, but these errors were encountered:

laboger · 2015-11-19T19:43:42Z

Originally I opened this as gccgo only, but now I see it applies to golang as well. The time.now function in sys_linux_ppc64x.s is calling gettimeofday which only has microsecond precision instead of nanosecond precision like Time is supposed.

Fetch the current time in nanoseconds, not microseconds, by using clock_gettime rather than gettimeofday. Update golang/go#11222. Fixes https://gcc.gnu.org/PR66574. Change-Id: Ia9596f6a4b301ac0aa3b311e91106d0b9952ec3f Reviewed-on: https://go-review.googlesource.com/17156 Reviewed-by: Ian Lance Taylor <iant@golang.org>

ianlancetaylor · 2015-11-21T01:31:48Z

This is now fixed on gccgo mainline but the problem remains for the GNU/Linux targets arm64, mips64x, ppc64x. They should call clock_gettime, not gettimeday.

tophj-ibm · 2016-07-27T16:02:12Z

As of go1.7rc3, I'm still seeing this as an issue, at least on ppc64le. Running the same test as above gives.

start: 2016-07-27 14:21:51.111599 +0000 UTC since: 0 now: 2016-07-27 14:21:51.1116 +0000 UTC
start: 2016-07-27 14:21:51.112122 +0000 UTC since: 1000 now: 2016-07-27 14:21:51.112124 +0000 UTC
start: 2016-07-27 14:21:51.112142 +0000 UTC since: 1000 now: 2016-07-27 14:21:51.112144 +0000 UTC
start: 2016-07-27 14:21:51.112162 +0000 UTC since: 260000 now: 2016-07-27 14:21:51.112423 +0000 UTC
start: 2016-07-27 14:21:51.112441 +0000 UTC since: 1000 now: 2016-07-27 14:21:51.112443 +0000 UTC

mwhudson · 2016-07-27T21:31:35Z

The bug is still open so that's not very surprising?

laboger · 2016-08-02T18:55:06Z

We're going to look into fixing this for ppc64x. Just wondering if there was any additional information to share on this. We don't know if it is only wrong for ppc64x or still incorrect on the other platforms mentioned above.

Fetch the current time in nanoseconds, not microseconds, by using clock_gettime rather than gettimeofday. Fixes golang#11222

gopherbot · 2016-08-10T19:00:32Z

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

Fetch the current time in nanoseconds, not microseconds, by using clock_gettime rather than gettimeofday. Updates #11222 Change-Id: I1c2c1b88f80ae82002518359436e19099061c6fb Reviewed-on: https://go-review.googlesource.com/26790 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org> Reviewed-by: Lynn Boger <laboger@linux.vnet.ibm.com> Reviewed-by: Minux Ma <minux@golang.org>

Fetch the current time in nanoseconds, not microseconds, by using clock_gettime rather than gettimeofday. Updates golang#11222 Change-Id: I1c2c1b88f80ae82002518359436e19099061c6fb

vogtd · 2016-08-23T18:00:24Z

I don't actually get where it is required that timestamps in Time format returned by time.Now() have actually nanosecond precision. Certainly not here:
https://golang.org/pkg/time/#Now

bradfitz · 2016-08-23T18:06:12Z

@vogtd, it's not required. It's nice.

clnperez · 2016-08-23T18:30:54Z

And also would be consistent between platforms. 👍

vogtd · 2016-08-23T20:03:00Z

All right, so it's rather an improvement request than a bugreport.

I'm a bit lost about about the status regarding s390[x]:

Is it already fixed in Golang for s390[x](or was it an issue there at all)?
If it's been fixed already, will that fix trickle down automatically into the Gofrontend or should I make a patch for that?

billotosyr · 2016-08-23T20:27:41Z

It is not yet fixed in golang for s390x.

ianlancetaylor · 2016-08-23T20:47:47Z

@vogtd The gofrontend used by gccgo uses different code to get the time. It already returns nanosecond precision for time.Now on s390 (by calling clock_gettime(CLOCK_REALTIME, ...)).

justincormack · 2016-08-24T17:40:58Z

@ianlancetaylor interested in the case of s390x on 1.7 ie not using gccgo, as that is what we are using now.

gopherbot · 2016-08-25T02:00:39Z

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

This should improve the precision of time.now() from microseconds to nanoseconds. Also, modify runtime.nanotime to keep it consistent with cleanup done to time.now. Updates #11222 for s390x. Change-Id: I27864115ea1fee7299360d9003cd3a8355f624d3 Reviewed-on: https://go-review.googlesource.com/27710 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>

rsc · 2016-10-27T13:24:40Z

Ian says gccgo is already OK. I assume it uses clock_gettime(CLOCK_REALTIME) always.

As for the gc toolchain, I surveyed all the time.now implementations in runtime/*.s:

darwin/386: kernel time equation + RDTSC, fallback to gettimeofday (microsecond)
darwin/amd64: kernel time equation + RDTSC, fallback to gettimeofday (microsecond)
darwin/arm: gettimeofday (microsecond)
darwin/arm64: gettimeofday (microsecond)
dragonfly/amd64: clock_gettime(CLOCK_REALTIME) (nanosecond)
freebsd/386: clock_gettime(CLOCK_REALTIME) (nanosecond)
freebsd/amd64: clock_gettime(CLOCK_REALTIME) (nanosecond)
freebsd/arm: clock_gettime(CLOCK_REALTIME) (nanosecond)
linux/386: clock_gettime(CLOCK_REALTIME) (nanosecond)
linux/amd64: vdso_clock_gettime(CLOCK_REALTIME) (nanosecond) if available, or else vdso_gettimeofday (microsecond)
linux/arm: clock_gettime(CLOCK_REALTIME) (nanosecond)
linux/arm64: gettimeofday (microsecond)
linux/mips64x: gettimeofday (microsecond)
linux/ppc64x: clock_gettime(CLOCK_REALTIME) (nanosecond)
linux/s390x: clock_gettime(CLOCK_REALTIME) (nanosecond)
nacl/386: clock_gettime(CLOCK_REALTIME) (nanosecond)
nacl/amd64p32: clock_gettime(CLOCK_REALTIME) (nanosecond)
nacl/arm: clock_gettime(CLOCK_REALTIME) (nanosecond)
netbsd/386: clock_gettime(CLOCK_REALTIME) (nanosecond)
netbsd/amd64: clock_gettime(CLOCK_REALTIME) (nanosecond)
netbsd/arm: clock_gettime(CLOCK_REALTIME) (nanosecond)
openbsd/386: clock_gettime(CLOCK_REALTIME) (nanosecond)
openbsd/amd64: clock_gettime(CLOCK_REALTIME) (nanosecond)
openbsd/arm: clock_gettime(CLOCK_REALTIME) (nanosecond)
plan9/386: nsec (nanosecond)
plan9/amd64: nsec (nanosecond)
plan9/arm: nsec (nanosecond)
solaris/amd64: clock_gettime(CLOCK_REALTIME) (nanosecond)
windows/386: read from kernel memory (100 nanosecond)
windows/amd64: read from kernel memory (100 nanosecond)

On OS X, there is no nanosecond system call. If the kernel equation is not available, the only fallback is gettimeofday (microseconds).

On Linux, arm64 and mips64x should use clock_gettime(CLOCK_REALTIME). That's easy since there is assembly for clock_gettime(CLOCK_MONOTONIC) already that I can copy. I sent CL 32177 for those.

Otherwise it looks like everything is fetching nanosecond precision already.

Of course, precision does not imply accuracy. I doubt that windows is updating the kernel memory copy of the current time every 100ns, for example, and invoking a clock_gettime(CLOCK_REALTIME) system call to fetch the time at nanosecond accuracy may itself take 10s or 100s of nanoseconds. In fact precision does not even imply precision. There's no guarantee that the kernel is even computing nanoseconds during the system call. It might always come back with only microseconds, for example. But that's not Go's problem.

gopherbot · 2016-10-27T13:25:38Z

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

bradfitz assigned ianlancetaylor Jun 15, 2015

ianlancetaylor added this to the Gccgo milestone Jun 15, 2015

brahmaroutu mentioned this issue Jul 13, 2015

time duration should be nano seconds, gccgo treats it as zero moby/moby#14599

Merged

ianlancetaylor changed the title ~~gccgo, time: time.Now() precision is in microseconds, not nanoseconds~~ runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds Nov 21, 2015

ianlancetaylor modified the milestones: Go1.6, Gccgo Nov 21, 2015

ianlancetaylor added the OS-Linux label Nov 21, 2015

rsc modified the milestones: Unplanned, Go1.6 Dec 5, 2015

ceseo added a commit to ceseo/go that referenced this issue Aug 10, 2016

runtime: Use clock_gettime to get current time on ppc64x

cf0c6a7

Fetch the current time in nanoseconds, not microseconds, by using clock_gettime rather than gettimeofday. Fixes golang#11222

bradfitz modified the milestones: Go1.8, Unplanned Aug 10, 2016

clnperez mentioned this issue Aug 24, 2016

Flaky test: DockerSwarmSuite.TestApiSwarmServicesStateReporting moby/moby#24805

Closed

quentinmit added the NeedsFix The path to resolution is known, but the work has not been done. label Oct 11, 2016

gopherbot closed this as completed in 5594074 Oct 27, 2016

golang locked and limited conversation to collaborators Oct 27, 2017

gopherbot added the FrozenDueToAge label Oct 27, 2017

rsc unassigned ianlancetaylor Jun 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds #11222

runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds #11222

laboger commented Jun 15, 2015

laboger commented Nov 19, 2015

ianlancetaylor commented Nov 21, 2015

tophj-ibm commented Jul 27, 2016

mwhudson commented Jul 27, 2016

laboger commented Aug 2, 2016

gopherbot commented Aug 10, 2016

vogtd commented Aug 23, 2016

bradfitz commented Aug 23, 2016

clnperez commented Aug 23, 2016

vogtd commented Aug 23, 2016

billotosyr commented Aug 23, 2016

ianlancetaylor commented Aug 23, 2016

justincormack commented Aug 24, 2016

gopherbot commented Aug 25, 2016

rsc commented Oct 27, 2016

gopherbot commented Oct 27, 2016

runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds #11222

runtime: on PPC64x, arm64, mips64x time.Now precision is in microseconds, not nanoseconds #11222

Comments

laboger commented Jun 15, 2015

laboger commented Nov 19, 2015

ianlancetaylor commented Nov 21, 2015

tophj-ibm commented Jul 27, 2016

mwhudson commented Jul 27, 2016

laboger commented Aug 2, 2016

gopherbot commented Aug 10, 2016

vogtd commented Aug 23, 2016

bradfitz commented Aug 23, 2016

clnperez commented Aug 23, 2016

vogtd commented Aug 23, 2016

billotosyr commented Aug 23, 2016

ianlancetaylor commented Aug 23, 2016

justincormack commented Aug 24, 2016

gopherbot commented Aug 25, 2016

rsc commented Oct 27, 2016

gopherbot commented Oct 27, 2016