Denne trivielle opgave opstod en fredag og skulle tage 2-3 minutters tid. Som altid, i det store hele.
En kollega bad om at få rettet et script på sin server. Jeg gjorde det, afleverede det til ham og bemærkede uden at tænke over det: «Tiden er foran med 5 minutter». Det er hans server, så han må selv finde ud af synkroniseringen. En halv time, en time gik, men han puster stadig og mumler stille.
«Uduelig! — tænkte jeg, mens jeg skiftede til konsollen server — nå, men jeg tager mig lige et par minutter mere.»
Lad os se, ntp, rdate, sdwdate er ikke installeret, timesyncd er deaktiveret og ikke startet.
# 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
Her vil jeg straks bemærke, at hardwaretiden er korrekt: det vil være lettere at orientere sig herefter.
Herfra begyndte rækken af fejl.
Fejl nummer ét. Selvsikkerhed
Klik 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
Alt er fint, tiden er synkroniseret, systemtiden svarer til hardwaretiden. «Tag hvad du vil», sagde jeg og gik tilbage til mine opgaver.
«Hvad skal jeg tage? — udbrød kollegaen. — Tiden er den samme!»
Jo flere standardopgaver du løser, jo mere bliver tankegangen begrænset, og du tænker ikke på, at hundrede eller tusinde situationer vil være anderledes, men ikke denne gang.
# 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
Systemtiden er igen forkert.
Lad os prøve igen:
# 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
Lad os prøve anderledes:
# 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
Og sådan her:
# 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
Tiden sættes på en brøkdel af et sekund, og så begynder den straks at «gå for hurtigt» igen.
I loggene, på tidspunktet for sådan en manuel ændring, ser vi kun systemets rapporter om, at tiden er ændret, i henholdsvis den korrekte/ukorrekte retning og sjældent Resyncing fra systemd-timesyncd.
Aug 25 21:18:51 wisi systemd[1]: Tiden er blevet ændret
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: Systemtiden er ændret. Resyncing.
Aug 25 21:18:51 wisi systemd[1187]: Tiden er blevet ændret
Aug 25 21:18:51 wisi systemd[1]: Tiden er blevet ændret
Aug 25 21:18:51 wisi systemd[1187]: Tiden er blevet ændret
her
# ps afx | grep "[1]187"
1187 ? Ss 0:02 /lib/systemd/systemd --user
På dette tidspunkt skulle årsagen allerede have været søgt, men hjernen har gennem 18 år som systemadministrator samlet statistik over «tid» fejl og skyder igen automatisk skylden på synkroniseringen.
Vi slukker den helt.
# 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
og i loggene
Aug 25 21:25:40 wisi systemd[1]: Tiden er blevet ændret
Aug 25 21:25:40 wisi systemd[1187]: Tiden er blevet ændret
Aug 25 21:29:30 wisi systemd[1]: Tiden er blevet ændret
Aug 25 21:29:30 wisi systemd[1187]: Tiden er blevet ændret
Resyncing forlod og ellers er loggene fejlfri.
Vi tjekker output tcpdump på port 123 på alle grænseflader. Der er ingen forespørgsler, men tiden «løber» stadig.
Fejl nummer to. Hastighed
Der er kun en time tilbage af arbejdsugen, og jeg vil ikke tage på weekend med en ubesluttet opgave (tænk ikke på tiden i koden, artiklen blev skrevet i de følgende dage).
Og her igen, i stedet for at lede efter årsagen, begyndte jeg at forsøge at finde en forklaring på resultatet. Jeg bruger ordet "finde", fordi uanset hvor logiske forklaringerne på resultatet måtte være, er det en fejlagtig tilgang til at løse problemet.
Denne server er en streaming-server, der konverterer DVB-S2-strømmen til IP. I DVB-S-strømmen er der timestamps, som modtagere, multiplexer, skrambler og TV ofte bruger til at synkronisere systemuheld. DVB-S-drivere er kompileret i kernen, så den hurtigste måde at garantere at fjerne DVB-S2-strømmen er at frakoble kablerne fra "parabolerne". Heldigvis er serveren på den anden side af væggen, så således skal det være.
Naturligvis, hvis logsene havde indeholdt det, de skulle, ville dette ikke være sket, men om det, igen, i slutningen af artiklen.
Og da vi allerede har fjernet alle satellitsignaler, fjerner vi også de jordbaserede — samtidig trækker vi alle netværkskablerne ud. Serveren bliver afskåret fra omverdenen og fungerer fuldstændigt autonomt, men systemuret går stadig for hurtigt.
Arbejd weekenden er slut, og spørgsmålet om dato/tid på den er ikke kritisk, så man kan bare gå hjem, men her laver jeg endnu en fejltagelse.
Fejl tre. Rådgivere.
Aldrig! Aldrig stille spørgsmål på fora og specialiserede (a la stackoverflow) websteder, hvis svaret kræver mere end at studere resultaterne på den første side af Google og læse én side af man.
De vil sende dig tilbage til Google for at læse den samme man og populært forklare reglerne på forummet/webstedet, men vil ikke give dig et svar.
Her er både objektive faktorer:
- ingen andre end dig kan vide problemet lige så godt;
- ingen kan udføre testene under de samme betingelser som du;
og subjektive:
- du kan have ikke givet alle oplysninger til at løse opgaven, fordi du allerede har fundet den "rette" vej og præsenterer essensen af spørgsmålet med fokus på den;
- den anklagede (moderator, veteran, admin) har altid ret, hvis den anklagede ikke har ret… ja, du ved…
Hvis du i dine svar er blevet inden for censureret sprogbrug, så har du stærke nerver.
Løsning
Det er ikke nødvendigt at dele opgaverne op i simple og komplekse.
Lad os holde op med at stole på vores erfaring, statistik, rådgivere og begynde ikke at "forklare" det endelige resultat, men i stedet konsekvent søge efter årsagen.
Da nogen sætter tiden, må der derfor finde et systemopkald sted.
Som dokumentationen for softwaren siger, at de bedste dokumenter er kilderne, så er den bedste hjælper i systemadministration audit, i vores tilfælde. auditd.
Et øjebliks tvivl.Jeg har hurtigt gennemgået manualerne, men var ikke helt sikker på, at tiden i Linux kun kan sættes ved hjælp af. clock_settime. og settimeofday., derfor valgte jeg til den første test alle "passende" opkald:
# 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
og droppede s390_runtime_instr, stime, timerfd_create., som jeg auditctl ikke genkendte, således startede jeg audit i form af:
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.Efter at have bekræftet, at der ikke er andre i de logfiler, der interesserer mig, end disse to, brugte jeg kun dem. syscalls Lad os starte audit af systemopkald.
Og så prøver vi at ændre datoen: clock_settime. og settimeofday. Der er tilføjet en fem sekunders forsinkelse for at sikre, at vores "parasit" justerer tiden.
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
Lad os se rapporten:
Her ser vi vores
# 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
og en som vi ikke kender. date chkcache_proces. Han dukkede op i rapporten ovenfor, da aureport sorterede output efter dato, da det blev konverteret fra binær form, og hændelsen fandt sted på det tidspunkt, vi fastsatte.date -s "2019-08-22 12:10:00". Hvem har skabt ham?.
— vores parasit er fundet. På trods af hans "ondskabsfulde" adfærd kan vi ikke opgive adgangssystemet, men vi vil stadig gerne vide,
# 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?Svaret blev hurtigt fundet i.
Hvor sødt det ser ud her. :
#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");
}
den kommenterede linje. af advarslen. Denne trivielle opgave opstod en fredag.…
Kilde: habr.com
