Mida lihtsam ülesanne, seda sagedamini teen vigu

Mida lihtsam ülesanne, seda sagedamini teen vigu

See tühine ülesanne tekkis ühel reede pärastlõunal ja oleks pidanud võtma 2-3 minutit. Üldiselt nagu alati.

Kolleeg palus mul skripti tema serveris parandada. Tegin seda, ulatasin talle ja kukkusin tahtmatult: "Aeg on 5 minutit kiire." Laske serveril sünkroonimisega ise hakkama saada. Möödus pool tundi, tund ja ta ikka punnis ja vaikselt kirus.

“Rumal! — mõtlesin serverikonsoolile üle minnes — okei, ma teen veel paar minutit pausi.

Vaatame ntp, date, sdwdate ei ole installeeritud timesyncd puudega ja ei tööta.

# 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

Siinkohal märgin kohe, et riistvaraaeg on õige: edasi on lihtsam navigeerida.

Siit sai alguse vigade jada.

Esimene viga. Enesekindlus

Klõpsa-klõps...

# 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

Kõik on korras, aeg on sünkroonitud, süsteemiaeg ühtib riistvaraga. "Võta," ütlesin ja pöördusin tagasi oma äri juurde.

"Võta mida? – oli kolleeg nördinud. "See on sama aeg!"

Mida rohkem te tüüpilisi probleeme lahendate, seda enam muutub teie mõtlemine pilgutuks ja te ei arva enam, et sajas või tuhandes olukord on teistsugune, kuid mitte seekord.

# 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

Süsteemi aeg on jälle vale.

Proovime uuesti:

# 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

Teeme seda teisiti:

# 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

Ja niimoodi:

# 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

Aeg seatakse sekundi murdosa peale ja hakkab kohe uuesti “tormama”.

Samas näeme logides sellise käsitsi muutmise hetkel ainult süsteemi teateid, et kell on muutunud vastavalt õiges/vales suunas ja aeg-ajalt Uuesti sünkroonimine süsteemist 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

siin

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

Siinkohal tuli juba põhjust otsida, kuid 18-aastase manustamise jooksul on ajju kogunenud statistika “ajaliste” vigade kohta ja harjumusest süüdistatakse taas sünkroniseerimist.
Lülitame selle täielikult välja.

# 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

ja palkides

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

Uuesti sünkroonimine kadunud ja muidu on palgid puutumata.

Järelduste kontrollimine tcpdump kõigi liideste pordis 123. Päringuid pole, aga aeg jookseb ikka ära.

Viga kaks. Kiirustage

Töönädala lõpuni on jäänud tund ja ma ei taha nädalavahetuseks lahkuda tühise lahendamata probleemiga (ärge jälgi koodis olevat kellaaega, artikkel on kirjutatud järgmistel päevadel ).
Ja siingi hakkasin põhjuse otsimise asemel püüdma tulemusele seletust välja mõelda. Ma ütlen “leiutama”, sest ükskõik kui loogiline tulemuse selgitus ka poleks, on see vigane lähenemine probleemi lahendamisele.

See server on voogedastusserver ja teisendab DVB-S2 voo IP-ks. DVB-S voog sisaldab ajatempleid, nii et vastuvõtjad, multiplekserid, skrambleerijad ja televiisorid kasutavad neid sageli süsteemi kella sünkroonimiseks. DVB-S-plaadi draiverid on tuuma sisse ehitatud, nii et kiireim viis DVB-S2 voo eemaldamise tagamiseks on "plaatidelt" tulevate kaablite lahtiühendamine. Õnneks on server seina taga, olgu nii.

Muidugi, kui logid oleksid sisaldanud seda, mis seal olema peaks, poleks seda juhtunud, kuid sellest lähemalt jällegi artikli lõpus.

Noh, kuna oleme juba kõik satelliidi signaalid eemaldanud, siis eemaldame ka maapealsed - samal ajal tõmbame kõik võrgukaablid välja. Server katkeb välismaailmast ja töötab täiesti autonoomselt, kuid süsteemikell on endiselt kiire.

Töönädal on möödas ja kuupäeva/kellaaja küsimus ise ei ole kriitiline, nii et võite lihtsalt koju minna, kuid siin ma teen uue vea.

Viga kolm. Nõuandjad

Mitte kunagi! Ärge kunagi esitage küsimusi foorumitel ja üldistel spetsialiseeritud (a la stackoverflow) saitidel, kui sellele vastamine nõuab rohkemat kui Google'i esimese lehe uurimine ja ühe man-lehe lugemist.

Saadavad su Google’isse tagasi, loevad sama meest ja seletavad rahvapäraselt foorumi/saidi reegleid, aga vastust ei anna.

Siin on mõned objektiivsed tegurid:

  • keegi peale sinu ei saa samuti probleemist teada;
  • keegi ei saa teste läbi viia samadel tingimustel kui teie

ja subjektiivne:

  • sa ei pruugi anda probleemi lahendamiseks kogu sisendit, sest oled juba “õige” suuna välja mõelnud ja esitad sellele keskendudes probleemi olemuse;
  • töödejuhatajal (moderaator, vanamees, admin) on alati õigus, kui töödejuhataja eksib... no tead...

Kui kommentaaridele vastates jäid tsenseeritud sõnavara piiridesse, siis on sul tugevad närvid.

otsus

Ülesandeid pole vaja jagada lihtsateks ja keerukateks.

Lõpetame oma kogemustele, statistikale, nõuandjatele lootmise ja hakkame mitte lõpptulemust “selgitama”, vaid järjekindlalt otsima põhjust.

Kuna kellaaja määrab keegi, peab toimuma vastav süsteemikutse.

Nii nagu tarkvara dokumentatsioonis on allikaks parimad dokumendid, nii ka süsteemihalduses on meie puhul parim abimees audit auditeeritud.

Kahtluse hetkKäisin mana läbi, aga polnud päris kindel, et Linuxis saab ainult kellaaega määrata clock_settime и määratud kellaaeg, seega valisin esimeseks testiks kõik "sobivad" kõned:

# 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

ja äraviskamine s390_runtime_instr, stime, timerfd_create, mis auditctl ei tundnud seda ära, käivitas algselt auditi kujul:

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

Pärast seda, kui olen veendunud, et mind huvitavates logikohtades pole muid palke syscallid Peale nende kahe kasutasin ainult neid edasi.

Süsteemikõne auditi käivitamine clock_settime и määratud kellaaeg ja proovige kuupäeva muuta:

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

Lisatakse viiesekundiline viivitus, et meie “parasiit” garanteeriks aja korrigeerimise.

Vaatame aruannet:

# 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

Siin näeme oma andmed ja meile tundmatu chkcache_processes. See sattus ülaltoodud aruandesse, kuna aureport sortis väljundi binaarsest teisendamisel kuupäeva järgi ja sündmus leidis aset meie määratud ajal kuupäev -s "2019-08-22 12:10:00".
Kes ta sünnitas?

# 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 - meie parasiit on leitud. Vaatamata selle "pahatahtlikule" käitumisele on tingimusliku juurdepääsu süsteemist võimatu keelduda, kuid ma tahaksin siiski teada oscam, WTF?

Vastus leitakse kiiresti lähtekoodid:

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

Kui armas see siin välja näeb kommenteeris välja rida hoiatus...

Allikas: www.habr.com

Lisa kommentaar