Безопасный Слой Гнезд ([info]dil) wrote in [info]ru_root,
@ 2008-04-06 13:27:00
Previous Entry  Add to memories!  Tell a Friend!  Next Entry
Часы на убунте отстают со страшной силой
Дано: Ubuntu 7.10 (gutsy) x86_64 на Core2 Duo (4300 @1.8 GHz). Ядро стандартное, 2.6.22-14-generic.

Проблема: при работающем ntpd часы отстают со скоростью примерно полтора часа в сутки. Началось несколько дней назад, до этого всё было нормально. Возможно, повлиял какой-то плановый апгрейд системы, но я не понимаю, отчего это может происходить.
Отключаю ntpd, синхронизирую время вручную c ntp.ubuntu.com с помощью ntpdate, оно синхронизируется. Через 2 минуты пробую повторить - расхожение 9 секунд:
# ntpdate ntp.ubuntu.com
 6 Apr 13:13:23 ntpdate[4126]: step time server 91.189.94.4 offset 9.565910 sec

13:13:13.661632 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472793.661615014 (2008/04/06 13:13:13)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472793.661615014 (2008/04/06 13:13:13)
13:13:13.800681 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.041534, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472793.661615014 (2008/04/06 13:13:13)
          Receive Timestamp:    3416472803.295147001 (2008/04/06 13:13:23)
          Transmit Timestamp:   3416472803.295152992 (2008/04/06 13:13:23)
            Originator - Receive Timestamp:  +9.633531987
            Originator - Transmit Timestamp: +9.633538007
13:13:13.800733 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472793.800724983 (2008/04/06 13:13:13)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472793.800724983 (2008/04/06 13:13:13)
13:13:13.941107 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.041534, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472793.800724983 (2008/04/06 13:13:13)
          Receive Timestamp:    3416472803.431502014 (2008/04/06 13:13:23)
          Transmit Timestamp:   3416472803.431508988 (2008/04/06 13:13:23)
            Originator - Receive Timestamp:  +9.630777001
            Originator - Transmit Timestamp: +9.630783975
13:13:13.941142 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472793.941133975 (2008/04/06 13:13:13)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472793.941133975 (2008/04/06 13:13:13)
13:13:14.072350 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.041534, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472793.941133975 (2008/04/06 13:13:13)
          Receive Timestamp:    3416472803.572658002 (2008/04/06 13:13:23)
          Transmit Timestamp:   3416472803.572664976 (2008/04/06 13:13:23)
            Originator - Receive Timestamp:  +9.631524026
            Originator - Transmit Timestamp: +9.631531000
13:13:14.072390 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472794.072379000 (2008/04/06 13:13:14)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472794.072379000 (2008/04/06 13:13:14)
13:13:14.240963 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.041534, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472794.072379000 (2008/04/06 13:13:14)
          Receive Timestamp:    3416472803.741396009 (2008/04/06 13:13:23)
          Transmit Timestamp:   3416472803.741402983 (2008/04/06 13:13:23)
            Originator - Receive Timestamp:  +9.669017016
            Originator - Transmit Timestamp: +9.669023990


Через пару минут пробую еще раз - время опять уползло на 7 секунд:
# ntpdate ntp.ubuntu.com
 6 Apr 13:15:17 ntpdate[4129]: step time server 91.189.94.4 offset 7.099964 sec

13:15:07.588550 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472907.588531017 (2008/04/06 13:15:07)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472907.588531017 (2008/04/06 13:15:07)
13:15:08.592572 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472908.592557013 (2008/04/06 13:15:08)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472908.592557013 (2008/04/06 13:15:08)
13:15:08.771063 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.043212, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472908.592557013 (2008/04/06 13:15:08)
          Receive Timestamp:    3416472915.781790971 (2008/04/06 13:15:15)
          Transmit Timestamp:   3416472915.781798005 (2008/04/06 13:15:15)
            Originator - Receive Timestamp:  +7.189234003
            Originator - Transmit Timestamp: +7.189241006
13:15:08.771141 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472908.771130025 (2008/04/06 13:15:08)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472908.771130025 (2008/04/06 13:15:08)
13:15:09.592612 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 4s, precision -6
        Root Delay: 1.000000, Root dispersion: 1.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472909.592597007 (2008/04/06 13:15:09)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472909.592597007 (2008/04/06 13:15:09)
13:15:10.026592 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 4s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.043243, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472909.592597007 (2008/04/06 13:15:09)
          Receive Timestamp:    3416472917.111323997 (2008/04/06 13:15:17)
          Transmit Timestamp:   3416472917.111331000 (2008/04/06 13:15:17)
            Originator - Receive Timestamp:  +7.518727004
            Originator - Transmit Timestamp: +7.518733978


Еще через 20 секунд опять разница в 2 секунды:
13:15:37.576663 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 192.168.3.32.123 > 91.189.94.4.123: NTPv4, length 48
        Client, Leap indicator: clock unsynchronized (192), Stratum 0, poll 6s, precision -20
        Root Delay: 0.000000, Root dispersion: 0.000000, Reference-ID: (unspec)
          Reference Timestamp:  0.000000000
          Originator Timestamp: 0.000000000
          Receive Timestamp:    0.000000000
          Transmit Timestamp:   3416472937.576636970 (2008/04/06 13:15:37)
            Originator - Receive Timestamp:  0.000000000
            Originator - Transmit Timestamp: 3416472937.576636970 (2008/04/06 13:15:37)
13:15:38.228132 IP (tos 0x10, ttl 54, id 0, offset 0, flags [DF], proto UDP (17), length 76) 91.189.94.4.123 > 192.168.3.32.123: NTPv4, length 48
        Server, Leap indicator:  (0), Stratum 2, poll 6s, precision -20
        Root Delay: 0.024765, Root dispersion: 0.043579, Reference-ID: 192.36.133.17
          Reference Timestamp:  3416472165.946129977 (2008/04/06 13:02:45)
          Originator Timestamp: 3416472937.576636970 (2008/04/06 13:15:37)
          Receive Timestamp:    3416472939.642203986 (2008/04/06 13:15:39)
          Transmit Timestamp:   3416472939.642211019 (2008/04/06 13:15:39)
            Originator - Receive Timestamp:  +2.065567038
            Originator - Transmit Timestamp: +2.065574042


Что это может быть? Куда копать? На всех остальных окрестных убунтах всё нормально, но они 32-битовые.

Upd: проблема вылечилась после очередной перезагрузки. Предыдущие перезагрузки совершенно не помогали. Похоже, глюк всё-таки чисто программный :(



(Post a new comment)


[info]zhuzh
2008-04-06 01:00 pm UTC (link)
может, в железе проблемы? у меня что-то подобное было на какой-то старой машине, починилось покупкой новой ;) с гарантированно-работающего LiveCD не пробовали грузиться?

(Reply to this) (Thread)


[info]dil
2008-04-06 02:01 pm UTC (link)
может, но раньше-то оно нормально работало, это совсем недавно началось.
У меня пока только одна гипотеза - таймер генерирует прерывания не с такой частотой, как думает ядро.

(Reply to this) (Parent)


[info]dmarck
2008-04-06 01:36 pm UTC (link)
У меня была одна такая платформа. Вылечилось, как это ни смешно, апгрейдом системного БИОСа - что-то там они в ACPI tables поломали.

(Reply to this) (Thread)


[info]dil
2008-04-06 02:02 pm UTC (link)
ым.. а как связан ACPI с таймером?

(Reply to this) (Parent)(Thread)


[info]dmarck
2008-04-06 02:05 pm UTC (link)
Вот для меня это тоже загадка, но факт остается фактом. Единственное моё предположение - какие-то поправочные коэффициенты оно там пыталось программировать, и программировало неправильно.

У меня проявлялось б/м одинаково на разных версиях фри и линукса, что 32, что 64 бит. После перепрошивки - починилось.

(Reply to this) (Parent)

> Что это может быть?
[info]poige
2008-04-06 02:27 pm UTC (link)
Посмотри man hwclock («глава» The Adjust Function), может быть помогут манипуляции с /etc/adjtime.

(Reply to this) (Thread)

Re: > Что это может быть?
[info]dil
2008-04-06 03:02 pm UTC (link)
Не, это не оно. adjtime хранит информацию о дрейфе аппаратных часов, чтобы исправлять считываемое оттуда время при старте ОС. А у меня программные часы в ядре отстают.

(Reply to this) (Parent)(Thread)

> Не, это не оно.
[info]poige
2008-04-06 03:43 pm UTC (link)
Может быть.

А что sudo cat /sys/devices/system/clocksource/clocksource0/* пишет?

(Reply to this) (Parent)(Thread)

Re: > Не, это не оно.
[info]dil
2008-04-06 05:44 pm UTC (link)
tsc hpet acpi_pm jiffies
tsc

(Reply to this) (Parent)(Thread)

Ммм, понятно
[info]poige
2008-04-06 05:53 pm UTC (link)
Может попробуешь echo hpet > current_clocksource ? :-)

(Reply to this) (Parent)(Thread)

Re: Ммм, понятно
[info]dil
2008-04-06 09:38 pm UTC (link)
уже поздно, оно само прошло :(

(Reply to this) (Parent)(Thread)

> уже поздно, оно само прошло :(
[info]poige
2008-04-07 07:21 am UTC (link)
А current_clocksource по-прежнему tsc?

(Reply to this) (Parent)(Thread)

Re: > уже поздно, оно само прошло :(
[info]dil
2008-04-07 07:42 am UTC (link)
да, по-прежнему tsc

(Reply to this) (Parent)(Thread)

> да, по-прежнему tsc
[info]poige
2008-04-07 07:45 am UTC (link)
BTW, в логах моей системы:

[ 108.748790] Clocksource tsc unstable (delta = -220741170 ns)

Наверное после этого, происходит переключение на использование hpet.

(Reply to this) (Parent)(Thread)

Re: > да, по-прежнему tsc
[info]dil
2008-04-07 09:14 pm UTC (link)
clocksource встречается только в контексте
"Time: tsc clocksource has been installed." при загрузке машины. Про смену clocksource ничего не нашел.

(Reply to this) (Parent)(Thread)

Попробуй, интереса ради, просто echo hpet сделать
[info]poige
2008-04-07 09:17 pm UTC (link)
 

(Reply to this) (Parent)(Thread)

Re: Попробуй, интереса ради, просто echo hpet сделать
[info]dil
2008-04-07 09:32 pm UTC (link)
Apr 7 22:31:09 kernel: [92292.469024] Time: hpet clocksource has been installed.

На что это повлияло, будет понятно завтра утром.

(Reply to this) (Parent)(Thread)

> На что это повлияло, будет понятно завтра утром.
[info]poige
2008-04-07 09:39 pm UTC (link)
«Попитка, не питка» ©

(Reply to this) (Parent)

> На что это повлияло, будет понятно завтра утром.
[info]poige
2008-04-09 11:53 am UTC (link)
И?…

(Reply to this) (Parent)

Да, ещё...
[info]poige
2008-04-07 07:48 am UTC (link)
У тебя scaling_governor какой-нибудь применяется? (Частота процессора от нагрузки на него зависит?) Не это-ли влияет на то, что часы иногда идут более-менее ровно, а иногда нет?

(Reply to this) (Parent)(Thread)

Re: Да, ещё...
[info]dil
2008-04-07 02:11 pm UTC (link)
вроде нет, это десктоп. но на всякий случай проверю.

(Reply to this) (Parent)(Thread)

> вроде нет, это десктоп.
[info]poige
2008-04-07 02:13 pm UTC (link)
Ну так это обычно на них и применяется. «Save The Power, Luke!»

(Reply to this) (Parent)(Thread)

Re: > вроде нет, это десктоп.
[info]dil
2008-04-07 09:30 pm UTC (link)
действительно, есть.
scaling_driver - acpi-cpufreq
scaling_governor - ondemand
А что это меняет?

(Reply to this) (Parent)(Thread)

> А что это меняет?
[info]poige
2008-04-07 09:31 pm UTC (link)
http://community.livejournal.com/ru_root/1407372.html?thread=15615628#t15615628

(Reply to this) (Parent)(Thread)

Re: > А что это меняет?
[info]dil
2008-04-07 09:35 pm UTC (link)
Да, но частота у обоих процессоров дергается и сейчас, а со временем со вчерашнего дня всё нормально..

(Reply to this) (Parent)(Thread)

> Да, но
[info]poige
2008-04-07 09:41 pm UTC (link)
Никаких «но». :-) Поставили эксперимент — смотрим. :-) Будут рез-ты — будем рассуждать дальше. :-)

(Reply to this) (Parent)(Thread)

Re: > Да, но
[info]dil
2008-04-10 05:54 am UTC (link)
Всё нормально. В логе записи от ntpd о расхождениях до плюс-минус 0.5 с, обычно в районе 0.1. В целом время правильное, проверил ntpdate'ом. Поменял источник обратно на tsc, посмотрим, поменяется ли что-нибудь.

(Reply to this) (Parent)(Thread)

> Поменял источник обратно на tsc
[info]poige
2008-04-10 05:57 am UTC (link)
Ясно )

(Reply to this) (Parent)

Re: > Да, но
[info]dil
2008-04-11 06:20 am UTC (link)
С tsc то же самое. В общем, оно само вылечилось :(

(Reply to this) (Parent)

Re: > Что это может быть?
[info]krino2
2008-04-07 11:40 am UTC (link)
что значит программные часы? они ведь тоже должны откуда-то тики брать.
у меня случилась похожая фигня, только у меня система с пентиумом 233 ммх года примерно 96-98го выпуска, по этому я на железо грешу. раньше у меня по крону нтпдейт время корректировал, но с какого-то момента за сутки разбег стал составлять несколько минут. сейчас у меня нтпд работает, он это как-то вытягивает..

(Reply to this) (Parent)(Thread)

Re: > Что это может быть?
[info]dil
2008-04-07 12:21 pm UTC (link)
они их берут от таймерного прерывания. которое программируется совершенно отдельно от железных часов.

ntpd, когда обнаруживает расхождение, не исправляет его резко, как ntpdate, а говорит ядру, что надо время подправить, и ядро его плавно подтягивает. Только вот похоже, оно его подтягивает медленнее, чем оно убегает.

(Reply to this) (Parent)(Thread)

Re: > Что это может быть?
[info]krino2
2008-04-07 01:50 pm UTC (link)
так вот это таймерное прерывание разве не может врать?
с моими часами прикол получился, когда уезжал на новогодние каникулы, выключил комп 2го января, а когда вернулся и включил, на календаре в биосе так второе января и осталось :-)

(Reply to this) (Parent)(Thread)

Re: > Что это может быть?
[info]dil
2008-04-07 02:10 pm UTC (link)
вот очень похоже, что оно и врёт, только я плохо понимаю, как это получается. там кварц, который выдает импульсы с высокой частотой, и программируемый делитель, который выбирает из этих импульсов каждый N-ный и по нему генерирует прерывание.
а вот биосовские часы совершенно независимот от этого работают, сами по себе, и могут глючить от старости, если батарейка села.

(Reply to this) (Parent)(Thread)

Re: > Что это может быть?
[info]krino2
2008-04-07 02:53 pm UTC (link)
так может кварц или делитель и проглючило? а в часах батарею я менял - не помогло, только перестал сбрасываться биос, когда на долго отключал его. сейчас у меня ntp.drift кажет -5.126, хотя, помнится раньше там было что-то в районе 3 с чем-то.

(Reply to this) (Parent)(Thread)

Какие нафиг кварцы, товарищи? :)
[info]poige
2008-04-07 09:26 pm UTC (link)
У [info]dil, ясно же сказано, clocksource — TSC. И в этой же статье по TSC@Wikipedia, кстати, описаны его drawbacks — вполне такие себе похожие симптомы.

(Reply to this) (Parent)


Create an Account
Forgot your login or password?
Login w/ OpenID
English • Español • Deutsch • Русский…