[gelöst] Verzögertes Ausschalten nach dem Herunterfahren

[smutbert]

Hi,

nachdem ich nun schon einige Zeit buster nutze schaltet sich mein Desktop PC nun plötzlich nach dem Herunterfahren meistens nur mit einiger Verzögerung aus, oft erst nach ungefähr 10 bis 15 Minuten, seltener nach 1 bis 2 Minuten oder wie es sich gehört auch sofort.

Das Herunterfahren selbst läuft ordnungsgemäß und ohne timeouts, lange stop-jobs oder sonstige auffällige Verzögerung ab, aber wieso der Computer nach dem Herunterfahren trotzdem eine Pause einlegt ist mir vollkommen unklar:

Code: Alles auswählen

[...]
Sep 20 12:20:50 iolaos systemd[1]: systemd-remount-fs.service: Succeeded.
Sep 20 12:20:50 iolaos systemd[1]: Stopped Remount Root and Kernel File Systems.
Sep 20 12:20:50 iolaos systemd[1]: Reached target Shutdown.
Sep 20 12:20:50 iolaos systemd[1]: Reached target Final Step.
Sep 20 12:20:50 iolaos systemd[1]: systemd-poweroff.service: Succeeded.
Sep 20 12:20:50 iolaos systemd[1]: Started Power-Off.
Sep 20 12:20:50 iolaos systemd[1]: Reached target Power-Off.
Sep 20 12:20:50 iolaos systemd[1]: Shutting down.
Sep 20 12:20:50 iolaos kernel: printk: systemd-shutdow: 76 output lines suppressed due to ratelimiting
Sep 20 12:20:50 iolaos systemd-shutdown[1]: Syncing filesystems and block devices.
Sep 20 12:20:50 iolaos systemd-journald[293]: Journal stopped

(Bei diesem Beispiel hat sich der Computer erst etwa 10 Minuten später um ~12:30 ausgeschaltet.)

Ich werde mir nun noch die Kernelmeldungen auf der Konsole ausgeben lassen, um vielleicht zu sehen ob der Kernel nach dem Beenden des Journals noch etwas ausgibt.

Habt ihr vielleicht Ideen was die Ursache für die Verzögerung sein könnte, wie ich herausfinde welche 76 Zeilen nach dem Shutdown im Log nicht aufgezeichnet wurden (für den Fall, dass die etwas damit zu tun haben) oder wie ich der Sache sonst noch auf den Grund gehen könnte.

lg smutbert

[cronoik]

Korreliert dieses Verhalten mit einem kuerzlichen Upgrade?

ie ich herausfinde welche 76 Zeilen nach dem Shutdown im Log nicht aufgezeichnet wurden (für den Fall, dass die etwas damit zu tun haben)

Das kannst du mit dem Bootparameter 'printk.devkmsg=on' machen [1].

[1] https://www.kernel.org/doc/Documentatio ... kernel.txt

[smutbert]

Danke cronoik
Die unterdrückten Zeilen habe ich noch nicht zu Gesicht bekommen, weil ich bis jetzt bei jedem Start die bootoption vergessen habe ☺

Nachdem ich mir nun aber schrittweise immer mehr Meldungen auf der Konsole ausgeben lasse, erhalte ich ungefähr das hier:

Code: Alles auswählen

[  OK  ] Reached target Power-Off.
[51987.231358] systemd-shutdown[1]: All filesystems unmountet.
[51987.xxxxxx] [...]
[51987.xxxxxx] [jede Menge weiterer Erfolgsmeldungen von systemd-shutdown]
[51987.xxxxxx] [...]
[51987.791038] ACPI: Preparing to enter system sleep state S5

und dann hängt es wobei etwa alle zwei Minuten ein neuer Absatz über den hängengebliebenen Task »systemd-shutdow:1« folgt

Code: Alles auswählen

INFO: task systemd-shutdow:1 blocked for more than 120 seconds:
          Not tainted 5.2.0-0.bpo.2-amd64 #1 Debian 5.2.9-2~bpo10+1
          ...

Ist jetzt nicht alles, da steht noch viel mehr, aber weil ich das abschreiben muss,erspare ich mir den Rest.

Nachdem die letzte unverzögerte und gleichzeitig wohl erwartete Meldung das „ACPI: Preparing to enter system sleep state S5“ ist, gehe ich einmal davon aus, dass inklusive Kernel alle der Meinung sind, dass sich das System jetzt ausschalten sollte und es das nur nicht tut.
Oder (unwahrscheinlicher) systemd-shutdown selbst hängenbleibt und das Ausschalten verhindert.

Als erstes habe ich jetzt ein BIOS-Update gemacht.

[cronoik]

Ich vermute mal das du die Probleme mit dem 4.19 Kernel nicht hast?

Nachdem die letzte unverzögerte und gleichzeitig wohl erwartete Meldung das „ACPI: Preparing to enter system sleep state S5“ ist, gehe ich einmal davon aus, dass inklusive Kernel alle der Meinung sind, dass sich das System jetzt ausschalten sollte und es das nur nicht tut.
Oder (unwahrscheinlicher) systemd-shutdown selbst hängenbleibt und das Ausschalten verhindert.

Die Meldungen kommen vom Kernel der selbst mitbekommen hat das er irgendwo haengt. Systemd ist hier nur der Aussloeser, aber nicht die Ursache. Vielleicht geben die unterdrueckten Zeilen oder dmesg einen Hinweis (Hier [1] war es beispielsweise nouveau.).

[1] https://bbs.archlinux.org/viewtopic.php?id=225836

[smutbert]

Ob der Kernel hängt ist wohl Ansichtssache. Ich interpretiere das so:
systemd-shutdown gibt dem Kernel den Befehl zum Abschalten und macht danach nichts mehr, nicht einmal sich selbst beenden.
Der Computer schaltet sich aber nicht ab. Der Kernel merkt dass systemd-shutdown nicht reagiert und gibt etwa alle 2 Minuten die Meldung über den nicht reagierenden Prozeß aus, bis sich der Computer endlich tatsächlich abschaltet.


Die Ausschaltverzögerung ist jetzt seit dem BIOS-Update nicht mehr aufgetreten. Ich weiß aber nicht ob das BIOS-Update den Fehler behoben hat oder die Tatsache, dass ich beim Update alle BIOS-Einstellungen verloren habe und noch nicht alles wieder so eingestellt habe, wie ich es gerne hätte.
Das werde ich erst langsam Einstellung für Einstellung erledigen, damit ich weiß welche Einstellung schuld sein könnte, wenn es wieder auftritt

Die unterdrückten Zeilen bleiben aber trotz der Kerneloption unterdrückt im Log. Ob sie auf der Konsole ausgegeben würden, kann ich nicht sagen, weil sich der Computer dazu jetzt viel zu schnell ausschaltet

Also eigentlich ist das Thema gelöst, ich weiß nur nicht wieso und wie ich zu den unterdrückten Zeilen im Log komme, würde mich auch noch immer interessieren.


EDIT:
Im Nachhinein ist mir noch aufgefallen, dass das Auftreten des Problems genau mit der Installation der zram-tools zusammengefallen ist. Umso merkwürdiger finde ich es allerdings, dass das BIOS-Update das Problem beseitigt hat.