search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
123.96k stars 17.66k forks source link

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

Closed laboger closed 8 years ago

laboger commented 9 years ago

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?

laboger commented 8 years ago

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.

ianlancetaylor commented 8 years ago

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 commented 8 years ago

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 commented 8 years ago

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

laboger commented 8 years ago

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.

gopherbot commented 8 years ago

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

vogtd commented 8 years ago

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 commented 8 years ago

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

clnperez commented 8 years ago

And also would be consistent between platforms. :+1:

vogtd commented 8 years ago

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

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

billotosyr commented 8 years ago

It is not yet fixed in golang for s390x.

ianlancetaylor commented 8 years ago

@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 commented 8 years ago

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

gopherbot commented 8 years ago

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

rsc commented 8 years ago

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:

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 commented 8 years ago

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