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]위의 두 가지 방법을 사용하여 더 이상 메시지가 표시되지 않습니다.

# 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)에서 작동하는 것으로 확인되었습니다.

관련 정보