Debian 10에서 종료 1분 30초 동안 "작업 실행 중지" 분석

Debian 10 데스크톱 버전을 설치했습니다. 1분 30초 정도 지연되는 등 종료가 자주 지연되는 것을 확인했습니다. Debian 9 설치에서는 이 문제가 발생하지 않습니다. (또는 적어도 덜 자주).

journalctl나중에 시스템 로그를 보면 지연( )도 보입니다 . 이 로그를 분석하고 싶습니다.

어떤 경우에는 사용자 서비스에 문제가 있는 것 같았습니다 pulseaudio.service. 그렇다면 TimeoutStopSec=2서비스 설정 등을 통해 이 문제를 쉽게 해결할 수 있습니다. (이것은 시스템 서비스가 아니며 사용자 서비스입니다. 시스템 서비스가 없습니다 pulseaudio.service.)

제가 본 두 번째 경우에는 pulseaudio.service요청하자마자 종료되는 것 같았습니다. 그렇다면 시간 제한을 설정해도 도움이 되지 않습니다 :-). 대신 pulseaudio.servicesystemd가 중지를 요청하기까지 오랜 지연이 있는 것 같습니다. 두 번째 로그를 보면 문제가 무엇인지 알 수 없습니다.

작동할 수 있는 더 광범위한 해결 방법이 있습니다(끝 참조). 그런데 구체적으로 무엇이 문제인지 알고 싶습니다.

질문

1. 아래의 두 번째 로그에는 제가 식별하지 못한 특정 문제가 표시됩니까?
2. 소프트웨어 버그로 인해 다음 로그가 발생할 수 있고 로그에서 특정 문제를 식별할 수 없는 것으로 예상되거나 알려진 상황이 있습니까?

내 현재 systemd패키지 버전은 입니다 241-5.

고쳐 쓰다

제 생각에는 이 질문이 다음과 관련이 있는 것 같습니다.문제 #12262. 이 문제에 대한 해결책은"cgroup-util: 스레드도 종료합니다"(홍보 #12621), 시스템 버전 243으로 병합되었습니다.

PR 링크의 토론에 따르면 버그는 cgroupsv2("통합 제어 그룹 계층 구조")에만 해당됩니다. Debian 10은 cgroupsv2를 사용하지만 Debian 9는 사용하지 않습니다. 보다 구체적으로 데비안 10은 다음을 사용합니다.과도기적 "하이브리드" 계층 구조.

systemd.legacy_systemd_cgroup_controller그래서 커널 부팅 옵션을 추가해 보았습니다 . 이 옵션을 사용하면 cgroup2파일 시스템이 어디에도 마운트되지 않고 마운트만 된 것을 볼 수 있습니다 cgroup. 안타깝게도 여전히 설명할 수 없는 종료 지연이 표시됩니다.

전체 로그:로그 종료 지연 2.txt

Sep 08 16:24:25 drystone kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-4.19.0-5-amd64 root=UUID=f10753fb-0a2d-4288-971d-5f33682ab5c0 ro systemd.legacy_systemd_cgroup_controller quiet

Sep 08 16:54:28 drystone systemd[1]: Stopped Firmware update daemon.
Sep 08 16:55:58 drystone systemd[1442]: Stopping D-Bus User Message Bus...
Sep 08 16:55:58 drystone systemd[1442]: Stopped target Default.
Sep 08 16:55:58 drystone systemd[1442]: Stopping Sound Service...
Sep 08 16:55:58 drystone systemd[1442]: pulseaudio.service: Succeeded.
Sep 08 16:55:58 drystone systemd[1442]: Stopped Sound Service.
Sep 08 16:55:58 drystone systemd[1442]: dbus.service: Main process exited, code=killed, status=15/TERM
Sep 08 16:55:58 drystone systemd[1442]: dbus.service: Succeeded.
Sep 08 16:55:58 drystone systemd[1442]: Stopped D-Bus User Message Bus.
Sep 08 16:55:58 drystone systemd[1442]: Stopped target Basic System.
Sep 08 16:55:58 drystone systemd[1442]: Stopped target Paths.
Sep 08 16:55:58 drystone systemd[1442]: Stopped target Timers.

또한 PR 토론에 따르면 대체 수정 방법은 Linux 커널 버전 5.2 이상을 사용하는 것입니다. 커널 수정 커밋은 다음과 같습니다."cgroup: PROCS 반복에서 활성 스레드가 있는 죽어가는 리더를 포함합니다.". 이는 안정 커널 시리즈 4.19.x에도 포함되어 있습니다. 이것안정적인 커밋날짜는 2019년 6월 10일입니다. 그러나 이 글을 쓰는 시점에서 현재 데비안 10 커널은4.19.67 기준,게시됨2019-04-27쯤. 따라서 이 데비안 커널에는 아직 수정 사항이 포함되어 있지 않습니다.

---

1. 펄스 오디오 종료 지연

Aug 31 08:40:28 drystone systemd[1862]: Stopped target Default.
Aug 31 08:40:28 drystone systemd[1862]: Stopping Sound Service...
Aug 31 08:40:28 drystone systemd[1]: Stopping User Manager for UID 1005...

...

Aug 31 08:41:57 drystone systemd[1862]: Stopping D-Bus User Message Bus...
Aug 31 08:41:57 drystone systemd[1862]: pulseaudio.service: Succeeded.
Aug 31 08:41:57 drystone systemd[1862]: Stopped Sound Service.
Aug 31 08:41:57 drystone systemd[1862]: dbus.service: Main process
exited, code=killed, status=15/TERM
Aug 31 08:41:57 drystone systemd[1862]: dbus.service: Succeeded.
Aug 31 08:41:57 drystone systemd[1862]: Stopped D-Bus User Message Bus.
Aug 31 08:41:57 drystone systemd[1862]: Stopped target Basic System.

...

Aug 31 08:41:57 drystone systemd[1862]: Reached target Shutdown.
Aug 31 08:41:57 drystone systemd[1862]: systemd-exit.service: Succeeded.
Aug 31 08:41:57 drystone systemd[1862]: Started Exit the Session.
Aug 31 08:41:57 drystone systemd[1862]: Reached target Exit the Session.
Aug 31 08:41:57 drystone systemd[1863]:
pam_unix(systemd-user:session): session closed for user mike

...

Aug 31 08:41:57 drystone systemd[1]: [email protected]: Succeeded.
Aug 31 08:41:57 drystone systemd[1]: Stopped User Manager for UID 1005.

2. 설명할 수 없는 종료 지연

전체 로그:로그 종료 지연.txt

Sep 03 11:42:47 drystone systemd[1]: Stopping User Manager for UID 1001...

...

Sep 03 11:42:47 drystone systemd[1]: Stopped Login Service.
Sep 03 11:44:16 drystone systemd[1359]: Stopping D-Bus User Message Bus...
Sep 03 11:44:16 drystone systemd[1359]: Stopping Sound Service...
Sep 03 11:44:16 drystone systemd[1359]: pulseaudio.service: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Stopped Sound Service.
Sep 03 11:44:16 drystone systemd[1359]: dbus.service: Main process exited, code=killed, status=15/TERM
Sep 03 11:44:16 drystone systemd[1359]: dbus.service: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Stopped D-Bus User Message Bus.
Sep 03 11:44:16 drystone systemd[1359]: Stopped target Basic System.
Sep 03 11:44:16 drystone systemd[1359]: Stopped target Sockets.
Sep 03 11:44:16 drystone systemd[1359]: gpg-agent.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed GnuPG cryptographic agent and passphrase cache.
Sep 03 11:44:16 drystone systemd[1359]: gpg-agent-ssh.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Sep 03 11:44:16 drystone systemd[1359]: dbus.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed D-Bus User Message Bus Socket.
Sep 03 11:44:16 drystone systemd[1359]: gpg-agent-browser.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
Sep 03 11:44:16 drystone systemd[1359]: gpg-agent-extra.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Sep 03 11:44:16 drystone systemd[1359]: dirmngr.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed GnuPG network certificate management daemon.
Sep 03 11:44:16 drystone systemd[1359]: Stopped target Timers.
Sep 03 11:44:16 drystone systemd[1359]: Stopped target Paths.
Sep 03 11:44:16 drystone systemd[1359]: pulseaudio.socket: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Closed Sound System.
Sep 03 11:44:16 drystone systemd[1359]: Reached target Shutdown.
Sep 03 11:44:16 drystone systemd[1359]: systemd-exit.service: Succeeded.
Sep 03 11:44:16 drystone systemd[1359]: Started Exit the Session.
Sep 03 11:44:16 drystone systemd[1359]: Reached target Exit the Session.
Sep 03 11:44:16 drystone systemd[1360]: pam_unix(systemd-user:session): session closed for user alan-sysop
Sep 03 11:44:16 drystone systemd[1]: [email protected]: Succeeded.
Sep 03 11:44:16 drystone systemd[1]: Stopped User Manager for UID 1001.

공개: 이 링크 로그에는 systemd[1]: Received SIGINT. Ctrl+Alt+Del을 누르면서 작성한 13줄도 포함되어 있습니다. 내가 알 수 있는 한, 이는 Plymouth 부트 스플래시를 전환하는 것 외에는 아무런 효과가 없습니다. 첫 번째 메시지는 시스템이 30초 동안 정지된 후에 나타납니다. 그래서 우리는 그것을 무시할 수 있다고 생각합니다.

pulseaudio.service를 지연시키는 정렬 종속성을 찾을 수 없습니다.

서비스 파일에는 다음에 대한 명시적인 순서 종속성이 없습니다 pulseaudio.service.

$ grep -r pulseaudio.service /usr/lib/systemd/user/
$

그 반대:

$ systemctl --user cat pulseaudio.service
# /usr/lib/systemd/user/pulseaudio.service
[Unit]
Description=Sound Service

# We require pulseaudio.socket to be active before starting the daemon, because
# while it is possible to use the service without the socket, it is not clear
# why it would be desirable.
#
# A user installing pulseaudio and doing `systemctl --user start pulseaudio`
# will not get the socket started, which might be confusing and problematic if
# the server is to be restarted later on, as the client autospawn feature
# might kick in. Also, a start of the socket unit will fail, adding to the
# confusion.
#
# After=pulseaudio.socket is not needed, as it is already implicit in the
# socket-service relationship, see systemd.socket(5).
Requires=pulseaudio.socket
ConditionUser=!root

[Service]
# Note that notify will only work if --daemonize=no
Type=notify
ExecStart=/usr/bin/pulseaudio --daemonize=no
Restart=on-failure

[Install]
Also=pulseaudio.socket
WantedBy=default.target

현재 시도 중인 해결 방법

diff --git a/systemd/system/[email protected]/override.conf b/systemd/system/[email protected]/override.conf
new file mode 100644
index 0000000..86734ef
--- /dev/null
+++ b/systemd/system/[email protected]/override.conf
@@ -0,0 +1,2 @@
+[Service]
+TimeoutStopSec=7s
diff --git a/systemd/user.conf b/systemd/user.conf
index b427f1e..cb5b646 100644
--- a/systemd/user.conf
+++ b/systemd/user.conf
@@ -21,7 +21,7 @@
 #DefaultStandardOutput=inherit
 #DefaultStandardError=inherit
 #DefaultTimeoutStartSec=90s
-#DefaultTimeoutStopSec=90s
+DefaultTimeoutStopSec=5s
 #DefaultRestartSec=100ms
 #DefaultStartLimitIntervalSec=10s
 #DefaultStartLimitBurst=5