90 Sekunden stop job beim Shutdown. Warum? Was?

**wodenhof** · 16-Jan-2022, 10:00

Dies ist eine junge Installation von openSUSE tumbleweed. Nach wenigen Tagen seit der Installation läuft der Shutdown auf einen Bremsklotz in Form einer 90-sekündigen Unterbrechung, bevor dann Schluss ist.

Ich habe auf der selben Maschine eine gleichalte zweite Tumbleweed Installation, die das nicht macht. Ich habe den Bootvorgang auf verbose gestellt. Jetzt sehe ich beim Shutdown "A stop job is running for session of user {me}" mit einem Timer, der auf 90 Sekunden hoch läuft. Das passiert nicht, wenn ich vorm Login gleich wieder herunterfahre.

Ich habe die logs in /var/log angesehen, aber die sind nur maschinenlesbar. Wie finde ich heraus, was da los ist?

**Sauerland** · 16-Jan-2022, 10:44

Das journal persistent machen und danach dort schauen.......

https://doc.opensuse.org/documentati...ournalctl.html

Da läuft ein systemd Service aus dem Ruder und es wird 90 Sekunden gewartet das der Dienst sich beendet, bevor dieser abgeschossen wird.
Hab ich auch ab und an.......

**wodenhof** · 17-Jan-2022, 13:59

Originally Posted by Sauerland

Das journal persistent machen und danach dort schauen.......

https://doc.opensuse.org/documentati...ournalctl.html

Da läuft ein systemd Service aus dem Ruder und es wird 90 Sekunden gewartet das der Dienst sich beendet, bevor dieser abgeschossen wird.
Hab ich auch ab und an.......

Okay, hab's gemacht, hier ist der Ausschnitt aus journalctl -r:

Code:

Jan 17 21:52:51 ryzen systemd[1]: Stopping User Login Management... 
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Consumed 13.423s CPU time.
Jan 17 21:52:51 ryzen systemd[1]: Stopped Session 2 of User matthias. 
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Failed with result 'timeout'.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2465 (n/a) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2461 (pipe-connection) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2460 (scdaemon) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Stopping timed out. Killing.
Jan 17 21:51:22 ryzen systemd[1808]: app-org.kde.dolphin-fd80401f3c77409ebb54cc484fa651da.scope: Consumed 4.613s CPU time.
Jan 17 21:51:21 ryzen systemd[1]: Condition check resulted in Tell Plymouth To Jump To initramfs being skipped. 
Jan 17 21:51:21 ryzen systemd[1]: Started Show Plymouth Reboot Screen. 
Jan 17 21:51:21 ryzen systemd[1]: Received SIGRTMIN+20 from PID 5724 (plymouthd). 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target Host and Network Name Lookups. 
Jan 17 21:51:21 ryzen systemd[1]: Stopped NTP client/server. 
Jan 17 21:51:21 ryzen systemd[1]: chronyd.service: Deactivated successfully. 
Jan 17 21:51:21 ryzen systemd[1]: Starting Show Plymouth Reboot Screen... 
Jan 17 21:51:21 ryzen systemd[1]: Stopping NTP client/server... 
Jan 17 21:51:21 ryzen chronyd[1172]: chronyd exiting 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target System Time Set. 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target System Time Synchronized. 
Jan 17 21:51:21 ryzen systemd[1]: display-manager.service: Consumed 12.118s CPU time.
Jan 17 21:51:21 ryzen systemd[1]: Stopped X Display Manager. 
Jan 17 21:51:21 ryzen systemd[1]: display-manager.service: Deactivated successfully. 
Jan 17 21:51:21 ryzen display-manager[1178]: Starting service sddm 
Jan 17 21:51:21 ryzen sddm[1266]: QProcess: Destroyed while process ("/usr/libexec/sddm/sddm-helper") is still running.
Jan 17 21:51:21 ryzen sddm[1266]: Running display stop script  "/usr/share/sddm/scripts/Xstop"

Ich wüste nicht, dass Dolphin noch lief?!?

**wodenhof** · 17-Jan-2022, 14:02

Ich habe nur 3 Mail-Accounts mit wenig Trafic.

Und ja, das passiert auch, wenn ich mich erst abmelde und dann 'runterfahre.

Danke an alle für die Unterstützung.

**karlmistelberger** · 18-Jan-2022, 00:39

Originally Posted by wodenhof

Okay, hab's gemacht, hier ist der Ausschnitt aus journalctl -r:

Code:

Jan 17 21:52:51 ryzen systemd[1]: Stopping User Login Management... 
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Consumed 13.423s CPU time.
Jan 17 21:52:51 ryzen systemd[1]: Stopped Session 2 of User matthias. 
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Failed with result 'timeout'.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2465 (n/a) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2461 (pipe-connection) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Killing process 2460 (scdaemon) with signal SIGKILL.
Jan 17 21:52:51 ryzen systemd[1]: session-2.scope: Stopping timed out. Killing.
Jan 17 21:51:22 ryzen systemd[1808]: app-org.kde.dolphin-fd80401f3c77409ebb54cc484fa651da.scope: Consumed 4.613s CPU time.
Jan 17 21:51:21 ryzen systemd[1]: Condition check resulted in Tell Plymouth To Jump To initramfs being skipped. 
Jan 17 21:51:21 ryzen systemd[1]: Started Show Plymouth Reboot Screen. 
Jan 17 21:51:21 ryzen systemd[1]: Received SIGRTMIN+20 from PID 5724 (plymouthd). 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target Host and Network Name Lookups. 
Jan 17 21:51:21 ryzen systemd[1]: Stopped NTP client/server. 
Jan 17 21:51:21 ryzen systemd[1]: chronyd.service: Deactivated successfully. 
Jan 17 21:51:21 ryzen systemd[1]: Starting Show Plymouth Reboot Screen... 
Jan 17 21:51:21 ryzen systemd[1]: Stopping NTP client/server... 
Jan 17 21:51:21 ryzen chronyd[1172]: chronyd exiting 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target System Time Set. 
Jan 17 21:51:21 ryzen systemd[1]: Stopped target System Time Synchronized. 
Jan 17 21:51:21 ryzen systemd[1]: display-manager.service: Consumed 12.118s CPU time.
Jan 17 21:51:21 ryzen systemd[1]: Stopped X Display Manager. 
Jan 17 21:51:21 ryzen systemd[1]: display-manager.service: Deactivated successfully. 
Jan 17 21:51:21 ryzen display-manager[1178]: Starting service sddm 
Jan 17 21:51:21 ryzen sddm[1266]: QProcess: Destroyed while process ("/usr/libexec/sddm/sddm-helper") is still running.
Jan 17 21:51:21 ryzen sddm[1266]: Running display stop script  "/usr/share/sddm/scripts/Xstop"

Ich wüste nicht, dass Dolphin noch lief?!?

Dolphin stoppte doch ordnungsgemäß. Siehe z.B. dieses Beispiel:

Code:

karl@erlangen:~> journalctl --user -b -1 -u app-org.kde.kmail2-37fc91f2d98b4ce4b48c81a9bed05c71.scope 
-- Journal begins at Wed 2021-12-15 08:27:13 CET, ends at Tue 2022-01-18 08:17:02 CET. -- 
Jan 17 19:46:24 erlangen systemd[1186]: Started KMail - E-Mail-Programm. 
Jan 17 19:46:26 erlangen kmail[1481]: Cannot initialize model with data QJsonObject(). missing: QJsonValue(string, "urls")
Jan 17 19:48:55 erlangen kmail[1481]: kf.notifications: env says KDE is running but SNI unavailable -- check KDE_FULL_SESSION and XDG_CURRENT_DESKTOP
Jan 17 19:48:55 erlangen kmail[1481]: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-cmd.socket"
Jan 17 19:48:55 erlangen kmail[1481]: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-cmd.socket"
Jan 17 19:48:55 erlangen kmail[1481]: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-cmd.socket"
Jan 17 19:48:55 erlangen systemd[1186]: Stopping KMail - E-Mail-Programm... 
Jan 17 19:48:55 erlangen systemd[1186]: Stopped KMail - E-Mail-Programm. 
Jan 17 19:48:55 erlangen systemd[1186]: app-org.kde.kmail2-37fc91f2d98b4ce4b48c81a9bed05c71.scope: Consumed 1.515s CPU time.
karl@erlangen:~>

Die Problembären sind die Prozesse 2460, 2461 und 2465. Wo gehören die hin?

**wodenhof** · 18-Jan-2022, 13:42

Originally Posted by karlmistelberger

Die Problembären sind die Prozesse 2460, 2461 und 2465. Wo gehören die hin?

Äh -- keine Ahnung. Wie kann man das herausbekommen? Die Nummern ändern sich doch nit jedem Booten...

Ach ja, und danke für den Hinweis in Sachen Dolphin

.

**wodenhof** · 18-Jan-2022, 13:46

But (in case this helps):

Code:

me@ryzen:~> sudo systemctl status session-2.scope   
● session-2.scope - Session 2 of User me 
     Loaded: loaded (/run/systemd/transient/session-2.scope; transient) 
  Transient: yes 
     Active: active (running) since Tue 2022-01-18 17:37:33 CET; 4h 6min ago 
      Tasks: 128 
        CPU: 48.967s 
     CGroup: /user.slice/user-1000.slice/session-2.scope 
             ├─5042 /usr/libexec/sddm/sddm-helper --socket /tmp/sddm-auth8d4488b6-4b19-4537-83c8-1f2541462c8a --id 1 --start /usr/bin/startplasma-x11 --user me 
             ├─5053 /usr/bin/startplasma-x11 
             ├─5132 /usr/bin/ssh-agent /usr/bin/gpg-agent --sh --daemon --keep-display /usr/libexec/xinit/xinitrc 
             ├─5133 /usr/bin/gpg-agent --sh --daemon --keep-display /usr/libexec/xinit/xinitrc 
             ├─5188 /usr/lib64/libexec/kf5/start_kdeinit 
             ├─5189 "kdeinit5: Running..." "" "" "" "" "" "" "" "" "" "" 
             ├─5190 /usr/lib64/libexec/kf5/klauncher --fd=9 
             ├─5203 /usr/bin/kded5 
             ├─5207 /usr/bin/kwin_x11 
             ├─5218 /usr/bin/xsettingsd 
             ├─5287 /usr/bin/ksmserver 
             ├─5297 /usr/lib64/libexec/polkit-kde-authentication-agent-1 
             ├─5299 /usr/lib64/libexec/org_kde_powerdevil 
             ├─5301 /usr/bin/kaccess 
             ├─5303 /usr/bin/plasmashell 
             ├─5306 /usr/bin/xembedsniproxy 
             ├─5308 /usr/lib64/libexec/baloo_file 
             ├─5405 /usr/bin/gmenudbusmenuproxy 
             ├─5451 /usr/libexec/geoclue-2.0/demos/agent 
             ├─5580 scdaemon --multi-server 
             ├─6234 /usr/lib64/libexec/kf5/kioslave5 /usr/lib64/qt5/plugins/kf5/kio/kio_file.so file "" local:/run/user/1000/kded5RVloyA.1.slave-socket 
             └─6236 /usr/lib64/libexec/kf5/kioslave5 /usr/lib64/qt5/plugins/kf5/kio/kio_file.so file "" local:/run/user/1000/kded5LTsJGn.2.slave-socket 

Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1453: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1631: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1739: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1980: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:2223: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: file:///usr/share/plasma/look-and-feel/org.kde.breeze.desktop/contents/components/UserList.qml:47:9: Unable to assign [undefined] to bool
Jan 18 18:35:55 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 19:34:15 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 20:32:35 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 21:30:55 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok

Since there was some complaint about "session-2.scope"...

**karlmistelberger** · 18-Jan-2022, 23:28

Originally Posted by wodenhof

But (in case this helps):

Code:

me@ryzen:~> sudo systemctl status session-2.scope   
● session-2.scope - Session 2 of User me 
     Loaded: loaded (/run/systemd/transient/session-2.scope; transient) 
  Transient: yes 
     Active: active (running) since Tue 2022-01-18 17:37:33 CET; 4h 6min ago 
      Tasks: 128 
        CPU: 48.967s 
     CGroup: /user.slice/user-1000.slice/session-2.scope 
             ├─5042 /usr/libexec/sddm/sddm-helper --socket /tmp/sddm-auth8d4488b6-4b19-4537-83c8-1f2541462c8a --id 1 --start /usr/bin/startplasma-x11 --user me 
             ├─5053 /usr/bin/startplasma-x11 
             ├─5132 /usr/bin/ssh-agent /usr/bin/gpg-agent --sh --daemon --keep-display /usr/libexec/xinit/xinitrc 
             ├─5133 /usr/bin/gpg-agent --sh --daemon --keep-display /usr/libexec/xinit/xinitrc 
             ├─5188 /usr/lib64/libexec/kf5/start_kdeinit 
             ├─5189 "kdeinit5: Running..." "" "" "" "" "" "" "" "" "" "" 
             ├─5190 /usr/lib64/libexec/kf5/klauncher --fd=9 
             ├─5203 /usr/bin/kded5 
             ├─5207 /usr/bin/kwin_x11 
             ├─5218 /usr/bin/xsettingsd 
             ├─5287 /usr/bin/ksmserver 
             ├─5297 /usr/lib64/libexec/polkit-kde-authentication-agent-1 
             ├─5299 /usr/lib64/libexec/org_kde_powerdevil 
             ├─5301 /usr/bin/kaccess 
             ├─5303 /usr/bin/plasmashell 
             ├─5306 /usr/bin/xembedsniproxy 
             ├─5308 /usr/lib64/libexec/baloo_file 
             ├─5405 /usr/bin/gmenudbusmenuproxy 
             ├─5451 /usr/libexec/geoclue-2.0/demos/agent 
             ├─5580 scdaemon --multi-server 
             ├─6234 /usr/lib64/libexec/kf5/kioslave5 /usr/lib64/qt5/plugins/kf5/kio/kio_file.so file "" local:/run/user/1000/kded5RVloyA.1.slave-socket 
             └─6236 /usr/lib64/libexec/kf5/kioslave5 /usr/lib64/qt5/plugins/kf5/kio/kio_file.so file "" local:/run/user/1000/kded5LTsJGn.2.slave-socket 

Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1453: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1631: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1739: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:1980: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: qt.svg: <input>:303:2223: Could not add child element to parent element because the types are incorrect.
Jan 18 17:48:54 ryzen kscreenlocker_greet[7336]: file:///usr/share/plasma/look-and-feel/org.kde.breeze.desktop/contents/components/UserList.qml:47:9: Unable to assign [undefined] to bool
Jan 18 18:35:55 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 19:34:15 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 20:32:35 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok
Jan 18 21:30:55 ryzen plasmashell[5303]: libkcups: Renew-Subscription last error: 0 successful-ok

Since there was some complaint about "session-2.scope"...

Ja. Diese Ausgabe hilft weiter. Weitere Details gibt es mit pstree:

Code:

erlangen:~ # pstree -pt 1188 
sddm-helper(1188)───startplasma-x11(1200)─┬─gpg-agent(1288)─┬─scdaemon(13096)───{pipe-connection}(13098) 
                                          │                 └─{gpg-agent}(13099) 
                                          ├─ssh-agent(1287) 
                                          └─{QDBusConnection}(1296) 
erlangen:~ #

Verdächtig sind die fett markierten Prozesse, letztlich deren Vater gpg-agent(1288). Warum die bei dir Probleme machen und bei mir keine weiß ich leider nicht.

Vieelicht liegt es an einem der Konfigurationsfiles:

Code:

karl@erlangen:~> find -name '*gpg*' 
./.gnupg/S.gpg-agent 
./.gnupg/gpg.conf 
./.gnupg/pubring.gpg 
./.gnupg/pubring.gpg~ 
./.gnupg/trustdb.gpg 
karl@erlangen:~>

**wodenhof** · 19-Jan-2022, 08:57

Super, was man "nebenher" so lernen kann, danke für "pstree". Also

Code:

me@ryzen:~> find -name '*gpg*' 
./.gnupg/trustdb.gpg 
./.gnupg/gpg-agent.conf

gnupg/trustdb.gpg ist nur maschinenlesbar.

gpg-agent.conf:

Code:

default-cache-ttl 300
max-cache-ttl 999999

Gibt das Probleme?

Im Übrigen habe ich session-2.scope mal vor dem 'runterfahren per systemctl gestoppt. Das beendet die grafische Sitzung, die 90 Sekunden Wartezeit bleibt aber.

Das Einzige möglicherweise gpg-relevante was ich gemacht habe, ist das Kopieren von KWalletinhalten und dem Salt auf den neuen Rechner. Kann es das sein?

<edit> Eben habe ich den gpg-agent mit "kill -9 ..." beendet. Damit verschwindet die Menu-Leiste von KDE aber sonst passiert >2 Minuten nix. Ich musste von einer Konsole aus rebooten -- und durfte dann die obligaten 90 Sekunden warten. </edit>

**karlmistelberger** · 19-Jan-2022, 13:13

Originally Posted by wodenhof

Super, was man "nebenher" so lernen kann, danke für "pstree". Also

Code:

me@ryzen:~> find -name '*gpg*' 
./.gnupg/trustdb.gpg 
./.gnupg/gpg-agent.conf

gnupg/trustdb.gpg ist nur maschinenlesbar.

gpg-agent.conf:

Code:

default-cache-ttl 300
max-cache-ttl 999999

Gibt das Probleme?

Ich denke das kann schon sein. Ich habe kein gpg-agent.conf und habe mein .gnupg/S.gpg-agent gelöscht. Nach dem Ausloggen und erneutem Einloggen gibt es auch keinen scdaemon mehr (ein paar Stunden später war er wieder da).

Im Übrigen habe ich session-2.scope mal vor dem 'runterfahren per systemctl gestoppt. Das beendet die grafische Sitzung, die 90 Sekunden Wartezeit bleibt aber. Das Einzige möglicherweise gpg-relevante was ich gemacht habe, ist das Kopieren von KWalletinhalten und dem Salt auf den neuen Rechner. Kann es das sein?

Kann ich mir denken.

<edit> Eben habe ich den gpg-agent mit "kill -9 ..." beendet. Damit verschwindet die Menu-Leiste von KDE aber sonst passiert >2 Minuten nix. Ich musste von einer Konsole aus rebooten -- und durfte dann die obligaten 90 Sekunden warten. </edit>

Dieses Verhalten erwarte ich. Ich würde scdaemon und eventuell Söhne killen, überprüfen ob sie tatsächlich tot sind und dann rebooten.

Mein user karl ist schon fünf Jahre alt. Alte Files machen hin wieder Schwierigkeiten. Ich lösche sie meist ohne Folgen. Im Zweifelsfall habe ich einen Backup.

Participation Requested

Thread: 90 Sekunden stop job beim Shutdown. Warum? Was?

Thread Tools

Display

Hybrid View