Bug 694646

Summary: qemu hangs upon shutdown
Product: [Fedora] Fedora Reporter: Daniel Belton <danielbelton>
Component: systemdAssignee: Lennart Poettering <lpoetter>
Status: CLOSED WORKSFORME QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 15CC: johannbg, lpoetter, metherid, mschmidt, notting, plautrba, robinlee.sysu
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-05-02 21:42:53 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Attachments:
Description Flags
messages shown during shutdown
none
image from shutdown
none
image from shutdown
none
image from shutdown
none
systemd debug log none

Description Daniel Belton 2011-04-07 20:27:05 UTC
Description of problem: system hangs upon shutdown


Version-Release number of selected component (if applicable): systemd 24-1


How reproducible: On every shutdown, the system hangs and does not completely shut down


Steps to Reproduce:
1. shutdown or restart the system
2. 
3.
  
Actual results: The system hangs upon shutdown. The last messages displayed are:

Stopping /tmp
Starting Save Random Seed
Starting Store Sound Card State
systemd[1]: unit tmp.mount entered failed state


Expected results: System to shutdown normally


Additional info:

Comment 1 Daniel Belton 2011-04-07 21:49:51 UTC
This looks like it is either a bug in qemu or a conflict between systemd and qemu.

I had installed qemu to test a few applications for an ARM processor, I deactivated it so it doesn't load and that solved the problem of my system hanging on shutdown. 

With qemu started, it hangs. With qemu disabled, it shuts down normally.


unfortunately, even running with systemd-debug, it doesn't get much information.

Apr  7 16:13:28 tower11 systemd[1]: Reloading.
Apr  7 16:13:28 tower11 kernel: [  615.806344] systemd[1]: atd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806383] systemd[1]: kdump.service changed dead -> failed
Apr  7 16:13:28 tower11 kernel: [  615.806406] systemd[1]: acpid.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806423] systemd[1]: cups.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806439] systemd[1]: portreserve.service changed dead -> exited
Apr  7 16:13:28 tower11 kernel: [  615.806460] systemd[1]: cgconfig.service changed dead -> failed
Apr  7 16:13:28 tower11 kernel: [  615.806478] systemd[1]: abrtd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806494] systemd[1]: ksmtuned.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806511] systemd[1]: qemu.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806528] systemd[1]: sshd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806543] systemd[1]: crond.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806558] systemd[1]: nfs.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806576] systemd[1]: irqbalance.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806593] systemd[1]: gpm.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806609] systemd[1]: nfslock.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806626] systemd[1]: sandbox.service changed dead -> exited
Apr  7 16:13:28 tower11 kernel: [  615.806642] systemd[1]: mdmonitor.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806678] systemd[1]: abrt-ccpp.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806694] systemd[1]: cpuspeed.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806711] systemd[1]: rpcidmapd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806728] systemd[1]: auditd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806743] systemd[1]: rpcgssd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806759] systemd[1]: rpcbind.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806774] systemd[1]: rpcsvcgssd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806790] systemd[1]: rsyslog.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806805] systemd[1]: ksm.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806822] systemd[1]: NetworkManager.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806837] systemd[1]: netfs.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806852] systemd[1]: ntpd.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806867] systemd[1]: rc-local.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.806883] systemd[1]: basic.target changed dead -> active
Apr  7 16:13:28 tower11 kernel: [  615.806899] systemd[1]: local-fs.target changed dead -> active
Apr  7 16:13:28 tower11 kernel: [  615.806914] systemd[1]: sysinit.target changed dead -> active
Apr  7 16:13:28 tower11 kernel: [  615.806933] systemd[1]: systemd-tmpfiles-setup.service changed dead -> exited
Apr  7 16:13:28 tower11 kernel: [  615.806949] systemd[1]: systemd-readahead-collect.service changed dead -> exited
Apr  7 16:13:28 tower11 kernel: [  615.806965] systemd[1]: systemd-readahead-replay.service changed dead -> exited
Apr  7 16:13:28 tower11 kernel: [  615.806981] systemd[1]: systemd-readahead-done.timer changed dead -> elapsed
Apr  7 16:13:28 tower11 kernel: [  615.806996] systemd[1]: graphical.target changed dead -> active
Apr  7 16:13:28 tower11 kernel: [  615.807074] systemd[1]: multi-user.target changed dead -> active
Apr  7 16:13:28 tower11 kernel: [  615.807098] systemd[1]: rtkit-daemon.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.807123] systemd[1]: system-setup-keyboard.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.807148] systemd[1]: prefdm.service changed dead -> running
Apr  7 16:13:28 tower11 kernel: [  615.807169] systemd[1]: syslog.target changed dead -> active
Apr  7 16:13:28 tower11 rsyslogd-2177: imuxsock begins to drop messages from pid 1 due to rate-limiting
Apr  7 16:14:39 tower11 rsyslogd-2177: imuxsock lost 100 messages from pid 1 due to rate-limiting

Comment 2 Lennart Poettering 2011-04-12 12:00:56 UTC
Can you please boot with systemd.log_level=debug and systemd.log_target=kmsg?

Then, please paste the last log messages you see on your screen here. (Photo if necessary)

Comment 3 Robin Lee 2011-04-12 17:53:33 UTC
Created attachment 491533 [details]
messages shown during shutdown

Comment 4 Daniel Belton 2011-04-12 18:15:27 UTC
Created attachment 491536 [details]
image from shutdown

images from shutdown

Comment 5 Daniel Belton 2011-04-12 18:16:25 UTC
Created attachment 491537 [details]
image from shutdown

Comment 6 Daniel Belton 2011-04-12 18:17:11 UTC
Created attachment 491538 [details]
image from shutdown

Comment 7 Daniel Belton 2011-04-12 18:23:33 UTC
Created attachment 491539 [details]
systemd debug log

log with systemd.debug 

As you can see, it is hanging on shutdown, but I am thinking now that it is a bug in qemu and not systemd.

If I let it sit for quite a while, it will eventually time out and power down/restart

You can see in the images (I know, not very good ones) that after a fairly long period of time, it does time out. 

I am thinking this bug really should be transferred over to the qemu people, but I'll wait and see what the response here is. It may still be a systemd issue, I don't know.

Comment 8 Robin Lee 2011-04-14 05:38:24 UTC
This may be a power management issue since suspending doesn't work either.

Comment 9 Lennart Poettering 2011-04-24 12:29:02 UTC
Seems stopping of qemu.service times out.

Comment 10 Lennart Poettering 2011-04-28 20:27:59 UTC
Hmm, this is probably caused by systemd shutting down /proc/sys/binfmt_misc at the same time as qemu still wants to access it.

Can you please do the following: place a shell script in /lib/systemd/systemd-shutdown:

#!/bin/sh
mount / -orw,remount
demsg > /dmesg.shutdown
mount / -oro,remount

mark it +x, then try to reproduce the issue with "systemd.log_level=debug" and "systemd.log_target=kmsg" on the kernel command line and wait for the timeout and eventual shutdown. On next reboot, retrieve the /dmesg.shutdown file, and attach it here. This should give me an idea what is going on.

Comment 11 Lennart Poettering 2011-04-28 20:29:07 UTC
(Ideally qemu should just drop rules in /etc/binfmt.d, and drop the sysv script. While that would certainly fix the issue it actually just sidesteps it, and I think we should fix the deadlock first)

Comment 12 Daniel Belton 2011-05-02 18:10:19 UTC
I did as requested, putting a shell script in /lib/systemd/system-shutdown (/lib/systemd/systemd-shutdown was a file so I opted for the folder figuring you had just made a typo) 

However, I no longer get qemu hanging upon shutdown anymore, and the /dmesg.shutdown file is an empty file. (I also changed the demsg > /dmesg.shutdown to dmesg > /dmesg.shutdown, same results) 

I no longer have the hang upon shutdown, with or without the shell script in /lib/systemd/system-shutdown. 

So possibly this issue is resolved? I don't remember having an update to qemu or systemd since I was having the freeze on shutdown. 

(and yes, qenu is running :D)

[root@tower11 ~]# systemctl status qemu.service
qemu.service - SYSV: Allow users to run non-native Linux programs by just clicking on them (or typing ./file.exe)
	  Loaded: loaded (/etc/rc.d/init.d/qemu)
	  Active: active (running) since Mon, 02 May 2011 13:02:28 -0500; 7min ago
	 Process: 1370 ExecStart=/etc/rc.d/init.d/qemu start (code=exited, status=0/SUCCESS)
	  CGroup: name=systemd:/system/qemu.service

Comment 13 Daniel Belton 2011-05-02 18:18:21 UTC
Looking back, I was running systemd-24 when I orignally had the problem with qemu, and now I am running systemd-25. Possibly there was a change that fixed the problem? 

I don't normally run with qemu started since I don't use it all the time, and I haven't been using it lately so it could have been fixed and I didn't notice.

Comment 14 Lennart Poettering 2011-05-02 21:42:53 UTC
OK, then let's close it. If you manage to reproduce this with v26, then please reopen.