Hi again, Commented inline.
You'll find more details concerning this issue. * Andreas Henriksson ([email protected]) wrote: > Hello Marcel! > > Quick reply below... > > On Thu, Nov 12, 2015 at 09:01:49PM -0500, Marcel wrote: > > Hi Andreas. > > > > Thanks for your quick reply. I appreciate it. > > > > I reckon that the misuse of init scripts is my responsibility > > however the service integration isn't perfect yet. A lot of > > scripts/packages still use init scripts. Monit comes immediately > > to my mind. It relies heavily on start/stop/restart. > > Any packaged software in Debian which directly invokes an init script > (ignoring service policy etc.) instead of doing so via invoke-rc.d > (which is the programmatical variant of the administrative 'service' > interface) is in conflict with the Debian policy and thus RC-buggy. > This is because 'policy-rc.d' should be taken into consideration which > it isn't if the script is invoked directly. I realize that, but I don't care. I expect packages to work, When they don't, I reconfigure. Only debian maintainers should care about this. That is my opinion. > > https://www.debian.org/doc/debian-policy/ch-opersys.html#s9.3.3 > > > > > And I was in a state of panic. I know full well how catastrophic > > the results of setting the clock too far away in time could do on this > > system. I couldn't remember the command name 'service' so I relied > > on what has been working faithfully for years, initd. > > Yes, fortunately the Debian systemd maintainers have LSB hooks in place > to defer your direct invokation to became a systemctl command instead. > (FWIW, the service command would also translate into a systemctl command > when running under systemd.) > > > > > I'll complete the transition to service whenever I have spare time. > > > > That being said, I saved the console so you can see each and every > > command I typed yesterday and the system reaction or absence of: > > Awesome! Thanks. > Even more awesome would be if you can reproduce the problem while > hacking the init script to add 'set -x' at the top so we can see > each and every command being run. Yes of course. See the attached file 'stop.txt'. Strange enough, 'hwclock.sh stop' is reported doing its job with 'set -x' whereas I know for a fact that it did not without. > Might also be useful to know your configuration for local/UTC time > in rtc, eg. /etc/adjtime shizuma@gt5232h-a3e401d:~$ cat /etc/adjtime -0.135568 1447433065 0.000000 1447433065 LOCAL > Also knowing your /etc/default/hwclock settings would be helpful. BADYEAR=no HWCLOCKACCESS=yes HWCLOCKPARS= HCTOSYS_DEVICE=rtc0 > > Quick commends below (I'll try to find time to look at this > with more details in the future). No emergency. Daylights savings are ON for all winter. It would be great if it were fixed for spring though. > > > > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh > > [ ok ] Usage: hwclock.sh {start|stop|reload|force-reload|show}. > > [ ok ] start sets kernel (system) clock from hardware (RTC) clock. > > [ ok ] stop and reload set hardware (RTC) clock from kernel (system) clock. > > ok. > > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh stop > > shizuma@gt5232h-a3e401d:~$ date > > mercredi 11 novembre 2015, 23:26:56 (UTC-0500) > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh show > > jeu 12 nov 2015 00:28:19 EST -0.084876 secondes > > shizuma@gt5232h-a3e401d:~$ date > > mercredi 11 novembre 2015, 23:27:30 (UTC-0500) > > So your system time seems it was 1 day behind your RTC time. No, it was 1 hour. There's 1h between 11120028 and 11112328, not 25. > Some serious time drift right there (unless your system time was > updated without syncing the RTC earlier somehow). > It's not drift. It's daylight savings turned on. And yes, 'system time was updated without syncing the RTC earlier somehow': The system time was updated sunday to compensate for daylight savings. It's automatic. But on shutdown 2 days ago, the RTC wasn't automatically updated from system time as it should have. Upon restart, the system time was updated from the wrong RTC time. So the system restarted with 1 hr ahead of time, and worse, with 1 day ahead of time too. See excerpt of syslog: (...) Nov 11 23:03:26 gt5232h-a3e401d kmotion_hkd1[20621]: signal SIGHUP detected, re-reading config file Nov 11 23:03:26 gt5232h-a3e401d freshclam[987]: Update process terminated Nov 12 00:14:13 gt5232h-a3e401d rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="1262" x-info="http://www.rsyslog.com";] start Nov 12 00:14:13 gt5232h-a3e401d rsyslogd-2307: warning: ~ action is deprecated, consider using the 'stop' statement instead [try http://www.rsyslog.co m/e/2307 ] (...) I rebooted at 23:03 The log ends at 11:03 PM on 11/11 and restarts at 12:14 AM on 11/12 You see a 1 hr 11 minutes difference whereas it was really 11 minutes. It took 11 minutes because a filecheck was triggered. However I made a supplemental mistake. I didn't realized we crossed midnight when I set the system time with the date command. I set the time correctly 1 hr back but I forgot to also remove 1 day to the currently reported day, worsening an already fragile situation. E.g. (retrieved from history) 5481 sudo date 11122320 (oops, we're still 11/11!) 5482 sudo date 11112320 > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh reload > > [info] Saving the system clock. > > [info] Hardware Clock updated to mercredi 11 novembre 2015, 23:28:07 > > (UTC-0500). > > Here you just wrote your system time to the RTC, which I guess means > you messed up your RTC time. That is precisely what I wanted. To copy the system time, which was now correct to the RTC which was still not. > > In the init script the 'stop' and 'reload' arguments are just aliases > for the very same thing. > The reason they still behave differently seems to simply be because > 'stop', 'start', 'restart' will be translated into 'systemctl <cmd> > hwclock' by the LSB init hooks for systemd. While the 'show' and > 'reload' commands will not (and just run the init script code) as > there's no direct generic systemctl equivalent. > > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh show > > mer 11 nov 2015 23:28:24 EST -0.062948 secondes > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh stop > > shizuma@gt5232h-a3e401d:~$ sudo /etc/init.d/hwclock.sh show > > mer 11 nov 2015 23:35:14 EST -0.969351 secondes > > shizuma@gt5232h-a3e401d:~$ date > > mercredi 11 novembre 2015, 23:37:35 (UTC-0500) > > > > > > I also tried the same commands on another system I maintain, with > > identical results: stop producing no output at all: > > > > root@NC-PH-0657-10:~# /etc/init.d/hwclock.sh show > > Thu 12 Nov 2015 06:47:32 PM MST -0.406578 seconds > > root@NC-PH-0657-10:~# date > > Thu Nov 12 18:47:34 MST 2015 > > root@NC-PH-0657-10:~# /etc/init.d/hwclock.sh stop > > root@NC-PH-0657-10:~# /etc/init.d/hwclock.sh show > > Thu 12 Nov 2015 06:47:56 PM MST -0.922150 seconds > > > > > > I understand that you would not maintain initd scripts. However an > > issue is still present - and maybe this very bug description should be > > changed accordingly. It's that on shutdown for reboot, the hardware clock > > wasn't properly updated. This should be addressed. > > So far the hwclock.sh script has no knowledge about systemd or > that it's obsolete/unused under systemd, but maybe it should > indeed grow a check that just aborts it if executed under systemd > environment to prevent issues like yours.... but really, you should > stop executing init scripts directly also. :P > > > > > I'd be more than happy to provide you with all the assistance you need. > > This is great. Too much of my time is wasted on people not following > up with feedback. Very much appreciated that you're interested in > seeing this through. > > > > > Is there something particular that I should look for in dmesg|system logs? > > I think I have an idea what's going on now and I'll have to think about > possible ways to prevent people shooting themselves in the foot. > > I hope the information provided above is helpful for your as well. > I'll add that if time is important to you, you should consider running > an ntpd (via the 'ntp' package or other equivalent implementation) that I already do. It's of paramount importance to me that the system time is exact. I do run ntpd for years. I repeat, the real issue is that on reboot, the system time wasn't automatically saved to the RTC as it should have. So the system restarted with the time reported being 1 hour later than expected and the day after on top of that. The 'stop' issue is secondary and trivial as I would always realize that something is wrong whenever I run it. Thanks again and best regards. > will help keep your system and hardware time in sync and up to date, > assuming you have network connection where you can reach a ntp server. > (systemd also ships a 'lightweight' SNTP variant called > systemd-timesyncd which you can enable. See: > "systemctl status systemd-timesyncd", not sure it's part of Jessie/8.2 > though.) > > Regards, > Andreas Henriksson
shizuma@gt5232h-a3e401d:~$ sudo /tmp/hwclock.sh stop + BADYEAR=no + HWCLOCKACCESS=yes + HWCLOCKPARS= + HCTOSYS_DEVICE=rtc0 + unset TZ + hwclocksh stop + '[' '!' -x /sbin/hwclock ']' + '[' '!' -r /etc/default/rcS ']' + . /etc/default/rcS ++ TMPTIME=10 ++ FSCKFIX=yes + '[' '!' -r /etc/default/hwclock ']' + . /etc/default/hwclock + . /lib/lsb/init-functions +++ run-parts --lsbsysinit --list /lib/lsb/init-functions.d ++ for hook in '$(run-parts --lsbsysinit --list /lib/lsb/init-functions.d 2>/dev/null)' ++ '[' -r /lib/lsb/init-functions.d/20-left-info-blocks ']' ++ . /lib/lsb/init-functions.d/20-left-info-blocks ++ for hook in '$(run-parts --lsbsysinit --list /lib/lsb/init-functions.d 2>/dev/null)' ++ '[' -r /lib/lsb/init-functions.d/40-systemd ']' ++ . /lib/lsb/init-functions.d/40-systemd +++ _use_systemctl=0 +++ '[' -d /run/systemd/system ']' +++ '[' -n '' ']' +++ '[' 9392 -ne 1 ']' +++ '[' -z '' ']' +++ '[' -z '' ']' +++ case $(readlink -f "$0") in ++++ readlink -f /tmp/hwclock.sh +++ '[' 0 = 1 ']' ++ FANCYTTY= ++ '[' -e /etc/lsb-base-logging.sh ']' ++ true + case "$BADYEAR" in + BADYEAR= + case "$1" in + '[' yes '!=' no ']' + log_action_msg 'Saving the system clock' + log_action_msg_pre 'Saving the system clock' + log_use_fancy_output + TPUT=/usr/bin/tput + EXPR=/usr/bin/expr + '[' -t 1 ']' + FANCYTTY=0 + case "$FANCYTTY" in + false + echo 'Saving the system clock.' + log_action_msg_post 'Saving the system clock' + : + /sbin/hwclock --rtc=/dev/rtc0 --systohc ++ date + verbose_log_action_msg 'Hardware Clock updated to vendredi 13 novembre 2015, 11:44:26 (UTC-0500)' + '[' '' = no ']' + log_action_msg 'Hardware Clock updated to vendredi 13 novembre 2015, 11:44:26 (UTC-0500)' + log_action_msg_pre 'Hardware Clock updated to vendredi 13 novembre 2015, 11:44:26 (UTC-0500)' + log_use_fancy_output + TPUT=/usr/bin/tput + EXPR=/usr/bin/expr + '[' -t 1 ']' + FANCYTTY=0 + case "$FANCYTTY" in + false + echo 'Hardware Clock updated to vendredi 13 novembre 2015, 11:44:26 (UTC-0500).' + log_action_msg_post 'Hardware Clock updated to vendredi 13 novembre 2015, 11:44:26 (UTC-0500)' + :
