ProHoster > Блог > администрация > Колкото по-проста е задачата, толкова по-често греша

Колкото по-проста е задачата, толкова по-често греша

Колкото по-проста е задачата, толкова по-често греша

Тази тривиална задача възникна един петък следобед и трябваше да отнеме 2-3 минути време. Общо взето както винаги.

Един колега ме помоли да оправя скрипта на неговия сървър. Направих го, подадох му го и неволно изпуснах: „Времето е 5 минути бързо.“ Нека сървърът сам да се справи със синхронизацията. Мина половин час, час, а той все пъхтеше и тихо ругаеше.

„Глупаво! — помислих си, превключвайки на сървърната конзола — добре, ще си взема почивка за още няколко минути.“

Да видим ntp, rdate, sdwdate не е инсталирано времесинкд деактивиран и не работи.

# 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

Тук веднага ще отбележа, че хардуерното време е правилно: ще бъде по-лесно да навигирате по-нататък.

Тук започна поредицата от грешки.

Първата грешка. Самоувереност

Щрак-клак...

# 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

Всичко е наред, времето е синхронизирано, системното време съвпада с хардуерното. „Вземи го“, казах и се върнах към работата си.

„Вземете какво? - възмути се колегата. „Все едно и също време!“

Колкото повече решавате типични проблеми, толкова повече вашето мислене става премигващо и вече не мислите, че стотната или хилядната ситуация ще бъде различна, но не и този път.

# 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

Системното време отново е грешно.

Нека опитаме отново:

# 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

Нека го направим по различен начин:

# 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

И така:

# 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

Времето е зададено за част от секундата и веднага започва да „бърза“ отново.

В същото време в регистрационните файлове по време на такава ръчна промяна виждаме само системни отчети, че времето се е променило съответно в правилната/грешната посока и от време на време Повторно синхронизиране от 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

тук

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

В този момент вече беше необходимо да се търси причината, но за 18 години администриране мозъкът натрупа статистика за грешки във „времето“ и по навик отново обвинява синхронизацията.
Нека го изключим напълно. 

# 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

и в дневниците

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

Повторно синхронизиране изчезна и иначе трупите са девствени.

Проверка на заключенията tcpdump на порт 123 на всички интерфейси. Няма заявки, но времето тече.

Грешка две. Втурвам се

Остава един час до края на работната седмица и не искам да тръгвам за уикенда с тривиален нерешен проблем (не обръщайте внимание на времето в кода, статията е написана през следващите дни ).
И тук отново, вместо да търся причината, започнах да се опитвам да измисля обяснение на резултата. Казвам „измисляне“, защото колкото и логично да е обяснението за резултата, това е погрешен подход за решаване на проблема.

Този сървър е стрийминг сървър и преобразува DVB-S2 потока в IP. DVB-S потокът съдържа времеви отпечатъци, така че приемниците, мултиплексорите, кодиращите устройства и телевизорите често ги използват за синхронизиране на системния часовник. Драйверите на DVB-S платката са вградени в ядрото, така че най-бързият начин да се гарантира, че DVB-S2 потокът е премахнат, е да изключите кабелите, идващи от „плочите“. За щастие, сървърът е зад стената, така да бъде.

Разбира се, ако дневниците съдържаха това, което трябваше да има, това нямаше да се случи, но повече за това отново в края на статията.

Е, тъй като вече премахнахме всички сателитни сигнали, ще премахнем и наземните - в същото време изваждаме всички мрежови кабели. Сървърът се откъсва от външния свят и работи напълно автономно, но системният часовник все още бърза.

Работната седмица свърши и самият проблем с датата/часа не е критичен, така че можете просто да се приберете, но тук допускам нова грешка.

Грешка трета. съветници

Никога! Никога не задавайте въпроси във форуми и общи специализирани (a la stackoverflow) сайтове, ако отговорът на тях изисква повече от изучаване на първата страница на Google и четене на една страница с ръководство.

Ще те върнат обратно в гугъл, ще прочетат същия човек и ще ти обяснят популярно правилата на форума/сайта, но няма да ти дадат отговор.

Ето някои обективни фактори:

  • никой освен вас не може да знае проблема;
  • никой не може да провежда тестове при същите условия като вашите

и субективно:

  • може да не дадете целия принос за решаването на проблема, защото вече сте измислили „правилната“ посока и представяте същността на проблема, като се фокусирате върху него;
  • бригадирът (модератор, старец, админ) винаги е прав, ако бригадирът греши... е, нали знаеш...

Ако, отговаряйки на коментари, сте останали в границите на цензурирания речник, значи имате здрави нерви.

Решение

Няма нужда да разделяте задачите на прости и сложни.

Спираме да разчитаме на нашия опит, статистика, съветници и започваме не да „обясняваме“ крайния резултат, а последователно да търсим причината.

Тъй като някой задава времето, трябва да се извърши съответното системно извикване.

Както в софтуерната документация най-добрите документи са източниците, така и в системната администрация най-добрият помощник е одитът, в нашия случай auditd.

Момент на съмнениеМинах през мана, но не бях напълно сигурен, че времето в Linux може да се настройва само clock_settime и settimeofday, така че за първия тест избрах всички „подходящи“ обаждания:

# 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

и изхвърляне s390_runtime_instr, stime, timerfd_create, който 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

След като се уверя, че няма други регистрационни файлове в местоположенията на регистрационни файлове, които ме интересуват системни извиквания Освен тези двете, само тях използвах по-нататък.

Изпълнение на одит на системно повикване clock_settime и settimeofday и опитайте да промените датата:

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

Добавя се забавяне от пет секунди, така че нашият „паразит“ гарантирано ще коригира времето.

Нека да разгледаме доклада:

# 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

Тук виждаме нашите дата и непознати за нас chkcache_processes. Попадна в горния отчет, защото aureport сортира изхода по дата при преобразуване от двоичен код и събитието се случи в зададения от нас час дата -s "2019-08-22 12:10:00".
Кой го е родил?

# 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 - нашият паразит е открит. Въпреки „злонамереното“ поведение е невъзможно да се откаже системата за условен достъп, но все пак бих искал да знам oscam, WTF?

Отговорът бързо се намира в източници:

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

Колко сладко изглежда тук коментира линия внимание...

Източник: www.habr.com

Добавяне на нов коментар