☰

¿Por qué systemd no captura la salida de los subprocesos de un servicio de usuario escrito en un script de shell?

tag-icon • tag-icon systemd shell stdout systemd-service
¿Por qué systemd no captura la salida de los subprocesos de un servicio de usuario escrito en un script de shell?

Aquí está mi increíble servicio, escrito en script de shell:

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

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

Produce algunos resultados repetitivos:

$ ~/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

Aquí hay una configuración de servicio de usuario para ello:

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

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

Pero cuando ejecuto este servicio, usando systemd 239, en la salida registrada faltan las líneas producidas por el subshell y el subproceso:

$ 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

¿Alguna idea de por qué? Al leer, parece que systemd normalmente capturaría la salida de los subprocesos aquí. ¿Es esto algo específico que hace el Shell que interactúa con esto?

Buscando en Google, veo gente que tiene problemas como este con Python, donde el almacenamiento en búfer es el culpable, pero no veo cómo eso puede ser relevante aquí.

EDITAR: Veo exactamente el mismo comportamiento después de eliminar el script de Shell de la ecuación, usando dos programas C simples. No veo este comportamiento con un proceso principal simple que reemplaza a systemd y recopila resultados a través de una tubería. Esto indica claramente que es systemd el que está haciendo algo extraño. Ver:https://github.com/tomwhoiscontrary/child-stdout-demo

EDITAR 2: Un colega observador que tiene raíz informa que (a) la salida del subprocesoesen el diario, simplemente no está asociado con el servicio, y (b) solo ve este comportamiento con unusuarioservicio; si él establece unsistemaservicio con el mismo código, ¡la salida del subproceso está asociada a él! ¿Seguramente esto es un error de systemd?

Respuesta1

EDITAR 2: Un colega observador que tiene raíz informa que (a) la salida del subproceso está en el diario, simplemente no está asociada con el servicio, y (b) solo ve este comportamiento con un servicio de usuario; si configura un servicio del sistema con el mismo código, ¡la salida del subproceso se asocia con él! ¿Seguramente esto es un error de systemd?

Es un problema conocido y de larga duración; el problema es que el kernel no proporciona medios suficientes para asociar un cliente de socket con un cgroup (a diferencia de, por ejemplo, la capacidad de recuperar el PID del cliente). Entonces, cada vez que Journald recibe un mensaje, solo conoce el PID del remitente, pero tiene queasincrónicamentebusque el nombre de su unidad en /proc/<pid>/cgroup. Si el proceso es de muy corta duración (como un subshell), es muy posible que salga antes de que se active el diario y, cuando se procese su mensaje, la información necesaria para asociar su salida con el servicio. ya no está disponible.

Estoy un poco confuso con los detalles, pero por lo que recuerdo, las versiones recientes de systemd tienen una solución parcial que solo funciona si la "tubería" estándar para el registro (que en realidad es un par de sockets) ha sido configurada por un proceso privilegiado. mientras que sus servicios de "usuario" los configura otra instancia de systemd que solo tiene los mismos privilegios que usted.

Respuesta2

Si bien no he investigado los detalles técnicos subyacentes, la misma solución que funciona para Python (deshabilitar el almacenamiento en búfer) también funciona en esta situación. Si uso este archivo de unidad...

[Unit]
Description=Demo App

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

...luego el resultado esperado se registra en el diario.

El unbuffercomando es parte del expectpaquete.

Esto funciona forzando que el comando se ejecute como un proceso interactivo adjunto a un dispositivo pty, lo que desactiva el almacenamiento en búfer normal.

Si no tiene el unbuffercomando a mano, puede usar el scriptcomando en su lugar:

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

información relacionada