[Bug 344356] New: using ntpd, some times the clock starts to go slow.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c2 Summary: using ntpd, some times the clock starts to go slow. Product: openSUSE 10.3 Version: Final Platform: i686 OS/Version: openSUSE 10.3 Status: NEW Severity: Normal Priority: P5 - None Component: Basesystem AssignedTo: bnc-team-screening@forge.provo.novell.com ReportedBy: robin.listas@telefonica.net QAContact: qa@suse.de Found By: --- Sometimes, I see messages like this in the kernel log: Nov 27 15:27:32 nimrodel kernel: ACPI: Sleep Button (CM) [SLPB] Nov 27 15:57:46 nimrodel kernel: set_rtc_mmss: can't update from 1 to 57 Nov 27 15:58:00 nimrodel syslog-ng[10590]: last message repeated 13 times Nov 27 15:58:00 nimrodel kernel: set_rtc_mmss: can't update from 1 to 58 Nov 27 15:58:03 nimrodel syslog-ng[10590]: last message repeated 3 times Nov 27 15:58:04 nimrodel kernel: set_rtc_mmss: can't update from 1 to 58 Nov 27 15:58:04 nimrodel kernel: set_rtc_mmss: can't update from 1 to 58 Nov 27 15:58:06 nimrodel kernel: set_rtc_mmss: can't update from 2 to 58 Nov 27 15:59:00 nimrodel syslog-ng[10590]: last message repeated 53 times Nov 27 15:59:00 nimrodel kernel: set_rtc_mmss: can't update from 2 to 59 Nov 27 15:59:03 nimrodel syslog-ng[10590]: last message repeated 3 times Nov 27 15:59:04 nimrodel kernel: set_rtc_mmss: can't update from 2 to 59 Nov 27 15:59:04 nimrodel kernel: set_rtc_mmss: can't update from 2 to 59 Nov 27 15:59:06 nimrodel kernel: set_rtc_mmss: can't update from 3 to 59 Nov 27 16:00:03 nimrodel syslog-ng[10590]: last message repeated 15 times (no more entries in 90 minutes) About the same period, ntp stops being able to maintain sync, and aborts: 27 Nov 15:27:38 ntpd[12905]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010) 27 Nov 15:27:38 ntpd[12905]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:38 ntpd[12905]: Deleting interface #2 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 27 Nov 15:27:38 ntpd[12905]: Deleting interface #3 eth0, fe80::240:f4ff:fe2e:b121#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 27 Nov 15:27:42 ntpd[12905]: peer 91.121.2.175 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:44 ntpd[12905]: peer 195.55.174.243 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:45 ntpd[12905]: peer 80.33.107.110 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:45 ntpd[12905]: peer 217.155.68.49 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:45 ntpd[12905]: peer 84.88.69.10 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:46 ntpd[12905]: peer 88.191.19.23 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:27:46 ntpd[12905]: peer 192.33.214.57 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 15:30:51 ntpd[12905]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521) 27 Nov 15:30:51 ntpd[12905]: synchronized to LOCAL(0), stratum 10 27 Nov 15:30:51 ntpd[12905]: kernel time sync status change 0001 27 Nov 15:30:51 ntpd[12905]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534) 27 Nov 15:30:51 ntpd[12905]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543) 27 Nov 15:31:56 ntpd[12905]: synchronized to 91.121.2.175, stratum 2 27 Nov 15:38:31 ntpd[12905]: synchronized to 192.33.214.57, stratum 2 27 Nov 15:39:25 ntpd[12905]: synchronized to 195.55.174.243, stratum 2 27 Nov 15:39:40 ntpd[12905]: synchronized to LOCAL(0), stratum 10 27 Nov 16:22:22 ntpd[12905]: synchronized to 84.88.69.10, stratum 2 27 Nov 16:22:22 ntpd[12905]: time correction of 1678 seconds exceeds sanity limit (1000); set clock manually to the correct UTC time. 27 Nov 16:22:22 ntpd[12905]: system event 'event_fault' (0x02) status 'leap_none, sync_ntp, 12 events, event_peer/strat_chg' (0x6c4) Then I have to restart it to force a time set: 27 Nov 17:13:54 ntpd[18877]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010) 27 Nov 17:13:55 ntpd[18877]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 27 Nov 17:13:55 ntpd[18877]: Deleting interface #2 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs The clock was going about half an hour slow - during my lunch hour! This thing started happening with 10.3, and is random. Normally, I'm not present or watching when it happens. Once I was scanning a page via a usb scanner, and the desktop froze. Sometimes the desktop freezes (the cpu applet and other things stop) till I press any key or move the mouse. Once the keyboard froze for 5 minutes (gkrelmn showed activity), and suddenly started working again, after 5 minutes, just as I had booted up a second computer and I was ready to try sshing (didn't have to). I tell all these things, but I don't know if they are related. I have also tried recompiling the kernel. One possibility is that all the time servers I use go bad and miss-set my clock (ntp goes to LOCAL(0)). Another is that the kernel clock doesn't respond well. I already have "logconfig =all" in "/etc/ntp.conf" and: KERNEL_LOGLEVEL=7 so I don't know what to activate to get more info about the problem. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 Mark Gordon <mtgordon@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |mtgordon@novell.com AssignedTo|bnc-team-screening@forge.provo.novell.com |mskibbe@novell.com -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c1 Michael Skibbe <mskibbe@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO Info Provider| |robin.listas@telefonica.net --- Comment #1 from Michael Skibbe <mskibbe@novell.com> 2007-11-28 01:09:52 MST --- please attach /var/log/messages, /var/log/ntp output of ntpdc -c pe -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c2 Carlos Robinson <robin.listas@telefonica.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW Info Provider|robin.listas@telefonica.net | --- Comment #2 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-28 13:16:07 MST --- Ok... but first I need some clarification. I modified /etc/syslog-ng/syslog-ng.conf so that the messages file doesn't contain everything; for instance, kernel messages are not there, and I assume you need them. As I think you need the logs when the problem is happening (right now the clock is normal), I'll create a new messages file with all except mail and auth.priv), but I won't have data till the problem happens again. Will that be OK? I'll attach the /var/log/messages of the session of the last fault (from boot to halt). At this moment (no clock problem): nimrodel:~ # ntpdc -c pe remote local st poll reach delay offset disp ======================================================================= *192.33.214.57 192.168.1.12 2 256 377 0.13472 -0.001096 0.11218 =LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03052 =punk.kls.es 192.168.1.12 2 256 377 0.07845 -0.009542 0.09975 =96.Red-213-96-1 192.168.1.12 2 256 377 0.09781 0.003004 0.09723 =ntp1.faelix.net 192.168.1.12 2 256 377 0.10646 0.025148 0.11868 =endor.ordrejedi 192.168.1.12 3 256 377 0.10638 -0.006700 0.12463 =time3.ethz.ch 192.168.1.12 2 256 377 0.10773 0.000898 0.10397 My pool of servers is: # First five willbe used for initial sync (/etc/sysconfig/ntp) server pool.ntp.org server es.pool.ntp.org server fr.pool.ntp.org server ch.pool.ntp.org server uk.pool.ntp.org server pool.ntp.org server pool.ntp.org server pool.ntp.org server pool.ntp.org server es.pool.ntp.org server es.pool.ntp.org #server es.pool.ntp.org #server es.pool.ntp.org server uk.pool.ntp.org #server uk.pool.ntp.org #server uk.pool.ntp.org server fr.pool.ntp.org #server fr.pool.ntp.org #server fr.pool.ntp.org server ch.pool.ntp.org server ch.pool.ntp.org server ch.pool.ntp.org server ch.pool.ntp.org -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c3 --- Comment #3 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-28 13:17:25 MST --- Created an attachment (id=185160) --> (https://bugzilla.novell.com/attachment.cgi?id=185160) partial messages file -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c4 --- Comment #4 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-28 13:24:06 MST --- Created an attachment (id=185161) --> (https://bugzilla.novell.com/attachment.cgi?id=185161) ntp log This ntp log contains data since last February, ie, since 10.2, perhaps a bit of 10.1 (I'm not sure now). If you search for "exceeds sanity limit" you will find that problems start on Nov 4th - I installed on the 3th. It has happened 5 times only. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c5 --- Comment #5 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-28 16:48:27 MST --- It is happening right now. The system local time is 00:19, and the real time is 00:23. nimrodel:~ # ntpdc -c pe remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13571 290.59757 0.12036 =LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03049 =punk.kls.es 192.168.1.12 2 1024 377 0.08014 290.59311 0.12131 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.22598 290.54091 0.12125 =srv1.m.faelix.n 192.168.1.12 2 1024 377 0.10805 290.62112 0.12129 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10883 290.58992 0.12135 *time3.ethz.ch 192.168.1.12 2 1024 377 0.10649 290.60127 0.12126 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 00:21:34 CET 2007 remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.12125 =LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03038 =punk.kls.es 192.168.1.12 2 1024 377 0.08014 290.59311 0.12131 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.22598 290.54091 0.12125 =srv1.m.faelix.n 192.168.1.12 2 1024 377 0.10805 290.62112 0.12129 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10883 290.58992 0.12135 *time3.ethz.ch 192.168.1.12 2 1024 377 0.10649 290.60127 0.12126 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 00:28:04 CET 2007 remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.12125 =LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03075 =punk.kls.es 192.168.1.12 2 1024 377 0.08014 290.59311 0.12131 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.22598 290.54091 0.12125 =srv1.m.faelix.n 192.168.1.12 2 1024 377 0.10805 290.62112 0.12129 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10883 290.58992 0.12135 *time3.ethz.ch 192.168.1.12 2 1024 377 0.10649 290.60127 0.12126 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 00:32:08 CET 2007 remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.12125 *LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03075 =punk.kls.es 192.168.1.12 2 1024 377 0.08012 295.27988 0.12161 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.11411 295.29405 0.12167 =srv1.m.faelix.n 192.168.1.12 2 1024 377 0.10986 295.30046 0.12164 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10886 295.27848 0.12166 =time3.ethz.ch 192.168.1.12 2 1024 377 0.11043 295.28876 0.12169 (the error is 5 minutes now) nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 00:37:07 CET 2007 remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.13649 *LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03065 =punk.kls.es 192.168.1.12 2 1024 377 0.08012 295.27988 0.12161 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.11411 295.29405 0.12167 =srv1.m.faelix.n 192.168.1.12 2 1024 377 0.10986 295.30046 0.12164 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10886 295.27848 0.12166 =time3.ethz.ch 192.168.1.12 2 1024 377 0.11043 295.28876 0.12169 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 00:41:30 CET 2007 remote local st poll reach delay offset disp ======================================================================= *192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.13649 =LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03084 =punk.kls.es 192.168.1.12 2 1024 377 0.08012 295.27988 0.12161 =96.Red-213-96-1 192.168.1.12 2 1024 377 0.11411 295.29405 0.12167 =ntp1.faelix.net 192.168.1.12 2 1024 377 0.10986 295.30046 0.12164 =endor.ordrejedi 192.168.1.12 3 1024 377 0.10886 295.27848 0.12166 =time3.ethz.ch 192.168.1.12 2 1024 377 0.11043 295.28876 0.12169 /var/log/ntp since last ntp restart (I enabled a hook to restart it every time I suspend to disk, thinking that might be the problem, but no): 28 Nov 16:30:24 ntpd[6148]: ntpd exiting on signal 15 28 Nov 16:30:24 ntpd[6148]: offset 0.000000 sec freq 78.416 ppm error 0.000001 poll 10 28 Nov 19:50:19 ntpd[19587]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010) 28 Nov 19:50:19 ntpd[19587]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:50:19 ntpd[19587]: Deleting interface #2 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 28 Nov 19:50:19 ntpd[19587]: Deleting interface #3 eth0, fe80::240:f4ff:fe2e:b121#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 28 Nov 19:50:25 ntpd[19587]: peer 212.9.75.245 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:50:25 ntpd[19587]: peer 193.142.245.196 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:50:25 ntpd[19587]: peer 213.161.194.93 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:50:25 ntpd[19587]: peer 192.33.98.103 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:50:26 ntpd[19587]: peer 192.33.214.57 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 19:53:32 ntpd[19587]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521) 28 Nov 19:53:32 ntpd[19587]: synchronized to LOCAL(0), stratum 10 28 Nov 19:53:32 ntpd[19587]: kernel time sync status change 0001 28 Nov 19:53:32 ntpd[19587]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534) 28 Nov 19:53:32 ntpd[19587]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543) 28 Nov 19:55:43 ntpd[19587]: synchronized to 192.33.214.57, stratum 2 28 Nov 20:03:19 ntpd[19587]: peer 213.96.197.96 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 28 Nov 20:06:24 ntpd[19587]: synchronized to 192.33.98.103, stratum 2 28 Nov 20:50:18 ntpd[19587]: offset -0.001408 sec freq 78.770 ppm error 0.001970 poll 7 28 Nov 21:01:16 ntpd[19587]: synchronized to 192.33.214.57, stratum 2 28 Nov 21:50:18 ntpd[19587]: offset -0.001597 sec freq 78.736 ppm error 0.004094 poll 9 28 Nov 22:38:00 ntpd[19587]: synchronized to 192.33.98.103, stratum 2 28 Nov 22:50:18 ntpd[19587]: offset 0.000773 sec freq 78.729 ppm error 0.005932 poll 10 28 Nov 23:50:18 ntpd[19587]: offset 0.002848 sec freq 78.946 ppm error 0.002366 poll 10 28 Nov 23:56:26 ntpd[19587]: synchronized to 192.33.214.57, stratum 2 29 Nov 00:02:53 ntpd[19587]: synchronized to LOCAL(0), stratum 10 29 Nov 00:13:29 ntpd[19587]: synchronized to 192.33.98.103, stratum 2 while I write this report, three more entries: 29 Nov 00:30:35 ntpd[19587]: synchronized to 212.9.75.245, stratum 2 29 Nov 00:31:30 ntpd[19587]: synchronized to LOCAL(0), stratum 10 29 Nov 00:37:39 ntpd[19587]: synchronized to 192.33.214.57, stratum 2 /var/log/kernel: Nov 28 19:49:49 nimrodel kernel: Restarting tasks ... done. Nov 28 19:49:53 nimrodel kernel: swsusp: Basic memory bitmaps freed Nov 28 19:49:56 nimrodel kernel: input: Power Button (FF) as /class/input/input9 Nov 28 19:49:56 nimrodel kernel: ACPI: Power Button (FF) [PWRF] Nov 28 19:49:56 nimrodel kernel: input: Power Button (CM) as /class/input/input10 Nov 28 19:49:56 nimrodel kernel: ACPI: Power Button (CM) [PWRB] Nov 28 19:49:56 nimrodel kernel: input: Sleep Button (CM) as /class/input/input11 Nov 28 19:49:56 nimrodel kernel: ACPI: Sleep Button (CM) [SLPB] Nov 28 23:55:29 nimrodel kernel: set_rtc_mmss: can't update from 0 to 55 Nov 28 23:55:29 nimrodel kernel: klogd 1.4.1, ---------- state change ---------- /var/log/messages: Nov 28 16:30:21 nimrodel gnome-power-manager: (cer) Hibernating computer because clicked tray Nov 28 19:49:49 nimrodel syslog-ng[3823]: STATS: dropped 0 Nov 28 19:49:54 nimrodel gnome-power-manager: (cer) Resuming computer Nov 28 19:49:56 nimrodel gnome-power-manager: (cer) hibernate failed Nov 28 19:50:18 nimrodel ntpdate[19502]: step time server 212.9.75.245 offset 4.583790 sec Nov 28 19:50:18 nimrodel ntpd[19586]: ntpd 4.2.4p3@1.1502-o Sat Sep 22 01:01:25 UTC 2007 (1) Nov 28 19:50:18 nimrodel ntpd[19587]: precision = 1.000 usec Nov 28 19:50:18 nimrodel ntpd[19587]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #0 wildcard, 0.0.0.0#123 Disabled Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #1 wildcard, ::#123 Disabled Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #2 lo, ::1#123 Enabled Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #3 eth0, fe80::240:f4ff:fe2e:b121#123 Enabled Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #4 lo, 127.0.0.1#123 Enabled Nov 28 19:50:18 nimrodel ntpd[19587]: Listening on interface #5 eth0, 192.168.1.12#123 Enabled Nov 28 19:50:18 nimrodel ntpd[19587]: kernel time sync status 0040 Nov 28 19:50:19 nimrodel ntpd[19587]: frequency initialized 78.416 PPM from /var/lib/ntp/drift/ntp.drift Nov 28 20:00:01 nimrodel /usr/sbin/cron[21174]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 20:19:29 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 190 Temperature_Celsius changed from 73 to 74 Nov 28 20:19:29 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 194 Temperature_Celsius changed from 27 to 26 Nov 28 20:19:29 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 71 to 74 Nov 28 20:19:29 nimrodel smartd[5218]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 26 to 24 Nov 28 20:19:29 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 33 to 31 Nov 28 20:30:01 nimrodel /usr/sbin/cron[23322]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 20:30:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 190 Temperature_Celsius changed from 74 to 73 Nov 28 20:30:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 194 Temperature_Celsius changed from 26 to 27 Nov 28 20:30:17 nimrodel smartd[5218]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 24 to 25 Nov 28 20:30:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 31 to 32 Nov 28 20:49:50 nimrodel syslog-ng[3823]: STATS: dropped 0 Nov 28 21:00:01 nimrodel /usr/sbin/cron[25777]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 21:00:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 74 to 73 Nov 28 21:00:16 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 59 to 60 Nov 28 21:00:16 nimrodel smartd[5218]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 25 to 26 Nov 28 21:00:16 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 32 to 33 Nov 28 21:24:21 nimrodel gconfd (root-27608): starting (version 2.20.0), pid 27608 user 'root' Nov 28 21:24:21 nimrodel gconfd (root-27608): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration source at position 0 Nov 28 21:24:21 nimrodel gconfd (root-27608): Resolved address "xml:readwrite:/root/.gconf" to a writable configuration source at position 1 Nov 28 21:24:21 nimrodel gconfd (root-27608): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source at position 2 Nov 28 21:24:21 nimrodel gconfd (root-27608): Resolved address "xml:readonly:/etc/gconf/gconf.xml.schemas" to a read-only configuration source at position 3 Nov 28 21:30:01 nimrodel /usr/sbin/cron[28110]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 21:30:17 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 73 to 72 Nov 28 21:30:17 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 60 to 58 Nov 28 21:30:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 59 to 60 Nov 28 21:30:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 59 to 60 Nov 28 21:49:50 nimrodel syslog-ng[3823]: STATS: dropped 0 Nov 28 22:00:01 nimrodel /usr/sbin/cron[30265]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 22:00:16 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 58 to 57 Nov 28 22:30:01 nimrodel /usr/sbin/cron[32324]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 22:30:16 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 57 to 59 Nov 28 22:49:50 nimrodel syslog-ng[3823]: STATS: dropped 0 Nov 28 23:00:01 nimrodel /usr/sbin/cron[2188]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 23:00:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 72 to 71 Nov 28 23:00:17 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 59 to 60 Nov 28 23:30:01 nimrodel /usr/sbin/cron[4300]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 28 23:45:02 nimrodel su: (to beagleindex) root on none Nov 28 23:45:02 nimrodel su: (to beagleindex) root on none Nov 28 23:45:18 nimrodel run-crons[5359]: beagle-crawl-system: OK Nov 28 23:45:32 nimrodel syslog-ng[3823]: SIGHUP received, restarting syslog-ng Nov 28 23:45:33 nimrodel syslog-ng[3823]: new configuration initialized Nov 28 23:45:42 nimrodel logrotate: ALERT exited abnormally with [1] Nov 28 23:45:42 nimrodel logrotate: /usr/bin/mysqladmin: connect to server at 'localhost' failed Nov 28 23:45:42 nimrodel logrotate: error: 'Access denied for user 'root'@'localhost' (using password: NO)' Nov 28 23:45:42 nimrodel logrotate: /etc/logrotate.d/mysql failed, probably because Nov 28 23:45:42 nimrodel logrotate: the root acount is protected by password. Nov 28 23:45:42 nimrodel logrotate: See comments in /etc/logrotate.d/mysql on how to fix this Nov 28 23:45:42 nimrodel logrotate: error: error running non-shared postrotate script for /var/lib/mysql/mysqld.log of '/var/lib/mysql/mysqld.log ' Nov 28 23:45:42 nimrodel logrotate: Reload syslog service..done Nov 28 23:45:42 nimrodel run-crons[5359]: logrotate: OK Nov 28 23:45:44 nimrodel run-crons[5359]: suse-clean_catman: OK Nov 28 23:47:36 nimrodel run-crons[5359]: suse-do_mandb: OK Nov 28 23:47:37 nimrodel su: (to nobody) root on none Nov 28 23:47:43 nimrodel syslog-ng[3823]: last message repeated 3 times Nov 28 23:47:43 nimrodel run-crons[5359]: suse-texlive: OK Nov 28 23:47:44 nimrodel run-crons[5359]: suse.de-backup-rc.config: OK Nov 28 23:47:47 nimrodel run-crons[5359]: suse.de-backup-rpmdb: OK Nov 28 23:47:47 nimrodel run-crons[5359]: suse.de-check-battery: OK Nov 28 23:47:49 nimrodel run-crons[5359]: suse.de-clean-tmp: OK Nov 28 23:47:49 nimrodel run-crons[5359]: suse.de-cron-local: OK Nov 28 23:47:49 nimrodel run-crons[5359]: suse.de-faxcron: OK Nov 28 23:47:49 nimrodel run-crons[5359]: suse.de-update-preload: OK Nov 28 23:47:49 nimrodel su: (to nobody) root on none Nov 28 23:48:34 nimrodel syslog-ng[3823]: last message repeated 2 times Nov 28 23:55:29 nimrodel syslog-ng[3823]: Cannot open file /dev/tty10 for writing (Permission denied) Nov 28 23:55:32 nimrodel run-crons[5359]: suse.de-updatedb: OK Nov 29 00:00:01 nimrodel /usr/sbin/cron[6804]: (root) CMD ( test -x /usr/lib/secchk/security-control.sh && /usr/lib/secchk/security-control.sh daily &) Nov 29 00:00:01 nimrodel /usr/sbin/cron[6806]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 29 00:00:17 nimrodel smartd[5218]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 60 to 59 Nov 29 00:00:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 60 to 59 Nov 29 00:00:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 195 Hardware_ECC_Recovered changed from 60 to 59 While I write this Nov 29 00:30:01 nimrodel /usr/sbin/cron[9518]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 29 00:30:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 190 Temperature_Celsius changed from 73 to 72 Nov 29 00:30:16 nimrodel smartd[5218]: Device: /dev/hda, SMART Usage Attribute: 194 Temperature_Celsius changed from 27 to 28 Nov 29 00:30:16 nimrodel smartd[5218]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 26 to 27 Nov 29 00:30:17 nimrodel smartd[5218]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 33 to 34 I'll restart ntp in a while. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c6 --- Comment #6 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-28 17:25:34 MST --- Restarted ntp. nimrodel:~ # rcntp restart Shutting down network time protocol daemon (NTPD) done Try to get initial date and time via NTP from pool.ntp.org es.pool.ntdoneg fr.pool.ntp.org ch.pool.ntp.org uk.pool.ntp.org Starting network time protocol daemon (NTPD) done nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 01:14:44 CET 2007 remote local st poll reach delay offset disp ======================================================================= =LOCAL(0) 127.0.0.1 10 64 1 0.00000 0.000000 2.81735 =srv0.m.faelix.n 192.168.1.12 2 64 1 0.09843 0.000841 2.81735 =caledonia.dataw 192.168.1.12 2 64 1 0.11655 0.004725 2.81735 =xolotl.zooomcla 192.168.1.12 3 64 1 0.12236 0.005479 2.81735 =125.Red-213-97- 192.168.1.12 2 64 1 0.11827 0.004959 2.81735 =ntp.dr-j.eu 192.168.1.12 2 64 1 0.10417 0.002932 2.81735 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 01:19:14 CET 2007 remote local st poll reach delay offset disp ======================================================================= *LOCAL(0) 127.0.0.1 10 64 37 0.00000 0.000000 0.66202 =srv0.m.faelix.n 192.168.1.12 2 64 37 0.09843 0.000841 0.66315 =caledonia.dataw 192.168.1.12 2 64 37 0.11613 0.006153 0.66339 =xolotl.zooomcla 192.168.1.12 3 64 37 0.11755 0.003882 0.66254 =125.Red-213-97- 192.168.1.12 2 64 37 0.11745 0.001420 0.66270 =ntp.dr-j.eu 192.168.1.12 2 64 37 0.09566 -0.001386 0.66284 nimrodel:~ # date ; ntpdc -c pe Thu Nov 29 01:20:23 CET 2007 remote local st poll reach delay offset disp ======================================================================= =LOCAL(0) 127.0.0.1 10 64 77 0.00000 0.000000 0.43399 *srv0.m.faelix.n 192.168.1.12 2 64 77 0.09843 0.000841 0.43623 =caledonia.dataw 192.168.1.12 2 64 77 0.11613 0.006153 0.43681 =xolotl.zooomcla 192.168.1.12 3 64 77 0.11755 0.003882 0.43568 =125.Red-213-97- 192.168.1.12 2 64 77 0.11745 0.001420 0.43578 =ntp.dr-j.eu 192.168.1.12 2 64 77 0.09566 -0.001386 0.43599 ntp log: 29 Nov 00:37:39 ntpd[19587]: synchronized to 192.33.214.57, stratum 2 29 Nov 00:50:18 ntpd[19587]: offset 0.000000 sec freq 78.947 ppm error 0.005062 poll 10 29 Nov 01:09:23 ntpd[19587]: ntpd exiting on signal 15 29 Nov 01:09:23 ntpd[19587]: offset 0.000000 sec freq 78.947 ppm error 0.003726 poll 10 29 Nov 01:14:36 ntpd[12215]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010) 29 Nov 01:14:37 ntpd[12215]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:14:37 ntpd[12215]: Deleting interface #2 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 29 Nov 01:14:37 ntpd[12215]: Deleting interface #3 eth0, fe80::240:f4ff:fe2e:b121#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs 29 Nov 01:14:41 ntpd[12215]: peer 193.142.245.154 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:14:41 ntpd[12215]: peer 213.251.134.188 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:14:41 ntpd[12215]: peer 213.97.131.125 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:14:42 ntpd[12215]: peer 195.216.64.208 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:14:42 ntpd[12215]: peer 194.88.212.205 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014) 29 Nov 01:17:52 ntpd[12215]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521) 29 Nov 01:17:52 ntpd[12215]: synchronized to LOCAL(0), stratum 10 29 Nov 01:17:52 ntpd[12215]: kernel time sync status change 0001 29 Nov 01:17:52 ntpd[12215]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534) 29 Nov 01:17:52 ntpd[12215]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543) 29 Nov 01:19:59 ntpd[12215]: synchronized to 193.142.245.154, stratum 2 29 Nov 01:23:15 ntpd[12215]: synchronized to 195.216.64.208, stratum 2 29 Nov 01:23:16 ntpd[12215]: synchronized to 193.142.245.154, stratum 2 kernel log: no new entries. messages log: Nov 29 00:45:33 nimrodel syslog-ng[3823]: STATS: dropped 0 Nov 29 01:00:01 nimrodel /usr/sbin/cron[11456]: (cer) CMD (/home/cer/bin/avisar_hablando time > /dev/null) Nov 29 01:14:25 nimrodel ntpdate[12194]: step time server 134.34.3.18 offset 295.288033 sec Nov 29 01:14:36 nimrodel ntpd[12214]: ntpd 4.2.4p3@1.1502-o Sat Sep 22 01:01:25 UTC 2007 (1) Nov 29 01:14:36 nimrodel ntpd[12215]: precision = 1.000 usec Nov 29 01:14:36 nimrodel ntpd[12215]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #0 wildcard, 0.0.0.0#123 Disabled Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #1 wildcard, ::#123 Disabled Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #2 lo, ::1#123 Enabled Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #3 eth0, fe80::240:f4ff:fe2e:b121#123 Enabled Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #4 lo, 127.0.0.1#123 Enabled Nov 29 01:14:36 nimrodel ntpd[12215]: Listening on interface #5 eth0, 192.168.1.12#123 Enabled Nov 29 01:14:36 nimrodel ntpd[12215]: kernel time sync status 0040 Nov 29 01:14:36 nimrodel named[4805]: *** POKED TIMER *** Nov 29 01:14:36 nimrodel syslog-ng[3823]: last message repeated 2 times Nov 29 01:14:36 nimrodel ntpd[12215]: frequency initialized 78.946 PPM from /var/lib/ntp/drift/ntp.drift It seems to be going well again, for the moment. Yesterday it happened while I was having lunch; today I was having dinner. Ie, it seems to happen while I'm not using the computer. Can it be trying to go to sleep, slowing the cpu? This cpu is not capable of throttling, AFAIK. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c7 Michael Skibbe <mskibbe@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO Info Provider| |robin.listas@telefonica.net --- Comment #7 from Michael Skibbe <mskibbe@novell.com> 2007-11-29 01:38:12 MST --- to comment #2: why you have following entry? server pool.ntp.org server pool.ntp.org server pool.ntp.org server pool.ntp.org found somewhere in comment #7: [...] 29 Nov 00:31:30 ntpd[19587]: synchronized to LOCAL(0), stratum 10 [...] and [...] remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.13649 *LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03065 [...] looks like your hardware clock is broken. but ntp knows that the time difference between server and local is to huge and sync to the bad local. when you restart ntpdate is called which forces the time correction so ntp works fine until the time diffs to much... something in the system is wrong but it doesn't looks like ntp is the problem. you told this happens if you are at lunch. do you have a program which starts to run if the computer is idle? -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356#c8 Carlos Robinson <robin.listas@telefonica.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW Info Provider|robin.listas@telefonica.net | --- Comment #8 from Carlos Robinson <robin.listas@telefonica.net> 2007-11-29 04:52:46 MST --- (In reply to comment #7 from Michael Skibbe)
to comment #2:
why you have following entry? server pool.ntp.org server pool.ntp.org server pool.ntp.org server pool.ntp.org
Why not? The idea is not mine; I read it somewhere. Each time you query for a server in the pool, it gives a different server: cer@nimrodel:~> host pool.ntp.org pool.ntp.org has address 84.88.69.10 pool.ntp.org has address 213.194.159.3 pool.ntp.org has address 195.55.174.243 cer@nimrodel:~> host pool.ntp.org pool.ntp.org has address 195.55.174.243 pool.ntp.org has address 84.88.69.10 pool.ntp.org has address 213.194.159.3 or: cer@nimrodel:~> host es.pool.ntp.org es.pool.ntp.org has address 195.10.6.126 es.pool.ntp.org has address 80.59.234.233 es.pool.ntp.org has address 80.33.117.152 cer@nimrodel:~> host es.pool.ntp.org es.pool.ntp.org has address 80.33.117.152 es.pool.ntp.org has address 195.10.6.126 es.pool.ntp.org has address 80.59.234.233 The idea is to give the program a lot of servers for it to find which are the best and use them. I have seen in the past that some of the servers in the pool are pretty bad, so I list more servers so it can find a bunch of good ones.
found somewhere in comment #7:
[...] 29 Nov 00:31:30 ntpd[19587]: synchronized to LOCAL(0), stratum 10 [...]
and
[...] remote local st poll reach delay offset disp ======================================================================= =192.33.214.57 192.168.1.12 2 1024 377 0.13612 295.28592 0.13649 *LOCAL(0) 127.0.0.1 10 64 377 0.00000 0.000000 0.03065 [...]
looks like your hardware clock is broken. but ntp knows that the time difference between server and local is to huge and sync to the bad local. when you restart ntpdate is called which forces the time correction so ntp works fine until the time diffs to much...
something in the system is wrong but it doesn't looks like ntp is the problem.
Remember that this doesn't happen always, not every day. Once it happened right while I was working; I think the machine stopped for 5 seconds while scanning a photo via USB and the clock started to go slow. Or it can be correct for days and days... in a month it has happened 6 times: cer@nimrodel:~> grep "exceeds sanity limit" /var/log/ntp 4 Nov 15:50:18 ntpd[5076]: time correction of 1190 seconds exceeds sanity limit (1000); set clock manually to the correct UTC time. 12 Nov 09:37:12 ntpd[5061]: 14 Nov 20:42:37 ntpd[5143]: 21 Nov 23:38:27 ntpd[5170]: 27 Nov 16:22:22 ntpd[12905]:
you told this happens if you are at lunch. do you have a program which starts to run if the computer is idle?
The screen saver. I'll be careful to leave it on during lunch to see if it consistently happens then. If that is consistent, I can disable the screen saver - but I can't believe a user's space program can interfere with kernel clock.
And yes, my guess is that ntp is not broken and that there is something wrong with the kernel maintained clock, but I have no idea what, or even what to do to see it. Maybe the kernel chooses the wrong type of clock during boot. It certainly started to go bad the following day to upgrading to 10.3. boot log extract: cer@nimrodel:~> grep -i clock /var/log/boot.msg <6>Time: tsc clocksource has been installed. <6>Real Time Clock Driver v1.12ac <6>Time: acpi_pm clocksource has been installed. <6>intel8x0_measure_ac97_clock: measured 50655 usecs <6>intel8x0: clocking to 48000 doneSetting up the hardware clockdone When you say "looks like your hardware clock is broken" - I don't suppose you mean the CMOS hardware clock? That does not affect after the system is up, as the time is by them correctly set up and the hardware clock is not consulted any more till next boot. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User robin.listas@telefonica.net added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c9 --- Comment #9 from Carlos Robinson <robin.listas@telefonica.net> 2007-12-04 14:10:08 MST --- I have more info. Doing this command: grep "time reset " /var/log/ntp | less I find interesting things. From last February (suse 10.2) till November 2nd, the resets are smaller than a second. From that point, which is the date when I upgraded to 10.3, the resets increase to several minutes! 1 Nov 11:28:02 ntpd[4669]: time reset +0.493571 s 1 Nov 19:54:33 ntpd[6168]: time reset +0.324889 s 2 Nov 11:56:25 ntpd[6168]: time reset +0.493251 s 2 Nov 14:09:49 ntpd[6168]: time reset +0.761453 s 2 Nov 18:57:50 ntpd[6168]: time reset +0.267648 s 2 Nov 19:19:37 ntpd[6168]: time reset +0.633949 s 3 Nov 15:04:26 ntpd[4993]: time reset +13.963114 s <=== upgrade to 10.3 3 Nov 16:14:24 ntpd[4993]: time reset +126.365828 s 3 Nov 19:12:32 ntpd[5051]: time reset +42.074367 s 4 Nov 12:46:09 ntpd[5076]: time reset +22.996088 s 4 Nov 13:32:56 ntpd[5076]: time reset +393.672856 s 5 Nov 13:35:23 ntpd[5163]: time reset +351.141250 s 5 Nov 14:00:25 ntpd[5163]: time reset +318.950445 s .. 30 Nov 12:48:37 ntpd[11777]: time reset +28.109032 s 1 Dec 00:31:56 ntpd[8904]: time reset +403.049432 s 1 Dec 23:48:30 ntpd[10935]: time reset +74.982738 s 3 Dec 19:31:42 ntpd[29084]: time reset +309.343782 s 3 Dec 20:34:30 ntpd[29084]: time reset +220.290279 s 4 Dec 12:22:58 ntpd[5847]: time reset +0.168114 s 4 Dec 14:04:05 ntpd[5847]: time reset +243.829774 s 4 Dec 15:23:59 ntpd[5847]: time reset +173.514626 s 4 Dec 16:05:21 ntpd[5847]: time reset +4.773942 s That's a definite problem in the clock system / ntp client in 10.3! One could thing that the hybernation cycles could have something to do, but they didn't in 10.2; and recently (Nov 22) I installed a hook to reset the ntp client on every hybernation cycle. Yesterday I disabled these two lines in the ntp config: server 127.127.1.0 # local clock (LCL) fudge 127.127.1.0 stratum 10 # LCL is unsynchronized And I can see the clock drifting fast when it loses the connection (without the message "synchronized to LOCAL(0), stratum 10"): 3 Dec 19:11:29 ntpd[29084]: synchronized to 88.191.43.2, stratum 2 3 Dec 19:12:44 ntpd[29084]: synchronized to 213.96.197.96, stratum 2 3 Dec 19:13:34 ntpd[29084]: no servers reachable 3 Dec 19:20:14 ntpd[29084]: synchronized to 88.191.43.2, stratum 2 3 Dec 19:21:32 ntpd[29084]: synchronized to 213.96.197.96, stratum 2 3 Dec 19:22:36 ntpd[29084]: synchronized to 88.191.43.2, stratum 2 3 Dec 19:31:42 ntpd[29084]: time reset +309.343782 s A 300" error in less than 20 minutes after "no servers reachable"! Before another hour passes, it happens again: 3 Dec 19:31:42 ntpd[29084]: system event 'event_clock_reset' (0x05) status 'sync_alarm, sync_unspec, 15 events, event_peer/strat_chg' (0xc0f4) 3 Dec 19:31:42 ntpd[29084]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_unspec, 15 events, event_clock_reset' (0xc0f5) 3 Dec 19:31:44 ntpd[29084]: peer 213.96.200.126 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:31:45 ntpd[29084]: peer 81.19.16.225 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:32:23 ntpd[29084]: peer 88.191.43.2 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:32:24 ntpd[29084]: peer 195.92.137.112 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:32:30 ntpd[29084]: peer 193.138.215.60 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:32:34 ntpd[29084]: peer 213.96.197.96 event 'event_reach' (0x84) status 'unreach, conf, 2 events, event_reach' (0x8024) 3 Dec 19:36:40 ntpd[29084]: synchronized to 88.191.43.2, stratum 2 3 Dec 19:36:40 ntpd[29084]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_ntp, 15 events, event_peer/strat_chg' (0x6f4) 3 Dec 19:36:40 ntpd[29084]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_ntp, 15 events, event_sync_chg' (0x6f3) 3 Dec 20:01:13 ntpd[29084]: offset 0.002029 sec freq 79.654 ppm error 0.002737 poll 6 3 Dec 20:15:34 ntpd[29084]: synchronized to 213.96.197.96, stratum 2 3 Dec 20:28:15 ntpd[29084]: no servers reachable 3 Dec 20:30:41 ntpd[29084]: synchronized to 88.191.43.2, stratum 2 3 Dec 20:34:30 ntpd[29084]: time reset +220.290279 s 220" delay in 6' after the "no servers reachable" message. What is happening here? -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User robin.listas@telefonica.net added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c10 --- Comment #10 from Carlos Robinson <robin.listas@telefonica.net> 2007-12-30 05:40:41 MST --- The real cause (bad clock) is reported in Bug 350981 - The system clock doesn't work correctly -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User mskibbe@novell.com added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c11 Michael Skibbe <mskibbe@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED Resolution| |INVALID --- Comment #11 from Michael Skibbe <mskibbe@novell.com> 2008-01-07 02:58:23 MST --- seems your hardware clock isn't working correct => invalid -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User robin.listas@telefonica.net added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c12 --- Comment #12 from Carlos Robinson <robin.listas@telefonica.net> 2008-01-07 13:46:58 MST --- Please, notice that the hardware clock is working correctly, as demonstrated by running opensuse 10.2 and seeing the problems disappear. It is a software problem, most probably in the kernel. This is explained in Bug 350981#4 (https://bugzilla.novell.com/show_bug.cgi?id=350981#c4) I assume that by HW clock you are not referring to the cmos clock? This is what the NTP literature calls hardware clock. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User martin.burnicki@meinberg.de added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c13 --- Comment #13 from Martin Burnicki <martin.burnicki@meinberg.de> 2008-01-07 14:43:29 MST --- Michael, (In reply to comment #11 from Michael Skibbe)
seems your hardware clock isn't working correct => invalid
From what I've read here and in the mailing list I'm also pretty sure this is a kernel problem. Maybe the latest kernel changes have broken the kernel's support for this particular hardware.
Anyway, where do you see a clue that the hardware might be faulty? Martin -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User mskibbe@novell.com added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c14 --- Comment #14 from Michael Skibbe <mskibbe@novell.com> 2008-01-08 05:06:18 MST --- i saw a big clue to say your hardware clock is faulty: 27 Nov 16:22:22 ntpd[12905]: time correction of 1678 seconds exceeds sanity limit (1000); set clock manually to the correct UTC time. and the huge offsets in such a small time you told me. this is definitly not a ntp problem! you opened the "same" bug here: #350981 -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User robin.listas@telefonica.net added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c15 --- Comment #15 from Carlos Robinson <robin.listas@telefonica.net> 2008-01-08 05:29:41 MST --- No, you are confused. As shown in Bug 350981#4, it is not the hardware clock that is bad, it is the kernel managing the hardware clock that is faulty. I repeat, I booted suse 10.2 (on request) the other day to test this, and it run fine. It is 10.3 that is faulty. I agree that the fault is not ntpd, but I never claimed that it was: ntpd simply "discovered" the problem. The ntpd quiting was the symptom. It is a software problem in the kernel included with 10.3. It is absolutely not a hardware problem, but perhaps a software problem in handling a particular hardware. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User mskibbe@novell.com added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c16 Michael Skibbe <mskibbe@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |REOPENED Resolution|INVALID | --- Comment #16 from Michael Skibbe <mskibbe@novell.com> 2008-01-08 05:46:06 MST --- reopen -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User mskibbe@novell.com added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c17 Michael Skibbe <mskibbe@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |mskibbe@novell.com AssignedTo|mskibbe@novell.com |bnc-team-screening@forge.provo.novell.com Status|REOPENED |NEW --- Comment #17 from Michael Skibbe <mskibbe@novell.com> 2008-01-08 05:47:36 MST --- please assign bug to someone who knows more about kernel time management. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User robin.listas@telefonica.net added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c18 --- Comment #18 from Carlos Robinson <robin.listas@telefonica.net> 2008-01-08 06:11:13 MST --- Perhaps you can simply close this one and concentrate in Bug 350981, which has the correct info. The present report served its purpose in learning which is the precise problem, and now the other one should be the appropriate bug to analyze. This one could then be closed as "duplicate", or even "invalid, not ntp but kernel, continued in Bug 350981". Whatever you see fit, except "invalid, hardware problem" :-) And I must thank you all in your efforts, this thing is not easy to analyze, and probably only affects few machines (one or two more came in the mail list). -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User martin.burnicki@meinberg.de added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c19 --- Comment #19 from Martin Burnicki <martin.burnicki@meinberg.de> 2008-01-08 06:37:57 MST --- Just FYI, I fully agree with Carlos. Martin -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=344356 User chrubis@novell.com added comment https://bugzilla.novell.com/show_bug.cgi?id=344356#c20 Cyril Hrubis <chrubis@novell.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED Resolution| |DUPLICATE --- Comment #20 from Cyril Hrubis <chrubis@novell.com> 2008-01-10 05:45:17 MST --- Closing as duplicate of 350981 because of comment #18. *** This bug has been marked as a duplicate of bug 350981 *** https://bugzilla.novell.com/show_bug.cgi?id=350981 -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
participants (1)
-
bugzilla_noreply＠novell.com