LinHES Forums • View topic - Weird Clock Changes

Board index KnoppMyth General

All times are UTC - 6 hours

Weird Clock Changes

Page 1 of 1

[ 5 posts ]

Print view

Previous topic Next topic

Author

Message

turpie

Post subject: Weird Clock Changes

Posted: Wed Oct 03, 2007 4:39 am

Joined: Wed Apr 28, 2004 10:42 pm

Posts: 405

Location: Bendigo, Victoria, Australia

My system has had a couple of weird clock changes lately. Since upgrading to R5F27 the clock in my KM machine has occasionally gone back in time, then returned to normal again later. A couple of times when I've turned the machine on it has had to do a fsck scan because it think that hundreds of days have passed since the check.
I'm not really sure where to start so does anyone have any idea of what is happening?

Here are some snippets of /var/log/messages

Code:

Oct  2 11:01:19 mythtv -- MARK --
Oct  2 11:02:55 mythtv shutdown[4849]: shutting down for system halt
Oct  2 11:03:03 mythtv kernel: Kernel logging (proc) stopped.
Oct  2 11:03:03 mythtv kernel: Kernel log daemon terminating.
Oct  2 11:03:04 mythtv exiting on signal 15
Jan  1 11:10:00 mythtv syslogd 1.4.1#20: restart.
Jan  1 11:10:00 mythtv kernel: klogd 1.4.1#20, log source = /proc/kmsg started.
Jan  1 11:10:00 mythtv kernel: Linux version 2.6.18-chw-13 (root@mythtv) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)) #1 SM
P PREEMPT Sat Jun 2 21:06:06 PDT 2007
Jan  1 11:10:00 mythtv kernel: BIOS-provided physical RAM map:

Code:

Jan  1 11:10:16 mythtv kernel: ACPI: PCI Interrupt 0000:00:05.0[A] -> Link [APC7] -> GSI 16 (level, low) -> IRQ 21
Jan  1 11:10:16 mythtv kernel: NVRM: loading NVIDIA UNIX x86 Kernel Module  1.0-9755  Mon Feb 26 23:21:15 PST 2007
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): starting (version 2.16.1), pid 8780 user 'mythtv'
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration s
ource at position 0
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): Resolved address "xml:readwrite:/home/mythtv/.gconf" to a writable configuration source at po
sition 1
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration so
urce at position 2
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): Resolved address "xml:readonly:/var/lib/gconf/debian.defaults" to a read-only configuration s
ource at position 3
Jan  1 11:10:22 mythtv gconfd (mythtv-8780): Resolved address "xml:readonly:/var/lib/gconf/defaults" to a read-only configuration source a
t position 4
Oct  3 18:47:19 mythtv gconfd (mythtv-8780): GConf server is not in use, shutting down.
Oct  3 18:47:19 mythtv gconfd (mythtv-8780): Exiting
Oct  3 19:06:27 mythtv -- MARK --

/var/log/kern.log

Code:

Jan  1 11:10:02 mythtv kernel: lirc_dev: lirc_register_plugin: sample_rate: 0
Jan  1 11:10:08 mythtv kernel: eth0: no IPv6 routers present
Jan  1 11:10:15 mythtv kernel: nvidia: module license 'NVIDIA' taints kernel.
Jan  1 11:10:16 mythtv kernel: ACPI: PCI Interrupt Link [APC7] enabled at IRQ 16
Jan  1 11:10:16 mythtv kernel: ACPI: PCI Interrupt 0000:00:05.0[A] -> Link [APC7] -> GSI 16 (level, low) -> IRQ 21
Jan  1 11:10:16 mythtv kernel: PCI: Setting latency timer of device 0000:00:05.0 to 64
Jan  1 11:10:16 mythtv kernel: NVRM: loading NVIDIA UNIX x86 Kernel Module  1.0-9755  Mon Feb 26 23:21:15 PST 2007
Oct  3 18:50:54 mythtv kernel: vp7045: USB control message 'in' went wrong.
Oct  3 19:00:40 mythtv kernel: vp7045: USB control message 'in' went wrong.
Oct  3 19:00:43 mythtv kernel: vp7045: USB control message 'in' went wrong.
Oct  3 20:09:56 mythtv kernel: vp7045: USB control message 'in' went wrong.

For some reason it seems to have booted up thinking it is Jan 1 2006 then somehow corrected itself to the right time.

Might using ACPI wakeups be affecting it.

_________________
Paul Turpie
-------------
<--Is your location in your profile? Why not?

Top

turpie

Post subject:

Posted: Wed Oct 03, 2007 4:49 am

Joined: Wed Apr 28, 2004 10:42 pm

Posts: 405

Location: Bendigo, Victoria, Australia

This log seems to suggest that ntpd was responsible for fixing the time, but why is it going out of whack in the first place?

/var/log/daemon.log

Code:

Oct  2 10:41:29 mythtv /etc/mysql/debian-start[3589]: Checking for crashed MySQL tables.
Oct  2 10:41:33 mythtv ntpd[3605]: ntpd 4.2.2p4@1.1585-o Sun Mar  4 13:21:35 UTC 2007 (1)
Oct  2 10:41:33 mythtv ntpd[3606]: precision = 2.000 usec
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface wildcard, 0.0.0.0#123 Disabled
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface wildcard, ::#123 Disabled
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface lo, ::1#123 Enabled
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface eth0, fe80::217:31ff:fe80:8b4d#123 Enabled
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface lo, 127.0.0.1#123 Enabled
Oct  2 10:41:33 mythtv ntpd[3606]: Listening on interface eth0, 10.0.0.20#123 Enabled
Oct  2 10:41:33 mythtv ntpd[3606]: kernel time sync status 0040
Oct  2 10:41:33 mythtv ntpd[3606]: frequency initialized -18.830 PPM from /var/lib/ntp/ntp.drift
Oct  2 10:41:44 mythtv lircd-0.8.2-CVS-pvr150[3346]: accepted new client on /dev/lircd
Oct  2 10:41:44 mythtv ntpd[3606]: synchronized to 59.167.252.133, stratum 2
Oct  2 10:41:44 mythtv ntpd[3606]: time reset -0.840738 s
Oct  2 10:41:44 mythtv ntpd[3606]: kernel time sync enabled 0001
Oct  2 10:45:50 mythtv ntpd[3606]: synchronized to 130.102.128.23, stratum 2
Oct  2 10:55:40 mythtv lircd-0.8.2-CVS-pvr150[3346]: accepted new client on /dev/lircd
Oct  2 10:59:51 mythtv lircd-0.8.2-CVS-pvr150[3346]: removed client
Oct  2 11:02:55 mythtv init: Switching to runlevel: 0
Oct  2 11:02:56 mythtv lircd-0.8.2-CVS-pvr150[3346]: caught signal
Oct  2 11:02:56 mythtv mysqld[3415]: 071002 11:02:56 [Note] /usr/sbin/mysqld: Normal shutdown
Oct  2 11:02:56 mythtv mysqld[3415]:
Oct  2 11:02:56 mythtv mysqld[3415]: 071002 11:02:56  InnoDB: Starting shutdown...
Oct  2 11:02:58 mythtv mysqld[3415]: 071002 11:02:58  InnoDB: Shutdown completed; log sequence number 0 43665
Oct  2 11:02:58 mythtv mysqld[3415]: 071002 11:02:58 [Note] /usr/sbin/mysqld: Shutdown complete
Oct  2 11:02:58 mythtv mysqld[3415]:
Oct  2 11:02:58 mythtv mysqld_safe[4927]: ended
Oct  2 11:03:03 mythtv ntpd[3606]: ntpd exiting on signal 15
Jan  1 11:10:02 mythtv lircd-0.8.2-CVS-pvr150[8314]: lircd(all) ready
Jan  1 11:10:03 mythtv mysqld_safe[8380]: started
Jan  1 11:10:03 mythtv mysqld[8383]: 060101 11:10:03  InnoDB: Started; log sequence number 0 43665
Jan  1 11:10:03 mythtv mysqld[8383]: 060101 11:10:03 [Note] /usr/sbin/mysqld: ready for connections.
Jan  1 11:10:03 mythtv mysqld[8383]: Version: '5.0.32-Debian_7etch1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian etch distr
ibution
Jan  1 11:10:04 mythtv /etc/mysql/debian-start[8420]: Upgrading MySQL tables if necessary.
Jan  1 11:10:09 mythtv /etc/mysql/debian-start[8558]: Checking for crashed MySQL tables.
Jan  1 11:10:13 mythtv ntpd[8574]: ntpd 4.2.2p4@1.1585-o Sun Mar  4 13:21:35 UTC 2007 (1)
Jan  1 11:10:13 mythtv ntpd[8575]: precision = 2.000 usec
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface wildcard, 0.0.0.0#123 Disabled
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface wildcard, ::#123 Disabled
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface lo, ::1#123 Enabled
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface eth0, fe80::217:31ff:fe80:8b4d#123 Enabled
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface lo, 127.0.0.1#123 Enabled
Jan  1 11:10:13 mythtv ntpd[8575]: Listening on interface eth0, 10.0.0.20#123 Enabled
Jan  1 11:10:13 mythtv ntpd[8575]: kernel time sync status 0040
Jan  1 11:10:13 mythtv ntpd[8575]: frequency initialized -18.505 PPM from /var/lib/ntp/ntp.drift
Jan  1 11:10:21 mythtv lircd-0.8.2-CVS-pvr150[8314]: accepted new client on /dev/lircd
Oct  3 18:46:51 mythtv ntpd[8575]: synchronized to 60.240.81.28, stratum 2
Oct  3 18:46:51 mythtv ntpd[8575]: time reset +55326987.392169 s
Oct  3 18:46:51 mythtv ntpd[8575]: kernel time sync enabled 0001
Oct  3 18:50:01 mythtv lircd-0.8.2-CVS-pvr150[8314]: accepted new client on /dev/lircd
Oct  3 18:51:24 mythtv ntpd[8575]: synchronized to 60.240.81.28, stratum 2
Oct  3 18:55:14 mythtv ntpd[8575]: synchronized to 121.0.1.1, stratum 2
Oct  3 19:59:55 mythtv ntpd[8575]: synchronized to 60.240.81.28, stratum 2
Oct  3 20:25:35 mythtv ntpd[8575]: synchronized to 121.0.1.1, stratum 2

_________________
Paul Turpie
-------------
<--Is your location in your profile? Why not?

Top

turpie

Post subject:

Posted: Wed Oct 03, 2007 5:14 pm

Joined: Wed Apr 28, 2004 10:42 pm

Posts: 405

Location: Bendigo, Victoria, Australia

Would my modification to /etc/init.d/hwclock.sh be to blame?

Quote:

stop|restart|reload|force-reload)
#
# Updates the Hardware Clock with the System Clock time.
# This will *override* any changes made to the Hardware Clock.
#
# WARNING: If you disable this, any changes to the system
# clock will not be carried across reboots.
#
ACPITIME=`cat /proc/acpi/alarm`
if [ "$HWCLOCKACCESS" != no ]; then
log_action_msg "Saving the system clock."
if [ "$GMT" = "-u" ]; then
GMT="--utc"
fi
/sbin/hwclock --systohc $GMT $HWCLOCKPARS $BADYEAR
verbose_log_action_msg "Hardware Clock updated to `date`"
echo "$ACPITIME" > /proc/acpi/alarm
else
verbose_log_action_msg "Not saving System Clock"
fi
;;

The red lines are the ones I added for ACPI wakeups.

_________________
Paul Turpie
-------------
<--Is your location in your profile? Why not?

Top

Verbetex

Post subject:

Posted: Wed Oct 17, 2007 2:05 pm

Joined: Thu Sep 08, 2005 6:24 am

Posts: 22

Location: UK

I'm getting the exact same thing!

I've set up mythwelcome and using ACPI to do the wakeup. However, I've not made the fussy bios change you have (modification of hwclock.sh) so I would rule that out for the problem.

This is resulting in my machine waking up, but not actually recording anything.

I'm using the following script to set the time:

Code:

#!/bin/bash
stamp_file=/home/mythtv/timestamp

#just log what we get as command line parameters
echo $1 $2 $3> $stamp_file

#i setted mythtv to output the number of seconds since epoch
#so i calculate the number of hours, minutes and seconds from
#now the computer has to wakeup:
sfn=$(($2 - `date +"%s"`))

#and then send it to /proc/acpi/wakeup in the format we saw above
y=`(echo $(($sfn - 3600))|awk '{print strftime("+00-00-00 %H:%M:%S", $1)}')`

echo "$y">/proc/acpi/alarm
echo "$y">>$stamp_file
echo "executed at `date`" >> $stamp_file
exit

Anyone have any ideas??

_________________
Knoppmyth: R5F27
CASE: Silverstone LC11-M
MB: ASUS M2NPV-VM
DTV: Hauppauge WinTV Nova-T-500
FORMAT: PAL (UK)
RAM: 1GB
HDD: 400GB Samsung Spinpoint 401
TV: Samsung LE32R74BDX (via Component)

Top

Verbetex

Post subject:

Posted: Wed Oct 17, 2007 3:40 pm

Joined: Thu Sep 08, 2005 6:24 am

Posts: 22

Location: UK

Not a proper fix, but I'm hoping that it may partially help...

I've basically installed ntpdate and added

Code:

ntpdate -u 0.debian.pool.ntp.org

to /etc/init.d/bootmisc.sh

Hopefully it'll update the time when the machine starts so it doesn't have to wait for the ntp deamon to kick in. However, this won't get round the disk checking on startup, but might help with starting a recording.

Top

Page 1 of 1

[ 5 posts ]

Board index KnoppMyth General

All times are UTC - 6 hours

Who is online

Users browsing this forum: No registered users and 15 guests

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum