[Qemu-devel] Issue with qemu-kvm.git + kvm.git - Machine shutdown doesn't terminate qemu-kvm process, guest RHEL 6

[Lucas Meneghel Rodrigues <lmr@redhat.com>]

Hi folks, I've noticed an issue during our sanity testing for upstream.
On a RHEL 6 VM, After we issue the shutdown command, the qemu-kvm
process is still alive for some reason, making autotest fail the test.
More info:

VM serial console:

2010-11-24 15:15:16: initctl: Event failed
2010-11-24 15:15:16: Shutting down Avahi daemon:
2010-11-24 15:15:16: [  OK  ]
2010-11-24 15:15:16: Stopping atd:
2010-11-24 15:15:16: [  OK  ]
2010-11-24 15:15:16: Stopping abrt daemon:
2010-11-24 15:15:16: [  OK  ]
2010-11-24 15:15:17: Stopping sshd:
2010-11-24 15:15:17: [  OK  ]
2010-11-24 15:15:17: 
2010-11-24 15:15:17: Shutting down postfix:
2010-11-24 15:15:17: [  OK  ]
2010-11-24 15:15:17: Stopping crond:
2010-11-24 15:15:18: [  OK  ]
2010-11-24 15:15:18: Stopping acpi daemon:
2010-11-24 15:15:18: [  OK  ]
2010-11-24 15:15:18: Stopping HAL daemon: [  OK  ]
2010-11-24 15:15:18: Stopping NetworkManager daemon:
2010-11-24 15:15:18: [  OK  ]
2010-11-24 15:15:18: Killing mdmonitor:
2010-11-24 15:15:19: [  OK  ]
2010-11-24 15:15:19: Stopping system message bus: [  OK  ]
2010-11-24 15:15:19: Stopping rpcbind:
2010-11-24 15:15:19: [  OK  ]
2010-11-24 15:15:19: Stopping auditd:
2010-11-24 15:15:19: [  OK  ]
2010-11-24 15:15:20: Shutting down loopback interface:
2010-11-24 15:15:21: [  OK  ]
2010-11-24 15:15:21: ip6tables: Flushing firewall rules: [  OK  ]
2010-11-24 15:15:21: ip6tables: Setting chains to policy ACCEPT: filter [  OK  ]
2010-11-24 15:15:21: ip6tables: Unloading modules:
2010-11-24 15:15:21: [  OK  ]
2010-11-24 15:15:22: iptables: Flushing firewall rules: [  OK  ]
2010-11-24 15:15:22: iptables: Setting chains to policy ACCEPT: filter [  OK  ]
2010-11-24 15:15:22: iptables: Unloading modules:
2010-11-24 15:15:22: [  OK  ]
2010-11-24 15:15:22: Stopping monitoring for VG vg_dhcp74229:
2010-11-24 15:15:22:   2 logical volume(s) in volume group "vg_dhcp74229" unmonitored
2010-11-24 15:15:23: [  OK  ]
2010-11-24 15:15:23: Sending all processes the TERM signal... [  OK  ]
2010-11-24 15:15:25: Sending all processes the KILL signal... [  OK  ]
2010-11-24 15:15:25: Saving random seed:  [  OK  ]
2010-11-24 15:15:25: Syncing hardware clock to system time
2010-11-24 15:15:27: [  OK  ]
2010-11-24 15:15:27: Turning off swap:  [  OK  ]
2010-11-24 15:15:27: Turning off quotas:  [  OK  ]
2010-11-24 15:15:27: Unmounting pipe file systems:
2010-11-24 15:15:27: [  OK  ]
2010-11-24 15:15:27: Unmounting file systems:  [  OK  ]
2010-11-24 15:15:27: init: Re-executing /sbin/init
2010-11-24 15:15:27: Halting system...
2010-11-24 15:15:29: Power down.
2010-11-24 15:19:56: (Process terminated with status 0)

^ Here we clearly see that the serial console showed a normal shutdown
process. In the test debug logs:

11/24 15:15:15 INFO |kvm_test_u:0073| Logged into guest vm1 using remote connection
11/24 15:15:15 INFO |  shutdown:0026| Shutdown command sent; waiting for guest to go down...
11/24 15:19:15 DEBUG| kvm_utils:0877| Timeout elapsed
11/24 15:19:15 ERROR|       kvm:0080| Test failed: TestFail: Guest refuses to go down
11/24 15:19:15 DEBUG|kvm_prepro:0114| Postprocessing VM 'vm1'...
11/24 15:19:15 DEBUG|kvm_prepro:0117| VM object found in environment
11/24 15:19:35 WARNI|kvm_prepro:0127| Could not find (qemu) prompt after command 'screendump /usr/local/autotest/results/default/kvm.qemu-kvm-git.smp2.RHEL.6.0.x86_64.shutdown/debug/post_vm1.ppm'. Output so far: ''
11/24 15:19:35 DEBUG|kvm_prepro:0136| 'kill_vm' specified; killing VM...
11/24 15:19:35 DEBUG|    kvm_vm:0766| Destroying VM with PID 19811...
11/24 15:19:35 DEBUG|    kvm_vm:0786| Trying to kill VM with monitor command...
11/24 15:19:55 WARNI|    kvm_vm:0790| Could not acquire exclusive lock to send monitor command 'quit'
11/24 15:19:55 DEBUG|    kvm_vm:0798| Cannot quit normally; sending a kill to close the deal...

So even though the machine is shut, the vm process is still alive and
then kvm-autotest considers the test as failed. The message 'Could not
find (qemu) prompt after command' is from autotest, means that the
monitor didn't return a prompt, as usual, which probably means the
process is alive but not functional.

kvm.git version:
11/24 14:27:19 INFO | kvm_utils:0407| Commit hash for git://git.kernel.org/pub/scm/linux/kernel/git/avi/kvm.git is 2a663fe561c625c1cd9707804df632e3cf1f982a (tag v2.6.32-56687-g2a663fe)
qemu-kvm.git version:
11/24 14:48:37 INFO | kvm_utils:0407| Commit hash for git://git.kernel.org/pub/scm/virt/kvm/qemu-kvm.git is b377474e589e5a1fe2abc7b13fafa8bad802637a (tag kvm-88-6260-gb377474) 
guest:
RHEL 6.0 64 bit, installed from the release CD.

I hope this is helpful.

Thanks!

Lucas