| View previous topic :: View next topic |
| Author |
Message |
sqeezer
n00b
Joined: 21 Nov 2004
Posts: 5
|
 Posted: Sun Nov 21, 2004 8:01 pm Post subject: Strange date problem |
 |
|
I have a strange differences in the result of 'date' function:
Sometimes the systemclock jumps about 100 minutes in the future
and back again.
I came across this problem, because the logfiles and almost everything which depends on the system clock behaves strange. (cron, at, mysql ...)
Example:
fsd:/# date
Sun Nov 21 20:14:51 CET 2004
fsd:/# date
Sun Nov 21 21:26:28 CET 2004
fsd:/# date
Sun Nov 21 20:15:02 CET 2004
Example2:
test.sh:
while :
do
date >>date.log
sleep 1
done
date.log:
...
Sun Nov 21 01:39:13 CET 2004
Sun Nov 21 01:39:14 CET 2004
Sun Nov 21 01:39:15 CET 2004
Sun Nov 21 01:39:16 CET 2004
Sun Nov 21 01:39:17 CET 2004
Sun Nov 21 02:50:53 CET 2004
Sun Nov 21 02:50:54 CET 2004
Sun Nov 21 01:39:21 CET 2004
Sun Nov 21 01:39:22 CET 2004
Sun Nov 21 01:39:23 CET 2004
...
But this script show NO anomalities:
while :
do
date >>date.log
hwclock --show >>date.log
sleep 1
done
Everythis ist normal in this log, the time increases continously as
expected.
The are no ntp proccesses running which could manipulate the date/time.
Any ideas?
Sqeezer |
|
| Back to top |
|
 |
andersmusikka
n00b
Joined: 29 Apr 2004
Posts: 23
|
| Posted: Sun Nov 21, 2004 8:51 pm Post subject: |
|
|
Wow, that was strange!
I'm not sure about this, but I think the hardware clock is typically only written at system shutdown. So it's no mystery that it's working properly.
Anyway, could you please replace
with
| Code: | | date --utc >>date.log |
and run the scripts again?
I have no idea what could be causing this, but if the anomaly isn't present with the --utc option, it has to be (?) the timezone that's somehow set to a real strange value every now and then (not a full hour).
If it's still there I suppose some process is actually changing the time. Are you absolutely *sure* that there's no ntpclient running somewhere? .-) |
|
| Back to top |
|
|
sqeezer
n00b
Joined: 21 Nov 2004
Posts: 5
|
| Posted: Sun Nov 21, 2004 11:21 pm Post subject: date --utc >>date.log |
|
|
while :
do
date --utc >>date.log
sleep 1
done
results in:
....
Sun Nov 21 23:16:28 UTC 2004
Sun Nov 21 23:16:29 UTC 2004
Sun Nov 21 23:16:30 UTC 2004
Sun Nov 21 23:16:31 UTC 2004
Sun Nov 21 23:16:32 UTC 2004
Sun Nov 21 23:16:33 UTC 2004
Sun Nov 21 23:16:34 UTC 2004
Sun Nov 21 23:16:35 UTC 2004
Sun Nov 21 23:16:36 UTC 2004
Sun Nov 21 23:16:37 UTC 2004
Mon Nov 22 00:28:13 UTC 2004
Mon Nov 22 00:28:14 UTC 2004
Sun Nov 21 23:16:41 UTC 2004
Sun Nov 21 23:16:42 UTC 2004
Sun Nov 21 23:16:43 UTC 2004
Sun Nov 21 23:16:44 UTC 2004
Sun Nov 21 23:16:45 UTC 2004
Sun Nov 21 23:16:46 UTC 2004
Sun Nov 21 23:16:47 UTC 2004
Sun Nov 21 23:16:48 UTC 2004
Sun Nov 21 23:16:49 UTC 2004
Sun Nov 21 23:16:50 UTC 2004
....
wired 'timehops' do appear without any plausible reason . |
|
| Back to top |
|
|
sqeezer
n00b
Joined: 21 Nov 2004
Posts: 5
|
| Posted: Sun Nov 21, 2004 11:30 pm Post subject: ps aux |
|
|
| Code: |
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.0 1492 416 ? S Oct30 0:08 init [2]
root 2 0.0 0.0 0 0 ? S Oct30 0:00 [keventd]
root 3 0.0 0.0 0 0 ? SN Oct30 0:00 [ksoftirqd_CPU0]
root 4 0.0 0.0 0 0 ? S Oct30 2:17 [kswapd]
root 5 0.0 0.0 0 0 ? S Oct30 0:00 [bdflush]
root 6 0.0 0.0 0 0 ? S Oct30 0:00 [kupdated]
root 8 0.0 0.0 0 0 ? S Oct30 2:58 [kjournald]
root 1448 0.0 0.0 0 0 ? S Oct30 0:00 [kapmd]
root 1496 0.0 0.0 2180 4 ? S Oct30 0:00 /bin/sh /usr/bin/safe_mysqld
mysql 1531 0.0 0.4 40396 2440 ? S Oct30 1:44 [mysqld]
mysql 1533 0.0 0.4 40396 2440 ? S Oct30 1:48 [mysqld]
mysql 1534 0.0 0.4 40396 2440 ? S Oct30 0:20 [mysqld]
mysql 1535 0.0 0.4 40396 2440 ? S Oct30 0:00 [mysqld]
daemon 1569 0.0 0.0 1384 88 ? Ss Oct30 0:00 [atd]
root 1587 0.0 0.0 1252 4 tty1 Ss+ Oct30 0:00 /sbin/getty 38400 tty1
root 1588 0.0 0.0 1252 4 tty2 Ss+ Oct30 0:00 /sbin/getty 38400 tty2
root 1589 0.0 0.0 1252 4 tty3 Ss+ Oct30 0:00 /sbin/getty 38400 tty3
root 1590 0.0 0.0 1252 4 tty4 Ss+ Oct30 0:00 /sbin/getty 38400 tty4
root 1591 0.0 0.0 1252 4 tty5 Ss+ Oct30 0:00 /sbin/getty 38400 tty5
root 1592 0.0 0.0 1252 4 tty6 Ss+ Oct30 0:00 /sbin/getty 38400 tty6
root 20609 0.0 0.1 1756 692 ? Ss Nov03 0:00 /usr/sbin/cron
root 20637 0.0 0.1 2220 672 ? Ss Nov03 0:00 /usr/sbin/inetd
root 23327 0.0 0.0 1656 400 ? S Nov03 0:00 /usr/sbin/courierlogger -pid=/var/run/courier/authdaemon/pid -start /usr/lib/courier/authlib/authda
root 23328 0.0 0.0 2320 448 ? S Nov03 0:00 /usr/lib/courier/authlib/authdaemond.mysql
root 23379 0.0 0.1 2368 756 ? Ss Nov03 0:00 /sbin/rpc.statd
root 23430 0.0 0.1 2464 660 ? S Nov03 0:03 /usr/sbin/couriertcpd -address=0 -stderrlogger=/usr/sbin/courierlogger -maxprocs=40 -maxperip=20 -p
root 23433 0.0 0.0 1664 440 ? S Nov03 0:03 /usr/sbin/courierlogger imaplogin
root 28961 0.0 0.0 1488 428 ? Ss Nov03 0:00 /usr/sbin/apmd -P /etc/apm/apmd_proxy --proxy-timeout 30
root 725 0.0 0.1 3056 864 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 726 0.0 0.1 3056 868 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 727 0.0 0.1 3056 856 ? S Nov03 0:00 /usr/lib/courier/authlib/authdaemond.mysql
root 728 0.0 0.1 3056 856 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 729 0.0 0.1 3056 852 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
mysql 1407 0.0 0.4 40396 2440 ? S Nov03 0:01 [mysqld]
mysql 1584 0.0 0.4 40396 2440 ? S Nov03 0:01 [mysqld]
amavis 7470 0.0 0.2 17192 1416 ? Ss Nov19 0:00 [amavisd-new]
amavis 7471 0.0 0.2 17192 1112 ? S Nov19 0:00 [amavisd-new]
amavis 7472 0.0 0.2 17192 1140 ? S Nov19 0:00 [amavisd-new]
daemon 10857 0.0 0.0 1608 412 ? Ss Nov19 0:01 [portmap]
root 10898 0.0 0.0 2084 440 ? Ss Nov19 0:00 /sbin/klogd
root 10949 0.0 0.1 2240 760 ? Ss Nov19 0:00 /sbin/syslogd
root 11102 0.0 0.2 3724 1212 ? Ss Nov19 0:00 /usr/sbin/sshd
nobody 12577 0.0 0.2 4760 1088 ? Ss Nov19 0:00 [proftpd]
clamav 13124 0.0 0.2 4312 1192 ? Ss Nov19 0:00 [freshclam]
clamav 13432 0.0 1.5 13944 7788 ? Ss Nov19 0:02 [clamd]
clamav 13712 0.0 1.5 13944 7788 ? S Nov20 0:00 [clamd]
mysql 2212 0.0 0.4 40396 2440 ? S Nov20 0:00 [mysqld]
mysql 5864 0.0 0.4 40396 2440 ? S Nov20 0:00 [mysqld]
mysql 6703 0.0 0.4 40396 2440 ? S Nov20 0:00 [mysqld]
root 2926 0.0 1.4 21208 7400 ? S Nov20 0:00 /usr/sbin/apache
mail 6895 0.0 0.2 3588 1180 ? Ss Nov20 0:00 [exim]
www-data 27843 0.0 5.2 39716 26400 ? S Nov21 0:06 [apache]
www-data 27844 0.0 2.1 24436 11088 ? S Nov21 0:08 [apache]
www-data 27845 0.0 2.0 23568 10192 ? S Nov21 0:04 [apache]
www-data 27846 0.0 3.2 29696 16528 ? S Nov21 0:05 [apache]
www-data 27847 0.0 2.1 23856 10668 ? S Nov21 0:05 [apache]
www-data 29066 0.0 2.0 23656 10232 ? S Nov21 0:02 [apache]
lp 30704 0.0 0.1 2452 792 ? Ss Nov21 0:00 [lpd]
www-data 971 0.0 5.3 40344 27032 ? S Nov21 0:05 [apache]
www-data 1019 0.0 1.8 22668 9412 ? S Nov21 0:05 [apache]
www-data 1024 0.0 5.2 39644 26412 ? S Nov21 0:06 [apache]
root 1476 0.0 0.4 7176 2056 ? Ss Nov21 0:00 sshd: root@pts/0
root 1482 0.0 0.3 2660 1528 pts/0 Ss Nov21 0:00 -bash
mail 21768 0.0 0.2 4672 1480 ? S 00:13 0:00 /usr/bin/imapd Maildir
mail 21792 0.0 0.3 4692 1528 ? S 00:14 0:00 /usr/bin/imapd Maildir
root 21880 0.0 0.2 2300 1024 pts/0 S 00:16 0:00 sh test.sh
root 22716 0.0 0.3 3604 1560 ? S 00:21 0:00 [exim]
mail 22718 0.0 0.3 3604 1596 ? S 00:21 0:00 [exim]
mysql 22719 0.0 0.4 40396 2440 ? S 00:21 0:00 [mysqld]
mysql 22777 0.0 0.0 0 0 ? Z 00:21 0:00 [mysqld] <defunct>
mysql 22778 0.0 0.0 0 0 ? Z 00:21 0:00 [mysqld] <defunct>
root 22780 0.0 0.0 2016 500 pts/0 S 00:21 0:00 sleep 1
root 22781 0.0 0.1 2480 848 pts/0 R+ 00:21 0:00 ps aux
|
and ps -U root -u root u:
| Code: |
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.0 1492 416 ? S Oct30 0:08 init [2]
root 2 0.0 0.0 0 0 ? S Oct30 0:00 [keventd]
root 3 0.0 0.0 0 0 ? SN Oct30 0:00 [ksoftirqd_CPU0]
root 4 0.0 0.0 0 0 ? S Oct30 2:17 [kswapd]
root 5 0.0 0.0 0 0 ? S Oct30 0:00 [bdflush]
root 6 0.0 0.0 0 0 ? S Oct30 0:00 [kupdated]
root 8 0.0 0.0 0 0 ? S Oct30 2:58 [kjournald]
root 1448 0.0 0.0 0 0 ? S Oct30 0:00 [kapmd]
root 1496 0.0 0.0 2180 4 ? S Oct30 0:00 /bin/sh /usr/bin/safe_mysqld
daemon 1569 0.0 0.0 1384 88 ? Ss Oct30 0:00 [atd]
root 1586 0.0 0.1 7044 604 ? Ss Oct30 0:00 /usr/bin/perl /usr/local/webmin/miniserv.pl /etc/webmin/miniserv.conf
root 1587 0.0 0.0 1252 4 tty1 Ss+ Oct30 0:00 /sbin/getty 38400 tty1
root 1588 0.0 0.0 1252 4 tty2 Ss+ Oct30 0:00 /sbin/getty 38400 tty2
root 1589 0.0 0.0 1252 4 tty3 Ss+ Oct30 0:00 /sbin/getty 38400 tty3
root 1590 0.0 0.0 1252 4 tty4 Ss+ Oct30 0:00 /sbin/getty 38400 tty4
root 1591 0.0 0.0 1252 4 tty5 Ss+ Oct30 0:00 /sbin/getty 38400 tty5
root 1592 0.0 0.0 1252 4 tty6 Ss+ Oct30 0:00 /sbin/getty 38400 tty6
root 20609 0.0 0.1 1756 692 ? Ss Nov03 0:00 /usr/sbin/cron
root 20637 0.0 0.1 2220 672 ? Ss Nov03 0:00 /usr/sbin/inetd
root 23327 0.0 0.0 1656 400 ? S Nov03 0:00 /usr/sbin/courierlogger -pid=/var/run/courier/authdaemon/pid -start /usr/lib/courier/authlib/authda
root 23328 0.0 0.0 2320 448 ? S Nov03 0:00 /usr/lib/courier/authlib/authdaemond.mysql
root 23379 0.0 0.1 2368 756 ? Ss Nov03 0:00 /sbin/rpc.statd
root 23430 0.0 0.1 2464 660 ? S Nov03 0:03 /usr/sbin/couriertcpd -address=0 -stderrlogger=/usr/sbin/courierlogger -maxprocs=40 -maxperip=20 -p
root 23433 0.0 0.0 1664 440 ? S Nov03 0:03 /usr/sbin/courierlogger imaplogin
root 28961 0.0 0.0 1488 428 ? Ss Nov03 0:00 /usr/sbin/apmd -P /etc/apm/apmd_proxy --proxy-timeout 30
root 725 0.0 0.1 3056 864 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 726 0.0 0.1 3056 868 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 727 0.0 0.1 3056 856 ? S Nov03 0:00 /usr/lib/courier/authlib/authdaemond.mysql
root 728 0.0 0.1 3056 856 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 729 0.0 0.1 3056 852 ? S Nov03 0:01 /usr/lib/courier/authlib/authdaemond.mysql
root 10898 0.0 0.0 2084 440 ? Ss Nov19 0:00 /sbin/klogd
root 10949 0.0 0.1 2240 760 ? Ss Nov19 0:00 /sbin/syslogd
root 11102 0.0 0.2 3724 1212 ? Ss Nov19 0:00 /usr/sbin/sshd
nobody 12577 0.0 0.2 4760 1088 ? Ss Nov19 0:00 [proftpd]
root 2926 0.0 1.4 21208 7400 ? S Nov20 0:00 /usr/sbin/apache
root 1476 0.0 0.4 7176 2056 ? Rs Nov21 0:00 sshd: root@pts/0
root 1482 0.0 0.3 2660 1528 pts/0 Ss Nov21 0:00 -bash
root 21880 0.0 0.2 2300 1024 pts/0 S 00:16 0:00 sh test.sh
root 22716 0.0 0.3 3604 1560 ? S 00:21 0:00 [exim]
root 23844 0.0 0.0 2016 500 pts/0 R 00:25 0:00 sleep 1
root 23847 0.0 0.1 2480 852 pts/0 R+ 00:25 0:00 ps -U root -u root u
|
as every process with root priviliges is suspicious. |
|
| Back to top |
|
|
sqeezer
n00b
Joined: 21 Nov 2004
Posts: 5
|
| Posted: Sun Nov 21, 2004 11:41 pm Post subject: |
|
|
I've already tried to shudown cron and watch the system clock
to finde out which process is responsible for this strangeness.
without any results so far.
what i will try now is to shut down all possible processes untill the clock stops doing strange things.... |
|
| Back to top |
|
|
sqeezer
n00b
Joined: 21 Nov 2004
Posts: 5
|
| Posted: Mon Nov 22, 2004 1:07 am Post subject: solution |
|
|
I killed almost every process without any effect on the clock.
The I made a kernel upgrade 2.4.2 --> 2.6.9
Now everything works fine, the clock increases linear.
Obviously the was a bug in the kernel or in one of the installed patches ...
thx
sqeezer |
|
| Back to top |
|
|
|
Kernel & Hardware
