Denne trivielle oppgaven oppsto en fredag ettermiddag og skulle ha tatt 2-3 minutter med tid. Generelt, som alltid.
En kollega ba meg fikse skriptet på serveren hans. Jeg gjorde det, ga det til ham og slapp utilsiktet: «Tiden er 5 minutter fort.» La serveren håndtere selve synkroniseringen. Det gikk en halvtime, en time, og han puffet fortsatt og bannet stille.
"Dum! — Jeg tenkte, og byttet til serverkonsollen — ok, jeg tar en pause i et par minutter til.»
La oss se ntp, rdate, sdwdate ikke installert tidssynkronisering deaktivert og kjører ikke.
# 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 umiddelbart merke at maskinvaretiden er riktig: det vil være lettere å navigere videre.
Det var her rekken av feil begynte.
Den første feilen. Selvtillit
Klikk-klakk...
# 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 bra, tiden er synkronisert, systemtiden matcher maskinvaren. "Ta den," sa jeg og gikk tilbake til virksomheten min.
«Ta hva? – Kollegaen var indignert. "Det er samme tid!"
Jo mer du løser typiske problemer, desto mer blinker tankegangen din og du tror ikke lenger at den hundre- eller tusende situasjonen vil være annerledes, men ikke denne gangen.
# 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 feil igjen.
La oss prøve igjen:
# 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
La oss gjøre det annerledes:
# 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 slik:
# 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 er satt til et brøkdel av et sekund, og begynner umiddelbart å "haste" igjen.
Samtidig ser vi i loggene, ved en slik manuell endring, kun systemrapporter om at tidspunktet har endret seg henholdsvis i riktig/feil retning og av og til Synkroniserer på nytt fra 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
her
# ps afx | grep "[1]187"
1187 ? Ss 0:02 /lib/systemd/systemd --user
På dette tidspunktet var det allerede nødvendig å lete etter årsaken, men i løpet av 18 år med administrasjon har hjernen samlet statistikk over "tids"-feil og, av vane, igjen skylder på synkronisering.
La oss slå den helt av.
# 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]: 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
Synkroniserer på nytt forsvant og ellers er tømmerstokkene uberørte.
Sjekker konklusjonene tcpdump på port 123 på alle grensesnitt. Det er ingen forespørsler, men tiden renner fortsatt.
Feil to. Skynde
Det er en time igjen til slutten av arbeidsuken, og jeg vil ikke reise til helgen med et trivielt uløst problem (ikke ta hensyn til tiden i koden, artikkelen ble skrevet i de påfølgende dagene ).
Og her igjen, i stedet for å lete etter årsaken, begynte jeg å prøve å komme med en forklaring på resultatet. Jeg sier "oppfinne" fordi uansett hvor logisk forklaringen på resultatet kan være, er det en mangelfull tilnærming til å løse problemet.
Denne serveren er en strømmeserver og konverterer DVB-S2-strømmen til IP. DVB-S-strømmen inneholder tidsstempler, så mottakere, multipleksere, scramblere og fjernsyn bruker dem ofte til å synkronisere systemklokken. DVB-S-kortdrivere er innebygd i kjernen, så den raskeste måten å sikre at DVB-S2-strømmen fjernes på er å koble fra kablene som kommer fra "platene". Heldigvis er serveren bak veggen, så det får det til.
Selvsagt, hvis loggene hadde inneholdt det som skulle stå der, ville dette ikke ha skjedd, men mer om det, igjen, på slutten av artikkelen.
Vel, siden vi allerede har fjernet alle satellittsignaler, vil vi også fjerne jordbaserte - samtidig trekker vi ut alle nettverkskablene. Serveren blir avskåret fra omverdenen og fungerer helt autonomt, men systemklokken har det fortsatt travelt.
Arbeidsuken er over, og selve dato/klokkeslett-problematikken er ikke kritisk, så du kan bare gå hjem, men her gjør jeg en ny feil.
Feil tre. Rådgivere
Aldri! Still aldri spørsmål på fora og generelle spesialiserte (a la stackoverflow) nettsteder hvis svaret på det krever mer enn å studere den første siden av Google og lese én man-side.
De vil sende deg tilbake til Google, lese samme mann og populært forklare reglene for forumet/siden, men vil ikke gi deg noe svar.
Her er noen objektive faktorer:
- ingen unntatt du kan også kjenne til problemet;
- ingen kan gjennomføre tester under samme forhold som dine
og subjektivt:
- du kan ikke gi alle innspill for å løse problemet, fordi du allerede har kommet opp med den "riktige" retningen og presenterer essensen av problemet med fokus på det;
- formannen (moderator, oldtimer, admin) har alltid rett, hvis formannen tar feil... vel, du vet...
Hvis du, når du svarte på kommentarer, holdt deg innenfor grensene for sensurert ordforråd, har du sterke nerver.
beslutning
Det er ikke nødvendig å dele opp oppgaver i enkle og komplekse.
Vi slutter å stole på vår erfaring, statistikk, rådgivere og begynner ikke å "forklare" sluttresultatet, men konsekvent lete etter årsaken.
Siden noen setter tiden, må det tilsvarende systemanropet skje.
Akkurat som i programvaredokumentasjon er de beste dokumentene kildene, så i systemadministrasjon er den beste assistenten revisjon, i vårt tilfelle revidert.
Et øyeblikks tvilJeg gikk gjennom manaen, men var ikke helt sikker på at tiden i Linux kun kan stilles inn klokke_innstillingstid и setttid på dagen, så for den første testen valgte jeg alle "passende" anrop:
# 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 kassering s390_runtime_instr, stime, timerfd_create, hvilken revisjonskontroll gjenkjente det ikke, startet først en revisjon i formen:
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 utimesEtter å ha forsikret meg om at det ikke er andre logger på loggplasseringene jeg er interessert i syscaller Foruten disse to brukte jeg bare dem videre.
Kjøre en systemsamtalerevisjon klokke_innstillingstid и setttid på dagen og prøv å endre datoen:
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
En fem sekunders forsinkelse legges til slik at vår "parasitt" garantert vil korrigere tiden.
La oss se på rapporten:
# 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
Her ser vi vår data og ukjent for oss chkcache_prosesser. Det havnet i rapporten ovenfor fordi aureport sorterte utdata etter dato ved konvertering fra binær, og hendelsen skjedde på tidspunktet vi satte dato -s "2019-08-22 12:10:00".
Hvem fødte ham?
# 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 - parasitten vår er funnet. Til tross for dens "ondsinnede" oppførsel, er det umulig å nekte det betingede tilgangssystemet, men jeg vil fortsatt gjerne vite oscam, WTF?
Svaret finner du raskt i :
#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");
}
Så søtt det ser ut her kommenterte ut linje advarsel...
Kilde: www.habr.com