ProHoster > Blog > Administration > Je einfacher die Aufgabe, desto hÀufiger mache ich Fehler.

Je einfacher die Aufgabe, desto hÀufiger mache ich Fehler.

Je einfacher die Aufgabe, desto hÀufiger mache ich Fehler.

Diese triviale Aufgabe trat an einem der Freitage auf und sollte 2-3 Minuten dauern. Im Großen und Ganzen wie immer.

Ein Kollege bat mich, ein Skript auf seinem Server zu Ă€ndern. Ich habe es gemacht, ihm gegeben und beilĂ€ufig gesagt: „Die Zeit geht 5 Minuten vor.“ Es ist sein Server, soll er sich selbst um die Synchronisation kĂŒmmern. Eine halbe Stunde, eine Stunde verging, und er arbeitet immer noch und flucht leise.

„Dussel!“, dachte ich, wĂ€hrend ich auf die Konsole umschaltete. Server „Na gut, ich nehme mir noch ein paar Minuten.“

Schauen wir mal, ntp, rdate, sdwdate sind nicht installiert, timesyncd ist 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 möchte ich gleich anmerken, dass die Hardware-Zeit korrekt ist: daran lÀsst sich weiter orientieren.

Von hier aus begann eine Reihe von Fehlern.

Fehler Nummer eins. Übermut.

Klick, klick


# 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 bestens, die Zeit wurde synchronisiert, die Systemzeit stimmt mit der Hardware-Zeit ĂŒberein. „Nimm es“, sagte ich und kehrte zu meinen Aufgaben zurĂŒck.

„Was nimmst du? – empörte sich der Kollege. – Die Zeit ist die gleiche!“

Je mehr man standardisierte Aufgaben löst, desto mehr verengt sich das Denken, und man denkt nicht mehr daran, dass die hundertste oder tausendste Situation anders sein könnte, aber nicht diesmal.

# 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.

Versuchen wir es noch einmal:

# 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

Lass es uns anders machen:

# 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

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 einen Bruchteil einer Sekunde eingestellt und beginnt sofort wieder, „davon zu laufen“.

Im Log sehen wir jedoch zum Zeitpunkt dieser manuellen Änderung nur Berichte des Systems, dass die Zeit entsprechend in die richtige oder falsche Richtung geĂ€ndert wurde, und das nur selten. Synchronisieren von systemd-timesyncd.

25. Aug 21:18:51 wisi systemd[1]: Die Zeit wurde geÀndert
25. Aug 21:18:51 wisi systemd-timesyncd[29258]: Systemzeit geÀndert. Synchronisierung.
25. Aug 21:18:51 wisi systemd[1187]: Die Zeit wurde geÀndert
25. Aug 21:18:51 wisi systemd[1]: Die Zeit wurde geÀndert
25. Aug 21:18:51 wisi systemd[1187]: Die Zeit wurde geÀndert

hier

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

In diesem Moment hĂ€tte man bereits nach der Ursache suchen mĂŒssen, aber nach 18 Jahren im Admin-Bereich hat das Gehirn eine Statistik ĂŒber „Zeitfehler“ angesammelt und beschuldigt aus Gewohnheit erneut die Synchronisierung.
Wir deaktivieren diese vollstÀndig.

# 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

25. Aug 21:25:40 wisi systemd[1]: Die Zeit wurde geÀndert
25. Aug 21:25:40 wisi systemd[1187]: Die Zeit wurde geÀndert
25. Aug 21:29:30 wisi systemd[1]: Die Zeit wurde geÀndert
25. Aug 21:29:30 wisi systemd[1187]: Die Zeit wurde geÀndert

Synchronisieren ist verschwunden und die restlichen Logs sind makellos.

Wir ĂŒberprĂŒfen die Ausgaben tcpdump ĂŒber Port 123 an allen Schnittstellen. Es sind keine Anfragen vorhanden, aber die Zeit „lĂ€uft“ weiterhin davon.

Zweiter Fehler. Eile

Bis zum Ende der Arbeitswoche bleibt eine Stunde, aber mit einer ungelösten Aufgabe in schlechter Verfassung ins Wochenende zu gehen, möchte man nicht (beachten Sie nicht die Zeit im Code, der Artikel wurde an den folgenden Tagen geschrieben).
Statt nach der Ursache zu suchen, habe ich angefangen, mir eine ErklĂ€rung fĂŒr das Ergebnis auszudenken. Ich sage „ausdenken“, weil, egal wie logisch die ErklĂ€rungen auch sein mögen, es ein fehlerhafter Ansatz zur Problemlösung ist.

Dieser Server ist ein Streaming-Server und wandelt den DVB-S2-Stream in IP um. Im DVB-S-Stream sind Zeitstempel vorhanden, die von EmpfĂ€ngern, Multiplexern, EntschlĂŒsselern und Fernsehern hĂ€ufig zur Synchronisierung der Systemuhr verwendet werden. Die DVB-S-Treiber sind im Kernel kompiliert, daher ist der schnellste Weg, den DVB-S2-Stream sicher zu entfernen, die Kabel von den „SchĂŒsseln“ zu trennen. GlĂŒcklicherweise befindet sich der Server an der Wand, weshalb es so sein soll.

NatĂŒrlich hĂ€tte dies nicht passieren dĂŒrfen, wenn in den Logs das gestanden hĂ€tte, was dort stehen sollte, aber dazu spĂ€ter mehr am Ende des Artikels.

Da wir bereits alle Satellitensignale entfernt haben, entfernen wir auch die terrestrischen – wĂ€hrend wir alle Netzwerkkabel herausziehen. Der Server wird vom externen Netz abgeschnitten und arbeitet vollstĂ€ndig autonom, aber die Systemuhr lĂ€uft weiterhin vor.

Die Arbeitswoche ist vorbei und die Frage nach Datum/Zeit ist nicht kritisch, daher kann man einfach nach Hause gehen. Aber hier mache ich einen neuen Fehler.

Dritter Fehler. Ratgeber.

Stellen Sie niemals Fragen in Foren oder allgemein spezialisierten Websites (wie stackoverflow), wenn die Antwort dafĂŒr mehr als das Studium der Ergebnisse der ersten Google-Seite und das Lesen einer Man-Seite erfordert.

Sie werden zurĂŒck zu Google geschickt, um wieder das gleiche Man zu lesen, und man erklĂ€rt Ihnen die Regeln des Forums/der Website auf populĂ€re Weise, aber sie geben Ihnen keine Antwort.

Es gibt sowohl objektive Faktoren:

  • niemand außer Ihnen kann das Problem so gut kennen;
  • niemand kann Tests unter den gleichen Bedingungen wie Sie durchfĂŒhren;

natĂŒrlich gibt es auch subjektive:

  • Sie könnten nicht alle Informationen fĂŒr die Lösung des Problems bereitstellen, weil Sie bereits eine „richtige“ Richtung gefunden haben und den Kern des Problems darauf basierend prĂ€sentieren;
  • Der Ă€ltere (Moderator, Veteran, Admin) hat immer recht. Wenn der Ältere falsch ist... nun, Sie wissen schon...

Wenn Sie bei den Antwortkommentaren im Rahmen der zensierten Sprache geblieben sind, dann haben Sie starke Nerven.

Lösung

Es ist nicht notwendig, Aufgaben in einfache und komplexe zu unterteilen.

Wir verlassen uns nicht mehr auf unsere Erfahrung, Statistiken oder Berater, sondern beginnen, nicht das Endergebnis zu "erklÀren", sondern schrittweise nach der Ursache zu suchen.

Wenn jemand die Zeit festlegt, muss ein entsprechender Systemaufruf stattfinden.

Wie in der Softwaredokumentation die besten Dokumente die Quellcodes sind, so ist im Systemadministration die beste UnterstĂŒtzung das Audit, in unserem Fall auditd.

Ein Moment des ZweifelnsIch habe die Man Pages durchgesehen, war mir aber nicht ganz sicher, dass die Zeit in Linux nur ĂŒber clock_settime und settimeofday, gesetzt werden kann. Daher habe ich fĂŒr den ersten Test alle "passenden" Aufrufe gewĂ€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 habe verworfen s390_runtime_instr, stime, timerfd_create, die ich nicht erkannt habe. UrsprĂŒnglich habe ich das Audit in folgender Form gestartet: 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

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 hatte, dass es an den fĂŒr mich interessanten Stellen in den Logs keine weiteren syscalls außer diesen beiden gab, habe ich nur noch diese verwendet.

Wir starten das Audit der Systemaufrufe clock_settime und settimeofday und versuchen, 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

Eine fĂŒnfsekĂŒndige Verzögerung wurde hinzugefĂŒgt, damit unser „Parasit“ die Zeit zuverlĂ€ssig korrigiert.

Wir sehen 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 unser date und eine uns unbekannte chkcache_proces. Er erschien im oben genannten Bericht, da aureport die Ausgabe nach Datum sortiert hat, als er aus dem binÀren Format umgewandelt wurde, und das Ereignis zur festgelegten Zeit stattfand. date -s "2019-08-22 12:10:00".
Wer hat ihn erschaffen?

# 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 „schĂ€dlichen“ Verhaltens kann man vom Conditional Access System nicht absehen, aber wir möchten trotzdem wissen, oscam, WTF?

Die Antwort wurde schnell in den Quellen:

#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 schön sieht hier die auskommentierte Zeile warning’a


Quelle: habr.com

Kaufen Sie zuverlĂ€ssiges Hosting fĂŒr Websites mit DDoS-Schutz, VPS VDS-Server đŸ”„ Kaufen Sie zuverlĂ€ssiges Hosting fĂŒr Websites mit DDoS-Schutz, VPS VDS-Server | ProHoster