Bug 907711

Summary: fail to poweroff guest when do system_powerdown in HMP monitor after login guest
Product: Red Hat Enterprise Linux 7 Reporter: Sibiao Luo <sluo>
Component: gnome-sessionAssignee: Ray Strode [halfline] <rstrode>
Status: CLOSED CURRENTRELEASE QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: high    
Version: 7.0CC: acathrow, chayang, flang, hhuang, juzhang, kwolf, michen, pbonzini, qzhang, sluo, virt-maint
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-08-08 19:07:30 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
serial log none

Description Sibiao Luo 2013-02-05 05:32:23 UTC
Description of problem:
boot up a rhel7 guest and login in guest, then do system_powerdown in HMP monitor, the guest fail to poweroff and can resume it by pressing keyboard.

Version-Release number of selected component (if applicable):
host info:
kernel-3.7.0-0.34.el7.x86_64
qemu-kvm-1.3.0-3.el7.x86_64
guest info:
3.7.0-0.34.el7.x86_64

How reproducible:
100%

Steps to Reproduce:
1.boot up a rhel7 guest and login in guest.
# /usr/libexec/qemu-kvm -M pc-1.3 -cpu Westmere -enable-kvm -m 2048 -smp 2,sockets=2,cores=1,threads=1 -no-kvm-pit-reinjection -usb -device usb-tablet,id=input0 -name sluo-test -uuid 350e716b-5f98-4bf0-9a2a-c8e423295244 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,max_ports=16,vectors=0,bus=pci.0,addr=0x3 -chardev socket,id=channel1,path=/tmp/helloworld1,server,nowait -device virtserialport,chardev=channel1,name=com.redhat.rhevm.vdsm,bus=virtio-serial0.0,id=port1 -chardev socket,id=channel2,path=/tmp/helloworld2,server,nowait -device virtserialport,chardev=channel2,name=com.redhat.rhevm.vdsm,bus=virtio-serial0.0,id=port2 -drive file=/home/RHEL-Server-7.0-64.qcow2,if=none,id=drive-system-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x4 -device scsi-hd,drive=drive-system-disk,bus=scsi0.0,id=system-disk,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x5,bootindex=2,event_idx=off -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x6 -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -device usb-ehci,id=ehci,bus=pci.0,addr=0x7 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=3 -k en-us -boot menu=on -qmp tcp:0:4444,server,nowait -serial unix:/tmp/ttyS0,server,nowait -vnc :1 -drive file=/home/floppy.vfd,if=none,id=drive-fdc0-0-0,format=raw -global isa-fdc.driveA=drive-fdc0-0-0 -drive file=/home/my-cdrom.iso,if=none,media=cdrom,format=raw,id=drive-ide1-0-1 -device ide-drive,drive=drive-ide1-0-1,id=ide1-0-1,bus=ide.0,unit=0 -chardev socket,path=/tmp/qga.sock,server,nowait,id=qga0 -device virtio-serial -device virtserialport,chardev=qga0,name=org.qemu.guest_agent.0 -monitor stdio
2.do system_powerdown in HMP monitor and check the VM status.
(qemu) system_powerdown 
(qemu) info status 
3.press any keyboard to resume the guest.
  
Actual results:
after steps 2, the guest fail to powerdown.
(qemu) system_powerdown 
(qemu) info status 
VM status: paused (suspended)
after steps 3, the guest can be resumed by pressing keyboard and can login guest again.

Expected results:
the guest can be poweroff successfully without any problem.

Additional info:

Comment 1 Sibiao Luo 2013-02-05 05:33:46 UTC
if do 'poweroff' command in guest, it can be poweroff successfully.

Comment 2 Chao Yang 2013-03-06 09:05:38 UTC
Hit this on kernel 3.8.0-0.40.el7.x86_64.
Both host kernel and guest kernel are 3.8.0-0.40.el7.x86_64.

Steps:
1. boot a rhel7 guest by:
# qemu-system-x86_64 -M q35 -monitor stdio -drive file=rhel7.0.qcow2,if=none,id=drive-ide0-0-0,format=qcow2,cache=none -device virtio-blk-pci,drive=drive-ide0-0-0,bootindex=1 -vnc :1 -m 2048 -smp 2 -netdev tap,id=hostnet0,vhost=on -device virtio-net-pci,netdev=hostnet0,id=net0,mac=78:2b:cb:6e:41:22 -enable-kvm -balloon none -boot menu=on -serial unix:/tmp/test,server,nowait
2. issue system_powerdown through qemu monitor to guest after bootup
3. resume guest by any keystroke
4. repeate step 2 
5. shutdown guest in guest by:
# shutdown -h now

Serial output will be attached.

Comment 3 Chao Yang 2013-03-06 09:06:39 UTC
Created attachment 705815 [details]
serial log

Comment 4 Chao Yang 2013-03-07 03:15:18 UTC
Another way to reproduce this issue:
1. boot a guest by:
# qemu-system-x86_64 -M q35 -monitor stdio -drive file=rhel7.0-1.qcow2,if=none,id=drive-ide0-0-0,format=qcow2,cache=none -device virtio-blk-pci,drive=drive-ide0-0-0,bootindex=1 -vnc :1 -m 2048 -smp 2 -netdev tap,id=hostnet0,vhost=on -device virtio-net-pci,netdev=hostnet0,id=net0,mac=78:2b:cb:6e:41:22 -balloon none -boot menu=on -device vfio-pci,host=22:00.0,id=pf,rombar=0 -enable-kvm -serial unix:/tmp/test,server,nowait -global PIIX4_PM.disable_s3=0
2. suspend guest to memory in guest
3. shutdown guest by:
# shutdown -h now

[  296.049635] dracut: Taking over mdmon processes.
[  296.095235] audit_printk_skb: 12 callbacks suppressed
[  296.127796] type=1400 audit(1362625732.792:406): avc:  denied  { search } for  pid=7795 comm="plymouthd" name="initramfs" dev="tmpfs" ino=1393 scontext=system_u:system_r:plymouthd_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=dir
[  296.182624] type=1300 audit(1362625732.792:406): arch=c000003e syscall=2 success=no exit=-13 a0=31e0411773 a1=102 a2=7 a3=0 items=0 ppid=1 pid=7795 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="plymouthd" exe="/oldroot/usr/sbin/plymouthd" subj=system_u:system_r:plymouthd_t:s0 key=(null)
[  296.283145] dracut Warning: Killing all remaining processes
[  296.384420] dracut Warning: Unmounted /oldroot/proc.
[  296.420265] dracut Warning: Unmounted /oldroot/sys/kernel/security.
[  296.453706] dracut Warning: Unmounted /oldroot/dev/shm.
[  296.496506] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/systemd.
[  296.529741] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/cpu,cpuacct.
[  296.569502] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/net_cls.
[  296.610514] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/perf_event.
[  296.652747] dracut Warning: Unmounted /oldroot/sys/fs/selinux.
[  296.685931] dracut Warning: Unmounted /oldroot/run.
[  296.718174] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/cpuset.
[  296.751066] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/devices.
[  296.784928] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/blkio.
[  296.830337] dracut Warning: Unmounted /oldroot/dev/pts.
[  296.862913] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/memory.
[  296.905925] dracut Warning: Unmounted /oldroot/dev.
[  296.940519] dracut Warning: Unmounted /oldroot/sys/fs/cgroup/freezer.
[  296.985826] dracut Warning: Unmounted /oldroot/sys/fs/cgroup.
[  297.019494] dracut Warning: Unmounted /oldroot/sys.
[  297.132489] dracut Warning: Unmounted /oldroot.
[  297.169111] dracut: Disassembling device-mapper devices
[  297.218317] dracut: Waiting for mdraid devices to be clean.
[  297.249266] dracut: Disassembling mdraid devices.
[  297.318742] kvm: exiting hardware virtualization
[  297.544869] ACPI: Preparing to enter system sleep state S5
[  297.574462] Disabling non-boot CPUs ...
[  297.602054] Unregister pv shared memory for cpu 1
[  297.637643] Broke affinity for irq 42
[  297.640052] Power down.
[  297.668624] dracut Warning: poweroff failed!
[  297.668624] dracut Warning:

Comment 5 Sibiao Luo 2013-07-03 03:46:58 UTC
(In reply to Sibiao Luo from comment #0)
> Description of problem:
> boot up a rhel7 guest and login in guest, then do system_powerdown in HMP
> monitor, the guest fail to poweroff and can resume it by pressing keyboard.
> 
If do system_powerdown after login to guest which met call trace, i paste the log here. 
If not login to guest before do system_powerdown, please refer to bug 980692. 

host info:
3.10.0-0.rc7.64.el7.x86_64
qemu-kvm-1.5.1-1.el7.x86_64
guest info:
3.10.0-0.rc7.64.el7.x86_64

# nc -U /tmp/ttyS0 
[   61.921745] PM: Syncing filesystems ... done.
[   63.003165] Freezing user space processes ... (elapsed 0.01 seconds) done.
[   63.015397] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[   63.026387] Suspending console(s) (use no_console_suspend to debug)
[   63.027083] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[   63.076812] ------------[ cut here ]------------
[   63.076818] WARNING: at kernel/irq/manage.c:1269 __free_irq+0x200/0x220()
[   63.076848] Modules linked in: fuse ebtable_nat nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_nat nf_nat_ipv6 ip6table_mangle bnep ip6t_REJECT nf_conntrack_ipv6 bluetooth nf_defrag_ipv6 iptable_nat nf_nat_ipv4 nf_nat iptable_mangle rfkill ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables sg xfs libcrc32c crc32_pclmul cirrus crc32c_intel ghash_clmulni_intel ttm virtio_console drm_kms_helper ppdev virtio_balloon drm microcode shpchp i2c_i801 lpc_ich i2c_core parport_pc mfd_core parport pcspkr uinput sd_mod crc_t10dif virtio_net virtio_scsi ahci libahci libata virtio_pci virtio_ring virtio dm_mirror dm_region_hash dm_log dm_mod
[   63.076850] CPU: 1 PID: 227 Comm: kworker/u8:5 Not tainted 3.10.0-0.rc7.64.el7.x86_64 #1
[   63.076851] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[   63.076855] Workqueue: events_unbound async_run_entry_fn
[   63.076858]  0000000000000009 ffff880146a03c00 ffffffff815fe65e ffff880146a03c38
[   63.076860]  ffffffff8105f531 ffff880146dfbb00 ffff880146e2c800 000000000000002f
[   63.076861]  ffff880146cc2084 ffff880146cc2000 ffff880146a03c48 ffffffff8105f60a
[   63.076862] Call Trace:
[   63.076866]  [<ffffffff815fe65e>] dump_stack+0x19/0x1b
[   63.076869]  [<ffffffff8105f531>] warn_slowpath_common+0x61/0x80
[   63.076870]  [<ffffffff8105f60a>] warn_slowpath_null+0x1a/0x20
[   63.076872]  [<ffffffff810ef720>] __free_irq+0x200/0x220
[   63.076873]  [<ffffffff810ef7d9>] free_irq+0x49/0xb0
[   63.076878]  [<ffffffffa0050511>] vp_del_vqs+0x61/0x90 [virtio_pci]
[   63.076881]  [<ffffffffa002fe4b>] virtscsi_remove_vqs+0x4b/0x50 [virtio_scsi]
[   63.076884]  [<ffffffffa002fe5e>] virtscsi_freeze+0xe/0x20 [virtio_scsi]
[   63.076887]  [<ffffffffa005018d>] virtio_pci_freeze+0x4d/0x80 [virtio_pci]
[   63.076890]  [<ffffffff8131762c>] pci_pm_suspend+0x6c/0x150
[   63.076891]  [<ffffffff813175c0>] ? pci_pm_freeze+0xc0/0xc0
[   63.076894]  [<ffffffff813e276e>] dpm_run_callback+0x2e/0x60
[   63.076896]  [<ffffffff813e3617>] __device_suspend+0xe7/0x280
[   63.076897]  [<ffffffff813e37cf>] async_suspend+0x1f/0xa0
[   63.076899]  [<ffffffff8108ae69>] async_run_entry_fn+0x39/0x120
[   63.076901]  [<ffffffff8107d106>] process_one_work+0x176/0x420
[   63.076904]  [<ffffffff8107dd2b>] worker_thread+0x11b/0x3a0
[   63.076906]  [<ffffffff8107dc10>] ? rescuer_thread+0x350/0x350
[   63.076908]  [<ffffffff810842d0>] kthread+0xc0/0xd0
[   63.076910]  [<ffffffff81084210>] ? insert_kthread_work+0x40/0x40
[   63.076912]  [<ffffffff8160ccac>] ret_from_fork+0x7c/0xb0
[   63.076914]  [<ffffffff81084210>] ? insert_kthread_work+0x40/0x40
[   63.076915] ---[ end trace 496927e3600f99a9 ]---
[   63.079917] PM: suspend of devices complete after 52.866 msecs
[   63.079976] PM: late suspend of devices complete after 0.057 msecs
[   63.080633] PM: noirq suspend of devices complete after 0.655 msecs
[   63.080640] ACPI: Preparing to enter system sleep state S3
[   63.080676] PM: Saving platform NVS memory
[   63.080677] Disabling non-boot CPUs ...
[   63.080693] Unregister pv shared memory for cpu 1
[   63.082657] smpboot: CPU 1 is now offline
[   63.082871] Unregister pv shared memory for cpu 2
[   63.084264] smpboot: CPU 2 is now offline
[   63.084450] Unregister pv shared memory for cpu 3
[   63.085832] smpboot: CPU 3 is now offline
[   63.086828] kvm-clock: cpu 0, msr 1:4ff86001, primary cpu clock, resume
[   63.086828] ACPI: Low-level resume complete
[   63.086828] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S0_] (20130328/hwxface-568)
[   63.086828] PM: Restoring platform NVS memory
[   63.086828] Enabling non-boot CPUs ...
[   63.086828] smpboot: Booting Node 0 Processor 1 APIC 0x1
[   63.082005] kvm-clock: cpu 1, msr 1:4ff86041, secondary cpu clock
[   63.160215] KVM setup async PF for cpu 1
[   63.160220] kvm-stealtime: cpu 1, msr 14fc8df00
[   63.160324] CPU1 is up
[   63.160346] smpboot: Booting Node 0 Processor 2 APIC 0x2
[   63.084041] kvm-clock: cpu 2, msr 1:4ff86081, secondary cpu clock
[   63.191741] KVM setup async PF for cpu 2
[   63.191745] kvm-stealtime: cpu 2, msr 14fd0df00
[   63.191798] CPU2 is up
[   63.191822] smpboot: Booting Node 0 Processor 3 APIC 0x3
[   63.085628] kvm-clock: cpu 3, msr 1:4ff860c1, secondary cpu clock
[   63.205245] KVM setup async PF for cpu 3
[   63.205248] kvm-stealtime: cpu 3, msr 14fd8df00
[   63.205305] CPU3 is up
[   63.205501] ACPI: Waking up from system sleep state S3
[   63.213959] PM: noirq resume of devices complete after 8.387 msecs
[   63.214040] PM: early resume of devices complete after 0.043 msecs
[   63.521168] ata3: SATA link down (SStatus 0 SControl 300)
[   63.522132] ata4: SATA link down (SStatus 0 SControl 300)
[   63.555152] ata6: SATA link down (SStatus 0 SControl 300)
[   63.561161] ata5: SATA link down (SStatus 0 SControl 300)
[   63.561272] ata1: SATA link down (SStatus 0 SControl 300)
[   63.561383] ata2: SATA link down (SStatus 0 SControl 300)
[   63.561514] PM: resume of devices complete after 347.471 msecs
[   63.635410] Restarting tasks ... done.

Comment 6 Hai Huang 2013-08-08 18:15:15 UTC
Appears to be a duplicate of https://bugzilla.redhat.com/show_activity.cgi?id=980692. Please confirm.

Comment 7 Laszlo Ersek 2013-08-08 19:07:30 UTC
Host: RHEL-7 nightly (updated today)
Guest: RHEL-7 nightly (updated today)

Host side command used for testing:
virsh qemu-monitor-command fw-seabios7.g-rhel7.e-rhel7 \
    --hmp system_powerdown

(1) /etc/systemd/system/default.target -> /lib/systemd/system/multi-user.target
(1a) when not logged in on the text console: system_powerdown works
(1b) when     logged in on the text console: system_powerdown works

(2) /etc/systemd/system/default.target -> /lib/systemd/system/graphical.target
(2a) when not logged in on the GUI: system_powerdown does not work
     (--> bug 980692)
(2b) when     logged in on the GUI: system_powerdown works
     (Ie. I cannot reproduce the bug; system_powerdown works as expected when
      the user is logged in to the GUI. The analysis in bug 980692 comment 13
      is related: when the user is logged in, the gnome session manager is in
      RUNNING state, in which phase it handles the ACPI event / Shutdown D-Bus
      message correctly.)

This bug report is very old (six months), it has been probably fixed since.