Wir optimieren die Softwarebereitstellung mit strace

Mein Hauptjob besteht überwiegend aus der Bereitstellung von Softwaresystemen, was bedeutet, dass ich viel Zeit damit verbringe, auf Fragen wie diese zu antworten:

• Das Programm funktioniert beim Entwickler, aber bei mir nicht. Warum?
• Gestern hat das Programm bei mir funktioniert, heute aber nicht mehr. Warum?

Das ist eine Art Debugging, die sich etwas von der gewöhnlichen Fehlerbehebung unterscheidet. Gewöhnliches Debugging bezieht sich auf die Logik des Codes, während das Debugging der Bereitstellung sich mit der Interaktion zwischen Code und Umgebung beschäftigt. Selbst wenn das Problem einen logischen Fehler als Ursprung hat, bedeutet die Tatsache, dass es auf einem Rechner funktioniert und auf einem anderen nicht, dass es irgendwie an der Umgebung liegt.

Deshalb benutze ich anstelle der üblichen Debugging-Tools gdb einen anderen Satz von Werkzeugen für das Bereitstellungsdebugging. Mein liebstes Werkzeug zur Lösung des Problems "Warum funktioniert dieses Programm bei mir nicht?" ist strace.

Was ist also strace?

strace — es ist ein Werkzeug zur "Nachverfolgung von Systemaufrufen". Es wurde ursprünglich für Linux entwickelt, aber die gleichen Debugging-Features können auch mit Tools für andere Systeme durchgeführt werden (DTrace oder ktrace).

Die Hauptanwendung ist ganz einfach. Man muss lediglich strace mit einem beliebigen Befehl starten, und es werden alle Systemaufrufe in einen Dump gesendet (obwohl man vermutlich zuerst strace installieren muss). strace):

$ strace echo Hallo
...Snippet vieler Daten...
write(1, "Hallo", 6)                   = 6
close(1)                               = 0
close(2)                               = 0
exit_group(0)                          = ?
+++ mit 0 beendet +++

Was sind Systemaufrufe? Sie sind eine Art API für den Betriebssystemkern. Früher hatten Softwareanwendungen direkten Zugriff auf die Hardware, auf der sie liefen. Musste beispielsweise etwas auf dem Bildschirm angezeigt werden, manipulierten sie die Ports oder verwendeten bestimmte Register im Speicher für Video-Geräte. Mit dem Aufkommen von Multitasking-Computersystemen entstand Chaos, da verschiedene Anwendungen um die Hardware konkurrierten. Fehler in einer Anwendung konnten andere zum Absturz bringen, wenn nicht sogar das gesamte System. Daher wurden im CPU privilegierte Modi (oder „Ring-Schutz“) eingeführt. Der privilegierteste war der Kernel: Er erhielt vollen Zugriff auf die Hardware und erzeugte weniger privilegierte Anwendungen, die den Zugriff beim Kernel anfordern mussten, um mit der Hardware zu interagieren – über Systemaufrufe.

Auf binärer Ebene unterscheidet sich ein Systemaufruf etwas von einem normalen Funktionsaufruf, jedoch verwenden die meisten Programme eine Wrapper-Funktion aus der Standardbibliothek. Das heißt, die Standardbibliothek POSIX C enthält den Funktionsaufruf write(),, der den architekturabhängigen Code für den Systemaufruf umfasst. write.

Kurz gesagt, jede Interaktion einer Anwendung mit ihrer Umgebung (Computersystemen) erfolgt über Systemaufrufe. Daher, wenn Software auf einem Rechner funktioniert und auf einem anderen nicht, ist es ratsam, die Ergebnisse der Verfolgung von Systemaufrufen zu überprüfen. Konkret finden Sie hier eine Liste typischer Punkte, die Sie mithilfe von Systemaufrufverfolgung analysieren können:

• Konsoleneingabe/-ausgabe
• Netzwerkeingabe/-ausgabe
• Zugriff auf das Dateisystem und Datei-IO
• Verwaltung der Lebensdauer von Prozess-Threads
• Niedrig-levelige Speicherverwaltung
• Zugriff auf spezielle Geräte-Treiber

Wann sollte man strace verwenden?

In der Theorie, strace wird es mit beliebigen Programmen im Benutzerspeicher verwendet, da jedes Programm im Benutzerspeicher Systemaufrufe machen muss. Es funktioniert effizienter mit kompilierbaren, niedrig-leveligen Programmen, funktioniert aber auch mit Hochsprachen wie Python, wenn man den zusätzlichen Lärm von Laufzeitumgebung und Interpreter durchdringen kann.

In voller Pracht strace zeigt sich während der Fehlersuche von Software, die auf einem Gerät gut funktioniert, auf einem anderen jedoch plötzlich Probleme verursacht und unklare Meldungen zu Dateien, Berechtigungen oder fehlgeschlagenen Befehlen ausgibt. Schade, aber es passt nicht so gut zu höherwertigen Problemen wie Zertifikatsprüfungsfehlern. Hier ist in der Regel eine Kombination erforderlich. strace, manchmal ltrace und andere hochentwickelte Werkzeuge (wie das Kommandozeilen-Tool openssl zur Zertifikatsfehlerbehebung).

Nehmen wir zum Beispiel die Arbeit auf einem isolierten Server, aber Systemaufruf-Tracking kann häufig auch auf komplexeren Bereitstellungsplattformen durchgeführt werden. Man muss nur die richtigen Werkzeuge auswählen.

Beispiel für einfaches Debugging

Angenommen, Sie möchten die beeindruckende Serveranwendung foo starten, und das erhalten Sie:

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

Offensichtlich konnte er die von Ihnen erstellte Konfigurationsdatei nicht finden. Das geschieht, da Paketmanager manchmal während der Kompilierung einer Anwendung den erwarteten Speicherort von Dateien überschreiben. Wenn man der Installationsanleitung für eine bestimmte Distribution folgt, findet man die Dateien bei einer anderen oft völlig woanders, als man es erwartet. Das Problem könnte in wenigen Sekunden gelöst werden, wenn die Fehlermeldung angeben würde, wo man nach der Konfigurationsdatei suchen sollte, aber das tut sie nicht. Wo sollte man also suchen?

Wenn der Zugriff auf den Quellcode möglich ist, kann man ihn durchlesen und alles herausfinden. Ein guter Plan B, aber nicht die schnellste Lösung. Man könnte einen schrittweisen Debugger wie verwenden, um zu sehen, was das Programm macht, doch es ist viel effizienter, ein Werkzeug zu nutzen, das speziell dafür entwickelt wurde, die Interaktionen mit der Umgebung anzuzeigen: gdb Es mag überflüssig erscheinen, aber die gute Nachricht ist, dass man den Großteil davon getrost ignorieren kann. Oft ist es nützlich, den Schalter -o zu verwenden, um die Ergebnisse der Verfolgung in einer separaten Datei zu speichern: strace.

Fazit strace Es mag übertrieben erscheinen, aber die gute Nachricht ist, dass man den größten Teil problemlos ignorieren kann. Oft ist es nützlich, den Befehl -o zu verwenden, um die Tracing-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)                           = ?
+++ beendet mit 1 +++

In etwa die gesamte erste Seite der Ausgabe strace — das ist normalerweise eine grundlegende Vorbereitung für den Start. (Viele Aufrufe mmap, mprotect, brk für Dinge wie die Erkennung von Low-Level-Speicher und die Anzeige dynamischer Bibliotheken.) Tatsächlich ist es während der Fehlersuche strace besser, die Ausgaben von hinten zu lesen. Am Ende wird es einen Aufruf geben, write, der eine Fehlermeldung ausgibt. Schauen wir nach oben und sehen den ersten fehlerhaften Systemaufruf — den Aufruf openat, der den Fehler ENOENT ('Datei oder Verzeichnis nicht gefunden') ausgibt und versucht, /etc/foo/config.json. Hier sollte die Konfigurationsdatei liegen.

Das war nur ein Beispiel, aber ich würde sagen, dass ich in 90 % der Zeit, die ich nutze, strace, es nichts viel Komplizierteres gibt, das ich ausführen muss. Weiter unten finden Sie eine vollständige Schritt-für-Schritt-Anleitung zur Fehlersuche:

• Sich über eine unklare Fehlermeldung der System-CPU des Programms zu ärgern,
• Das Programm mit strace
• Neustarten und die Fehlermeldung in den Trace-Ergebnissen finden
• Nach oben gehen, bis Sie auf den ersten fehlgeschlagenen Systemaufruf stoßen

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

Hinweise

Bevor ich ein Beispiel für eine komplexere Fehlersuche zeige, möchte ich Ihnen einige Tricks für eine effektive Nutzung vorstellen. strace:

man — Ihr Freund

Auf vielen *nix-Systemen können Sie die vollständige Liste der Systemaufrufe an den Kernel erhalten, indem Sie man syscalls. Sie sehen Dinge wie brk(2), daher können Sie weitere Informationen erhalten, indem Sie man 2 brk.

Ein paar kleine Stolpersteine: man 2 fork zeigt mir die Seite für die Shell fork() in GNU libc, die sich, wie sich herausstellt, durch den Aufruf clone()implementiert. Die Semantik des Aufrufs fork fork()bleibt gleich, wenn man ein Programm schreibt, das Die Semantik des Aufrufsverwendet, und die Nachverfolgung startet — ich werde keine Aufrufe finden clone(), stattdessen wird es strace.

. Solche Stolpersteine verwirren, wenn man anfängt, den Quellcode mit der Ausgabe zu vergleichen.

strace Verwenden Sie -o, um die Ausgabe in eine Datei zu speichern. strace Dies kann umfangreiche Ausgaben erzeugen, sodass es oft sinnvoll ist, die Ergebnisse der Nachverfolgung in separaten Dateien zu speichern (wie im obigen Beispiel). Außerdem hilft es, die Programmausgabe nicht mit der Ausgabe

im Terminal zu verwechseln.

Verwenden Sie -s, um mehr Argumentdaten anzuzeigen. strace Sie haben sicherlich bemerkt, dass die zweite Hälfte der Fehlermeldung im obigen Beispiel der Nachverfolgung nicht angezeigt wird. Das liegt daran, dass -s 128 zum Aufruf hinzu. strace.

-u erleichtert die Verfolgung von Dateisockeln und ähnlichem.

„Alles ist eine Datei“ bedeutet, dass *nix-Systeme alle Ein- und Ausgaben anhand von Dateideskriptoren ausführen, unabhängig davon, ob sie auf eine Datei, das Netzwerk oder interprozessuale Kanäle angewendet werden. Das ist praktisch für die Programmierung, erschwert jedoch das Nachverfolgen dessen, was tatsächlich geschieht, wenn man die allgemeinen read und write in den Ergebnissen der Systemaufrufverfolgung sieht.

Durch Hinzufügen des Operators -uwerden Sie strace jeden Dateideskriptor in der Ausgabe mit einem Vermerk annotieren, auf was er zeigt.

Hängen Sie sich an einen bereits laufenden Prozess mit -p**

Wie im folgenden Beispiel zu sehen ist, muss man manchmal ein Programm verfolgen, das bereits läuft. Wenn bekannt ist, dass es als Prozess 1337 läuft (sagen wir, aus den Ausgaben ps), kann man es so verfolgen:

$ strace -p 1337
...Systemaufruf-Trace-Ausgabe...

Möglicherweise benötigen Sie Root-Rechte.

Verwenden Sie -f, um untergeordnete Prozesse zu verfolgen.

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

Wenn Sie der Meinung sind, dass der Fehler im untergeordneten Prozess liegt, verwenden Sie den Operator -f, um dessen Verfolgung zu aktivieren. Der Nachteil dabei ist, dass die Ausgabe noch verwirrender wird. Wenn strace ein Prozess oder ein Zweig verfolgt wird, zeigt es einen einheitlichen Fluss von Ereignissen bei den Aufrufen. Wenn jedoch gleichzeitig mehrere Prozesse verfolgt werden, können Sie möglicherweise den Beginn eines Aufrufs sehen, unterbrochen durch die Nachricht <unfinished …>, gefolgt von einer Reihe von Aufrufen für andere Ausführungszweige, und erst danach das Ende des ersten mit <… foocall resumed>. Oder teilen Sie alle Verfolgungsergebnisse in verschiedene Dateien auf, indem Sie ebenfalls den Operator -ff verwenden (siehe Handbuch. zum strace).

Filtern Sie die Verfolgung mit -e

Wie Sie sehen, ist das Ergebnis der Verfolgung eine echte Ansammlung aller möglichen Systemaufrufe. Mit dem Flag -e kann die Verfolgung gefiltert werden (siehe die Richtlinien zum strace). Der Hauptvorteil besteht darin, dass das Starten der Verfolgung mit Filterung schneller ist als eine vollständige Verfolgung zu machen und dann grep`Wenn ich ehrlich bin, ist es mir fast immer egal.

Nicht alle Fehler sind schlecht

Ein einfaches und häufiges Beispiel ist ein Programm, das eine Datei an mehreren Orten sucht, wie ein Shell-Befehl, der herausfindet, in welchem Verzeichnis 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
...

Die Heuristik „letzte fehlgeschlagene Anfrage vor der Fehlermeldung“ ist nützlich, um relevante Fehler zu finden. Wie dem auch sei, es ist sinnvoll, am Ende zu beginnen.

Die Systemaufrufe lassen sich gut durch Programmierhandbücher in C nachvollziehen.

Die Standardaufrufe an C-Bibliotheken sind keine Systemaufrufe, sondern nur eine dünne Oberfläche. Wenn Sie also ein wenig verstehen, wie und was in C funktioniert, wird es Ihnen leichter fallen, die Ergebnisse der Systemaufruftre tracing zu verstehen. Wenn Sie beispielsweise Probleme bei der Fehlersuche mit Netzwerkaufrufen haben, werfen Sie einen Blick auf das klassische „Handbuch zur Netzwerkprogrammierung“ von Stevens..

Ein komplexeres Debugging-Beispiel

Ich habe bereits erwähnt, dass ein einfaches Debugging-Beispiel das ist, womit ich größtenteils in meiner Arbeit mit stracezu tun habe. Manchmal ist jedoch echtes Nachforschen erforderlich, deshalb hier ein reales Beispiel für komplexeres Debugging.

bcron — ein Auftragsplaner, eine weitere Implementierung eines *nix-Demons. 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

Also, bcron er hat versucht, eine bestimmte Datei zu schreiben, aber es hat nicht funktioniert, und er gibt nicht zu, warum. Lassen Sie uns das näher ansehen. 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 +++

Nahe dem Ende gibt es eine Fehlermeldung write, aber dieses Mal ist etwas anders. Erstens gibt es keinen relevanten Systemaufruf-Fehler, der normalerweise davor auftritt. Zweitens scheint jemand das Fehlermeldung bereits gelesen zu haben. Es sieht so aus, als ob das wirkliche Problem woanders liegt, und bcrontab gibt nur die Meldung wieder.

Wenn wir uns man 2 readanschauen, sehen wir, dass das erste Argument (3) ein Dateideskriptor ist, den *nix für alle Eingabe-/Ausgabeverarbeitung verwendet. Wie können wir herausfinden, was der Dateideskriptor 3 darstellt? In diesem speziellen Fall könnte man strace mit dem Operator starten -u (siehe oben), und er wird automatisch erzählen, jedoch ist es hilfreich, zu wissen, wie man die Ergebnisse der Traceroute liest und analysiert.

Die Quelle des Dateideskriptor kann einer der vielen Systemaufrufe 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, die Aufrufe suchen wir, indem wir 3 zurückgeben (d.h. wir suchen nach „= 3“ in den Ergebnissen der Traceroute). In diesem Ergebnis sind es 2: openat ganz oben und socket in der Mitte. openat öffnet eine Datei, aber close(3) wird danach zeigen, dass sie wieder geschlossen wird. (Hinweis: 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 unter dem Pfad /var/run/bcron-spool.

verbunden ist. Daher muss der Prozess gefunden werden, der mit unix socket auf der anderen Seite verbunden ist. Zu diesem Zweck gibt es ein paar raffinierte Tricks, und beide werden für die Fehlersuche bei Serverbereitstellungen nützlich sein. Der erste — verwenden Sie netstat oder das neuere ss (Socket-Status). Beide Befehle zeigen aktive Netzwerkverbindungen des Systems an und verwenden den Operator -l zum Beschreiben der Lausch-Sockets sowie den Operator -p um die Programme anzuzeigen, die als Client mit dem Socket verbunden sind. (Es gibt viele 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 bedeutet, dass der lauschende Socket mit dem Befehl inixserver, der mit der Prozess-ID 20629 arbeitet, verbunden ist. (Zufälligerweise verwendet er Dateideskriptor 3 als Socket.)

Ein weiteres wirklich nützliches Werkzeug zur Auffindung derselben Informationen heißt lsof. Es listet alle geöffneten Dateien (oder Dateideskriptoren) im System auf. Alternativ kann man 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 etwas wie strace strace -o /tmp/trace -p 20629 verbinden kann. Wenn man den Cron-Job in einem anderen Terminal bearbeitet, erhält man die Ausgabe der Traceergebnisse mit der auftretenden Fehlermeldung. Und hier ist das Ergebnis:. Wenn Sie den Cron-Job in einem anderen Terminal bearbeiten, erhalten Sie die Ausgabe der Tracing-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)

(Letzte accept() wird nicht bei der Traceroute abgeschlossen.) Und leider, dieses Ergebnis enthält nicht den Fehler, den wir suchen. Wir sehen keine Nachrichten, die bcrontag an den Socket gesendet hat oder von ihm empfangen hat. Stattdessen nur Prozessmanagement (clone, wait4, SIGCHLD usw.) Dieser Prozess erzeugt einen Kindprozess, der, wie man vermuten kann, die eigentliche Arbeit verrichtet. Und wenn wir seine Spur verfolgen müssen, fügen Sie dem Aufruf hinzu strace -f. Das werden wir finden, 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 f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (Keine solche Datei oder Verzeichnis)
21470 exit_group(111)                   = ?
21470 +++ beendet mit 111 +++

Hier, das ist schon etwas. Prozess 21470 erhält den Fehler „Zugriff verweigert“ beim Versuch, eine Datei unter dem Pfad tmp/spool.21470.1573692319.854640 (bezieht sich auf das aktuelle Arbeitsverzeichnis). Wüssten wir einfach, welches das aktuelle Arbeitsverzeichnis ist, hätten wir auch den vollständigen Pfad und könnten herausfinden, warum der Prozess darin keine temporäre Datei erstellen kann. Leider ist der Prozess bereits beendet, daher lässt sich nicht einfach benutzen. lsof -p 21470 um das aktuelle Verzeichnis zu finden, aber wir können in die entgegengesetzte Richtung arbeiten - nach Systemaufrufen für PID 21470 suchen, die das Verzeichnis ändern. (Wenn es solche nicht gibt, hat PID 21470 diese wahrscheinlich vom Elternteil geerbt, und das ist schon über lsof -p nicht herauszufinden.) Dieser Systemaufruf ist chdir (was sich leicht mit modernen Netzwerksuchmaschinen herausfinden lässt). Hier sind die Ergebnisse der Rückwärtssuche basierend auf den Trace-Ergebnissen bis zum Server von 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 (Berechtigung verweigert) 
21470 write(1, "32:ZCould not create temporary f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (Keine solche Datei oder Verzeichnis)
21470 exit_group(111)                   = ?
21470 +++ beendet mit 111 +++

(Wenn Sie sich unsicher sind, sollten Sie vielleicht meinen vorherigen Beitrag lesen) über die Verwaltung von *nix-Prozessen und Shells). Also, der Server PID 20629 hat nicht die Berechtigung, eine Datei im Verzeichnis zu erstellen /var/spool/cron/tmp/spool.21470.1573692319.854640. Wahrscheinlich liegt das an den klassischen Einstellungen der Dateiberechtigungen. 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 liegt das Problem! Der Server läuft als Benutzer-Cron, aber nur der Root hat die Berechtigung, in das Verzeichnis zu schreiben /var/spool/cron/tmp/. Ein einfacher Befehl chown cron /var/spool/cron/tmp/ wird bcron korrekt funktionieren. (Wenn das nicht das Problem war, könnte der nächste Verdächtige ein Sicherheitsmodul des Kernels wie SELinux oder AppArmor sein; daher würde ich das Kernel-Log mit dmesg.)

Gesamt

Für Anfänger kann die Analyse von Systemaufruf-Trace-Ausgaben überwältigend sein, aber ich hoffe, ich habe gezeigt, dass sie eine schnelle Möglichkeit sind, eine ganze Reihe von häufigen Bereitstellungsproblemen zu debuggen. Stellen Sie sich vor, Sie versuchen, einen Mehrprozess bcron, mit einem schrittweisen Debugger zu debuggen.

Die Analyse der Trace-Ergebnisse rückwärts entlang der Systemaufrufkette erfordert Geschick, aber wie ich bereits sagte, ist es fast immer hilfreich. strace, ich führe einfach einen Trace-Rout durch und suche nach Fehlern, beginnend am Ende. Auf jeden Fall hilft es mir, eine Menge Zeit bei der Fehlersuche zu sparen. Ich hoffe, es ist auch für Sie nützlich. strace Wie wir bei ЦИАН Terabytes an Logs gezähmt haben

Quelle: habr.com