Această sarcină trivială a apărut într-o zi de vineri și ar fi trebuit să dureze 2-3 minute. În general, ca întotdeauna.
Un coleg m-a rugat să corectez un script pe serverul lui. L-am făcut, i l-am predat și, din greșeală, am lăsat să se audă: „Timpul are o întârziere de 5 minute”. Serverul este al lui, să se descurce singur cu sincronizarea. A trecut o jumătate de oră, o oră, și el tot se chinuie și înjură în liniște.
„Ce nepriceput! — m-am gândit, schimbându-mi consola. server — bine, mă voi mai desprinde pentru câteva minute.”
Să ne uităm, ntp, rdate, sdwdate nu sunt instalate, timesyncd este oprit și nu rulează.
# 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
Aici menționez imediat că timpul hardware este corect: pe acesta ne va fi mai ușor să ne orientăm mai departe.
De aici a început seria de erori.
Prima eroare. Încrederea de sine
Clipește…
# 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
Totul este excelent, timpul s-a sincronizat, sistemul coincide cu cel hardware. „Ia-l”, am spus și m-am întors la treburile mele.
„Ce să iau? — s-a revoltat colegul. — Timpul este același!”
Cu cât rezolvi mai multe sarcini tipice, cu atât mai mult îți restrângi gândirea și nu mai gândești că cea de-a o sută sau a o mie situație va fi diferită, dar nu de data aceasta.
# 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
Timpul sistemului este din nou incorect.
Să încercăm din nou:
# 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
Să o facem diferit:
# 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
Dar aș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
Timpul este stabilit într-o fracțiune de secundă și începe din nou să „aleargă”.
În același timp, în loguri, în momentul unei astfel de schimbări manuale, vedem doar rapoartele sistemului despre faptul că timpul s-a schimbat, respectiv în direcții corecte/incorecte și ocazional Resyncing de la systemd-timesyncd.
Aug 25 21:18:51 wisi systemd[1]: Timpul a fost schimbat
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: Timpul sistemului s-a schimbat. Resyncing.
Aug 25 21:18:51 wisi systemd[1187]: Timpul a fost schimbat
Aug 25 21:18:51 wisi systemd[1]: Timpul a fost schimbat
Aug 25 21:18:51 wisi systemd[1187]: Timpul a fost schimbat
aici
# ps afx | grep "[1]187"
1187 ? Ss 0:02 /lib/systemd/systemd --user
În acel moment, deja trebuia să căutăm cauza, dar creierul, după 18 ani de administrare, a acumulat statistica erorilor „timpului” și din obișnuință din nou dă vina pe sincronizare.
Oprim complet aceasta.
# 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
și în loguri
Aug 25 21:25:40 wisi systemd[1]: Timpul a fost schimbat
Aug 25 21:25:40 wisi systemd[1187]: Timpul a fost schimbat
Aug 25 21:29:30 wisi systemd[1]: Timpul a fost schimbat
Aug 25 21:29:30 wisi systemd[1187]: Timpul a fost schimbat
Resyncing a dispărut și restul logurilor sunt immaculate.
Verificăm ieșirile tcpdump pe portul 123 pe toate interfețele. Nu există cereri, dar timpul tot „aleargă”.
A doua eroare. Întârzierile
Au mai rămas o oră până la sfârșitul săptămânii de lucru, iar a pleca în weekend cu o sarcină lăsată deoparte nu îmi place (nu luați în seamă timpul din cod, articolul a fost scris în zilele următoare).
Și din nou, în loc să caut motivul, am început să încerc să găsesc o explicație pentru rezultat. Spun "să găsesc", pentru că, oricum ar fi logice explicațiile rezultatului, este o abordare greșită pentru a rezolva problema.
Acest server este unul de streaming și convertește fluxul DVB-S2 în IP. În fluxul DVB-S sunt marcaje de timp, de aceea receptorii, multiplexoarele, scrambler-urile și televizoarele le folosesc adesea pentru a sincroniza ceasurile sistemului. Driverele plăcilor DVB-S sunt incluse în nucleu, așa că cel mai rapid mod de a elimina garantat fluxul DVB-S2 este să deconectezi cablurile venind din "farfurii". Din fericire, serverul este în spatele unui zid, așa că așa trebuie să fie.
Desigur, dacă logurile ar conține ceea ce ar trebui, acest lucru nu s-ar fi întâmplat, dar despre asta, din nou, la sfârșitul articolului.
Ei bine, și cum am eliminat toate semnalele satellite, să eliminăm și cele terestre — între timp, tragem toate cablurile de rețea. Serverul devine complet izolat de lumea exterioară și funcționează complet autonom, dar ceasurile sistemului tot grăbesc.
Săptămâna de lucru s-a încheiat, iar întrebarea dată/ora nu este critică pentru el, așa că pot pur și simplu să merg acasă, dar aici fac o nouă greșeală.
Greșeala a treia. Sfătuitorii.
Niciodată! Niciodată nu puneți întrebări pe forumuri și pe site-uri specializate (gen stackoverflow) dacă răspunsul necesită mai mult decât să studiați rezultatele primei pagini de pe Google și să citiți o pagină man.
Vă vor trimite înapoi la Google, să citiți același man și vă vor explica popular regulile forumului/site-ului, dar nu vă vor oferi un răspuns.
Aici sunt atât factori obiectivi:
- nimeni în afară de tine nu poate cunoaște problema la fel de bine;
- nimeni nu poate efectua teste în aceleași condiții ca tine.
Dar și subiectivi:
- poți să nu oferi toți parametrii necesari pentru a rezolva problema, pentru că deja ai găsit o direcție "corectă" și îți expui esența întrebării axându-te pe asta;
- seniorul (moderator, veteran, admin) are întotdeauna dreptate, dacă seniorul nu are dreptate… ei bine, știți voi...
Dacă, în comentariile de răspuns, ai rămas în limitele unui limbaj cenzurat, înseamnă că ai nervi puternici.
Soluție
Nu trebuie să împărțiți sarcinile în simple și complexe.
Opriți-vă să vă bazați pe experiența, statistica, sfătuitorii voștri și începeți să nu "explicați" rezultatul final, ci să căutați sistematic cauza.
Dacă cineva stabilește timpul, atunci trebuie să aibă loc un apel sistemic corespunzător.
Așa cum în documentația software-ului cele mai bune documente sunt sursele, tot așa în administrarea sistemelor cel mai bun ajutor este auditul, în cazul nostru. auditd.
Un moment de îndoialăAm parcurs documentele, dar nu am fost pe de-a-ntregul sigur că timpul în Linux poate fi stabilit doar clock_settime și settimeofday, așa că pentru primul test am ales toate apelurile "potrivite".
# 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
și abandonând s390_runtime_instr, stime, timerfd_create, pe care auditctl nu le-am recunoscut, inițial am lansat auditul sub forma:
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 utimesAsigurându-mă că nu sunt alte înregistrări în logurile care mă interesează syscalls în afară de acestea două, am folosit doar ele.
Pornim auditul apelurilor sistemice clock_settime și settimeofday și încercăm să schimbăm data:
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
O întârziere de cinci secunde a fost adăugată pentru ca "parazitul" nostru să corecteze cu siguranță timpul.
Să vedem raportul:
# 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
Aici vedem date și necunoscutul nostru chkcache_proces. A apărut în raportul de mai sus, deoarece aureport a sortat ieșirea după dată în procesul de conversie din formatul binar, iar evenimentul a avut loc la timpul stabilit de noi. date -s "2019-08-22 12:10:00".
Cine l-a generat?
# 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 — parazitul nostru a fost găsit. În ciuda comportamentului său "nefast", nu ne putem desprinde de sistemul de acces condiționat, dar totuși ne-ar plăcea să știm, oscam, WTF?
Răspunsul a fost găsit rapid în :
#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");
}
Ce drăguț arată aici linia comentată de avertizare Această sarcină trivială a apărut într-una din zilele de vineri.…
Sursa: habr.com
