Ju enklare uppgiften är, desto oftare gör jag misstag

Ju enklare uppgiften är, desto oftare gör jag misstag

Denna triviala uppgift uppstod en fredagseftermiddag och borde ha tagit 2-3 minuters tid. I allmänhet, som alltid.

En kollega bad mig fixa skriptet på sin server. Jag gjorde det, räckte den till honom och släppte oavsiktligt: ​​"Tiden är 5 minuter snabb." Låt servern sköta synkroniseringen själv. En halvtimme, en timme gick, och han puffade fortfarande och förbannade tyst.

"Dum! — Jag tänkte och bytte till serverkonsolen — okej, jag tar en paus i ett par minuter till.

Vi kollar ntp, rdate, sdwdate inte installerad tidssynk inaktiverad och inte igång.

# 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

Här kommer jag omedelbart att notera att hårdvarutiden är korrekt: det blir lättare att navigera vidare.

Отсюда и началась череда ошибок.

Det första misstaget. Självförtroende

Klick-klack...

# 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

Всё отлично, время синхронизировалось, системное совпадает с аппаратным. «Забирай», — обронил я и вернулся к своим делам.

«Что забирай? — возмутился коллега. — Время прежнее!»

Ju mer du löser typiska problem, desto mer blinkar ditt tänkande och du tror inte längre att den hundrade eller tusende situationen kommer att vara annorlunda, men inte den här gången.

# 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 är fel igen.

Låt oss försöka 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

Låt oss göra det annorlunda:

# 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

Men så här:

# 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 är inställd på en bråkdel av en sekund och börjar genast "rusa" igen.

При этом в логах, на момент такой ручной смены, видим лишь отчёты системы, о том, что время изменилось, соответственно в правильную/неправильную стороны и изредка Synkroniseras om от 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

här

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

В этот момент уже нужно было искать причину, но мозг за 18 лет админства наработал статистику ошибок «времени» и по привычке снова обвиняет синхронизацию.
Låt oss stänga av det 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

och i loggarna

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

Synkroniseras om försvann och i övrigt är stockarna orörda.

Проверяем выводы tcpdump по 123-му порту на всех интерфейсах. Никаких запросов нет, но время всё также «убегает».

Fel två. Rusa

До конца рабочей недели остаётся час, а уходить на выходные с плёвой нерешенной задачей не хочется (не обращайте внимания на время в коде, статья писалась в последующие дни).
Och här igen, istället för att leta efter orsaken, började jag försöka komma på en förklaring till resultatet. Jag säger "uppfinna" för hur logisk förklaringen till resultatet än kan vara, så är det ett felaktigt tillvägagångssätt för att lösa problemet.

Данный сервер является стримминговым и преобразовывает поток DVB-S2 в IP. В потоке DVB-S присутствуют метки времени, поэтому приемники, мультиплексоры, скремблеры и телевизоры часто используют их для синхронизации системных часов. Драйвера DVB-S плат вкомпилены в ядро, поэтому самый быстрый способ гарантированно убрать DVB-S2-поток — это отключить кабели идущие с «тарелок». Благо сервер за стенкой, посему так тому и быть.

Självklart, om loggarna hade innehållit det som skulle finnas där så hade detta inte hänt, men mer om det, igen, i slutet av artikeln.

Jo, eftersom vi redan har tagit bort alla satellitsignaler kommer vi också att ta bort markbundna - samtidigt drar vi ut alla nätverkskablar. Servern blir avskuren från omvärlden och fungerar helt autonomt, men systemklockan har fortfarande bråttom.

Arbetsveckan är över, och själva datum/tid-frågan är inte kritisk, så du kan bara gå hem, men här gör jag ett nytt misstag.

Fel tre. Rådgivare

Aldrig! Ställ aldrig frågor på forum och allmänt specialiserade (a la stackoverflow) webbplatser om svaret på det kräver mer än att studera första sidan på Google och läsa en man-sida.

De kommer att skicka tillbaka dig till Google, läsa samma man och populärt förklara reglerna för forumet/sajten, men kommer inte att ge dig något svar.

Här är några objektiva faktorer:

  • ingen förutom du kan också känna till problemet;
  • ingen kan utföra tester under samma förhållanden som dina

och subjektivt:

  • du kanske inte ger all input för att lösa problemet, eftersom du redan har kommit på "rätt" riktning och presenterar kärnan i frågan med fokus på det;
  • förmannen (moderator, oldtimer, admin) har alltid rätt, om förmannen har fel... ja, du vet...

Если при ответных комментариях вы остались в рамках цензурной лексики, значит у вас крепкие нервы.

beslutet

Det finns ingen anledning att dela upp uppgifter i enkla och komplexa.

Vi slutar förlita oss på vår erfarenhet, statistik, rådgivare och börjar inte "förklara" slutresultatet, utan att konsekvent leta efter orsaken.

Eftersom någon ställer in tiden måste motsvarande systemanrop inträffa.

Precis som i mjukvarudokumentation är de bästa dokumenten källorna, så inom systemadministration är den bästa assistenten revision, i vårt fall granskas.

Ett ögonblick av tvivelЯ пробежался по манам, но не был до конца уверен, что время в Linux может устанавливаться только clock_settime и inställd tid på dagen, поэтому для первого теста выбрал все «подходящие» вызовы:

# 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

och kassering s390_runtime_instr, stime, timerfd_create, som auditctl не признал, изначально запустил аудит в виде:

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 att ha sett till att det inte finns några andra loggar på loggplatserna är jag intresserad av syscalls Förutom dessa två använde jag bara dem vidare.

Kör en systemsamtalsrevision clock_settime и inställd tid på dagen и пробуем сменить дату:

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

En femsekunders fördröjning läggs till så att vår "parasit" garanterat korrigerar tiden.

Låt oss se 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

Здесь мы видим наш datum и неизвестный нам chkcache_processer. Det hamnade i rapporten ovan eftersom aureport sorterade utdata efter datum vid konvertering från binär, och händelsen inträffade vid den tidpunkt vi ställde in datum -s "2019-08-22 12:10:00".
Vem födde honom?

# 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 - vår parasit har hittats. Trots dess "skadliga" beteende är det omöjligt att vägra systemet med villkorad tillgång, men jag skulle fortfarande vilja veta oscam, WTF?

Svaret hittas snabbt i källor:

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

Vad gulligt det ser ut här kommenterade ut строчка varning.

Källa: will.com

Lägg en kommentar