systemdサービスがルートレスの「podman実行」プロセスを開始したときに、その出力がログ内のサービスと相関しないのはなぜですか?

systemdサービスがルートレスの「podman実行」プロセスを開始したときに、その出力がログ内のサービスと相関しないのはなぜですか?

/etc/systemd/system/logtest.servicePodmanコンテナにいくつかのテキストを出力する簡単なシステムサービスがあります。

[Unit]
Description=Systemd log test

[Service]
Type=oneshot
ExecStart=podman run --rm busybox echo This should get logged.

サービスを開始すると、次のテキスト行が表示されます。

# systemctl start logtest
# journalctl -u logtest --since '1 min ago'
Mar 28 20:55:31 testserver systemd[1]: Starting Systemd log test...
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.027215747 +0000 UTC m=+0.084992872 image pull  busybox
Mar 28 20:55:32 testserver podman[435178]: 
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.27963909 +0000 UTC m=+0.337416181 container create f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.611727831 +0000 UTC m=+0.669504926 container init f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:32 testserver stupefied_gould[435330]: This should get logged.
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.674571326 +0000 UTC m=+0.732348424 container start f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.674724261 +0000 UTC m=+0.732501430 container attach f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:32 testserver podman[435178]: This should get logged.
Mar 28 20:55:32 testserver podman[435178]: 2022-03-28 20:55:32.707256608 +0000 UTC m=+0.765033742 container died f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:33 testserver podman[435178]: 2022-03-28 20:55:33.291714221 +0000 UTC m=+1.349491334 container remove f08d9eb3e843f601873c1b3db721c42175a56b27b9680dbd123781ca3ff7b808 (image=docker.io/library/busybox:latest, name=stupefied_gould)
Mar 28 20:55:33 testserver systemd[1]: logtest.service: Deactivated successfully.
Mar 28 20:55:33 testserver systemd[1]: Finished Systemd log test.

でも同じ状況が見られるsystemctl status logtest

User=logtestuserただし、このセクションを追加して他のユーザーの下にルートレスモードでコンテナを作成すると、上記の[Service]2つの方法でメッセージが表示されなくなります。

# systemctl start logtest
# journalctl -u logtest --since '1 min ago'
Mar 28 20:29:24 testserver systemd[1]: Starting Systemd log test...
Mar 28 20:29:26 testserver systemd[1]: logtest.service: Deactivated successfully.
Mar 28 20:29:26 testserver systemd[1]: Finished Systemd log test.

ただし、ログメッセージは失われません。journalctl以下を使用しないと、全出力で表示できます-u

# journalctl --since '1 min ago'
Mar 28 20:29:24 testserver systemd[1]: Starting Systemd log test...
Mar 28 20:29:25 testserver systemd[393984]: Started podman-434593.scope.
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.026488198 +0000 UTC m=+0.171108223 image pull  busybox
Mar 28 20:29:25 testserver podman[434593]: 
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.29202509 +0000 UTC m=+0.436645186 container create 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:25 testserver systemd[393984]: Started libcrun container.
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.575793516 +0000 UTC m=+0.720413681 container init 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:25 testserver cool_leavitt[434664]: This should get logged.
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.668965604 +0000 UTC m=+0.813585693 container start 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.669194055 +0000 UTC m=+0.813814093 container attach 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:25 testserver podman[434593]: This should get logged.
Mar 28 20:29:25 testserver podman[434593]: 2022-03-28 20:29:25.715669116 +0000 UTC m=+0.860289157 container died 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:26 testserver podman[434593]: 2022-03-28 20:29:26.417620766 +0000 UTC m=+1.562240892 container remove 4d81454621f7b0629bb72047e7e0df6490bfb6bf50dd09d5fe5c59de123c4fb9 (image=docker.io/library/busybox:latest, name=cool_leavitt)
Mar 28 20:29:26 testserver systemd[1]: logtest.service: Deactivated successfully.
Mar 28 20:29:26 testserver systemd[1]: Finished Systemd log test.

したがって、何らかの方法でサービスとの接続が解除されます。なぜこれが起こるのですか?ルート以外のコンテナでサービスログを表示する正しい方法、または少なくとも良い解決策がありますか?

シェルから直接コンテナを実行すると、次のメッセージが表示されます。

# sudo -u logtestuser podman run --rm busybox echo This should get logged.
This should get logged.

このコマンドは、systemdがサービスを開始する方法と非常に似ていると思います。明らかに、このプロセスには出力がありますpodman run。だから、なぜサービスに接続しないのか理解できません。

これはかなり最近のFedora 35で使用されていますloginctl enable-linger logtestuser

ベストアンサー1

これは、SystemDが他のユーザーとして実行されるシステムサービスです。@ericsolender私が知っている限り、この問題は上流の協力なしには解決できません(つまり、問題はPodmanにはありません)。

この問題に対する簡単だが制限的な回避策は、stdoutとstderrを単純なテキストファイルにリダイレクトするようにSystemDを設定し、別の方法でログローテーションを処理することです。

[Service]
User=USER
#...
StandardOutput=append:STDOUT_FILE
StandardError=append:STDERR_FILE

ファイルSTDOUT_FILESTDERR_FILEアクセスできる必要がありますUSER

この方法はテストされ、systemd 249(2023-05)で動作することが確認されました。

おすすめ記事