[libvirt-users] Problem with libvirt migration

Daniel Bidwell bidwell at andrews.edu
Fri Mar 12 13:49:38 UTC 2010 

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?



-- 
Daniel R. Bidwell       |       bidwell at andrews.edu
Andrews University      |       Information Technology Services
If two always agree, one of them is unnecessary
"Friends don't let friends do DOS"
"In theory, theory and practice are the same.
In practice, however, they are not."

More information about the libvirt-users mailing list