ProHoster > Blog > Administrácia > Čím jednoduchšia úloha, tým častejšie sa mýlim

Čím jednoduchšia úloha, tým častejšie sa mýlim

Čím jednoduchšia úloha, tým častejšie sa mýlim

Táto triviálna úloha vznikla v jeden z piatkov a mala zabrať 2-3 minúty. V podstate, ako vždy.

Kolega ma požiadal, aby som opravil skript na jeho serveri. Urobil som to, odovzdal mu to a nenápadne som poznamenal: „Čas sa ponáhľa o 5 minút“. Je to jeho server, nech sa s časovaním popasuje sám. Polhodina, hodina uplynula a on stále frfľa a potichu nadáva.

„Nemenovec! — pomyslel som si, prepínajúc sa do konzoly servera — nuž dobre, odtrhnem sa ešte na pár minút.“

Pozeráme sa, ntp, rdate, sdwdate nie sú nainštalované, timesyncd je vypnutý a nebeží.

# 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

Preto hneď poznamenám, že hardvérový čas je správny: podľa neho sa bude ďalej ľahšie orientovať.

Odtiaľto začala séria chýb.

Chyba prvá. Sebavedomie

Klač-klač…

# 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

Všetko je v poriadku, čas sa synchronizoval, systémový súhlasí s hardvérovým. „Vezmi si to“, — povedal som a vrátil sa k svojim záležitostiam.

„Čo si vezmi? — pohoršoval sa kolega. — Čas je rovnaký!“

Čím viac riešiš typové úlohy, tým viac sa skresľuje myslenie a už nemyslíš, že stotina alebo tisíca situácia bude iná, ale nie tentoraz.

# 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

Systémový čas je opäť nesprávny.

Skúsime znova:

# 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

Poďme inak:

# 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

A takto:

# 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

Čas sa nastavuje na zlomok sekundy, a hneď začína znova „ponáhľať“.

Pri tom v logoch, v okamihu takej ručnej zmeny, vidíme len hlásenia systému, že čas sa zmenil, prípadne na správnu/neprávnu stranu a zriedka Resyncing od systemd-timesyncd.

Aug 25 21:18:51 wisi systemd[1]: Čas sa zmenil
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: Systémový čas sa zmenil. Resynchronizujem.
Aug 25 21:18:51 wisi systemd[1187]: Čas sa zmenil
Aug 25 21:18:51 wisi systemd[1]: Čas sa zmenil
Aug 25 21:18:51 wisi systemd[1187]: Čas sa zmenil

tu

# ps afx | grep "[1]187"
 1187 ?        Ss     0:02 /lib/systemd/systemd --user

V tento moment už bolo potrebné hľadať príčinu, ale mozog za 18 rokov správy serverov si naakumuloval štatistiku chýb „času“ a zo zvyku opäť obviňuje synchronizáciu.
Vypneme ju úplne.

# 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

a v logoch

Aug 25 21:25:40 wisi systemd[1]: Čas sa zmenil
Aug 25 21:25:40 wisi systemd[1187]: Čas sa zmenil
Aug 25 21:29:30 wisi systemd[1]: Čas sa zmenil
Aug 25 21:29:30 wisi systemd[1187]: Čas sa zmenil

Resyncing zmizol a v ostatných logoch je všetko panensky čisté.

Kontrolujeme výstupy tcpdump po 123. porte na všetkých rozhraniach. Žiadne požiadavky nie sú, ale čas stále „uteká“.

Chyba druhá. Ponáhľanie

Do konca pracovného týždňa zostáva hodina a nechce sa mi odísť na víkend s nezaplatenou úlohou (nevšímajte si čas v kóde, článok sa písal v nasledujúcich dňoch).
A opäť, namiesto toho, aby som hľadal príčinu, som sa snažil nájsť vysvetlenie výsledku. Hovorím "nájsť", pretože, bez ohľadu na to, aké logické by mohli byť vysvetlenia výsledku, je to chybný prístup k riešeniu problému.

Tento server je streamovací a prevádza tok DVB-S2 na IP. V toku DVB-S sú prítomné časové pečiatky, a preto prijímače, multiplexory, skramblerov a televízory často používajú ich na synchronizáciu systémových hodín. Ovládače DVB-S dosiek sú zakompilované v jadre, preto najrýchlejší spôsob, ako zabezpečiť odstránenie DVB-S2 toku, je odpojiť káble idúce z "tanierov". Našťastie server je za stenou, takže to tak bude.

Samozrejme, keby v logoch bolo to, čo tam malo byť, k tomu by nedošlo, ale o tom, opäť, až na konci článku.

A keďže sme už odstránili všetky satelitné signály, odstránime aj terestriálne — zároveň vytiahneme všetky sieťové káble. Server sa stáva odrezaným od vonkajšieho sveta a pracuje absolútne autonómne, ale systémové hodiny sa stále ponáhľajú.

Pracovný týždeň sa skončil, a otázka dátumu/ času na ňom nie je kritická, takže môžem jednoducho ísť domov, ale tu robím novú chybu.

Chyba tretia. Rady.

Nikdy! Nikdy sa nepýtajte otázky na fórach a špeciálnych (ako stackoverflow) stránkach, ak odpoveď na ňu vyžaduje viac ako štúdium výsledkov prvej stránky Googlu a prečítanie jednej stránky manuálu.

Pošlú vás späť na Google, aby ste si prečítali ten istý manuál a populárne vysvetlili pravidlá fóra/ stránky, ale nedajú vám odpoveď.

Existujú tu jednak objektívne faktory:

  • nikto okrem vás nemôže poznať problém rovnako dobre;
  • nikto nemôže vykonať testy za rovnakých podmienok ako vy

tak aj subjektívne:

  • môžete nezverejniť všetky vstupy na vyriešenie úlohy, pretože ste už vymysleli "správny" smer a argumentujete podstatou otázky, opierajúc sa o neho;
  • staršina (moderátor, starý známy, admin) má vždy pravdu; ak staršina nemá pravdu... no, viete...

Ak ste pri odpovediach zostali v rámci cenzurálneho slovníka, znamená to, že máte silné nervy.

Riešenie

Nenechávajte úlohy rozdelené na jednoduché a zložité.

Prestávame sa spoliehať na svoju skúsenosť, štatistiku, poradcov a začíname ne"vysvetľovať" konečný výsledok, ale postupne hľadať príčinu.

Ak niekto nastavuje čas, musí dôjsť k zodpovedajúcemu systémovému volaniu.

Ako v dokumentácii softvéru sú najlepšími dokmi zdrojové kódy, tak v systémovej administrácii je najlepším pomocníkom audit, v našom prípade. auditd.

Chvíľka pochybnostíPrebehol som manuály, ale nebol som si úplne istý, že čas v Linuxe môže byť nastavovaný iba clock_settime a settimeofday, preto som na prvý test vybral všetky „príslušné“ volania:

# 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

a vylúčil s390_runtime_instr, stime, timerfd_create, ktoré auditctl na začiatku neuznal, spustil som audit v podobe:

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

Ubezpečil som sa, že na miestach logov, ktoré ma zaujímali, nie sú iné syscalls okrem týchto dvoch, ďalej som používal iba ich.

Spúšťame audit systémových volaní clock_settime a settimeofday a skúšame zmeniť dátum:

# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D

Päťsekundové oneskorenie bolo pridané, aby náš „parazit“ zaručene upravil čas.

Pozrieme sa na správu:

# 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

Tu vidíme našu date a nám neznámu chkcache_proces. Objavil sa v správe vyššie, pretože aureport usporiadal výstup podľa dátumu pri konverzii z binárneho formátu, a udalosť sa stala v čase, ktorý sme nastavili. date -s "2019-08-22 12:10:00".
Kto ho vyprodukoval?

# 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 — náš parazit bol nájdený. Napriek jeho „škodlivému“ správaniu sa nedá vzdať systému podmieneného prístupu, ale predsa by ma zaujímalo, oscam, WTF?

Odpoveď bola rýchlo nájdená v zdrojových kódoch.:

#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");
}

Ako pekne to tu vyzerá zakomentovaná riadok warning’a…

Zdroj: habr.com

Kúpte si spoľahlivý hosting pre webové stránky s ochranou proti DDoS, VPS VDS servery 🔥 Kúpte si spoľahlivý hosting pre webové stránky s ochranou proti DDoS, VPS VDS servery | ProHoster