Гэтая трывіяльная задача ўзнікла ў адзін з пятнічных дзён і павінна была заняць 2-3 хвіліны часу. Увогуле, як заўжды.
Калега папрасіў паправіць скрыпт у яго на серверы. Зрабіў, здаў яму і ўпусціў незнарок: «Час спяшаецца на 5 хвілін». Сервер яго, няхай сам і разбіраецца з сінхранізацыяй. Паўгадзіны, гадзіна прайшла, а ён усё пыхкае і ціха мацюкаецца.
«Бястолач! - Падумаў я, перамыкаючыся ў кансоль сервера - ну добра адарвуся яшчэ на пару хвілін.
Глядзім, ntp, rdate, sdwdate не ўстаноўлены, сінхранізацыя часу адключаны і не запушчаны.
# 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
Тут адразу адзначу, што апаратны час слушны: па ім будзе лягчэй арыентавацца далей.
Адсюль і пачалася чарада памылак.
Памылка першая. Самаўпэўненасць
Клац-клац…
# 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]: Time has been changed
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: System time changed. Resyncing.
Aug 25 21:18:51 wisi systemd[1187]: Time has been changed
Aug 25 21:18:51 wisi systemd[1]: Time has been changed
Aug 25 21:18:51 wisi systemd[1187]: Time has been changed
тут
# 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]: Time has been changed
Aug 25 21:25:40 wisi systemd[1187]: Time has been changed
Aug 25 21:29:30 wisi systemd[1]: Time has been changed
Aug 25 21:29:30 wisi systemd[1187]: Time has been changed
Resyncing знік і ў астатнім логі некранута чыстыя.
Правяраем высновы tcpdump па 123-му порце на ўсіх інтэрфейсах. Ніякіх запытаў няма, але час усё таксама "ўцякае".
Памылка другая. Спешка
Да канца працоўнага тыдня застаецца гадзіна, а сыходзіць на выходныя з плявой нявырашанай задачай не жадаецца (не зважайце на час у кодзе, артыкул пісалася ў наступныя дні).
І тут ізноў замест таго каб шукаць прычыну я пачаў спрабаваць прыдумаць тлумачэнне выніку. Я кажу "прыдумаць", таму што не гледзячы на тое, якімі б не былі лагічнымі тлумачэнні выніку, гэта памылковы падыход вырашэння праблемы.
Дадзены сервер з'яўляецца стрыммінгавым і пераўтварае струмень DVB-S2 у IP. У струмені DVB-S прысутнічаюць пазнакі часу, таму прымачы, мультыплексары, скрэмблеры і тэлевізары часта выкарыстоўваюць іх для сінхранізацыі сістэмных гадзін. Драйвера DVB-S поплаткаў укампілі ў ядро, таму самы хуткі спосаб гарантавана прыбраць DVB-S2-струмень - гэта адключыць кабелі ідучыя з «талерак». Балазе сервер за сцяной, таму так таму і быць.
Вядома, калі б у логах было тое, што там павінна быць, гэтага б не адбылося, але пра гэта, зноў жа, у канцы артыкула.
Ну і раз мы ўжо выдалілі ўсе спадарожнікавыя сігналы выдалім і наземныя – адначасна выдзіраем усе сеткавыя кабеля. Сервер становіцца адрэзаным ад навакольнага свету і працуе абсалютна аўтаномна, але сістэмныя гадзіны ўсё таксама спяшаюцца.
Рабочы тыдзень скончаны, а само пытанне даты/часу на ім не крытычнае, таму можна проста пайсці дадому, але тут я раблю новы промах.
Памылка трэцяя. Дарадцы
Ніколі! Ніколі не задавайце пытанні на форумах і агульнаспецыялізаваных (а-ля stackoverflow) сайтах, калі адказ на яго патрабуе больш за вывучэнне выдачы першай старонкі гугла і прачыткі адной старонкі man'а.
Вас пашлюць назад у google, пачытаць усё той жа man і папулярна растлумачаць правілы форума/сайта, але не дадуць адказу.
Тут ёсць як аб'ектыўныя фактары:
- ніхто акрамя вас не можа ведаць праблему таксама добра;
- ніхто не можа правесці тэсты ў такіх жа як у вас умовах
так і суб'ектыўныя:
- вы можаце не выдаць усіх уступных для рашэння задачы, таму што ўжо прыдумалі «правільны» кірунак і выкладаеце сутнасць пытання ўпіраючы на яго;
- старшына (мадэратар, старажыл, адмін) заўсёды мае рацыю, калі старшына не мае рацыю… ну вы ведаеце…
Калі пры адказных каментарах вы засталіся ў рамках цэнзурнай лексікі, значыць у вас моцныя нервы.
рашэнне
Ня трэба дзяліць задачы на простыя і складаныя.
Перастаём спадзявацца на свой досвед, статыстыку, дарадцаў і пачынаем не «тлумачыць» канчатковы вынік, а паслядоўна шукаць чыннік.
Раз нехта ўсталёўвае час значыць павінен адбыцца які адпавядае сістэмны выклік.
Як у дакументацыі софту лепшыя докі - гэта зыходнікі, так у сістэмным адміністраванні лепшы памочнік - гэта аўдыт, у нашым выпадку рэвізавана.
Хвілінка сумневыЯ прабегся па манах, але не быў да канца ўпэўнены, што час у Linux можа ўсталёўвацца толькі clock_settime и ўсталяваць час дня, таму для першага тэсту абраў усе «падыходныя» выклікі:
# 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Пераканаўшыся, што ў месцах логаў, якія мяне цікавяць, няма іншых. сістэмныя выклікі акрамя гэтых двух далей выкарыстоўваў толькі іх.
Запускаем аўдыт сістэмных выклікаў clock_settime и ўсталяваць час дня і спрабуем змяніць дату:
# 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
Тут мы бачым наш дата і невядомы нам 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