☰

Por que o systemd não captura a saída de subprocessos de um serviço de usuário escrito em shell script?

tag-icon • tag-icon systemd shell stdout systemd-service
Por que o systemd não captura a saída de subprocessos de um serviço de usuário escrito em shell script?

Aqui está meu serviço incrível, escrito em shell script:

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

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

Produz alguma saída repetitiva:

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

Aqui está uma configuração de serviço do usuário para ele:

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

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

Mas quando executo este serviço, usando o systemd 239, faltam na saída registrada as linhas produzidas pelo subshell e pelo subprocesso:

$ 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

Alguma ideia do porquê? Pela leitura, parece que o systemd normalmente capturaria a saída dos subprocessos aqui. Isso é algo específico que o shell está fazendo e interagindo com isso?

Pesquisando no Google, vejo pessoas tendo problemas como esse com Python, onde o buffer é o culpado, mas não vejo como isso pode ser relevante aqui.

EDIT: Vejo exatamente o mesmo comportamento depois de retirar o shell script da equação, usando dois programas C simples. Não vejo esse comportamento com um processo pai simples substituindo o systemd e coletando a saída por meio de um pipe. Isso indica fortemente que é o systemd que está fazendo algo estranho. Ver:https://github.com/tomwhoiscontrary/child-stdout-demo

EDIT 2: Um colega observador que tem root relata que (a) a saída do subprocessoéno diário, simplesmente não está associado ao serviço, e (b) ele só vê esse comportamento com umdo utilizadorserviço; se ele montar umsistemaserviço com o mesmo código, a saída do subprocesso está associada a ele! Certamente este é um bug do systemd?

Responder1

EDIT 2: Um colega observador que possui root relata que (a) a saída do subprocesso está no diário, simplesmente não está associada ao serviço e (b) ele só vê esse comportamento com um serviço de usuário; se ele configurar um serviço do sistema com o mesmo código, a saída do subprocesso será associada a ele! Certamente este é um bug do systemd?

É um problema conhecido e duradouro; o problema é que o kernel não fornece meios suficientes para associar um cliente soquete a um cgroup (ao contrário, por exemplo, da capacidade de recuperar o PID do cliente). Portanto, sempre que o journald recebe uma mensagem, ele conhece apenas o PID do remetente, mas precisade forma assíncronaprocure o nome da unidade em /proc/<pid>/cgroup. Se o processo tiver vida muito curta (como um subshell), pode muito bem ser que ele saia antes mesmo de o journald ser acordado - e no momento em que sua mensagem for processada, as informações necessárias para associar sua saída ao serviço não está mais disponível.

Estou um pouco confuso com os detalhes, mas pelo que me lembro, as versões recentes do systemd têm uma solução parcial que só funciona se o "pipe" stdout para o journald (que é realmente um par de soquetes) tiver sido configurado por um processo privilegiado, enquanto seus serviços de "usuário" são configurados por outra instância do systemd que possui apenas os mesmos privilégios que você.

Responder2

Embora eu não tenha investigado os detalhes técnicos subjacentes, a mesma solução que funciona para Python (desativar buffer) também funciona nessa situação. Se eu usar este arquivo de unidade ...

[Unit]
Description=Demo App

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

... então a saída esperada é registrada no diário.

O unbuffercomando faz parte do expectpacote.

Isso funciona forçando a execução do comando como um processo interativo anexado a um dispositivo pty, o que desativa o buffer normal.

Se você não tiver o unbuffercomando em mãos, poderá usar o scriptcomando:

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

informação relacionada