☰

Warum erfasst systemd die Ausgabe von Unterprozessen eines in einem Shell-Skript geschriebenen Benutzerdienstes nicht?

tag-icon • tag-icon systemd shell stdout systemd-service
Warum erfasst systemd die Ausgabe von Unterprozessen eines in einem Shell-Skript geschriebenen Benutzerdienstes nicht?

Hier ist mein erstaunlicher Dienst, geschrieben in Shell-Skript:

$ cat ~/junk/demoapp 
#! /bin/bash -eu

while true
do
    echo "in shell"
    ( echo "in subshell" )
    /usr/bin/echo "in subprocess"
    sleep 1
done

Es wird eine sich wiederholende Ausgabe erzeugt:

$ ~/junk/demoapp
in shell
in subshell
in subprocess
in shell
in subshell
in subprocess
in shell
in subshell
in subprocess
in shell
in subshell
in subprocess
^C

Hier ist eine Benutzerdienstkonfiguration dafür:

$ cat ~/.config/systemd/user/demoapp.service 
[Unit]
Description=Demo App

[Service]
Type=exec
ExecStart=/home/tomanderson/junk/demoapp

Aber wenn ich diesen Dienst mit systemd 239 ausführe, fehlen in der protokollierten Ausgabe die von der Subshell und dem Unterprozess erzeugten Zeilen:

$ systemctl --user daemon-reload

$ systemctl --user start demoapp

$ journalctl --user --unit demoapp

Sep 12 18:53:27 myhost systemd[539847]: Started Demo App.
Sep 12 18:53:27 myhost demoapp[559387]: in shell
Sep 12 18:53:28 myhost demoapp[559387]: in shell
Sep 12 18:53:29 myhost demoapp[559387]: in shell
Sep 12 18:53:30 myhost demoapp[559387]: in shell
Sep 12 18:53:31 myhost demoapp[559387]: in shell
Sep 12 18:53:32 myhost demoapp[559387]: in shell
Sep 12 18:53:33 myhost demoapp[559387]: in shell
Sep 12 18:53:34 myhost demoapp[559387]: in shell
Sep 12 18:53:35 myhost demoapp[559387]: in shell

Irgendeine Idee, warum? Wenn man sich umschaut, scheint es, dass systemd hier normalerweise die Ausgabe von Unterprozessen erfassen würde. Ist das etwas Bestimmtes, was die Shell tut und was damit interagiert?

Beim Googeln habe ich festgestellt, dass manche Leute ähnliche Probleme mit Python haben und die Ursache darin liegt, dass das Puffern der Grund ist. Ich sehe jedoch nicht, inwiefern das hier relevant sein könnte.

EDIT: Ich sehe genau dasselbe Verhalten, nachdem ich Shell-Skripte aus der Gleichung genommen habe und zwei einfache C-Programme verwende. Ich sehe dieses Verhalten nicht, wenn ein einfacher übergeordneter Prozess den Platz von systemd einnimmt und die Ausgabe über eine Pipe sammelt. Dies deutet stark darauf hin, dass systemd etwas Seltsames tut. Siehe:https://github.com/tomwhoiscontrary/child-stdout-demo

EDIT 2: Ein aufmerksamer Kollege mit Root-Rechten berichtet, dass (a) die Ausgabe des UnterprozessesIstim Journal, es ist einfach nicht mit dem Dienst verbunden, und (b) er sieht dieses Verhalten nur mit einemBenutzerService; wenn er einenSystemDienst mit demselben Code, die Ausgabe des Unterprozesses ist damit verknüpft! Das ist doch sicher ein Systemd-Fehler, oder?

Antwort1

EDIT 2: Ein aufmerksamer Kollege mit Root-Rechten berichtet, dass (a) die Subprozessausgabe im Journal steht, aber nicht mit dem Dienst verknüpft ist, und (b) er dieses Verhalten nur bei einem Benutzerdienst sieht; wenn er einen Systemdienst mit demselben Code einrichtet, ist die Subprozessausgabe damit verknüpft! Das ist doch sicher ein Systemd-Fehler, oder?

Es ist ein bekanntes, seit langem bestehendes Problem. Das Problem besteht darin, dass der Kernel keine ausreichenden Mittel bereitstellt, um einen Socket-Client mit einer Cgroup zu verknüpfen (anders als beispielsweise die Möglichkeit, die PID des Clients abzurufen). Wenn Journald also eine Nachricht empfängt, kennt es nur die PID des Absenders, muss aberasynchronSuchen Sie den Unit-Namen unter /proc/<pid>/cgroup. Wenn der Prozess sehr kurzlebig ist (z. B. eine Subshell), kann es durchaus sein, dass er beendet wird, bevor journald überhaupt aufgeweckt wird – und bis seine Nachricht verarbeitet ist, sind die Informationen, die erforderlich sind, um seine Ausgabe dem Dienst zuzuordnen, nicht mehr verfügbar.

Ich bin mir über die Details nicht ganz im Klaren, aber soweit ich mich erinnere, gibt es in den neuesten Systemd-Versionen einen teilweisen Workaround, der nur funktioniert, wenn die Standardout-„Pipe“ zu Journald (was eigentlich ein Socket-Paar ist) von einem privilegierten Prozess eingerichtet wurde, Ihre „Benutzer“-Dienste jedoch von einer anderen Systemd-Instanz eingerichtet werden, die nur über dieselben Privilegien wie Sie selbst verfügt.

Antwort2

Obwohl ich die zugrunde liegenden technischen Details nicht untersucht habe, funktioniert dieselbe Lösung, die für Python funktioniert (Pufferung deaktivieren), auch in dieser Situation. Wenn ich diese Unit-Datei verwende ...

[Unit]
Description=Demo App

[Service]
Type=exec
ExecStart=/usr/bin/unbuffer %h/bin/demoapp

...dann wird die erwartete Ausgabe im Journal protokolliert.

Der unbufferBefehl ist Teil des expectPakets.

Dies funktioniert, indem die Ausführung des Befehls als interaktiver Prozess erzwungen wird, der an ein PTY-Gerät angeschlossen ist, wodurch die normale Pufferung deaktiviert wird.

Wenn Sie den Befehl nicht zur Hand haben , können Sie stattdessen unbufferden folgenden Befehl verwenden :script

ExecStart=/usr/bin/script -c %h/bin/demoapp /dev/null

verwandte Informationen