Re: [chrony-users] RTC Trimming Issues

[John.Florian@xxxxxxxx]

Ed W <lists@xxxxxxxxxxxxxx> wrote on 10/29/2012
18:03:36:
> 
> On 29/10/2012 21:01, John.Florian@xxxxxxxx wrote:
> 
> Any ideas how to get these RTCs to do the right thing and join us
in
> this decade? 
>
> 
> Fun problem!

I'm glad you think so and thank you for responding!


> Out of curiousity, have you taken one dodgy machine, logged in and
> figured out of it's a problem setting the RTC, or with it *staying*
set?
> 
> eg 
> - run "trimrtc", then after a few seconds do you see the
correct 
> date with "rtcdata"?

Nope.

chronyc> password SuperSecretSquirrelSauce
200 OK
chronyc> rtcdata
RTC ref time (UTC) : Wed Jan  1 00:05:05 2003
Number of samples  : 0
Number of runs     : 4
Sample span period :    0
RTC is fast by     : -310217856.000000 seconds
RTC gains time at  :    17.773 ppm
chronyc> trimrtc
200 OK
chronyc> rtcdata
RTC ref time (UTC) : Wed Jan  1 00:05:05 2003
Number of samples  : 0
Number of runs     : 4
Sample span period :    0
RTC is fast by     : -310217856.000000 seconds
RTC gains time at  :    17.773 ppm
chronyc> rtcdata
RTC ref time (UTC) : Wed Jan  1 00:05:05 2003
Number of samples  : 0
Number of runs     : 4
Sample span period :    0
RTC is fast by     : -310217856.000000 seconds
RTC gains time at  :    17.773 ppm
chronyc> ^D

So this would indicate that the write to the RTC is
failing, right?  Even if that's true (which sounds bad), shouldn't
the "RTC ref time (UTC)" be advancing forward?

> - if you stop chrony, does hwclock show the correct time in the RTC?


It's been awhile since I last dug deep into this,
so I don't recall hwclock behavior well, but this looks fishy:

# systemctl stop chronyd.service
# hwclock --show
hwclock: select() to /dev/rtc to wait for clock tick
timed out: Success
# hwclock --show
hwclock: select() to /dev/rtc to wait for clock tick
timed out: Success

It certainly isn't showing date/time with that.

> - Can you set the correct (ish) time with hwclock?

This looks broken too:

# date
Tue Oct 30 09:28:01 EDT 2012
# hwclock --systohc
hwclock: select() to /dev/rtc to wait for clock tick
timed out: Success
# hwclock --show
hwclock: select() to /dev/rtc to wait for clock tick
timed out: Success

> When you reboot does it stay set?

Given the above results, I suspect this is irrelevant,
but just for grins, I rebooted it and found a "surprise inside":

chronyc> rtcdata
RTC ref time (UTC) : Tue Oct 30 13:45:07 2012
Number of samples  : 10
Number of runs     : 5
Sample span period :  360
RTC is fast by     :     0.021813
seconds
RTC gains time at  :    22.403 ppm

I'll have to keep an eye on this to see if this "sticks"
now or if it goes whacky again.

> My thought might be that something is wrong with the rtcclock driver
> in the kernel. When you try and set the time it's not getting set.
 
> Reading is working for whatever reason. Any clues on boot? 

Seems like a good theory.  I'm not sure what
to make of the above tests though.

I haven't seen anything unusual beyond what was shown
in my first post.  Here are the relevant messages from the same system
tested above, after it was rebooted:

# grep -iE 'clock|rtc' /var/log/messages
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 0.155092] RTC time: 13:36:43, date: 10/30/12
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 0.306016] Switching to clocksource pit
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 0.442879] Switching to clocksource acpi_pm
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.090074] Refined TSC clocksource calibration: 499.901 MHz.
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.100046] Switching to clocksource tsc
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.723128] rtc_cmos 00:04: RTC can wake from S4
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.733368] rtc_cmos 00:04: rtc core: registered rtc_cmos as rtc0
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.745071] rtc0: alarms up to one day, 242 bytes nvram
Oct 30 09:37:24 aos-000bab25053c kernel: [  
 3.929895] rtc_cmos 00:04: setting system clock to 2012-10-30 13:36:47
UTC (1351604207)
Oct 30 09:39:13 aos-000bab25053c chronyd[1524]: System
clock wrong by 0.398802 seconds, adjustment started
Oct 30 09:41:16 aos-000bab25053c chronyd[1524]: System
clock wrong by 0.037130 seconds, adjustment started
Oct 30 09:41:39 aos-000bab25053c chronyd[1524]: System
clock wrong by -0.037034 seconds, adjustment started
Oct 30 09:42:21 aos-000bab25053c chronyd[1524]: System
clock wrong by 0.026047 seconds, adjustment started

So this looks good to my eye and fits with what rtcdata
showed after boot, all of which doesn't seem to fit what I was expecting
to see just before rebooting.

--
John Florian