NetBSD Problem Report #53016
From kivinen@vielako.iki.fi Mon Feb 12 18:23:19 2018
Return-Path: <kivinen@vielako.iki.fi>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
by mollari.NetBSD.org (Postfix) with ESMTPS id D83977A1EA
for <gnats-bugs@gnats.NetBSD.org>; Mon, 12 Feb 2018 18:23:19 +0000 (UTC)
Message-Id: <201802121715.w1CHF131007087@vielako.iki.fi>
Date: Mon, 12 Feb 2018 19:15:01 +0200 (EET)
From: kivinen@iki.fi
Reply-To: kivinen@iki.fi
To: gnats-bugs@NetBSD.org
Subject: Clock not stable
X-Send-Pr-Version: 3.95
>Number: 53016
>Category: kern
>Synopsis: Clock not stable
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: kern-bug-people
>State: open
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Mon Feb 12 18:25:00 +0000 2018
>Last-Modified: Fri Nov 30 23:20:01 +0000 2018
>Originator: Tero Kivinen
>Release: NetBSD 8.0_BETA
>Organization:
IKI ry
>Environment:
System: NetBSD vielako.iki.fi 8.0_BETA NetBSD 8.0_BETA (GENERIC) #0: Wed Nov 8 23:20:26 EET 2017 kivinen@vielako.iki.fi:/usr/obj/sys/arch/amd64/compile/GENERIC amd64
Architecture: x86_64
Machine: amd64
Supermicro X8SIU (0123456789)
cpu0 at mainbus0 apid 0
cpu0: Intel(R) Xeon(R) CPU X3430 @ 2.40GHz, id 0x106e5
cpu0: package 0, core 0, smt 0
cpu1 at mainbus0 apid 2
cpu1: Intel(R) Xeon(R) CPU X3430 @ 2.40GHz, id 0x106e5
cpu1: package 0, core 1, smt 0
cpu2 at mainbus0 apid 4
cpu2: Intel(R) Xeon(R) CPU X3430 @ 2.40GHz, id 0x106e5
cpu2: package 0, core 2, smt 0
cpu3 at mainbus0 apid 6
cpu3: Intel(R) Xeon(R) CPU X3430 @ 2.40GHz, id 0x106e5
cpu3: package 0, core 3, smt 0
>Description:
Even when running ntpd the clock is not stable. It might get more than
one second out of sync in few minues. The speed seems to be constant
and depends on the kern.timecounter.hardware value:
Timecounter Clock speed Comments
TSC -0.47ms / minute Stabile change
clockinterrupt -370ms / minute Jumps 50 ms or so every now and then
ichlpcib0 +3.05ms / minute Stabile change
hpet0 +3.12ms / minute Stabile change
ACPI-FAST +3.05ms / minute Stabile change
lapic +-1s / minute Seems to be random, goes up and down randomly
i8254 +2.28ms / minute Stabile change
These values are run without ntp, by changing the timecounter hardware
and then setting time with ntpdate -b, and then waiting for two
minutes, and using ntpdate -q to measure tim difference as fast as
possible (i.e. every 6-7 seconds). Then we plotted the time changes in
excel to see how stable the change was.
When using old version of NetBSD 6.1 there was no issues.
We have script that will show logs from other machines, it is annoying
that in few minutes even when running ntpd the machines are off by few
seconds in time, and script will complain that times from other
machines are in the future...
This might also related to the other issue that the machine crashes
every now and then (between few days or a month) with kernel panic
saying:
fpusave_lwp: did not
Looking at sys/arch/x86/x86/fpu.c it seems it does loop checking
hardware_ticks and loops until they change, so if time is not stable
perhaps it causes the loop to continue or something. I will make
separate bug report of this.
>How-To-Repeat:
Install netbsd 8 on similar machine.
>Fix:
No fix known.
>Audit-Trail:
From: coypu@sdf.org
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Tue, 6 Mar 2018 18:33:34 +0000
I have two machines, one that was drifting so badly I could notice it
without logs to compare, and another that claims a zero drift from NTP.
A difference is that the drifting first machine's dmesg says:
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
ERROR: 4316413966 cycle TSC drift observed
As for this inducing panics, someone mentioned we have some non-ideal
behaviour if a clock interrupt is missed (something like: we try to
catch up on missed clock interrupts? I wonder if this blows up with very
many missed clock interrupts)
From: Tero Kivinen <kivinen@iki.fi>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Tue, 6 Mar 2018 21:40:43 +0200
coypu@sdf.org writes:
> A difference is that the drifting first machine's dmesg says:
> timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
> ERROR: 4316413966 cycle TSC drift observed
Nothing like that during boot. Dmesg output is of course completely
usable, as it is full of "cprng 461 94681 15: creating with partial
entropy" lines, so cannot know if it has happened after boot:
~>fgrep timecount /var/run/dmesg.boot
timecounter: Timecounters tick every 10.000 msec
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
timecounter: Timecounter "ACPI-Fast" frequency 3579545 Hz quality 1000
timecounter: Timecounter "hpet0" frequency 14318180 Hz quality 2000
timecounter: Timecounter "ichlpcib0" frequency 3579545 Hz quality 1000
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
timecounter: Timecounter "TSC" frequency 2400117960 Hz quality 3000
> As for this inducing panics, someone mentioned we have some non-ideal
> behaviour if a clock interrupt is missed (something like: we try to
> catch up on missed clock interrupts? I wonder if this blows up with very
> many missed clock interrupts)
Btw, I updated the machine to netbsd 8 from 2018-02-27, and no changes
in the clock drift, but no crash yet (but it has been only up for 7
days since, so cannot say anything yet):
NetBSD vielako.iki.fi 8.0_BETA NetBSD 8.0_BETA (GENERIC) #0: Tue Feb 27 03:12:27 EET 2018 kivinen@vielako.iki.fi:/usr/obj/sys/arch/amd64/compile/GENERIC amd64
--
kivinen@iki.fi
From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Sat, 31 Mar 2018 16:28:38 -0000 (UTC)
kivinen@iki.fi writes:
> Timecounter Clock speed Comments
> TSC -0.47ms / minute Stabile change
> clockinterrupt -370ms / minute Jumps 50 ms or so every now and then
> ichlpcib0 +3.05ms / minute Stabile change
> hpet0 +3.12ms / minute Stabile change
> ACPI-FAST +3.05ms / minute Stabile change
> lapic +-1s / minute Seems to be random, goes up and down randomly
> i8254 +2.28ms / minute Stabile change
3ms / minute is a rather usual value for a PC clock. That's an error
of about 50ppm or 4 seconds per day.
If ntpd cannot correct this, I'd guess there is a problem with the NTP
setup.
--
--
Michael van Elst
Internet: mlelstv@serpens.de
"A potential Snark may lurk in every tree."
From: Tero Kivinen <kivinen@iki.fi>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 01:47:29 +0300
Michael van Elst writes:
> 3ms / minute is a rather usual value for a PC clock. That's an error
> of about 50ppm or 4 seconds per day.
It is actually worse than that. When I stopped ntpd to check whether
this issue was fixed by latest kernel and forgot to restart it, the
clock was around 20 seconds off after about 10 hours or so.
> If ntpd cannot correct this, I'd guess there is a problem with the NTP
> setup.
ntp can keep it inside few seconds, but as the poll interval can go to
quite big value for ntp, it can get several seconds from real time
before ntp fixes it.
Also the clock drift is not completely stable, it seems to jump around
every now and then or something. When running the tests it seemed to
be quite stable few ms per minue for few minute tests we run, but
during few hours you have much bigger jumps in there.
For example now the clock offset was 1.7 seconds before the ntpd fixed
it:
----------------------------------------------------------------------
vielako (0:29) ~>ntpdate -q -u time1.mikes.fi
server 194.100.49.151, stratum 2, offset 1.788493, delay 0.02718
4 Apr 00:29:24 ntpdate[17818]: step time server 194.100.49.151 offset 1.788493 sec
vielako (0:29) ~>
... (I did not do anything to fix the clock, but ntpd is running on background)
vielako (0:31) ~>ntpdate -q -u time1.mikes.fi
server 194.100.49.151, stratum 2, offset 0.000574, delay 0.02744
4 Apr 00:31:39 ntpdate[10719]: adjust time server 194.100.49.151 offset 0.000574 sec
vielako (0:31) ~>
----------------------------------------------------------------------
Now one hour later the drift is already 2.7 seconds again.
----------------------------------------------------------------------
vielako (1:39) ~>ntpdate -q -u time1.mikes.fi
server 194.100.49.151, stratum 2, offset 2.789676, delay 0.02701
4 Apr 01:39:45 ntpdate[16936]: step time server 194.100.49.151 offset 2.789676 sec
vielako (1:39) ~>
--
kivinen@iki.fi
From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 02:08:25 -0000 (UTC)
kivinen@iki.fi (Tero Kivinen) writes:
>ntp can keep it inside few seconds, but as the poll interval can go to
>quite big value for ntp, it can get several seconds from real time
>before ntp fixes it.
That's not how ntpd works. The clock is adjusted all the time by
running it slower or faster.
>Now one hour later the drift is already 2.7 seconds again.
>----------------------------------------------------------------------
>vielako (1:39) ~>ntpdate -q -u time1.mikes.fi
>server 194.100.49.151, stratum 2, offset 2.789676, delay 0.02701
> 4 Apr 01:39:45 ntpdate[16936]: step time server 194.100.49.151 offset 2.789676 sec
Please check with 'ntpq -p' whether ntpd actually synchronizes to
a time server. E.g.:
% ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
+time3.mikes.fi 193.166.4.57 2 u 753 1024 377 66.337 0.878 6.327
*ptbtime3.ptb.de .PTB. 1 u 466 1024 377 28.496 -0.758 0.732
+time.nrc.ca 132.246.11.231 2 u 559 1024 377 116.518 -0.451 4.356
The '*' shows the time server that is used for synchronization, a '+'
indicates verified backups.
And check with 'ntptime' the adjustment of the system time. E.g.:
% ntptime
ntp_gettime() returns code 0 (OK)
time de6eb184.e5ba3ca8 Wed, Apr 4 2018 4:05:56.897, (.897373194),
maximum error 325351 us, estimated error 1085 us, TAI offset 0
ntp_adjtime() returns code 0 (OK)
modes 0x0 (),
offset -244.122 us, frequency -1.885 ppm, interval 1 s,
maximum error 325351 us, estimated error 1085 us,
status 0x2001 (PLL,NANO),
time constant 10, precision 0.001 us, tolerance 496 ppm,
--
--
Michael van Elst
Internet: mlelstv@serpens.de
"A potential Snark may lurk in every tree."
From: Robert Elz <kre@munnari.OZ.AU>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 04 Apr 2018 09:35:41 +0700
Date: Wed, 4 Apr 2018 02:10:01 +0000 (UTC)
From: mlelstv@serpens.de (Michael van Elst)
Message-ID: <20180404021001.05AE67A1E9@mollari.NetBSD.org>
| That's not how ntpd works. The clock is adjusted all the time by
| running it slower or faster.
That's how NTP is supposed to work, but there is a maximum value to the
"slower or faster" that it will apply. If the underlying clock is off by more
than what the adjustment can handle, then time will still slide, just slower.
When ntpd detects the difference between the correct time and the clock
time has become too big, it causes time to jump, and the whole process
repeats.
| Please check with 'ntpq -p' whether ntpd actually synchronizes to
| a time server.
I doubt that is the issue. Rather attempt to see why ...
kivinen@iki.fi said:
| It is actually worse than that. When I stopped ntpd to check whether this
| issue was fixed by latest kernel and forgot to restart it, the clock was
| around 20 seconds off after about 10 hours or so.
That's 2 secs/hour, or 1/1800 which is more than ntp can fix by adjusting.
I suspect that the system needs to switch to using some other clock source
than the one it is picking by default.
kre
From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 05:45:24 -0000 (UTC)
kre@munnari.OZ.AU (Robert Elz) writes:
> That's 2 secs/hour, or 1/1800 which is more than ntp can fix by adjusting.
In his tests he said the deviation was 3ms per minute, or 180ms per hour.
> I suspect that the system needs to switch to using some other clock source
> than the one it is picking by default.
He already mentioned the deviations for all clock sources. 'lapic' and
also 'clockinterrupt' were bad. The rest looked like an average PC that
is not kept in sync by ntpd.
That doesn't mean that the default clock source (TSC) has no problem
on the Xeon X3430. In particular, TSC can behave nice during a test
but different when the system is unobserved for 10 hours. But
things like hpet0, ACPI-FAST or i8254 should be sane because they
are independent of the CPU and NetBSD6.1 didn't have problems keeping
time.
--
--
Michael van Elst
Internet: mlelstv@serpens.de
"A potential Snark may lurk in every tree."
From: Robert Elz <kre@munnari.OZ.AU>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 04 Apr 2018 12:58:31 +0700
Date: Wed, 4 Apr 2018 05:50:01 +0000 (UTC)
From: mlelstv@serpens.de (Michael van Elst)
Message-ID: <20180404055001.7B4BC7A220@mollari.NetBSD.org>
| In his tests he said the deviation was 3ms per minute, or 180ms per hour.
Yes, but that was while ntpd was running. The 2 sec/hour was when it wasn't.
| He already mentioned the deviations for all clock sources. 'lapic' and
| also 'clockinterrupt' were bad. The rest looked like an average PC that
| is not kept in sync by ntpd.
When you start getting to issues of clock sources on PCs you get right
outside my comfort zone, so what to do next, etc, I will leave for you, or
someone else...
kre
From: Joerg Sonnenberger <joerg@bec.de>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org,
netbsd-bugs@netbsd.org, kivinen@iki.fi
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 10:10:22 +0200
On Wed, Apr 04, 2018 at 05:50:01AM +0000, Michael van Elst wrote:
> He already mentioned the deviations for all clock sources. 'lapic' and
> also 'clockinterrupt' were bad. The rest looked like an average PC that
> is not kept in sync by ntpd.
...this makes me suspect that the system goes into deep sleep states
occassionally, where the lapic is stopped. That would also explain time
keeping problems of ntpd, since the ntp frequency adjustments are done
in the time interrupt, not by fudging the time counter frequencies.
Joerg
From: Tero Kivinen <kivinen@iki.fi>
To: Joerg Sonnenberger <joerg@bec.de>
Cc: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org, gnats-admin@netbsd.org,
netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 12:41:39 +0300
Joerg Sonnenberger writes:
> On Wed, Apr 04, 2018 at 05:50:01AM +0000, Michael van Elst wrote:
> > He already mentioned the deviations for all clock sources. 'lapic' and
> > also 'clockinterrupt' were bad. The rest looked like an average PC that
> > is not kept in sync by ntpd.
>
> ...this makes me suspect that the system goes into deep sleep states
> occassionally, where the lapic is stopped. That would also explain time
> keeping problems of ntpd, since the ntp frequency adjustments are done
> in the time interrupt, not by fudging the time counter frequencies.
That is my guess, as ntpd seems to be synced in to the servers:
vielako (11:53) ~>ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*194.100.49.151 194.100.49.132 2 u 36 64 377 0.974 -0.065 8.740
+ntp1.aalto.fi 194.100.49.134 2 u 38 64 377 14.225 -0.096 0.031
-mail.bbnetworks 185.103.110.248 3 u 35 64 377 0.503 -0.142 0.108
+ftp.mikes.fi 194.100.49.133 2 u 38 64 377 1.227 -0.105 0.087
-ntp2.aalto.fi 194.100.49.132 2 u 39 64 377 14.111 -0.242 0.083
vielako (11:53) ~>
Also when I we run the tests we DID NOT have ntpd running, but the
test were run only for few minutes at times, and we didn't see any
jumps during that (except for clockinterrupt and lapic).
On the other hand the bahvior I saw yesterday was so that time was 1.7
seconds off, got fixed by ntpd (most likely realized drift was too
big, and jumped it to correct time), then seemed to be mostly correct
for few minutes while I still checked it (drift in order of few ms),
but then when I came back an hour later the time was 2.7 off again.
I did not see when this jump happened. I will put test script in the
machine now to measure the time every 10 seconds, so I can see how it
behaves over longer period of time.
The current timecounter I am using is the default, i.e., TSC.
As I said in my original bug report this might be related to the
#53017 where the machine crashes because it cannot save the fpu
context.
Looking at that code in sys/arch/x86/x86/fpu.c it spins until ticks !=
hardclock_ticks (ticks stored from the beginning) and this loop has
just x86_pause and spins++ in it.
Then the machine panics if we managed to spin more than 100000000
times in that loop within one hardclock_ticks. Now if the
hardclock_ticks is missing ticks, it might take so long that this loop
expires and panics the whole machine.
I think hardclock_ticks is 10ms, so to be able to run 100M loop
iterations within 10ms, I should have clock speed over 10GHz (and of
course the actual loop takes more than one clock cycle to run).
Hmm... now looking at the code I think there is a bug there too, as it
does not reread the ticks when the loop ends because of ticks !=
hardclock_ticks, but this does not cause crash, it just causes
different busy loop.
I.e., code reads ticks from hardclock_ticks, starts outer loop:
spins = 0;
ticks = hardclock_ticks;
for (;;) {
...
tries to do saving, does not manage to do that, sends ipi:
...
x86_send_ipi(oci, X86_IPI_SYNCH_FPU);
...
and then goes to wait for this to happen:
while (pcb->pcb_fpcpu == oci && ticks == hardclock_ticks) {
x86_pause();
spins++;
}
Now if this exists because the ticks != hardclock_ticks, it exits this
loop, and if spins is small enough it will go to the main loop again,
try to save context again, does not succeed, sends ipi, comes to this
loop again, but now as ticks is not reread this exists immediately
etc, so then it will loop inside the main loop until it can save the
context.
if (spins > 100000000) {
panic("fpusave_lwp: did not");
}
And this panic with "very descriptive" text is the one that is
happening also in this machine.
So if the does not get advanced, pcb->pcb_fpcpu isn't updated for some
reason or long time, then we will hit this.
I assume the hardclock_ticks is updated by one cpu and perhaps that
same cpu is in some kind of deep sleep state, and also has the fpu
context, so thats why another cpu has enough time to loop 100M times
here or something? I will put some debugging prints there to see what
happens when it actually crashes...
}
--
kivinen@iki.fi
From: Tero Kivinen <kivinen@iki.fi>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 19:31:06 +0300
Tero Kivinen writes:
> I did not see when this jump happened. I will put test script in the
> machine now to measure the time every 10 seconds, so I can see how it
> behaves over longer period of time.
I put a loop running which queries the clock every 10 seconds from ntp
server and prints out the results.
It worked without issues for 8 hours and then the clock jumped:
4 Apr 18:01:13 ntpdate: adjust time server 194.100.49.151 offset -0.000322 sec
4 Apr 18:01:30 ntpdate: adjust time server 194.100.49.152 offset -0.000314 sec
4 Apr 18:01:46 ntpdate: adjust time server 130.233.224.52 offset -0.000330 sec
4 Apr 18:02:02 ntpdate: adjust time server 130.233.224.60 offset -0.000338 sec
4 Apr 18:02:20 ntpdate: step time server 2a00:1c30:1:100::10 offset 1.788490 sec
4 Apr 18:02:37 ntpdate: step time server 194.100.49.151 offset 1.789461 sec
4 Apr 18:02:54 ntpdate: step time server 194.100.49.152 offset 1.789493 sec
4 Apr 18:03:13 ntpdate: step time server 130.233.224.52 offset 1.789210 sec
So the issue is NOT related to TCS timecounter being inaccurate, but
it is related for the machine skipping ticks for 1-2 seconds every now
and then.
During this the ntp looses sync:
vielako (18:27) ~>ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
194.100.49.151 194.100.49.134 2 u 189 1024 277 1.847 1789.52 1656.97
*ntp1.aalto.fi 193.166.4.49 2 u 933 1024 377 14.269 -0.314 676.392
+mail.bbnetworks 84.20.147.187 3 u 964 1024 377 0.617 -1.125 676.472
ftp.mikes.fi 194.100.49.132 2 u 98 1024 377 1.438 1789.56 1656.91
ntp2.aalto.fi 193.166.4.49 2 u 63 1024 377 14.191 1789.06 1714.93
vielako (18:27) ~>
I.e. others are already 1.7 seconds off, but the master and backup
have not noticed this yet.
vielako (18:28) ~>ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
194.100.49.151 194.100.49.134 2 u 323 1024 277 1.847 1789.52 1656.97
+ntp1.aalto.fi 193.166.4.49 2 u 1067 1024 377 14.269 -0.314 676.392
mail.bbnetworks 84.20.147.187 3 u 56 1024 377 0.609 1788.69 1657.05
ftp.mikes.fi 194.100.49.132 2 u 230 1024 377 1.438 1789.56 1656.91
ntp2.aalto.fi 193.166.4.49 2 u 195 1024 377 14.191 1789.06 1714.93
After a while master notices issue, and then bit later the backup sees
the issue too:
vielako (18:29) ~>ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
194.100.49.151 194.100.49.134 2 u 344 1024 277 1.847 1789.52 1656.97
ntp1.aalto.fi 193.166.4.49 2 u 2 1024 377 14.287 1789.42 1657.04
mail.bbnetworks 84.20.147.187 3 u 77 1024 377 0.609 1788.69 1657.05
ftp.mikes.fi 194.100.49.132 2 u 251 1024 377 1.438 1789.56 1656.91
ntp2.aalto.fi 193.166.4.49 2 u 216 1024 377 14.191 1789.06 1714.93
and then we have lost sync, and need to wait for a while to readjust
everything and fix the situation. I.e., this is the reason it takes so
long to fix the issue...
On the other hand ntpd is not designed to cope with machine clock
loosing 1.7 seconds during 10 seconds...
I will leave the script running and see if this occurs close to the
exact hour later too (this time it happened between
18:02:02-18:02:20).
This is our user database machine and every hour it checks whether it
needs to regenerate the config files, and it did regenerate some of
those including dnssec signing and so on. Looking at the times it
seems this time jump might have happened during the dnssec signing
operation using dnssec-signzone... The signed file was created
18:02:02 which matches time when clock drift happened.
--
kivinen@iki.fi
From: Joerg Sonnenberger <joerg@bec.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 4 Apr 2018 23:24:46 +0200
On Wed, Apr 04, 2018 at 04:35:01PM +0000, Tero Kivinen wrote:
> The following reply was made to PR kern/53016; it has been noted by GNATS.
>
> From: Tero Kivinen <kivinen@iki.fi>
> To: gnats-bugs@NetBSD.org
> Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
> Subject: Re: kern/53016: Clock not stable
> Date: Wed, 4 Apr 2018 19:31:06 +0300
>
> Tero Kivinen writes:
> > I did not see when this jump happened. I will put test script in the
> > machine now to measure the time every 10 seconds, so I can see how it
> > behaves over longer period of time.
>
> I put a loop running which queries the clock every 10 seconds from ntp
> server and prints out the results.
Can you also run some background load, main() { for (;;) ; } or so in
the background to rule out whether it is deep sleep? Enough instances,
even with nice 20, to just keep all cores busy.
Joerg
From: Tero Kivinen <kivinen@iki.fi>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Fri, 6 Apr 2018 04:15:37 +0300
Joerg Sonnenberger writes:
> Can you also run some background load, main() { for (;;) ; } or so in
> the background to rule out whether it is deep sleep? Enough instances,
> even with nice 20, to just keep all cores busy.
When running some tests earlier, I noticed that if I run
dnssec-signzone -N INCREMENT iki.fi
in a loop, I can get the clock drift to happen more often. It is also
easy to see that the drift happened, as the time command normally
reports:
u:11.19s s:0.01s r:3.37s 331%
but in this case the user cpu time was still same (11 seconds), but
real time was only 1.6 seconds instead of 3.4 seconds and cpu usage %
was around 700%, even though the machine only has 4 cores...
So I do not think this is actually going to the any kind of sleep
state, as dnssec-signzone actually uses all cores with full 100% cpu.
I tried to see if running busy loops (like you suggested with just
for(;;); in them) could cause issues, but that didn't affect anything.
Next I tried to busy loop doing fpu operations (for(d=0.0; d <
9.0e20;d += 0.00001);) but no difference there, so it might that
dnssec-signzone does some crypto operations or more complicated fpu
operations that cause this issue to happen.
--
kivinen@iki.fi
From: coypu@sdf.org
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Fri, 6 Apr 2018 03:57:26 +0000
Is that because of down-clocking for AVX code execution?
From: Mouse <mouse@Rodents-Montreal.ORG>
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Wed, 16 May 2018 21:25:01 -0400 (EDT)
Quite possibly not relevant, but I have a machine that, under NetBSD as
old as 5.2, keeps _really_ bad time if I leave it set on the default
clock source. (Really bad, as in, the difference between time
intervals measured by the machine and time intervals measured by
wallclock time is a factor of at least 2 and I think it was more like
10.) I have to change kern.timecounter.hardware to get decent clock
behaviour (I set it to hpet0 each boot, and the clock then keeps
perfectly acceptable time then; ntp.drift contains "3.605").
I forget what the default timecounter is, and now is not a good time to
reboot it to see, but I suspect it's TSC, based on searching dmesg.boot
for timecounter:
timecounter: Timecounters tick every 10.000 msec
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
timecounter: Timecounter "ACPI-Fast" frequency 3579545 Hz quality 1000
timecounter: Timecounter "hpet0" frequency 23999999 Hz quality 2000
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
timecounter: Timecounter "TSC" frequency 11664676160 Hz quality 3000
This is, of course, related to the problem described only in that they
both involve bad timekeeping, and the behaviour changes with choice of
timecounter. But it does make me slightly suspicious that some aspect
of it may be longstanding.
/~\ The ASCII Mouse
\ / Ribbon Campaign
X Against HTML mouse@rodents-montreal.org
/ \ Email! 7D C8 61 52 5D E7 2D 39 4E F1 31 3E E8 B3 27 4B
From: Nathanial Sloss <nat@netbsd.org>
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Thu, 17 May 2018 13:27:53 +1000
--Boundary-00=_6aP/apxLurubmRJ
Content-Type: Text/Plain;
charset="us-ascii"
Content-Transfer-Encoding: 7bit
Hi,
My proposal, which seems to work is to only read the tsc register from the
boot cpu ensuring there is no discrepancy between tsc counters between cpus.
With this patch the wall clock and assoc times seem to be stable.
Best regards,
Nat
--Boundary-00=_6aP/apxLurubmRJ
Content-Type: text/x-patch;
charset="ISO-8859-1";
name="tsc.c.diff"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
filename="tsc.c.diff"
Index: tsc.c
===================================================================
RCS file: /cvsroot/src/sys/arch/x86/x86/tsc.c,v
retrieving revision 1.37
diff -u -p -r1.37 tsc.c
--- tsc.c 2 Oct 2017 19:23:16 -0000 1.37
+++ tsc.c 17 May 2018 03:25:07 -0000
@@ -314,7 +314,7 @@ cpu_hascounter(void)
uint64_t
cpu_counter_serializing(void)
{
- if (tsc_good)
+ if (tsc_good && curcpu() == tsc_sync_cpu)
return rdmsr(MSR_TSC);
else
return cpu_counter();
--Boundary-00=_6aP/apxLurubmRJ--
From: coypu@sdf.org
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Thu, 17 May 2018 04:53:51 +0000
Have we considered using rdtscp if it's available
my i7-6700HQ drifted 7 seconds in a day of uptime.
From: coypu@sdf.org
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Thu, 17 May 2018 05:58:41 +0000
nvm, I misread what rdtscp does.
From: Thomas Klausner <wiz@NetBSD.org>
To: NetBSD bugtracking <gnats-bugs@NetBSD.org>
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Thu, 17 May 2018 08:16:02 +0200
On Thu, May 17, 2018 at 01:30:01AM +0000, Mouse wrote:
> Quite possibly not relevant, but I have a machine that, under NetBSD as
> old as 5.2, keeps _really_ bad time if I leave it set on the default
> clock source. (Really bad, as in, the difference between time
> intervals measured by the machine and time intervals measured by
> wallclock time is a factor of at least 2 and I think it was more like
> 10.) I have to change kern.timecounter.hardware to get decent clock
> behaviour (I set it to hpet0 each boot, and the clock then keeps
> perfectly acceptable time then; ntp.drift contains "3.605").
I have
kern.timecounter.hardware=hpet0
in my /etc/sysctl.conf since 2009 (5.99.x) for similar reasons.
Thomas
From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Thu, 17 May 2018 13:08:32 -0000 (UTC)
wiz@NetBSD.org (Thomas Klausner) writes:
> I have
> kern.timecounter.hardware=hpet0
> in my /etc/sysctl.conf since 2009 (5.99.x) for similar reasons.
Shouldn't that all be fine for more recent NetBSD versions as we only
use the TSC when tagged as invariant?
--
--
Michael van Elst
Internet: mlelstv@serpens.de
"A potential Snark may lurk in every tree."
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/53016: Clock not stable
Date: Mon, 26 Nov 2018 18:06:34 +0000
This got mangled up by gnats, which thought it was a new PR
submission and was further confused by it coming as HTML.
------
From: Jay Patel <jaypatel.ani@gmail.com>
To: gnats-admin@netbsd.org
Subject: Clock not stable
Date: Thu, 22 Nov 2018 09:00:01 +0000 (UTC)
does OpenNTPD gives same result? http://www.openntpd.org/portable.html
--
Jay Patel
*https://unitedbsd.com/ <https://unitedbsd.com/>*
*usually found @ https://riot.im/app/#/room/#bsd:matrix.org
<https://riot.im/app/#/room/%23bsd:matrix.org>*
From: Tero Kivinen <kivinen@iki.fi>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/53016: Clock not stable
Date: Sat, 1 Dec 2018 01:19:05 +0200
David Holland writes:
> This got mangled up by gnats, which thought it was a new PR
> submission and was further confused by it coming as HTML.
>
> From: Jay Patel <jaypatel.ani@gmail.com>
> To: gnats-admin@netbsd.org
> Subject: Clock not stable
> Date: Thu, 22 Nov 2018 09:00:01 +0000 (UTC)
>
> does OpenNTPD gives same result? http://www.openntpd.org/portable.html
I replied to that:
I have not tried, but as the issue was that machine clock just stopped
for almost 2 seconds for an instant I the issue is not really in the
ntp.
Btw, I have not seen those those time skippings lately anymore, so
this issue might have disappeared. Also I have not seen the
fpusave_lwp did not panics either for 166 days (since I updated the
kernel April 6).
I think perhaps this and the kern/53017 could be closed, as they do
not seem to be repeating anymore.
--
kivinen@iki.fi
>Unformatted:
NetBSD 8.0_BETA GENERIC from 2017-11-08.
(Contact us)
$NetBSD: query-full-pr,v 1.43 2018/01/16 07:36:43 maya Exp $
$NetBSD: gnats_config.sh,v 1.9 2014/08/02 14:16:04 spz Exp $
Copyright © 1994-2017
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.
Home