Re: [libvirt-users] Problem with libvirt migration

I have two hosts, vm1 and vm2, which are both running libvirt 0.7.0. They share a common ocfs2 file system that resides on a san, and have identical network configurations. I am running qemu-kvm 0.11.0 on ubuntu 9.10 servers. I start base32 on vm1 and it comes up (it also runs fine if started on vm2). Then from vm2 I do: vm2#: virsh -c qemu://vm1/system migrate --live base32 qemu://vm2/system The migration starts and the vm2 virsh returns to the prompt. vm2 shows base32 as running and vm1 shows base32 as stopped. The console for base32 on vm2 is frozen and unresponsive. I have the debug level set to 1 on both machines. This is an excerpt from the virsh.log file from vm1: 8:19:40.772: debug : qemudDomainMigratePerform:6513 : base32: migrate reply: migrate "tcp:vm2.cc.andrews.edu:49152" 08:19:40.772: debug : qemudShutdownVMDaemon:2076 : Shutting down VM 'base32' 08:19:40.773: debug : virEventRemoveHandleImpl:173 : Remove handle 11 08:19:40.773: debug : virEventRemoveHandleImpl:186 : mark delete 9 19 08:19:40.773: debug : virEventInterruptLocked:640 : Interrupting 08:19:40.773: debug : virRun:796 : /usr/bin/virt-aa-helper -R -u libvirt-2469118c-9b90-44e3-a6ce-01a08bfe28f5 08:19:40.773: debug : virEventRunOnce:567 : Poll got 1 event 08:19:40.773: debug : virEventDispatchHandles:450 : Dispatch n=0 f=5 w=1 e=1 (nil) 08:19:40.773: debug : virEventDispatchHandles:440 : Skip deleted n=9 w=11 f=19 08:19:40.773: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:40.773: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:40.773: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:40.773: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:40.773: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:40.774: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:40.774: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:40.774: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:40.774: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:40.774: debug : virEventMakePollFDs:365 : Prepare n=9 w=12, f=16 e=1 08:19:40.774: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:40.774: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:40.774: debug : virEventRunOnce:565 : Poll on 10 handles 0x2628850 timeout -1 08:19:40.960: debug : virEventUpdateTimeoutImpl:247 : Updating timer 1 timeout with 0 ms freq 08:19:40.960: debug : virEventInterruptLocked:640 : Interrupting 08:19:40.960: debug : virDomainFree:1922 : domain=0x2605c60 08:19:40.960: debug : virUnrefDomain:373 : unref domain 0x2605c60 base32 1 08:19:40.960: debug : virReleaseDomain:327 : release domain 0x2605c60 base32 08:19:40.960: debug : virReleaseDomain:343 : unref connection 0x2679bd0 2 08:19:40.960: debug : virEventUpdateHandleImpl:146 : Update handle w=12 e=3 The logs on vm2 (destination host) are: 08:19:29.566: debug : virDomainMigratePrepare2:3233 : dconn=0x2096d50, cookie=0x7ff72bf59dc0, cookielen=0x7ff72bf59dcc, uri_in=(null), uri_out=0x20839f0,flags=1, dname=(null), bandwidth=0, dom_xml=<domain type='kvm' id='1'> <name>base32</name> <uuid>2469118c-9b90-44e3-a6ce-01a08bfe28f5</uuid> <memory>262144</memory> <currentMemory>262144</currentMemory> <vcpu>1</vcpu> <os> <type arch='i686' machine='pc-0.11'>hvm</type> <boot dev='hd'/> </os> <features> <acpi/> </features> <clock offset='utc'/> <on_poweroff>destroy</on_poweroff> <on_reboot>restart</on_reboot> <on_crash>destroy</on_crash> <devices> <emulator>/usr/bin/kvm</emulator> <disk type='file' device='disk'> <source file='/home/vms/base32/base32.vmdk'/> <target dev='hda' bus='ide'/> </disk> <interface type='bridge'> <mac address='00:0c:29:db:97:14'/> <source bridge='br0'/> <target dev='vnet0'/> <model type='e1000'/> </interface> <input type='mouse' bus='ps2'/> <graphics type='vnc' port='5900' autoport='yes' listen='127.0.0.1'/> <video> <model type='cirrus' vram='9216' heads='1'/> </video> </devices> <seclabel type='dynamic' model='apparmor'> <label>libvirt-2469118c-9b90-44e3-a6ce-01a08bfe28f5</label> <imagelabel>libvirt-2469118c-9b90-44e3-a6ce-01a08bfe28f5</imagelabel> </seclabel> </domain> 08:19:29.569: debug : virGetDomain:296 : New hash entry 0x20941a0 08:19:29.569: debug : virDomainGetUUIDString:2441 : domain=0x20941a0, buf=0x7ff72bf584f8 08:19:29.569: debug : virDomainGetUUID:2407 : domain=0x20941a0, uuid=0x7ff72bf58450 08:19:29.569: debug : virExecWithHook:607 : /usr/bin/virt-aa-helper -c -u libvirt-2469118c-9b90-44e3-a6ce-01a08bfe28f5 08:19:29.857: debug : virExecWithHook:607 : /usr/bin/kvm -help 08:19:29.865: debug : virEventRunOnce:567 : Poll got 1 event 08:19:29.871: debug : virEventDispatchHandles:450 : Dispatch n=4 f=3 w=5 e=1 0x2058040 08:19:29.871: info : qemudDispatchSignalEvent:370 : Received unexpected signal 17 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:29.871: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 08:19:29.871: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:29.871: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:29.871: debug : virEventRunOnce:565 : Poll on 10 handles 0x2091480 timeout -1 08:19:29.872: debug : virEventRunOnce:567 : Poll got 2 event 08:19:29.872: debug : virEventDispatchHandles:450 : Dispatch n=2 f=8 w=3 e=1 0x2074e90 08:19:29.872: debug : device_added:513 : net_4a_cf_74_02_5d_6c 08:19:29.872: debug : virExecWithHook:607 : /usr/bin/kvm -S -M pc-0.11 -cpu qemu32 -m 256 -smp 1 -name base32 -uuid 2469118c-9b90-44e3-a6ce-01a08bfe28f5 -monitor unix:/var/run/libvirt/qemu/base32.monitor,server,nowait -boot c -drive file=/home/vms/base32/base32.vmdk,if=ide,index=0,boot=on -net nic,macaddr=00:0c:29:db:97:14,vlan=0,model=e1000,name=e1000.0 -net tap,fd=19,vlan=0,name=tap.0 -serial none -parallel none -usb -vnc 127.0.0.1:0 -vga cirrus -incoming tcp:0.0.0.0:49152 08:19:29.885: debug : virEventDispatchHandles:450 : Dispatch n=4 f=3 w=5 e=1 0x2058040 08:19:29.885: info : qemudDispatchSignalEvent:370 : Received unexpected signal 17 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 08:19:29.885: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:29.885: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:29.885: debug : virEventRunOnce:565 : Poll on 10 handles 0x2091480 timeout -1 08:19:29.885: debug : virEventRunOnce:567 : Poll got 1 event 08:19:29.885: debug : virEventDispatchHandles:450 : Dispatch n=4 f=3 w=5 e=1 0x2058040 08:19:29.885: info : qemudDispatchSignalEvent:370 : Received unexpected signal 17 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:29.885: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 08:19:29.885: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:29.885: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:29.885: debug : virEventRunOnce:565 : Poll on 10 handles 0x2091480 timeout -1 08:19:30.075: debug : virEventAddHandleImpl:112 : Add handle 19 0 0x425d40 0x2073710 08:19:30.075: debug : virEventAddHandleImpl:116 : Used 10 handle slots, adding 10 more 08:19:30.075: debug : virEventInterruptLocked:640 : Interrupting 08:19:30.075: debug : virEventRunOnce:567 : Poll got 1 event 08:19:30.075: debug : virEventDispatchHandles:450 : Dispatch n=0 f=5 w=1 e=1 (nil) 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 8:19:30.075: debug : virEventMakePollFDs:365 : Prepare n=10 w=12, f=19 e=0 08:19:30.075: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:30.075: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:30.075: debug : virEventRunOnce:565 : Poll on 11 handles 0x2091480 timeout -1 08:19:30.076: debug : qemudDomainSetMemoryBalloon:3175 : base32: balloon reply: balloon 256 08:19:30.077: debug : virEventUpdateTimeoutImpl:247 : Updating timer 1 timeout with 0 ms freq 08:19:30.077: debug : virEventInterruptLocked:640 : Interrupting 08:19:30.077: debug : virEventRunOnce:567 : Poll got 1 event 08:19:30.077: debug : virEventUpdateHandleImpl:146 : Update handle w=11 e=3 08:19:30.077: debug : virEventUpdateTimeoutImpl:247 : Updating timer 1 timeout with -1 ms freq 08:19:30.077: debug : virEventInterruptLocked:640 : Interrupting 08:19:30.077: debug : virEventInterruptLocked:636 : Skip interrupt, 1 846931856 08:19:30.077: debug : virEventDispatchHandles:450 : Dispatch n=0 f=5 w=1 e=1 (nil) 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=5 08:19:30.077: debug : virEventMakePollFDs:365 : Prepare n=10 w=12, f=19 e=0 08:19:30.077: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:30.077: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:30.077: debug : virEventRunOnce:565 : Poll on 11 handles 0x2091480 timeout -1 08:19:30.077: debug : virEventRunOnce:567 : Poll got 2 event 08:19:30.077: debug : virEventDispatchHandles:450 : Dispatch n=0 f=5 w=1 e=1 (nil) 08:19:30.077: debug : virEventDispatchHandles:450 : Dispatch n=9 f=16 w=11 e=4 0x2058040 08:19:30.078: debug : virEventUpdateHandleImpl:146 : Update handle w=11 e=1 08:19:30.078: debug : virEventInterruptLocked:636 : Skip interrupt, 1 846931856 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 08:19:30.078: debug : virEventMakePollFDs:365 : Prepare n=10 w=12, f=19 e=0 08:19:30.078: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:30.078: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:30.078: debug : virEventRunOnce:565 : Poll on 11 handles 0x2091480 timeout -1 08:19:40.936: debug : virEventRunOnce:567 : Poll got 1 event 08:19:40.936: debug : virEventDispatchHandles:450 : Dispatch n=9 f=16 w=11 e=1 0x2058040 08:19:40.937: debug : virEventUpdateHandleImpl:146 : Update handle w=11 e=1 08:19:40.937: debug : virEventInterruptLocked:636 : Skip interrupt, 1 846931856 08:19:40.937: debug : virEventUpdateHandleImpl:146 : Update handle w=11 e=1 08:19:40.937: debug : virEventInterruptLocked:636 : Skip interrupt, 1 846931856 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=5 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=8 e=0 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=8 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=9 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=3 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=25 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=6 w=7, f=12 e=25 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=7 w=8, f=14 e=25 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=8 w=9, f=15 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=9 w=11, f=16 e=1 08:19:40.937: debug : virEventMakePollFDs:365 : Prepare n=10 w=12, f=19 e=0 08:19:40.937: debug : virEventCalculateTimeout:313 : Calculate expiry of 3 timers 08:19:40.937: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms 08:19:40.937: debug : virEventRunOnce:565 : Poll on 11 handles 0x2091480 timeout -1 08:19:40.937: debug : virDomainMigrateFinish2:3281 : dconn=0x2096d50, dname=base32, cookie=(nil), cookielen=0, uri=tcp:vm2.cc.andrews.edu:49152, flags=1, retcode=0 08:19:40.938: debug : virGetDomain:298 : Existing hash entry 0x20941a0: refs now 2 08:19:40.938: debug : virEventUpdateTimeoutImpl:247 : Updating timer 1 timeout with 0 ms freq 08:19:40.938: debug : virEventInterruptLocked:640 : Interrupting 08:19:40.938: debug : virEventUpdateHandleImpl:146 : Update handle w=11 e=3 08:19:40.938: debug : virEventInterruptLocked:640 : Interrupting The migration appears to have completed successfully, but the console doesn't respond to anything and neither does the ethernet. Any ideas on how to get past this last step?