Debugging der Softwarebereitstellung mit strace

Meine Haupttätigkeit besteht größtenteils aus dem Deployen von Software-Systemen, das heißt, ich verbringe viel Zeit damit, solche Fragen zu beantworten:

• Auf dem Rechner des Entwicklers funktioniert die Software, aber auf meinem nicht. Warum?
• Gestern lief die Software auf meinem Rechner, heute nicht. Warum?

Das ist eine Art von Debugging, das sich etwas von herkömmlichem Debugging unterscheidet. Herkömmliches Debugging bezieht sich auf die Logik des Codes, während das Deployment-Debugging das Zusammenspiel zwischen dem Code und der Umgebung betrifft. Selbst wenn die Wurzel des Problems ein logischer Fehler ist, bedeutet die Tatsache, dass es auf einer Maschine funktioniert und auf einer anderen nicht, dass es irgendwie an der Umgebung liegt.

Deshalb habe ich anstelle gewöhnlicher Debugging-Tools wie gdb ein anderes Set von Tools für das Deployment-Debugging. Und mein Lieblingstool zur Lösung des Problems „Warum funktioniert diese Software auf meinem Rechner nicht?“ nennt sich strace.

Was ist also strace?

strace — es ist ein Tool zur „Verfolgung von Systemaufrufen“. Ursprünglich für Linux entwickelt, können ähnliche Debugging-Tricks auch mit Tools für andere Systeme betrieben werden (DTrace oder ktrace).

Die Hauptanwendung ist ganz einfach. Man muss lediglich strace mit jedem Befehl ausführen, und es erstellt ein Dump aller Systemaufrufe (obwohl man wahrscheinlich zuerst die Software installieren muss) strace):

$ strace echo Hello
...Snip lots of stuff...
write(1, "Hellon", 6)                  = 6
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

Was sind das für Systemaufrufe? Es ist eine Art API für den Kernel des Betriebssystems. Früher hatte die Software direkten Zugriff auf die „Hardware“, auf der sie lief. Wenn man beispielsweise etwas auf dem Bildschirm darstellen wollte, interagierte sie direkt mit den Ports oder den im Speicher abgebildeten Registern für Videogeräte. Als Mehrbenutzersysteme populär wurden, herrschte Chaos, weil verschiedene Anwendungen um den Zugriff auf die „Hardware“ kämpften. Fehler in einer Anwendung konnten den Betrieb anderer Anwendungen stören oder sogar das gesamte System zum Absturz bringen. Daher wurden im CPU Privilegienlevel (oder „Ring-Schutz“) eingeführt. Das privilegierteste Element ist der Kernel: er hatte vollständigen Zugriff auf die „Hardware“ und erzeugte weniger privilegierte Anwendungen, die bei der Interaktion mit der „Hardware“ den Zugang vom Kernel anfragen mussten — durch Systemaufrufe.

Auf binärer Ebene unterscheidet sich der Systemaufruf etwas von einem einfachen Funktionsaufruf, jedoch verwenden die meisten Programme eine Wrapper-Bibliothek aus der Standardbibliothek. D.h. die Standardbibliothek POSIX C enthält den Funktionsaufruf write(), der gesamten architekturabhängigen Code für Systemaufrufe enthält. schreiben.

Kurz gesagt, jede Interaktion einer Anwendung mit ihrer Umgebung (Computersystemen) erfolgt über Systemaufrufe. Wenn Software auf einer Maschine funktioniert und auf einer anderen nicht, ist es ratsam, die Ergebnisse der Systemaufrufverfolgung zu überprüfen. Genauer gesagt, hier ist eine Liste typischer Punkte, die man durch Systemaufrufverfolgung analysieren kann:

• Konsoleneingabe- und -ausgabe
• Netzwerkeingabe- und -ausgabe
• Zugriff auf das Dateisystem und Dateieingabe- und -ausgabe
• Verwaltung der Lebensdauer von Prozess-Threads
• Niedrigstufige Speicherverwaltung
• Zugriff auf spezielle Gerätetreiber

Wann sollte man strace verwenden?

In der Theorie strace wird es mit allen Programmen im Benutzerspeicher verwendet, denn jedes Programm im Benutzerspeicher muss Systemaufrufe tätigen. Es funktioniert effektiver mit kompilierbaren, niedrigstufigen Programmen, aber auch mit hochgradig abstrahierten Sprachen wie Python, sofern man sich durch den zusätzlichen Lärm der Laufzeitumgebung und des Interpreters hindurchkämpfen kann.

In voller Pracht strace zeigt es sich während der Fehlersuche in Software, die auf einer Maschine gut funktioniert, auf einer anderen jedoch plötzlich nicht mehr läuft und unklare Fehlermeldungen zu Dateien, Berechtigungen oder gescheiterten Versuchen, bestimmte Befehle auszuführen, liefert… Schade, aber es harmoniert nicht so gut mit hochgradigen Problemen wie der Überprüfung von Zertifikaten. Üblicherweise erfordert es hier eine Kombination strace, manchmal ltrace und Werkzeugen höheren Niveaus (wie einem Befehlszeilenwerkzeug openssl zur Zertifikatsüberprüfung).

Um ein Beispiel zu nennen, nehmen wir die Arbeit auf einem isolierten Server, aber die Systemaufrufverfolgung kann oft auch auf komplexeren Bereitstellungsplattformen durchgeführt werden. Man muss nur das passende Werkzeug finden.

Beispiel für einfaches Debugging

Angenommen, Sie möchten die fantastische Serveranwendung foo starten, und erhalten folgendes:

$ foo
Fehler beim Öffnen der Konfigurationsdatei: Datei oder Verzeichnis nicht gefunden

Offensichtlich ist es ihm nicht gelungen, die von Ihnen erstellte Konfigurationsdatei zu finden. Das passiert manchmal, weil Paketmanager beim Kompilieren von Anwendungen den erwarteten Speicherort von Dateien überschreiben. Wenn man den Installationsanleitungen für eine Distribution folgt, findet man in einer anderen die Dateien oft an ganz anderen Orten, als man es erwartet. Das Problem könnte in wenigen Sekunden gelöst werden, wenn die Fehlermeldung sagen würde, wo man die Konfigurationsdatei suchen sollte, aber sie sagt es nicht. Wo also suchen?

Wenn der Quellcode zugänglich ist, kann man ihn lesen und alles herausfinden. Ein guter Backup-Plan, aber nicht die schnellste Lösung. Man könnte einen schrittweisen Debugger wie verwenden, gdb um zu sehen, was das Programm tut, aber es ist viel effizienter, ein Werkzeug zu verwenden, das speziell dafür entwickelt wurde, um die Interaktion mit der Umgebung anzuzeigen: strace.

Ausgabe strace mag überflüssig erscheinen, aber die gute Nachricht ist, dass man den größten Teil davon getrost ignorieren kann. Es ist oft hilfreich, den -o-Operator zu verwenden, um die Trace-Ergebnisse in einer separaten Datei zu speichern:

$ strace -o /tmp/trace foo
Fehler beim Öffnen der Konfigurationsdatei: Datei oder Verzeichnis nicht gefunden
$ cat /tmp/trace
execve("foo", ["foo"], 0x7ffce98dc010 /* 16 vars */) = 0
brk(NULL) = 0x56363b3fb000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=25186, ...}) = 0
mmap(NULL, 25186, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2f12cf1000
close(3) = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "177ELF2113 3 > 1 260A2 "..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2f12cef000
mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f2f12b2e000
mprotect(0x7f2f12b50000, 1658880, PROT_NONE) = 0
mmap(0x7f2f12b50000, 1343488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f2f12b50000
mmap(0x7f2f12c98000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7f2f12c98000
mmap(0x7f2f12ce5000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f2f12ce5000
mmap(0x7f2f12ceb000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f2f12ceb000
close(3) = 0
arch_prctl(ARCH_SET_FS, 0x7f2f12cf0500) = 0
mprotect(0x7f2f12ce5000, 16384, PROT_READ) = 0
mprotect(0x56363b08b000, 4096, PROT_READ) = 0
mprotect(0x7f2f12d1f000, 4096, PROT_READ) = 0
munmap(0x7f2f12cf1000, 25186) = 0
openat(AT_FDCWD, "/etc/foo/config.json", O_RDONLY) = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
dup(2) = 3
fcntl(3, F_GETFL) = 0x2 (flags O_RDWR)
brk(NULL) = 0x56363b3fb000
brk(0x56363b41c000) = 0x56363b41c000
fstat(3, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0x8), ...}) = 0
write(3, "Fehler beim Öffnen der Konfigurationsdatei"..., 60) = 60
close(3) = 0
exit_group(1) = ?
+++ mit 1 beendet +++

Ungefähr die gesamte erste Seite der Ausgabe strace — das ist normalerweise eine niederwertige Vorbereitung zum Starten. (Viele Aufrufe mmap, mprotect, brk für Dinge wie die Erkennung von niederwertigem Speicher und das Laden von dynamischen Bibliotheken.) Eigentlich, während des Debuggens sind die Ausgaben strace am besten von unten nach oben zu lesen. Am Ende wird ein Aufruf schreiben, der eine Fehlermeldung ausgibt. Schauen wir nach oben und sehen den ersten fehlerhaften Systemaufruf — den Aufruf openat, der den Fehler ausgibt ENOENT ( /etc/foo/config.json). Hier sollte die Konfigurationsdatei liegen.

Das war nur ein Beispiel, aber ich würde sagen, dass ich 90 % der Zeit, in der ich benutze strace, nichts viel komplizierteres machen muss. Unten ist eine vollständige Schritt-für-Schritt-Anleitung zum Debuggen:

• Sich über die unklare Fehlermeldung einer Systemfehler von der Anwendung ärgern
• Das Programm neu starten mit strace
• In den Trace-Ergebnissen die Fehlermeldung suchen
• Nach oben gehen, bis man auf den ersten fehlgeschlagenen Systemaufruf stößt

Es ist sehr wahrscheinlich, dass der Systemaufruf im 4. Schritt zeigt, was schiefgegangen ist.

Hinweise

Bevor ich ein Beispiel für ein komplexeres Debugging zeige, möchte ich Ihnen einige Tipps für eine effektive Nutzung geben. strace:

man — Ihr Freund

Auf vielen *nix-Systemen können Sie die vollständige Liste der Systemaufrufe an den Kernel erhalten, indem Sie folgendes ausführen: man syscalls. Sie werden Dinge wie sehen brk(2), was bedeutet, dass Sie mehr Informationen erhalten können, indem Sie man 2 brk.

Kleine Stolpersteine: man 2 fork zeigt mir die Seite für die fork() in GNU libc, die anscheinend durch den Aufruf umgesetzt wird clone(). Die Semantik des Aufrufs fork bleibt gleich, wenn Sie ein Programm schreiben, das verwendet fork(), und die Nachverfolgung ausführen — ich werde keine Aufrufe finden fork, stattdessen werden es clone(). Solche Stolpersteine verwirren nur, wenn man beginnt, den Quellcode mit der Ausgabe zu vergleichen. strace.

Verwenden Sie -o, um die Ausgabe in einer Datei zu speichern.

strace Kann umfangreiche Ausgaben generieren, daher ist es oft nützlich, die Ergebnisse der Nachverfolgung in separaten Dateien zu speichern (wie im obigen Beispiel). Das hilft auch, die Programm-Ausgabe nicht mit der Ausgabe strace in der Konsole zu verwechseln.

Verwenden Sie -s, um mehr Daten des Arguments anzuzeigen.

Sie haben sicherlich bemerkt, dass die zweite Hälfte der Fehlermeldung im obigen Beispiel der Nachverfolgung nicht angezeigt wird. Das liegt daran, dass strace standardmäßig nur die ersten 32 Bytes der Argument-String zeigt. Wenn Sie mehr sehen möchten, fügen Sie etwas wie hinzu -s 128 zum Aufruf. strace.

-u erleichtert das Nachverfolgen von Dateien, Sockets usw.

„Alles ist eine Datei“ bedeutet, dass *nix-Systeme alle Ein- und Ausgaben unter Verwendung von Dateideskriptoren durchführen, unabhängig davon, ob es sich um eine Datei, ein Netzwerk oder interprozessuale Kanäle handelt. Das ist bequem für die Programmierung, aber es erschwert es, zu verfolgen, was wirklich passiert, wenn Sie gängige lesen und schreiben in den Ergebnissen der Systemaufruf-Nachverfolgung sehen.

Indem Sie den Operator -uhinzufügen, zwingen Sie strace eine Anmerkung für jeden Dateideskriptor in der Ausgabe anzufügen, worauf er zeigt.

Schließen Sie sich mit -p einem bereits laufenden Prozess an.

Wie im folgenden Beispiel zu sehen ist, muss man manchmal ein Programm nachverfolgen, das bereits läuft. Wenn bekannt ist, dass es als Prozess 1337 läuft (sagen wir, aus Ausgaben von ps), können Sie es so nachverfolgen:

$ strace -p 1337
...Systemaufruf-Nachverfolgungsausgabe...

Möglicherweise benötigen Sie root-Rechte.

Verwenden Sie -f, um die untergeordneten Prozesse zu überwachen.

strace Standardmäßig wird nur ein Prozess nachverfolgt. Wenn dieser Prozess jedoch untergeordnete Prozesse erzeugt, können Sie den Systemaufruf zur Erzeugung des untergeordneten Prozesses sehen, aber die Systemaufrufe des untergeordneten Prozesses werden nicht angezeigt.

Wenn Sie glauben, der Fehler liegt im untergeordneten Prozess, verwenden Sie den Operator -f, das aktivieren Sie dessen Nachverfolgung. Der Nachteil dabei ist, dass die Ausgabe Sie noch mehr verwirren kann. Wenn strace ein Prozess oder ein Zweig nachverfolgt wird, zeigt es einen einheitlichen Fluss von Ereignissen und Aufrufen. Wenn gleichzeitig mehrere Prozesse nachverfolgt werden, sehen Sie möglicherweise den Anfang eines Aufrufs, der durch eine Nachricht unterbrochen wird <unfinished …>, gefolgt von einer Reihe von Aufrufen für andere Ausführungszweige, und erst dann das Ende des ersten mit <… foocall resumed>. Oder trennen Sie alle Nachverfolgungsergebnisse in verschiedene Dateien, indem Sie auch den Operator verwenden -ff (Details siehe in Handbuch nach strace).

Filtern Sie die Nachverfolgung mit -e

Wie Sie sehen können, besteht das Ergebnis der Nachverfolgung aus einer Menge aller möglichen Systemaufrufe. Mit der Flagge -e kann die Nachverfolgung gefiltert werden (siehe Anleitung nach strace). Der Hauptvorteil besteht darin, dass das Ausführen der Nachverfolgung mit Filterung schneller ist, als eine vollständige Nachverfolgung durchzuführen und dann grep` zu analysieren. Um ehrlich zu sein, ist mir das fast immer egal.

Nicht alle Fehler sind schlecht

Ein einfaches und verbreitetes Beispiel ist ein Programm, das nach einer Datei an mehreren Stellen sucht, ähnlich wie eine Shell, die sucht, in welchem Papierkorbverzeichnis sich die ausführbare Datei befindet:

$ strace sh -c uname
...
stat("/home/user/bin/uname", 0x7ffceb817820) = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
stat("/usr/local/bin/uname", 0x7ffceb817820) = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
stat("/usr/bin/uname", {st_mode=S_IFREG|0755, st_size=39584, ...}) = 0
...

Heuristik des Typs „letzte fehlgeschlagene Anfrage vor der Fehlermeldung“ ist gut geeignet, um relevante Fehler zu finden. Wie auch immer, es ist sinnvoll, am Ende zu beginnen.

Die Dokumentation zu Programmierung in C hilft dabei, Systemaufrufe gut zu verstehen.

Standardbibliotheksaufrufe in C sind keine Systemaufrufe, sondern nur eine dünne Oberflächenschicht. Wenn Sie also ein wenig verstehen, wie und was in C zu tun ist, wird es Ihnen leichter fallen, die Ergebnisse der Systemaufrufnachverfolgung zu durchdringen. Wenn Sie beispielsweise Probleme bei der Fehlersuche bei Aufrufen an Netzwerkframeworks haben, schauen Sie sich das klassische „Netzwerkprogrammierungs-Handbuch“ von Keith Biddle an..

Ein komplizierterer Debugging-Beispiel

Ich habe bereits gesagt, dass ein einfaches Debugging-Beispiel ein Beispiel dafür ist, womit ich es größtenteils in der Arbeit mit strace. Manchmal ist jedoch eine richtige Untersuchung erforderlich, also hier ein tatsächliches Beispiel für aufwändigeres Debugging.

bcron — ein Job-Planer, eine weitere Implementierung eines *nix-Daemons. CronEr ist auf dem Server installiert, aber wenn jemand versucht, den Zeitplan zu bearbeiten, passiert Folgendes:

# crontab -e -u logs
bcrontab: Fatal: Could not create temporary file

Okay, also bcron hat versucht, eine Datei zu schreiben, aber es hat nicht geklappt, und er gibt nicht zu, warum. Lassen Sie uns herausfinden, strace:

# strace -o /tmp/trace crontab -e -u logs
bcrontab: Fatal: Could not create temporary file
# cat /tmp/trace
...
openat(AT_FDCWD, "bcrontab.14779.1573691864.847933", O_RDONLY) = 3
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
read(3, "#Ansible: logsaggn20 14 * * * lo"..., 8192) = 150
read(3, "", 8192)                       = 0
munmap(0x7f82049b4000, 8192)            = 0
close(3)                                = 0
socket(AF_UNIX, SOCK_STREAM, 0)         = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/bcron-spool"}, 110) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
write(3, "156:Slogs #Ansible: logsaggn20 1"..., 161) = 161
read(3, "32:ZCould not create temporary f"..., 8192) = 36
munmap(0x7f82049b4000, 8192)            = 0
close(3)                                = 0
write(2, "bcrontab: Fatal: Could not creat"..., 49) = 49
unlink("bcrontab.14779.1573691864.847933") = 0
exit_group(111)                         = ?
+++ exited with 111 +++

Gegen Ende gibt es einen Fehlerbericht schreiben, aber diesmal ist etwas anders. Erstens gibt es keinen relevanten Fehler des Systemaufrufs, der normalerweise davor auftritt. Zweitens sieht es so aus, als hätte schon jemand die Fehlermeldung gelesen. Es scheint, als läge das eigentliche Problem woanders, während bcrontab einfach die Meldung wiederholt.

Wenn man sich die man 2 readanschaut, sieht man, dass das erste Argument (3) ein Dateideskriptor ist, den *nix für alle Ein- und Ausgabevorgänge verwendet. Wie kann man herausfinden, was der Dateideskriptor 3 repräsentiert? In diesem speziellen Fall kann man strace mit dem Operator -u (siehe oben) ausführen, und er wird automatisch erzählen, jedoch ist es hilfreich zu wissen, wie man solche Dinge liest und die Trace-Ergebnisse analysiert.

Die Quelle des Dateideskriptors kann einer von vielen Systemaufrufen sein (es hängt davon ab, wofür der Deskriptor gedacht ist — für die Konsole, einen Netzwerk-Socket, eine Datei oder etwas anderes), aber wie dem auch sei, wir suchen die Aufrufe, die 3 zurückgeben (d.h. wir suchen «= 3» in den Trace-Ergebnissen). In diesem Ergebnis gibt es 2: openat ganz oben und socket in der Mitte. openat öffnet die Datei, aber schließen(3) zeigt danach, dass sie wieder geschlossen wird. (Achtung: Dateideskriptoren können wiederverwendet werden, wenn sie geöffnet und geschlossen werden). Der Aufruf socket() passt, da er der letzte vor read()ist, und es scheint, dass bcrontab mit etwas über einen Socket arbeitet. Die nächste Zeile zeigt, dass der Dateideskriptor mit unix domain socket über den Pfad verbunden ist. /var/run/bcron-spool.

Also, man muss den Prozess finden, der an unix socket auf der anderen Seite gebunden ist. Dafür gibt es ein paar elegante Tricks, und beide werden nützlich sein, um die Serverbereitstellungen zu debuggen. Der erste ist, netstat oder neuer ss (Socket-Status). Beide Befehle zeigen aktive Netzwerkverbindungen des Systems und nehmen den Operator -l zur Beschreibung von hörenden Sockets sowie den Operator -p zur Anzeige von Programmen, die als Clients mit dem Socket verbunden sind. (Es gibt wesentlich mehr nützliche Optionen, aber für diese Aufgabe sind diese beiden ausreichend.)

# ss -pl | grep /var/run/bcron-spool
u_str LISTEN 0   128   /var/run/bcron-spool 1466637   * 0   users:(("unixserver",pid=20629,fd=3))

Das zeigt, dass das hörende — ein Befehl ist inixserver, der mit der Prozess-ID 20629 arbeitet. (Und zufällig verwendet es Dateideskriptor 3 als Socket.)

Ein zweites wirklich nützliches Werkzeug, um die gleichen Informationen zu finden, heißt lsof. Es listet alle geöffneten Dateien (oder Dateideskriptoren) im System auf. Alternativ kann man auch Informationen über eine bestimmte Datei erhalten:

# lsof /var/run/bcron-spool
COMMAND   PID   USER  FD  TYPE  DEVICE              SIZE/OFF  NODE    NAME
unixserve 20629 cron  3u  unix  0x000000005ac4bd83  0t0       1466637 /var/run/bcron-spool type=STREAM

Der Prozess 20629 ist ein langlebiger Server, sodass man ihn mit strace unter Verwendung von etwas wie strace -o /tmp/trace -p 20629. Wenn man den Cron-Job in einem anderen Terminal bearbeitet, erhält man die Ausgabe der Trace-Ergebnisse mit dem auftretenden Fehler. Und hier ist das Ergebnis:

accept(3, NULL, NULL)                   = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21181
close(4)                                = 0
accept(3, NULL, NULL)                   = ? ERESTARTSYS (Wird neu gestartet, wenn SA_RESTART gesetzt ist)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21181, si_uid=998, si_status=0, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG|WSTOPPED, NULL) = 21181
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (Keine Kindprozesse)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]})                 = 43
accept(3, NULL, NULL)                   = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21200
close(4)                                = 0
accept(3, NULL, NULL)                   = ? ERESTARTSYS (Wird neu gestartet, wenn SA_RESTART gesetzt ist)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21200, si_uid=998, si_status=111, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 111}], WNOHANG|WSTOPPED, NULL) = 21200
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (Keine Kindprozesse)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]})                 = 43
accept(3, NULL, NULL

(Der letzte accept() wird bei der Tracierung nicht beendet.) Leider enthält dieses Ergebnis wieder nicht den Fehler, den wir suchen. Wir sehen keine Nachrichten, die bcrontag an den Socket sendet oder von ihm empfängt. Stattdessen gibt es nur die Prozesskontrolle (clone, wait4, SIGCHLD Und so weiter.) Dieser Prozess erzeugt einen Tochterprozess, der, wie man erraten kann, die eigentliche Arbeit verrichtet. Und wenn man ihren Verlauf verfolgen muss, fügen Sie dem Aufruf hinzu strace -f. Das ist, was wir finden werden, wenn wir im neuen Ergebnis mit strace nach einer Fehlermeldung suchen -f -o /tmp/trace -p 20629:

21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Zugriff verweigert) 
21470 write(1, "32:ZKonnte temporäre Datei nicht erstellen"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: Protokolle:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
21470 exit_group(111)                   = ?
21470 +++ mit 111 beendet +++

Hier, das ist schon etwas. Der Prozess 21470 erhält den Fehler „Zugriff verweigert“, als er versucht, eine Datei unter dem Pfad tmp/spool.21470.1573692319.854640 zu erstellen (bezogen auf das aktuelle Arbeitsverzeichnis). Wenn wir nur das aktuelle Arbeitsverzeichnis wüssten, würden wir den vollständigen Pfad kennen und herausfinden, warum der Prozess seine temporäre Datei nicht erstellen kann. Leider ist der Prozess bereits beendet, daher können wir nicht einfach lsof -p 21470 verwenden, um das aktuelle Verzeichnis zu finden, aber wir können rückwärts arbeiten – wir suchen die Systemaufrufe des PID 21470, die das Verzeichnis ändern. (Wenn es keine gibt, hat PID 21470 sie wahrscheinlich vom Elternprozess geerbt, und das lässt sich schon über lsof -p nicht herausfinden.) Dieser Systemaufruf ist chdir (was sich leicht mit modernen Netzsuchmaschinen herausfinden lässt). Hier sind die Ergebnisse der rückwärtigen Suche bis zum Server PID 20629:

20629 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21470
...
21470 execve("/usr/sbin/bcron-spool", ["bcron-spool"], 0x55d2460807e0 /* 27 vars */) = 0
...
21470 chdir("/var/spool/cron")          = 0
...
21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Zugriff verweigert) 
21470 write(1, "32:ZKonnte temporäre Datei nicht erstellen"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: Protokolle:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
21470 exit_group(111)                   = ?
21470 +++ mit 111 beendet +++

(Falls Sie sich nicht zurechtfinden, sollten Sie vielleicht meinen vorherigen Beitrag lesen über Prozessmanagement in *nix und Shells.) Also, der Server PID 20629 hat keine Berechtigung, eine Datei unter dem Pfad /var/spool/cron/tmp/spool.21470.1573692319.854640zu erstellen. Höchstwahrscheinlich liegt das an den klassischen Berechtigungseinstellungen des Dateisystems. Lassen Sie uns überprüfen:

# ls -ld /var/spool/cron/tmp/
drwxr-xr-x 2 root root 4096 Nov  6 05:33 /var/spool/cron/tmp/
# ps u -p 20629
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
cron     20629  0.0  0.0   2276   752 ?        Ss   Nov14   0:00 unixserver -U /var/run/bcron-spool -- bcron-spool

Hier ist der Hund begraben! Der Server läuft als Benutzercron, aber nur root hat die Berechtigung, in das Verzeichnis zu schreiben /var/spool/cron/tmp/. Ein einfacher Befehl chown cron /var/spool/cron/tmp/ würde ermöglichen bcron richtig arbeiten. (Wenn das Problem nicht darin lag, ist der nächste wahrscheinlichste Verdächtige das Sicherheitsmodul des Kernels, entweder SELinux oder AppArmor, also würde ich das Kernel-Protokoll mit dmesg.)

Insgesamt

Einsteiger können in den Ergebnissen von Systemaufruf-Trace verloren gehen, aber ich hoffe, ich habe gezeigt, dass sie eine schnelle Methode zur Fehlersuche einer ganzen Reihe von verbreiteten Bereitstellungsproblemen sind. Stellen Sie sich vor, Sie versuchen, eine mehrprozessuale bcron, mit einem schrittweisen Debugger zu debuggen.

Die Analyse der Trace-Ergebnisse rückwärts entlang der Kette der Systemaufrufe erfordert Geschick, aber wie ich bereits sagte, nutze ich fast immer strace, um einfach das Trace-Ergebnis zu erhalten und nach Fehlern zu suchen, beginnend vom Ende. So oder so, strace hilft es mir, eine Menge Zeit beim Debuggen zu sparen. Ich hoffe, es wird auch Ihnen nützlich sein.

Quelle: habr.com