Subject: [Ntp] Wtrlt: Issues with clock_getres() and clock_gettime() on fast machines

From: "Ulrich Windl" <[email-masked]>
Date: Tue, 03 Nov 2020 14:24:35 +0100

(Originally sent to the old list; sorry)
>>> "Ulrich Windl" <[email-masked]> schrieb am 03.11.2020
um
10:40 in Nachricht <[email-masked]>:
> Hi!
> 
> I ran into a problem with an application doing timing:
> clock_getres() returns 1 nanosecond as resolution, even though the actual 
> clock may have less resolution.
> Trying to avoid outputting fractional digits that are more or less nonsense,

> I tried to find out the maximum resolution by doing a few fast clock
samples, 
> building and sorting differences.
> That worked, but then I suddenly got a clock resolution of zero (less than 
> one nanosecond)!
> I debugged it, and actually I saw up to three subsequent calls to 
> clock_gettime() (CLOCK_MONOTONIC in my case) returning exactly the same 
> timestamp, while the time between the calls should be around 2 microseconds

> or so.
> 
> I think in the past (possibly excluding plain old time()) the clock 
> resolution always had been faster than the shortest possible clock polling 
> interval, but recent machines seem to turn that around: If your polling 
> interval is less or equal to clock resolution, the same timestamp will be 
> returned.
> I also think that in the past there was a work‑around ensuring that the time

> will at least advance by one nanosecond between calls, but that's obviously

> not common any more.
> The other problem is with NTP corrections: Assume your clock resolution 
> actually is 1 nanosecond or better, and the minimum polling delay is also 
> about one nanosecond, and the system clock is too fast, going to be
corrected 
> to be slower. Wouldn't then a number of clock_gettime() retrun identical 
> timestamps, or maybe, even worse show a clock running backwards?
> Dividing by a zero or negative time difference will not result in good rate

> numbers, not to talk about application crashes (as it was in my case, so I 
> got alerted initially)...
> 
> I think these issues should be addressed by some informational document, 
> helping implementers to "do things right". Opinions?
> 
> Regards,
> Ulrich

---

From: Miroslav Lichvar <[email-masked]>
Date: Thu, 12 Nov 2020 13:25:55 +0100

> > timestamp, while the time between the calls should be around 2 microseconds

What clocksource did the system use? If it wasn't something
high-resolution like the TSC, I think that wouldn't be unexpected to
get the same value multiple times.

> > interval is less or equal to clock resolution, the same timestamp will be 

No, that depends on the clocksource. In the old days, when the system
clock was just counting interrupts (e.g. 100 per second), that was
normal.

> > will at least advance by one nanosecond between calls, but that's obviously

I don't remember seeing such a workaround. I'm quite certain it wasn't
in Linux.

> > timestamps, or maybe, even worse show a clock running backwards?

It shouldn't never go backward, unless something steps the clock, or
there is a bug in the kernel. Internally, the kernel tracks the error
due to frequency adjustments and it specifically shifts the clock
ahead to avoid some application getting out-of-order timestamps. This
error is corrected over time.

-- 
Miroslav Lichvar

---

From: "Ulrich Windl" <[email-masked]>
Date: Thu, 12 Nov 2020 14:12:44 +0100

>>> Miroslav Lichvar <[email-masked]> schrieb am 12.11.2020 um 13:25 in
> get the same value multiple times.

The "system" was a virtual machine (Xen PVM) _without_ overcommitted CPUs:
Oct 22 17:17:08 v04 kernel: clocksource: refined-jiffies: mask: 0xffffffff
max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Oct 22 17:17:08 v04 kernel: clocksource: xen: mask: 0xffffffffffffffff
max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
Oct 22 17:17:08 v04 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles:
0xffffffff, max_idle_ns: 7645041785100000 ns
Oct 22 17:17:08 v04 kernel: clocksource: Switched to clocksource xen
Oct 22 17:17:08 v04 kernel: clocksource: tsc: mask: 0xffffffffffffffff
max_cycles: 0x266d81f462f, max_idle_ns: 440795264519 ns
Oct 22 17:17:08 v04 kernel: sched_clock: Marking stable (3111544281,
0)->(47790526197528292, -47790523085984011)

Whatever the above means...

> clock was just counting interrupts (e.g. 100 per second), that was

Agreed, I didn't check what gettimeofday actually returned, but I'm sure the
result wasn't zero-padded.

> I don't remember seeing such a workaround. I'm quite certain it wasn't

I had seen it in some multi-processor code returning the time.

> there is a bug in the kernel. Internally, the kernel tracks the error

OK.

> error is corrected over time.

Regards,
Ulrich Windl

---

From: Miroslav Lichvar <[email-masked]>
Date: Thu, 12 Nov 2020 14:50:02 +0100

> The "system" was a virtual machine (Xen PVM) _without_ overcommitted CPUs:

That could explain it. I'm not very familiar with Xen, but generally
the TSC can be virtualized in order to enable migrations, and all kind
of weird things can happen, depending on how it is implemented.

For timekeeping it's best to have access to the real TSC.

> result wasn't zero-padded.

That wouldn't be unexpected if something adjusted the clock (e.g. NTP
client), or the clocksource frequency wasn't just right for the
timestamps to end up with zeros at the end.

-- 
Miroslav Lichvar

---

From: Hal Murray <[email-masked]>
Date: Thu, 12 Nov 2020 12:27:14 -0800

>>> I also think that in the past there was a work‑around
>>> ensuring that the time will at least advance by one nanosecond
>>> between calls, but that's obviously not common any more.

> I had seen it in some multi-processor code returning the time. 

I think one of the BSDs had/has it for the leap second processing.  They stop 
the clock for a second, but each call to get the time bumped the time by a 
nanosecond so databases that used time for unique IDs would keep working 
correctly.

-- 
These are my opinions.  I hate spam.