Je einfacher die Aufgabe, desto häufiger mache ich Fehler

Je einfacher die Aufgabe, desto häufiger mache ich Fehler

Diese triviale Aufgabe entstand an einem Freitagnachmittag und hätte 2-3 Minuten Zeit in Anspruch nehmen sollen. Im Allgemeinen wie immer.

Ein Kollege hat mich gebeten, das Skript auf seinem Server zu reparieren. Ich tat es, reichte es ihm und ließ versehentlich fallen: „Die Zeit ist 5 Minuten schnell.“ Lassen Sie den Server die Synchronisierung selbst durchführen. Eine halbe Stunde, eine Stunde verging, und er schnaufte immer noch und fluchte leise.

"Dumm! – dachte ich, als ich zur Serverkonsole wechselte – okay, ich mache noch ein paar Minuten Pause.“

Aussehen ntp, rdate, sdwdate nicht installiert Zeitsynchronisation deaktiviert und läuft nicht.

# 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

Hier fällt mir sofort auf, dass die Hardware-Zeit stimmt: Es wird einfacher, weiter zu navigieren.

Hier begann die Fehlerserie.

Der erste Fehler. Selbstvertrauen

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

Alles ist in Ordnung, die Zeit ist synchronisiert, die Systemzeit stimmt mit der Hardwarezeit überein. „Nimm es“, sagte ich und kehrte zu meinem Geschäft zurück.

"Nimm was? - Der Kollege war empört. „Es ist die gleiche Zeit!“

Je mehr Sie typische Probleme lösen, desto mehr wird Ihr Denken engmaschiger und Sie glauben nicht mehr, dass die hundertste oder tausendste Situation anders sein wird, aber dieses Mal nicht.

# 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

Die Systemzeit ist wieder falsch.

Lass es uns erneut versuchen:

# 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

Machen wir es anders:

# 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

Und hier so:

# 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

Die Zeit wird auf den Bruchteil einer Sekunde eingestellt und beginnt sofort wieder zu „rasen“.

Gleichzeitig sehen wir in den Protokollen zum Zeitpunkt einer solchen manuellen Änderung nur Systemmeldungen, dass sich die Zeit jeweils in die richtige/falsche Richtung und gelegentlich geändert hat Erneut synchronisieren von 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

hier

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

Zu diesem Zeitpunkt war es bereits notwendig, nach der Ursache zu suchen, aber im Laufe der 18-jährigen Verwaltung hat das Gehirn Statistiken über „Zeitfehler“ gesammelt und gibt aus Gewohnheit erneut der Synchronisation die Schuld.
Schalten wir es komplett aus.

# 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

und in den Protokollen

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

Erneut synchronisieren verschwunden und ansonsten sind die Protokolle makellos.

Überprüfung der Schlussfolgerungen tcpdump auf Port 123 auf allen Schnittstellen. Es gibt keine Anfragen, aber die Zeit rennt trotzdem davon.

Fehler zwei. Eilen

Bis zum Ende der Arbeitswoche bleibt noch eine Stunde, und ich möchte nicht mit einem trivialen ungelösten Problem ins Wochenende gehen (achten Sie nicht auf die Zeit im Code, der Artikel wurde in den folgenden Tagen geschrieben). ).
Und auch hier begann ich, anstatt nach dem Grund zu suchen, eine Erklärung für das Ergebnis zu finden. Ich sage „erfinden“, denn egal wie logisch die Erklärung für das Ergebnis auch sein mag, es ist ein fehlerhafter Ansatz zur Lösung des Problems.

Dieser Server ist ein Streaming-Server und wandelt den DVB-S2-Stream in IP um. Der DVB-S-Stream enthält Zeitstempel, daher verwenden Receiver, Multiplexer, Scrambler und Fernseher diese häufig zur Synchronisierung der Systemuhr. DVB-S-Kartentreiber sind im Kernel integriert. Der schnellste Weg, um sicherzustellen, dass der DVB-S2-Stream entfernt wird, besteht darin, die von den „Platten“ kommenden Kabel zu trennen. Glücklicherweise ist der Server hinter der Wand, also sei es so.

Wenn die Protokolle das enthalten hätten, was dort sein sollte, wäre dies natürlich nicht passiert, aber mehr dazu am Ende des Artikels.

Nun, da wir bereits alle Satellitensignale entfernt haben, werden wir auch die terrestrischen entfernen – gleichzeitig ziehen wir alle Netzwerkkabel heraus. Der Server wird von der Außenwelt abgeschnitten und arbeitet völlig autonom, die Systemuhr ist jedoch immer noch in Eile.

Die Arbeitswoche ist vorbei und das Datum/Uhrzeit-Problem selbst ist nicht kritisch, Sie können also einfach nach Hause gehen, aber hier mache ich einen neuen Fehler.

Fehler drei. Berater

Niemals! Stellen Sie niemals Fragen in Foren und allgemeinen Spezialseiten (à la Stackoverflow), wenn die Antwort darauf mehr erfordert als das Studium der ersten Seite von Google und das Lesen einer Manpage.

Sie werden Sie zu Google zurückschicken, denselben Mann lesen und im Volksmund die Regeln des Forums/der Website erklären, Ihnen aber keine Antwort geben.

Hier sind einige objektive Faktoren:

  • Niemand außer Ihnen kann das Problem auch kennen;
  • Niemand kann Tests unter den gleichen Bedingungen wie bei Ihnen durchführen

und subjektiv:

  • Möglicherweise geben Sie nicht den gesamten Input zur Lösung des Problems, weil Sie bereits die „richtige“ Richtung gefunden haben und den Kern des Problems darlegen, indem Sie sich darauf konzentrieren.
  • Der Vorarbeiter (Moderator, Oldtimer, Admin) hat immer Recht, wenn der Vorarbeiter Unrecht hat ... na ja, wissen Sie ...

Wenn Sie bei der Beantwortung von Kommentaren innerhalb der Grenzen des zensierten Vokabulars geblieben sind, dann haben Sie starke Nerven.

Lösung

Es besteht keine Notwendigkeit, Aufgaben in einfache und komplexe Aufgaben zu unterteilen.

Wir verlassen uns nicht mehr auf unsere Erfahrungen, Statistiken und Berater und beginnen nicht, das Endergebnis zu „erklären“, sondern konsequent nach der Ursache zu suchen.

Da jemand die Zeit einstellt, muss der entsprechende Systemaufruf erfolgen.

So wie in der Softwaredokumentation die besten Dokumente die Quellen sind, so ist in der Systemadministration in unserem Fall das Audit der beste Assistent geprüft.

Ein Moment des ZweifelsIch bin das Mana durchgegangen, war mir aber nicht ganz sicher, dass die Zeit unter Linux nur eingestellt werden kann clock_settime и Tageszeit einstellen, also habe ich für den ersten Test alle „passenden“ Aufrufe ausgewählt:

# 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

und verwerfen s390_runtime_instr, stime, timerfd_createwelche auditctl erkannte es nicht und startete zunächst ein Audit in der Form:

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

Nachdem ich sichergestellt habe, dass sich an den für mich interessanten Protokollspeicherorten keine anderen Protokolle befinden Systemaufrufe Außer diesen beiden habe ich nur sie weiter verwendet.

Ausführen einer Systemaufrufprüfung clock_settime и Tageszeit einstellen und versuchen Sie, das Datum zu ändern:

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

Damit unser „Parasit“ garantiert die Zeit korrigiert, wird eine Verzögerung von fünf Sekunden hinzugefügt.

Wir schauen uns den Bericht an:

# 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

Hier sehen wir unsere Datum und uns unbekannt chkcache_processes. Es landete im obigen Bericht, weil aureport die Ausgabe bei der Konvertierung vom Binärformat nach Datum sortierte und das Ereignis zum von uns festgelegten Zeitpunkt auftrat date -s „2019 08:22:12“.
Wer hat ihn geboren?

# 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 - Unser Parasit wurde gefunden. Trotz seines „böswilligen“ Verhaltens ist es unmöglich, das Zugangskontrollsystem abzulehnen, aber ich würde es trotzdem gerne wissen Oscam, WTF?

Die Antwort ist schnell gefunden Quellcodes:

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

Wie süß es hier aussieht auskommentiert Linie Warnung...

Source: habr.com

Kommentar hinzufügen