ProHoster > Blog > Uprava > Preprostejša ko je naloga, pogosteje delam napake

Preprostejša ko je naloga, pogosteje delam napake

Preprostejša ko je naloga, pogosteje delam napake

Ta trivialna naloga se je pojavila nekega petka popoldne in bi morala vzeti 2-3 minute časa. Na splošno, kot vedno.

Kolega me je prosil, naj popravim skripto na njegovem strežniku. To sem storil, mu ga dal in nehote rekel: "Čas je hiter 5 minut." Naj strežnik sam poskrbi za sinhronizacijo. Pol ure, ura je minila, on pa še vedno sopiha in tiho preklinja.

»Neumno! — pomislil sem, ko sem preklopil na strežniško konzolo — v redu, vzel si bom še nekaj minut odmora.”

Pa poglejmo ntp, rdate, sdwdate ni nameščeno timesyncd onemogočeno in se ne izvaja.

# 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

Tukaj bom takoj opozoril, da je čas strojne opreme pravilen: lažje bo krmariti naprej.

Tu se je začela serija napak.

Prva napaka. Samozavest

Klik-klak...

# 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

Vse je v redu, čas je sinhroniziran, sistemski čas se ujema s strojnim. "Vzemi," sem rekel in se vrnil k svojemu poslu.

»Vzeti kaj? - je bil ogorčen kolega. "Isti čas je!"

Bolj ko rešujete tipične probleme, bolj se vaše razmišljanje utripa in ne mislite več, da bo stotino ali tisočo situacija drugačna, a ne tokrat.

# 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

Sistemski čas je spet napačen.

Poskusimo 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

Naredimo drugače:

# 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

In takole:

# 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 je nastavljen na delček sekunde in takoj začne znova "hiteti".

Hkrati pa v dnevnikih v času takšne ročne spremembe vidimo le sistemska poročila, da se je čas spremenil v pravo/napačno smer in občasno Ponovna sinhronizacija iz 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

tukaj

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

Na tej točki je bilo že treba iskati razlog, a v 18 letih upravljanja so možgani nabrali statistiko o "časovnih" napakah in iz navade spet krivijo sinhronizacijo.
Popolnoma izklopimo. 

# 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

in v dnevnikih

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

Ponovna sinhronizacija izginil in sicer so hlodi nedotaknjeni.

Preverjanje zaključkov tcpdump na vratih 123 na vseh vmesnikih. Prošenj ni, a čas vseeno beži.

Druga napaka. Hitenje

Do konca delovnega tedna je še ena ura in nočem oditi za vikend z banalnim nerešenim problemom (ne bodite pozorni na čas v kodi, članek je nastal v naslednjih dneh ).
In spet sem namesto iskanja vzroka začel poskušati najti razlago za rezultat. Pravim "izumiti", ker ne glede na to, kako logična je razlaga rezultata, je to napačen pristop k reševanju problema.

Ta strežnik je pretočni strežnik in pretvori tok DVB-S2 v IP. Tok DVB-S vsebuje časovne žige, zato jih sprejemniki, multiplekserji, kodirniki in televizorji pogosto uporabljajo za sinhronizacijo sistemske ure. Gonilniki plošče DVB-S so vgrajeni v jedro, zato je najhitrejši način za zagotovitev odstranitve toka DVB-S2 tako, da odklopite kable, ki prihajajo iz "plošč". Na srečo je strežnik za zidom, tako je.

Seveda, če bi dnevniki vsebovali tisto, kar bi moralo biti, se to ne bi zgodilo, a o tem spet na koncu članka.

No, ker smo že odstranili vse satelitske signale, bomo odstranili tudi zemeljske - hkrati izvlečemo vse omrežne kable. Strežnik postane odrezan od zunanjega sveta in deluje povsem avtonomno, sistemska ura pa še vedno hiti.

Delovnega tedna je konec in sama težava z datumom/uro ni kritična, tako da lahko greš domov, a tukaj naredim novo napako.

Napaka tri. Svetovalci

Nikoli! Nikoli ne postavljajte vprašanj na forumih in splošnih specializiranih (a la stackoverflow) spletnih mestih, če odgovor nanje zahteva več kot preučevanje prve strani Googla in branje ene strani z navodili.

Poslali vas bodo nazaj na Google, prebrali istega človeka in poljudno razložili pravila foruma/strani, vendar vam ne bodo dali odgovora.

Tukaj je nekaj objektivnih dejavnikov:

  • nihče razen vas ne more poznati problema;
  • nihče ne more izvajati testov pod enakimi pogoji kot vaši

in subjektivno:

  • morda ne boste dali vsega prispevka k rešitvi problema, ker ste že izbrali »pravo« smer in predstavljate bistvo problema in se osredotočate nanj;
  • delovodja (moderator, starodobnik, admin) ima vedno prav, če se delovodja moti... no, saj veste...

Če ste pri odgovarjanju na komentarje ostali v mejah cenzuriranega besedišča, potem imate močne živce.

odločitev

Nalog ni treba deliti na preproste in zapletene.

Nehamo se zanašati na svoje izkušnje, statistiko, svetovalce in začnemo ne »razlagati« končnega rezultata, ampak dosledno iskati razlog.

Ker nekdo nastavi čas, se mora zgoditi ustrezen sistemski klic.

Tako kot so v programski dokumentaciji najboljši dokumenti viri, je tudi v sistemski administraciji najboljši pomočnik revizija, v našem primeru auditd.

Trenutek dvomaŠel sem skozi mano, vendar nisem bil povsem prepričan, da je čas v Linuxu mogoče samo nastaviti clock_settime и settimeofday, zato sem za prvi test izbral vse »primerne« klice:

# 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

in odmetavanje s390_runtime_instr, stime, timerfd_create, ki auditctl ni prepoznal, sprva sprožil revizijo v obliki:

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

Potem ko sem se prepričal, da na lokacijah dnevnikov, ki me zanimajo, ni drugih dnevnikov sistemske klice Poleg teh dveh sem naprej uporabljal samo njiju.

Izvajanje revizije sistemskega klica clock_settime и settimeofday in poskusite spremeniti datum:

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

Doda se petsekundna zakasnitev, tako da naš "parazit" zajamčeno popravi čas.

Poglejmo poročilo:

# 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

Tukaj vidimo naše Datum in nam neznano chkcache_processes. Končalo se je v zgornjem poročilu, ker je aureport pri pretvorbi iz binarnega izhoda razvrstil po datumu in se je dogodek zgodil ob času, ki smo ga nastavili datum -s "2019-08-22 12:10:00".
Kdo ga je rodil?

# 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 - naš parazit je bil najden. Kljub "zlonamernemu" vedenju je nemogoče zavrniti sistem pogojnega dostopa, vendar bi vseeno rad vedel oscam, WTF?

Odgovor se hitro najde v izvorne kode:

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

Kako ljubko je videti tukaj komentiral linija Opozorilo...

Vir: www.habr.com

Dodaj komentar