My system clock only jumps, not ticks? (Linux)
Gert Robben
tor at gert.robben.nu
Tue Dec 1 17:34:49 UTC 2009
Hello,
Tor logs these messages continuously:
Nov 29 23:30:15.618 [warn] Your system clock just jumped 2189 seconds forward; assuming established circuits no longer work.
Nov 30 00:35:45.024 [warn] Your system clock just jumped 3930 seconds forward; assuming established circuits no longer work.
Nov 30 01:10:21.651 [warn] Your system clock just jumped 2076 seconds forward; assuming established circuits no longer work.
As can be seen, every jump is exactly the time since the last jump (I've tested this for a day).
So the clock doesn't seem to progress in between the jumps.
In the past I never had this problem, however I don't know when it appeared (maybe 1-2 months ago?), or what I might have done to cause it. Old logs are lost because they are kept in RAM.
I use an Alix 2C2 board, with Debian Lenny.
I tried Linux kernels 2.6.28-2.6.31 from kernel.org, and Tor 0.2.0 (from Debian) and 0.2.1 (from deb.torproject.org), which don't make a difference.
IIRC, I used 2.6.28 long ago, at that time I didn't have a problem. So I assume it's not the kernel.
Below this mail is the output of various commands. What can be concluded:
- The 2 NTP servers I tried both agree about the time
- RTC drifts only 2s/day
- System time drifts only 26s/day
- (I didn't have any time daemons running during the below commands)
Also, after this test, I used adjtimex to set the kernel clock frequency from 0 (see below) to 5347487, but that didn't make any difference either.
What is also weird, is that Tor doesn't respond well to SIGINT. It seems to shutdown in forever instead of in 30 seconds. Maybe it's related?
# killall -INT tor
# sleep 3m;tail -n1 /var/log/tor/log
Dec 01 18:13:03.813 [notice] Interrupt: will shut down in 30 seconds. Interrupt again to exit now.
# killall -INT tor
# tail -n2 /var/log/tor/log
Dec 01 18:13:03.813 [notice] Interrupt: will shut down in 30 seconds. Interrupt again to exit now.
Dec 01 18:16:43.917 [notice] Sigint received a second time; exiting now.
I've looked at previous posts about clock jumps, but I have the idea I have a different problem because these jumps are much larger, and because in this case the starting point of the jump is always the previous jump. And I don't use virtualization.
Or could it be faulty hardware? A friend of mine has the exact same board, if it's really necessary maybe I can test with his.
Any advice? Thanks!
Gert Robben
---- 8< ----
alix:/rw# ls /etc/adjtime
ls: cannot access /etc/adjtime: No such file or directory
alix:/rw# ls -l /dev/rtc*
lrwxrwxrwx 1 root root 4 Sep 26 16:38 /dev/rtc -> rtc0
crw-rw---- 1 root root 254, 0 Sep 26 16:38 /dev/rtc0
# cat /sys/devices/system/clocksource/clocksource0/available_clocksource
tsc
# rdate -vn ntp.uu.nl
Mon Nov 30 00:23:36 CET 2009
rdate: adjust local clock by 0.033507 seconds
# rdate -vn 0.nl.pool.ntp.org
Mon Nov 30 00:24:05 CET 2009
rdate: adjust local clock by 0.008656 seconds
# hwclock --debug --noadjfile --systohc --utc
hwclock from util-linux-ng 2.13.1.1
Using /dev interface to clock.
Assuming hardware clock is kept in UTC time.
Waiting for clock tick...
...got clock tick
Time read from Hardware Clock: 2009/11/29 23:24:06
Hw clock time : 2009/11/29 23:24:06 = 1259537046 seconds since 1969
Time elapsed since reference time has been 0.004192 seconds.
Delaying further to reach the next full second.
Setting Hardware Clock to 23:24:07 = 1259537047 seconds since 1969
ioctl(RTC_SET_TIME) was successful.
Clock drifted 0.0 seconds in the past 1259537035 seconds in spite of a drift factor of -0.000000 seconds/day.
Adjusting drift factor by 0.000000 seconds/day
# cat /proc/driver/rtc
rtc_time : 23:24:07
rtc_date : 2009-11-29
alrm_time : 00:00:00
alrm_date : ****-**-**
alarm_IRQ : no
alrm_pending : no
24hr : yes
periodic_IRQ : no
update_IRQ : no
HPET_emulated : no
DST_enable : no
periodic_freq : 1024
batt_status : okay
# adjtimex -p
mode: 0
offset: 0
frequency: 0
maxerror: 16000000
esterror: 16000000
status: 64
time_constant: 2
precision: 1
tolerance: 32768000
tick: 10000
raw time: 1259537047s 509299us = 1259537047.509299
return value = 5
# adjtimex -c$((60*24)) -i60
--- current --- -- suggested --
cmos time system-cmos error_ppm tick freq tick freq
1259537048 0.000319
1259537108 -0.016563 -281.4 10000 0
1259537168 -0.033440 -281.3 10000 0 10002 5327175
---- 8< ----
1259623268 -24.240457 -281.7 10000 0 10002 5355560
1259623328 -24.257361 -281.7 10000 0 10002 5356341
1259623388 -24.274265 -281.7 10000 0 10002 5356602
# rdate -vn ntp.uu.nl
Tue Dec 1 00:23:09 CET 2009
rdate: adjust local clock by 26.260063 seconds
# hwclock --debug --noadjfile --systohc --utc
hwclock from util-linux-ng 2.13.1.1
Using /dev interface to clock.
Assuming hardware clock is kept in UTC time.
Waiting for clock tick...
...got clock tick
Time read from Hardware Clock: 2009/11/30 23:23:09
Hw clock time : 2009/11/30 23:23:09 = 1259623389 seconds since 1969
Time elapsed since reference time has been 0.986044 seconds.
Delaying further to reach the next full second.
Setting Hardware Clock to 23:23:11 = 1259623391 seconds since 1969
ioctl(RTC_SET_TIME) was successful.
Clock drifted 2.0 seconds in the past 1259623379 seconds in spite of a drift factor of -0.000000 seconds/day.
Adjusting drift factor by 0.000136 seconds/day
# cat /var/log/tor/log|grep jumped
Nov 29 23:30:15.618 [warn] Your system clock just jumped 2189 seconds forward; assuming established circuits no longer work.
Nov 30 00:35:45.024 [warn] Your system clock just jumped 3930 seconds forward; assuming established circuits no longer work.
Nov 30 01:10:21.651 [warn] Your system clock just jumped 2076 seconds forward; assuming established circuits no longer work.
---- 8< ----
Dec 01 00:04:25.164 [warn] Your system clock just jumped 675 seconds forward; assuming established circuits no longer work.
Dec 01 00:13:47.230 [warn] Your system clock just jumped 562 seconds forward; assuming established circuits no longer work.
Dec 01 00:23:11.885 [warn] Your system clock just jumped 564 seconds forward; assuming established circuits no longer work.
# cat /etc/tor/torrc|grep ^[A-Z]|egrep -v Contact\|Nick
SocksPort 9050
SocksListenAddress 127.0.0.1
Log notice file /var/log/tor/log
ORPort 443
ORListenAddress 0.0.0.0:9030
RelayBandwidthRate 12 MB
RelayBandwidthBurst 12 MB
ExitPolicy reject *:*
AccountingStart week 7 00:00
AvoidDiskWrites 1
CircuitBuildTimeout 30
NumEntryGuards 6
KeepalivePeriod 60
NewCircuitPeriod 15
AccountingMax 80 GB
MaxAdvertisedBandwidth 70 KB
# dmesg|egrep -i 'pit|tsc|time|clock|clk|resolution'
[ 0.000000] Fast TSC calibration using PIT
[ 0.001017] Calibrating delay loop (skipped), value calculated using timer frequency.. 996.24 BogoMIPS (lpj=498123)
[ 0.017055] geode-mfgpt: 8 MFGPT timers available.
[ 0.018010] geode-mfgpt: Registered timer 0
[ 0.019036] mfgpt-timer: Registering MFGPT timer 0 as a clock event, using IRQ 7
[ 0.037274] Switched to high resolution mode on CPU 0
[ 0.210329] pc87413 WDT: initialized. timeout=1 min
[ 0.274223] rtc_cmos rtc_cmos: setting system clock to 2009-11-29 21:04:55 UTC (1259528695)
***********************************************************************
To unsubscribe, send an e-mail to majordomo at torproject.org with
unsubscribe or-talk in the body. http://archives.seul.org/or/talk/
More information about the tor-talk
mailing list