
Тази тривиална задача възникна в един от петъчните дни и трябваше да отнеме 2-3 минути време. Общо взето, както винаги.
Колегата помоли да поправя скрипта му на сървъра. Направих го, предадох му го и ненароком изтървах: „Времето бърза с 5 минути“. Сървърът е негов, нека сам се оправя със синхронизацията. Половин час, един час мина, а той все още се поти и тихо роптае.
„Глупак! — помислих си, превключвайки в конзолата. сървър — добре, ще се отклоня още за няколко минути.“
Гледаме, ntp, rdate, sdwdate не са инсталирани, timesyncd е изключен и не е стартиран.
# timedatectl
Local time: Sun 2019-08-25 20:44:39 +03
Universal time: Sun 2019-08-25 17:44:39 UTC
RTC time: Sun 2019-08-25 17:39:52
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: no
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
Тук веднага ще отбележа, че хардуерното време е вярно: по него ще бъде по-лесно да се ориентираме нататък.
Оттук започна серията от грешки.
Грешка първа. Самонадеяност
Клик-klik…
# systemctl enable systemd-timesyncd.service && systemctl start systemd-timesyncd.service && ntpdate 0.ru.pool.ntp.org && timedatectl set-ntp on && timedatectl
25 Aug 21:00:10 ntpdate[28114]: adjust time server 195.210.189.106 offset -249.015251 sec
Local time: Sun 2019-08-25 21:00:10 +03
Universal time: Sun 2019-08-25 18:00:10 UTC
RTC time: Sun 2019-08-25 18:00:10
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
DST active: n/a
Всичко е отлично, времето е синхронизирано, системното съвпада с хардуерното. „Вземи го“, — казах и се върнах към моите дела.
„Какво да взимам? — възмути се колегата. — Времето е същото!“
Колкото повече решаваш типови задачи, толкова повече мисленето ти се стеснява и вече не мислиш, че стотната или хиляда ситуация ще бъде различна, но не и този път.
# timedatectl
Local time: Sun 2019-08-25 21:09:15 +03
Universal time: Sun 2019-08-25 18:09:15 UTC
RTC time: Sun 2019-08-25 18:05:04
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
Системното време отново е неправилно.
Ще пробваме отново:
# ntpdate 0.ru.pool.ntp.org && timedatectl && sleep 1 && timedatectl
25 Aug 21:07:37 ntpdate[30350]: step time server 89.175.20.7 offset -249.220828 sec
Local time: Sun 2019-08-25 21:07:37 +03
Universal time: Sun 2019-08-25 18:07:37 UTC
RTC time: Sun 2019-08-25 18:07:37
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
DST active: n/a
Local time: Sun 2019-08-25 21:11:46 +03
Universal time: Sun 2019-08-25 18:11:46 UTC
RTC time: Sun 2019-08-25 18:07:37
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
Нека опитаме по различен начин:
# date -s "2019-08-25 21:10:30" && date && sleep 1 && timedatectl
Sun Aug 25 21:10:30 +03 2019
Sun Aug 25 21:10:30 +03 2019
Local time: Sun 2019-08-25 21:14:36 +03
Universal time: Sun 2019-08-25 18:14:36 UTC
RTC time: Sun 2019-08-25 18:10:30
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
А какво ще кажеш за това:
# hwclock --hctosys && timedatectl && sleep 1 && timedatectl
Local time: Sun 2019-08-25 21:11:31 +03
Universal time: Sun 2019-08-25 18:11:31 UTC
RTC time: Sun 2019-08-25 18:11:31
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
DST active: n/a
Local time: Sun 2019-08-25 21:15:36 +03
Universal time: Sun 2019-08-25 18:15:36 UTC
RTC time: Sun 2019-08-25 18:11:32
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: yes
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
Времето се задава за част от секундата и веднага започва отново да „бърза“.
При това в логовете, в момента на такава ръчна смяна, виждаме само доклади на системата за това, че времето е променено, съответно в правилната/неправилната посока и от време на време Resyncing от systemd-timesyncd.
Aug 25 21:18:51 wisi systemd[1]: Времето е променено
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: Системното време е променено. Ресинхронизиране.
Aug 25 21:18:51 wisi systemd[1187]: Времето е променено
Aug 25 21:18:51 wisi systemd[1]: Времето е променено
Aug 25 21:18:51 wisi systemd[1187]: Времето е променено
тук.
# ps afx | grep "[1]187"
1187 ? Ss 0:02 /lib/systemd/systemd --user
В този момент вече трябваше да търся причината, но мозъкът ми за 18 години администриране е натрупал статистика за грешки във времето и по навик отново обвинява синхронизацията.
Изключваме я напълно.
# timedatectl set-ntp off && systemctl stop systemd-timesyncd.service
# hwclock --hctosys && timedatectl && sleep 1 && timedatectl
Local time: Sun 2019-08-25 21:25:40 +03
Universal time: Sun 2019-08-25 18:25:40 UTC
RTC time: Sun 2019-08-25 18:25:40
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: no
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
Local time: Sun 2019-08-25 21:29:31 +03
Universal time: Sun 2019-08-25 18:29:31 UTC
RTC time: Sun 2019-08-25 18:25:41
Time zone: Europe/Minsk (+03, +0300)
NTP enabled: no
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
и в логовете
Aug 25 21:25:40 wisi systemd[1]: Времето е променено
Aug 25 21:25:40 wisi systemd[1187]: Времето е променено
Aug 25 21:29:30 wisi systemd[1]: Времето е променено
Aug 25 21:29:30 wisi systemd[1187]: Времето е променено
Resyncing изчезна и останалите логове са девствено чисти.
Проверяваме изходите tcpdump по 123-ти порт на всички интерфейси. Никаки запитвания няма, но времето все още „бяга“.
Грешка втора. Бързина
До края на работната седмица остава час, а не искам да заминавам за уикенда с неприключена задача (не обръщайте внимание на времето в кода, статията беше написана в следващите дни).
И отново, вместо да търся причината, започнах да измислям обяснение за резултата. Казвам "измислям", защото, независимо колко логични да изглеждат обясненията за резултата, това е погрешен подход за решаване на проблема.
Този сървър е стрийминг и преобразува потока DVB-S2 в IP. В DVB-S потока има времеви етикети, затова приемниците, мултиплексорите, скремблерите и телевизорите често ги използват за синхронизиране на системните часове. Драйверите на платките DVB-S са вградени в ядрото, така че най-бързият начин гарантировано да се премахне DVB-S2 потока е да се изключат кабелите, идващи от "тарелките". Добре, че сървърът е зад стената, следователно така да бъде.
Разбира се, ако в логовете имаше това, което трябваше да бъде, това нямаше да се случи, но за това, отново, в края на статията.
И тъй като вече сме премахнали всички спътникови сигнали, нека премахнем и наземните — паралелно изваждаме всички мрежови кабели. Сървърът става изолиран от външния свят и работи напълно автономно, но системните часове все пак бързат.
Работната седмица е приключила, а самият въпрос за дата/време на него не е критичен, затова може просто да отида у дома, но тук направих нова грешка.
Третата грешка. Съветниците
Никога! Никога не задавайте въпроси във форуми и общоспециализирани (като stackoverflow) сайтове, ако отговорът на него изисква повече от изучаване на резултатите от първата страница на google и прочитане на една страница от man.
Вас ще ви върнат обратно в google, за да прочетете същия man и популярно ще обяснят правилата на форума/сайта, но няма да ви дадат отговор.
Тук има както обективни фактори:
- никой освен вас не може да знае проблема толкова добре;
- никой не може да проведе тестове при същите условия, каквито имате вие.
така и субективни:
- може да не предоставите всички входни данни за решаване на задачата, защото вече сте измислили "правилната" посока и изложите същността на въпроса, основавайки се на нея;
- старшина (модератор, дългогодишен член, админ) винаги е прав, ако старшината не е прав… знаеш какво следва…
Ако в отговорите сте останали в рамките на цензурния език, значи имате здрави нерви.
Решение
Не трябва да разделяте задачите на прости и сложни.
Спираме да се осланяме на собствения опит, статистиката, съветниците и започваме не "да обясняваме" крайния резултат, а последователно да търсим причината.
Ако някой настройва времето, значи трябва да се извърши съответно системно повикване.
Както в документацията на софтуера най-добрите документи са изходния код, така и в системното администриране най-добрият помощник е аудитът, в нашия случай. auditd.
Минута съмнение.Прегледах мановете, но не бях напълно сигурен, че времето в Linux може да се задава само. clock_settime. и settimeofday., затова за първия тест избрах всички 'подходящи' повиквания:
# man syscalls | col | grep -F '(2)' | grep -vE '(:|;)' | grep -E '(time|date|clock)' | sed "s/(2).*//" | xargs -I SYSCALL echo "-S SYSCALL " | xargs echo
-S adjtimex -S clock_adjtime -S clock_getres -S clock_gettime -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S s390_runtime_instr -S setitimer -S settimeofday -S stime -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_create -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes
и отхвърлих s390_runtime_instr, stime, timerfd_create., които auditctl не разпозна.
Първоначално стартирах аудита във формата:auditctl -a exit,always -S adjtimex -S clock_adjtime -S clock_getres -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S semtimedop -S setitimer -S settimeofday -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes. syscalls. Освен тези две по-нататък използвах само тях.
Стартираме аудита на системните повиквания. clock_settime. и settimeofday. и пробваме да сменим датата:
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
Петсекундна забавяне е добавена, за да гарантира, че нашият 'паразит' със сигурност коригира времето.
Гледаме отчета:
# aureport -s -i
Syscall Report
=======================================
# date time syscall pid comm auid event
=======================================
Warning - freq is non-zero and incremental flushing not selected.
1. 08/22/2019 12:10:00 settimeofday 3088 chkcache_proces root 479630
2. 08/26/2019 09:37:06 clock_settime 1538 date root 479629
Тук виждаме нашия date и неизвестния ни chkcache_proces.Той се появи в горния отчет, тъй като aureport е сортирал изхода по дата при преобразуването от бинарен вид, а събитието се е случило в зададеното от нас време. date -s '2019-08-22 12:10:00'..
Кой го е създал?
# ausearch -sc settimeofday --comm "chkcache_proces"
----
time->Thu Aug 22 12:10:00 2019
type=PROCTITLE msg=audit(1566465000.000:479630): proctitle="/usr/local/bin/oscam"
type=SYSCALL msg=audit(1566465000.000:479630): arch=c000003e syscall=164 success=yes exit=0 a0=7fde0dfc6e60 a1=0 a2=136cf a3=713ba56 items=0 ppid=3081 pid=3088 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts20 ses=68149 comm="chkcache_proces" exe="/usr/local/bin/oscam" key=(null)
/usr/local/bin/oscam — нашият паразит е открит. Независимо от 'зловредното' му поведение, не можем да се откажем от системата за условен достъп, но все пак бих искал да знам, oscam., WTF?
Отговорът бързо е намерен в :
#if defined(CLOCKFIX)
if (tv.tv_sec > lasttime.tv_sec || (tv.tv_sec == lasttime.tv_sec && tv.tv_usec >= lasttime.tv_usec)) // check for time issues!
{
lasttime = tv; // register this valid time
}
else
{
tv = lasttime;
settimeofday(&tv, NULL); // set time back to last known valid time
//fprintf(stderr, "*** WARNING: BAD TIME AFFECTING WHOLE OSCAM ECM HANDLING, SYSTEMTIME SET TO LAST KNOWN VALID TIME **** n");
}
Как добре изглежда тук коментираната строка. warning’a.…
Източник: habr.com
