FS#34708 - [systemd] (200-1) Shutdown services don't run.

Attached to Project: Arch Linux
Opened by Erich Luckerbauer (moleculecolony) - Tuesday, 09 April 2013, 23:15 GMT
Last edited by Dave Reisner (falconindy) - Friday, 10 May 2013, 12:44 GMT
Task Type Bug Report
Category Packages: Core
Status Closed
Assigned To Dave Reisner (falconindy)
Tom Gundersen (tomegun)
Architecture x86_64
Severity High
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Description:
Since last version of systemd, the services in (etc.. or usr..)/shutdown.target.wants don't get executed. That is, sometimes they do get executed at shutdown, but most of the time they don't.

Additional info:
* package version(s)
systemd-200.1
linux-3.8.6-1
* config and/or log files etc.


Steps to reproduce:
Do a couple of shutdowns and find out that for example alsa.store.service gets executed only sporadically. (journalctl | grep Store)

One possible workaround is to put the commands under ExecStopPost= of a service that is known to stop gracefully and in time to allow the desired operations. (What worked in my case was lirc.)
This task depends upon

Closed by  Dave Reisner (falconindy)
Friday, 10 May 2013, 12:44 GMT
Reason for closing:  Upstream
Additional comments about closing:  https://bugs.freedesktop.org/show_bug.cg i?id=64365
Comment by Erich Luckerbauer (moleculecolony) - Sunday, 14 April 2013, 17:57 GMT
Found out that the problem was that some services those depend upon get terminated too early. I got confused because this changed with the last update, in two places at once (alsa and mysql). Probably they accelerated the shutdown process in total, and so my scripts from the shutdown.target don't work anymore.

I guess systemd is missing something like Depends= that postpones the terminating of services in the shutdown process if they are needed. And I don't want to use Requires= or Wants= because that would start mysql anew and that's not what I want.

So my solution was to make a script called shutdown that first executes my commands, and only then calls poweroff from systemd.

Maybe this "bug" could be closed, or left here for others with the same problem to read. (And maybe someone wants to open a feature request with the systemd guys.)
Comment by Dave Reisner (falconindy) - Sunday, 14 April 2013, 18:01 GMT
Can you reproduce with 201? I can't.
Comment by Dave Reisner (falconindy) - Sunday, 14 April 2013, 18:03 GMT
Should be already fixed by:

http://cgit.freedesktop.org/systemd/systemd/commit/?id=aaf7eb81be91
Comment by Erich Luckerbauer (moleculecolony) - Sunday, 14 April 2013, 18:06 GMT
I did lots of shutdowns yesterday for testing purposes, and here's the relation between shutdowns and executions of alsa.store.service:


[eri] journalctl | grep stopped
Apr 13 01:14:33 mitlDing systemd-journal[157]: Journal stopped
Apr 13 01:25:49 mitlDing systemd-journal[159]: Journal stopped
Apr 13 01:29:33 mitlDing systemd-journal[157]: Journal stopped
Apr 13 01:48:20 mitlDing systemd-journal[159]: Journal stopped
Apr 13 01:54:48 mitlDing systemd-journal[158]: Journal stopped
Apr 13 02:06:31 mitlDing systemd-journal[158]: Journal stopped
Apr 13 02:38:26 mitlDing systemd-journal[158]: Journal stopped
Apr 13 06:18:05 mitlDing systemd-journal[158]: Journal stopped
Apr 13 10:49:01 mitlDing systemd-journal[159]: Journal stopped
Apr 13 10:59:03 mitlDing systemd-journal[157]: Journal stopped
Apr 13 11:22:21 mitlDing systemd-journal[158]: Journal stopped
Apr 13 11:33:14 mitlDing systemd-journal[159]: Journal stopped
Apr 13 11:36:58 mitlDing systemd-journal[159]: Journal stopped
Apr 13 11:54:48 mitlDing systemd-journal[157]: Journal stopped
Apr 13 12:15:14 mitlDing systemd-journal[157]: Journal stopped
Apr 13 12:17:31 mitlDing systemd-journal[157]: Journal stopped
Apr 13 12:19:24 mitlDing systemd-journal[158]: Journal stopped
Apr 13 12:22:50 mitlDing systemd-journal[157]: Journal stopped
Apr 13 12:28:41 mitlDing systemd-journal[159]: Journal stopped
Apr 13 12:33:30 mitlDing systemd-journal[158]: Journal stopped
Apr 13 12:49:40 mitlDing systemd-journal[158]: Journal stopped
Apr 13 13:27:40 mitlDing systemd-journal[157]: Journal stopped
Apr 13 13:30:50 mitlDing systemd-journal[157]: Journal stopped
Apr 13 13:33:49 mitlDing systemd-journal[158]: Journal stopped
Apr 13 14:34:38 mitlDing systemd-journal[157]: Journal stopped
Apr 13 18:05:12 mitlDing systemd-journal[157]: Journal stopped
Apr 13 20:05:08 mitlDing systemd-journal[157]: Journal stopped
Apr 13 22:12:04 mitlDing systemd-journal[157]: Journal stopped
Apr 14 00:15:08 mitlDing systemd-journal[159]: Journal stopped
Apr 14 06:16:31 mitlDing systemd-journal[159]: Journal stopped
Apr 14 09:45:36 mitlDing systemd-journal[158]: Journal stopped
[eri] journalctl | grep Store
Apr 13 02:38:23 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 11:22:17 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 11:36:54 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 12:15:09 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 12:22:46 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 13:27:36 mitlDing systemd[1]: Started Store Sound Card State.
Apr 13 13:30:47 mitlDing systemd[1]: Started Store Sound Card State.
[eri] systemd --version
systemd 201
+PAM -LIBWRAP -AUDIT -SELINUX -IMA -SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ
[eri]
Comment by Dave Reisner (falconindy) - Sunday, 14 April 2013, 18:10 GMT
journalctl -u alsa-store # seems like a more appropriate thing to look at....

alsa-store runs every time on shutdown for me.
Comment by Erich Luckerbauer (moleculecolony) - Sunday, 14 April 2013, 18:22 GMT
It's basically the same (see below).

I'm running the custom alsa services, and maybe the only difference with you is that I use alsa loopback for jack output, so that it probably takes longer until the alsa-store can begin.

But I guess it's a fundamental problem, if sound.target doesn't know it should wait for alsa-store then it terminates, and alsa-store can't run. (At least that's what I imagine in this case, with my problem it was so, mysql terminated, and the script couldn't query the database.)


[eri] journalctl -u alsa-store
-- Logs begin at Sam 2013-04-13 01:13:25 CEST, end at Son 2013-04-14 20:08:23 CEST. --
Apr 13 02:38:23 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 11:22:17 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 11:36:54 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 12:15:09 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 12:22:46 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 13:27:36 mitlDing systemd[1]: Started Store Sound Card State.
-- Reboot --
Apr 13 13:30:47 mitlDing systemd[1]: Started Store Sound Card State.
[eri]
Comment by Dave Reisner (falconindy) - Monday, 15 April 2013, 13:46 GMT
Feel free to report upstream if you think you can actually reproduce this on 201. Nothing for Arch packaging to do here.

Loading...