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

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

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

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

Колегата помоли да коригирам скрипта му на сървъра. Направих го, предадох му го и неволно казах: „Времето изостава с 5 минути“. Сървърът му да се справя с синхронизацията сам. Половин час, един час мина, а той все още се мъчи и тихо мърмори.

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

Гледаме, ntp, rdate, sdwdate не са инсталирани, timesyncd е изключен и не работи.

# 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

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

При това в логовете, по време на тази ръчна промяна, виждаме само отчети от системата, че времето е променено, съответно в правилната/неправилната посока и от време на време Resyncing от systemd-timesyncd.

Aug 25 21:18:51 wisi systemd[1]: Времето е променено
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: Системното време е променено. Ресинхронизиране.
Aug 25 21:18:51 wisi systemd[1187]: Времето е променено
Aug 25 21:18:51 wisi systemd[1]: Времето е променено
Aug 25 21:18:51 wisi systemd[1187]: Времето е променено

тук

# 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]: Времето е променено
Aug 25 21:25:40 wisi systemd[1187]: Времето е променено
Aug 25 21:29:30 wisi systemd[1]: Времето е променено
Aug 25 21:29:30 wisi systemd[1187]: Времето е променено

Resyncing липсва и в останалите логове е безупречно чисто.

Проверяваме изходите tcpdump по 123-ия порт на всички интерфейси. Никакви заявки няма, но времето пак „бяга“.

Грешка втора. Бързане

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

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

Разбира се, ако в логовете имаше това, което трябва да има, това нямаше да се случи, но за това, отново, в края на статията.

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

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

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

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

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

Тук има както обективни фактори:

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

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

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

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

Решение

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

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

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

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

Убедих се, че в интересуващите ме места в логовете няма други syscalls освен тези две, след това използвах само тях.

Започваме одит на системните извиквания 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

Тук виждаме нашия date и непознатия за нас chkcache_proces. Той се озова в отчета по-горе, тъй като aureport сортира изхода по дата при преобразуването от бинарен формат, а събитието се случи в установеното от нас време date -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");
}

Колко мило изглежда тук закоментираният ред warning’a…

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

Купете надежден хостинг за сайтове с защита от DDoS, VPS VDS сървъри 🔥 Купете надежден хостинг за сайтове с защита от DDoS, VPS VDS сървъри | ProHoster