Re: 答复: [Xen-devel] Xen Live Migration Fail

["\"涂堂��(Tang-Hsun Tu)\"" <iwantplay@gmail.com>]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: text/plain; charset=GB2312, Size: 4256 bytes --]

Hi,

Thanks for your reply.

In recent days, I update my xen to the latest xen-4.0-testing.hg,

and retry the migration. It works fine.

However, it still has some strange problems.

Supporse there are two machines, A and B.

If I start a DomU (HVM) at A, then migrate to B, it works.

Then, I migrate from B to A, it works.

However, when I start a DomU at B, then migrate to A, it fails.

It means, if the first migration from B to A, it fails.
But, A->B, then B->A, it works.

It fails at restoring the DomU, and
the log shows "ERROR Internal error: error setting the HVM context".
The logs are also attached.

===================================================================

Another problem is that when I patch QEMU to support multiple DomUs to
play audio (enable mix),
like this,
the patch at tools/xen-setup,

#./configure --disable-gfx-check --disable-curses --disable-slirp "$@"
--prefix=${PREFIX}
./configure --audio-drv-list=alsa --enable-mixemu --disable-gfx-check
--disable-curses --disable-slirp "$@" --prefix=${PREFIX}

Then, the latest xen also fails, does this patch will affect live migration?



Thanks!



Best Regards,
Tang-Hsun Tu

ì¶ 2010/11/23 ÉÏÎç 10:05, songwei Ìáµ½:
> Did you modify the xend-config.sxp correctly?  Those comments in the
> discussion thread below, could be helpful for your question.
>  http://lists.xensource.com/archives/html/xen-users/2009-03/msg00079.html
>
> thanks,
> -James ( Song Wei)
>
>  
>
> sender: xen-devel-bounces@lists.xensource.com
> [mailto:xen-devel-bounces@lists.xensource.com] represent ͿСӖ
> timer: 2010Äê11ÔÂ20ÈÕ 18:49
> receiver: xen-devel@lists.xensource.com
> subject: [Xen-devel] Xen Live Migration Fail
>
> Dear all:
>
>       I am trying to migrate a WinXP HVM (64M memory) from a machine
> (sender) to another machine (receiver) through AoE disk, however, there are
> some errors when do the following command:
> (My xen version is xen-4.0.1-rc5.hg, kernel 2.6.31.13, xen
> xen-4.0.1-rc6-pre,  Both sender and receiver are the same xen version)
>
>       xm migrate --live domain_id receiver_ip
>
> ===============================================
>       The error message at sender side is:
>
> Error: timed out
> Usage: xm migrate <Domain> <Host>
> ...
> ===============================================
>
>
>      Then, I read the xend.log (sender) and find this error message:
>
> ===============================================
> [2010-11-20 18:12:45 4667] INFO (XendDomain:1206) Domain WinXP_HVM_Migrate
> (1) unpaused.
> [2010-11-20 18:14:06 4667] DEBUG (XendCheckpoint:124) [xc_save]:
> /usr/lib/xen/bin/xc_save 35 1 0 0 5
> [2010-11-20 18:14:06 4667] INFO (XendCheckpoint:423) xc_save: failed to get
> the suspend evtchn port ...
> [2010-11-20 18:14:33 4667] WARNING (image:552) domain
> migrating-WinXP_HVM_Migrate: device model failure: pid 4871: died due to
> signal 6; see /var/log/xen/qemu-dm-WinXP_HVM_Migrate.log
> [2010-11-20 18:14:33 4667] INFO (XendDomainInfo:2088) Domain has
> shutdown: name=migrating-WinXP_HVM_Migrate id=1 reason=suspend.
> [2010-11-20 18:14:43 4667] INFO (XendCheckpoint:423) ERROR Internal
> error: Suspend request failed
> [2010-11-20 18:14:43 4667] INFO (XendCheckpoint:423) ERROR Internal
> error: Domain appears not to have suspended [2010-11-20 18:14:48 4667] INFO
> (XendCheckpoint:423) xc_save: timed out waiting for qemu logdirty response.
> ...
> ===============================================
>
>
>        And the qemu-dm.log gives a "buffer overflow" message as following:
>
> ===============================================
> ...
> device model saving state
> *** buffer overflow detected ***: /usr/lib64/xen/bin/qemu-dm terminated
> ======= Backtrace: =========
> /lib/libc.so.6(__fortify_fail+0x37)[0x7fecab467217]
> /lib/libc.so.6(+0xfe0d0)[0x7fecab4660d0]
> /lib/libc.so.6(+0xfd539)[0x7fecab465539]
> /lib/libc.so.6(_IO_default_xsputn+0xcc)[0x7fecab3ddd1c]
> /lib/libc.so.6(_IO_vfprintf+0x14c)[0x7fecab3ad4ec]
> ===============================================
>
>
>      The logs are also attached. Any ideas or patches to fix this problem ?
> Thanks!
>
> Best Regards,
> Tang-Hsun Tu
>
>

[-- Attachment #2: fail_qemu-dm-WinXP_HVM_Migrate.log --]
[-- Type: text/plain, Size: 1486 bytes --]

domid: 5
config qemu network with xen bridge for  tap5.0 xenbr0
Using file /dev/vg_xen/lv_xp_vm in read-write mode
Watching /local/domain/0/device-model/5/logdirty/cmd
Watching /local/domain/0/device-model/5/command
char device redirected to /dev/pts/2
qemu_map_cache_init nr_buckets = 10000 size 4194304
shared page at pfn feffd
buffered io page at pfn feffb
Guest uuid = 8a1fce68-d1ca-63cf-30a7-24cf2ed548f7
Time offset set 0
populating video RAM at ff000000
mapping video RAM from ff000000
Register xen platform.
Done register platform.
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is rw state.
xs_read(/local/domain/0/device-model/5/xen_extended_power_mgmt): read error
xs_read(): vncpasswd get error. /vm/8a1fce68-d1ca-63cf-30a7-24cf2ed548f7/vncpasswd.
Log-dirty: no command yet.
I/O request not ready: 0, ptr: 0, port: 0, data: 0, count: 0, size: 0
xs_read(/local/domain/5/log-throttling): read error
qemu: ignoring not-understood drive `/local/domain/5/log-throttling'
medium change watch on `/local/domain/5/log-throttling' - unknown device, ignored
vga s->lfb_addr = f1000000 s->lfb_end = f1400000 
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is rw state.
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is ro state.
vga s->lfb_addr = f1000000 s->lfb_end = f1400000 
mapping vram to f1000000 - f1400000
Log-dirty command enable
dm-command: pause and save state
device model saving state
Log-dirty command disable

[-- Attachment #3: fail_xend_sender_162.log --]
[-- Type: text/plain, Size: 17482 bytes --]

[2010-11-22 18:03:34 8645] INFO (SrvDaemon:332) Xend Daemon started
[2010-11-22 18:03:34 8645] INFO (SrvDaemon:336) Xend changeset: unavailable.
[2010-11-22 18:03:34 8645] INFO (XendNetwork:114) Not recreating missing unmanaged network peth0
[2010-11-22 18:03:35 8645] DEBUG (XendDomainInfo:149) XendDomainInfo.recreate({'max_vcpu_id': 3, 'cpu_time': 318843296434L, 'ssidref': 0, 'hvm': 0, 'shutdown_reason': 255, 'dying': 0, 'online_vcpus': 4, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 17179869180L, 'shutdown': 0, 'mem_kb': 524288L, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'blocked': 0, 'name': 'Domain-0'})
[2010-11-22 18:03:35 8645] INFO (XendDomainInfo:167) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
[2010-11-22 18:03:35 8645] DEBUG (XendDomain:464) Adding Domain: 0
[2010-11-22 18:03:35 8645] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:03:35 8645] DEBUG (XendDomain:398) number of vcpus to use is 0
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: VBD.set_device not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: VBD.set_type not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: session.get_all_records not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: event.get_record not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: event.get_all not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: VIF.set_device not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: VIF.set_MAC not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: VIF.set_MTU not found
[2010-11-22 18:03:35 8645] WARNING (XendAPI:705) API call: debug.get_all not found
[2010-11-22 18:03:35 8645] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication has been disabled for this server.
[2010-11-22 18:03:35 8645] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:101) XendDomainInfo.create(['vm', ['name', 'WinXP_HVM_Migrate'], ['memory', 256], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['vcpus', 1], ['oos', 1], ['image', ['hvm', ['kernel', '/usr/lib64/xen/boot/hvmloader'], ['videoram', 4], ['serial', 'pty'], ['acpi', 1], ['apic', 1], ['boot', 'dca'], ['cpuid', []], ['cpuid_check', []], ['device_model', '/usr/lib64/xen/bin/qemu-dm'], ['display', 'localhost:11.0'], ['fda', ''], ['fdb', ''], ['guest_os_type', 'default'], ['hap', 1], ['hpet', 0], ['isa', 0], ['keymap', ''], ['localtime', 0], ['nographic', 0], ['oos', 1], ['pae', 1], ['pci', []], ['pci_msitranslate', 1], ['pci_power_mgmt', 0], ['rtc_timeoffset', 0], ['sdl', 0], ['soundhw', 'ac97'], ['stdvga', 1], ['timer_mode', 1], ['usb', 0], ['usbdevice', 'tablet'], ['vcpus', 1], ['vnc', 1], ['vncdisplay', 6], ['vnclisten', '0.0.0.0'], ['vncunused', 1], ['viridian', 0], ['vpt_align', 1], ['xauthority', '/home/crilit/.Xauthority'], ['xen_platform_pci', 1], ['memory_sharing', 0], ['vncpasswd', 'XXXXXXXX'], ['tsc_mode', 0], ['nomigrate', 0]]], ['s3_integrity', 1], ['device', ['vbd', ['uname', 'phy:/dev/vg_xen/lv_xp_vm'], ['dev', 'hda'], ['mode', 'w']]], ['device', ['vif', ['bridge', 'xenbr0'], ['type', 'ioemu']]]])
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:2508) XendDomainInfo.constructDomain
[2010-11-22 18:04:08 8645] DEBUG (balloon:220) Balloon: 3269644 KiB free; need 16384; done.
[2010-11-22 18:04:08 8645] DEBUG (XendDomain:464) Adding Domain: 5
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:2818) XendDomainInfo.initDomain: 5 256
[2010-11-22 18:04:08 8645] DEBUG (image:339) No VNC passwd configured for vfb access
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: boot, val: dca
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: fda, val: None
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: fdb, val: None
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: soundhw, val: ac97
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: localtime, val: 0
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: serial, val: ['pty']
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: std-vga, val: 1
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: isa, val: 0
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: acpi, val: 1
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: usb, val: 0
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: usbdevice, val: tablet
[2010-11-22 18:04:08 8645] DEBUG (image:891) args: gfx_passthru, val: None
[2010-11-22 18:04:08 8645] INFO (image:822) Need to create platform device.[domid:5]
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:2845) _initDomain:shadow_memory=0x0, memory_static_max=0x10000000, memory_static_min=0x0.
[2010-11-22 18:04:08 8645] INFO (image:182) buildDomain os=hvm dom=5 vcpus=1
[2010-11-22 18:04:08 8645] DEBUG (image:949) domid          = 5
[2010-11-22 18:04:08 8645] DEBUG (image:950) image          = /usr/lib64/xen/boot/hvmloader
[2010-11-22 18:04:08 8645] DEBUG (image:951) store_evtchn   = 2
[2010-11-22 18:04:08 8645] DEBUG (image:952) memsize        = 256
[2010-11-22 18:04:08 8645] DEBUG (image:953) target         = 256
[2010-11-22 18:04:08 8645] DEBUG (image:954) vcpus          = 1
[2010-11-22 18:04:08 8645] DEBUG (image:955) vcpu_avail     = 1
[2010-11-22 18:04:08 8645] DEBUG (image:956) acpi           = 1
[2010-11-22 18:04:08 8645] DEBUG (image:957) apic           = 1
[2010-11-22 18:04:08 8645] INFO (XendDomainInfo:2367) createDevice: vfb : {'vncunused': 1, 'other_config': {'vncunused': 1, 'vnclisten': '0.0.0.0', 'vnc': '1', 'vncdisplay': 6}, 'vnc': '1', 'uuid': 'a794b889-6d20-bd59-8ab0-6ddce513fc26', 'vnclisten': '0.0.0.0', 'vncdisplay': 6}
[2010-11-22 18:04:08 8645] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/5/0'} to /local/domain/5/device/vfb/0.
[2010-11-22 18:04:08 8645] DEBUG (DevController:97) DevController: writing {'vncunused': '1', 'domain': 'WinXP_HVM_Migrate', 'vnc': '1', 'uuid': 'a794b889-6d20-bd59-8ab0-6ddce513fc26', 'frontend-id': '5', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'state': '1', 'online': '1', 'frontend': '/local/domain/5/device/vfb/0'} to /local/domain/0/backend/vfb/5/0.
[2010-11-22 18:04:08 8645] INFO (XendDomainInfo:2367) createDevice: vbd : {'uuid': '61ba0cc5-b6fe-4a6d-431c-ffd4df5c93af', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda', 'uname': 'phy:/dev/vg_xen/lv_xp_vm', 'mode': 'w'}
[2010-11-22 18:04:08 8645] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '768', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/5/768'} to /local/domain/5/device/vbd/768.
[2010-11-22 18:04:08 8645] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/5/device/vbd/768', 'uuid': '61ba0cc5-b6fe-4a6d-431c-ffd4df5c93af', 'bootable': '1', 'dev': 'hda', 'state': '1', 'params': '/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'online': '1', 'frontend-id': '5', 'type': 'phy'} to /local/domain/0/backend/vbd/5/768.
[2010-11-22 18:04:08 8645] INFO (XendDomainInfo:2367) createDevice: vif : {'bridge': 'xenbr0', 'mac': '00:16:3e:54:e1:54', 'type': 'ioemu', 'uuid': 'd02a38fb-c731-2ff7-2496-973be59caeb4'}
[2010-11-22 18:04:08 8645] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vif/5/0'} to /local/domain/5/device/vif/0.
[2010-11-22 18:04:08 8645] DEBUG (DevController:97) DevController: writing {'bridge': 'xenbr0', 'domain': 'WinXP_HVM_Migrate', 'handle': '0', 'uuid': 'd02a38fb-c731-2ff7-2496-973be59caeb4', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:54:e1:54', 'frontend-id': '5', 'state': '1', 'online': '1', 'frontend': '/local/domain/5/device/vif/0', 'type': 'ioemu'} to /local/domain/0/backend/vif/5/0.
[2010-11-22 18:04:08 8645] INFO (image:418) spawning device models: /usr/lib64/xen/bin/qemu-dm ['/usr/lib64/xen/bin/qemu-dm', '-d', '5', '-domain-name', 'WinXP_HVM_Migrate', '-videoram', '4', '-vnc', '0.0.0.0:6', '-vncunused', '-vcpus', '1', '-vcpu_avail', '0x1', '-boot', 'dca', '-soundhw', 'ac97', '-serial', 'pty', '-std-vga', '-acpi', '-usbdevice', 'tablet', '-net', 'nic,vlan=1,macaddr=00:16:3e:54:e1:54,model=rtl8139', '-net', 'tap,vlan=1,ifname=tap5.0,bridge=xenbr0', '-M', 'xenfv']
[2010-11-22 18:04:08 8645] INFO (image:467) device model pid: 8812
[2010-11-22 18:04:08 8645] INFO (image:590) waiting for sentinel_fifo
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:3400) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '3', 'uuid': '8a1fce68-d1ca-63cf-30a7-24cf2ed548f7', 'on_reboot': 'restart', 'start_time': '1290420248.36', 'on_poweroff': 'destroy', 'bootloader_args': '', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'bootloader': '', 'image': '(hvm (kernel ) (superpages 0) (videoram 4) (hpet 0) (stdvga 1) (vnclisten 0.0.0.0) (loader /usr/lib64/xen/boot/hvmloader) (xen_platform_pci 1) (rtc_timeoffset 0) (pci ()) (hap 1) (localtime 0) (timer_mode 1) (vncdisplay 6) (pci_msitranslate 1) (oos 1) (apic 1) (sdl 0) (usbdevice tablet) (display localhost:11.0) (vpt_align 1) (serial pty) (vncunused 1) (soundhw ac97) (boot dca) (pae 1) (viridian 0) (acpi 1) (vnc 1) (nographic 0) (nomigrate 0) (usb 0) (tsc_mode 0) (guest_os_type default) (device_model /usr/lib64/xen/bin/qemu-dm) (pci_power_mgmt 0) (xauthority /home/crilit/.Xauthority) (isa 0) (notes (SUSPEND_CANCEL 1)))', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:1804) Storing domain details: {'console/port': '3', 'description': '', 'console/limit': '1048576', 'store/port': '2', 'vm': '/vm/8a1fce68-d1ca-63cf-30a7-24cf2ed548f7', 'domid': '5', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'store/ring-ref': '1044476', 'console/type': 'ioemu', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 18:04:08 8645] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/5/0'} to /local/domain/5/device/console/0.
[2010-11-22 18:04:08 8645] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/5/device/console/0', 'uuid': '44036f50-8832-a662-c587-dda32d49d0e6', 'frontend-id': '5', 'state': '1', 'location': '3', 'online': '1', 'protocol': 'vt100'} to /local/domain/0/backend/console/5/0.
[2010-11-22 18:04:08 8645] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices tap2.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vif.
[2010-11-22 18:04:08 8645] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 18:04:08 8645] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vif/5/0/hotplug-status.
[2010-11-22 18:04:08 8645] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vkbd.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices ioports.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices tap.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vif2.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices console.
[2010-11-22 18:04:08 8645] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vscsi.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vbd.
[2010-11-22 18:04:08 8645] DEBUG (DevController:144) Waiting for 768.
[2010-11-22 18:04:08 8645] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/5/768/hotplug-status.
[2010-11-22 18:04:08 8645] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices irq.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vfb.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices pci.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vusb.
[2010-11-22 18:04:08 8645] DEBUG (DevController:139) Waiting for devices vtpm.
[2010-11-22 18:04:08 8645] INFO (XendDomain:1206) Domain WinXP_HVM_Migrate (5) unpaused.
[2010-11-22 18:06:44 8645] DEBUG (XendCheckpoint:124) [xc_save]: /usr/lib/xen/bin/xc_save 35 5 0 0 5
[2010-11-22 18:06:44 8645] INFO (XendCheckpoint:423) xc_save: failed to get the suspend evtchn port
[2010-11-22 18:06:44 8645] INFO (XendCheckpoint:423) 
[2010-11-22 18:07:11 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 1   0%\b\b\b\b  5%\b\b\b\b 10%\b\b\b\b 15%\b\b\b\b 20%\b\b\b\b 25%\b\b\b\b 30%\b\b\b\b 35%\b\b\b\b 40%\b\b\b\b 45%\b\b\b\b 50%\b\b\b\b 55%\b\b\b\b 60%\b\b\b\b 65%\b\b\b\b 70%\b\b\b\b 75%\b\b\b\b 80%\b\b\b\b 85%\b\b\b\b 90%\b\b\b\b 95%\r 1: sent 68992, skipped 1664, delta 26471ms, dom0 34%, target 2%, sent 85Mb/s, dirtied 4Mb/s 3965 pages
[2010-11-22 18:07:12 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 2   0%\b\b\b\b  5%\r 2: sent 3764, skipped 201, delta 1229ms, dom0 42%, target 2%, sent 100Mb/s, dirtied 39Mb/s 1480 pages
[2010-11-22 18:07:13 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 3   0%\r 3: sent 1386, skipped 94, delta 442ms, dom0 41%, target 3%, sent 102Mb/s, dirtied 107Mb/s 1452 pages
[2010-11-22 18:07:13 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 4   0%\r 4: sent 1367, skipped 85, delta 484ms, dom0 35%, target 1%, sent 92Mb/s, dirtied 75Mb/s 1117 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 5   0%\r 5: sent 1052, skipped 65, delta 387ms, dom0 37%, target 2%, sent 89Mb/s, dirtied 92Mb/s 1088 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 6   0%\r 6: sent 1024, skipped 64, delta 396ms, dom0 29%, target 4%, sent 84Mb/s, dirtied 39Mb/s 480 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 7   0%\r 7: sent 474, skipped 6, delta 151ms, dom0 31%, target 0%, sent 102Mb/s, dirtied 234Mb/s 1079 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 8   0%\r 8: sent 1026, skipped 53, delta 349ms, dom0 27%, target 2%, sent 96Mb/s, dirtied 9Mb/s 101 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 9   0%\r 9: sent 101, skipped 0, delta 20ms, dom0 25%, target 0%, sent 165Mb/s, dirtied 36Mb/s 22 pages
[2010-11-22 18:07:14 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 10   0%\r 10: sent 22, skipped 0, Start last iteration
[2010-11-22 18:07:14 8645] DEBUG (XendCheckpoint:394) suspend
[2010-11-22 18:07:14 8645] DEBUG (XendCheckpoint:127) In saveInputHandler suspend
[2010-11-22 18:07:14 8645] DEBUG (XendCheckpoint:129) Suspending 5 ...
[2010-11-22 18:07:14 8645] DEBUG (XendDomainInfo:519) XendDomainInfo.shutdown(suspend)
[2010-11-22 18:07:14 8645] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:07:14 8645] INFO (XendDomainInfo:536) HVM save:remote shutdown dom 5!
[2010-11-22 18:07:15 8645] INFO (XendDomainInfo:2088) Domain has shutdown: name=migrating-WinXP_HVM_Migrate id=5 reason=suspend.
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:135) Domain 5 suspended.
[2010-11-22 18:07:15 8645] INFO (image:538) signalDeviceModel:restore dm state to running
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) SUSPEND shinfo 000fffff
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) delta 196ms, dom0 31%, target 0%, sent 3Mb/s, dirtied 170Mb/s 1017 pages
[2010-11-22 18:07:15 8645] DEBUG (XendCheckpoint:144) Written done
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) Saving memory pages: iter 11   0%\r 11: sent 1017, skipped 0, delta 15ms, dom0 13%, target 0%, sent 2221Mb/s, dirtied 2221Mb/s 1017 pages
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) Total pages sent= 80225 (0.08x)
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) (of which 0 were fixups)
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) All memory is saved
[2010-11-22 18:07:15 8645] INFO (XendCheckpoint:423) Save exit rc=0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:3053) XendDomainInfo.destroy: domid=5
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2411) Destroying device model
[2010-11-22 18:07:15 8645] INFO (image:615) migrating-WinXP_HVM_Migrate device model terminated
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2424) Removing console/0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2424) Removing vbd/768
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/768
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:2424) Removing vfb/0
[2010-11-22 18:07:15 8645] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0

[-- Attachment #4: fail_xxend_receiver_164.log --]
[-- Type: text/plain, Size: 13794 bytes --]

[2010-11-22 18:03:30 7592] INFO (SrvDaemon:332) Xend Daemon started
[2010-11-22 18:03:30 7592] INFO (SrvDaemon:336) Xend changeset: unavailable.
[2010-11-22 18:03:31 7592] DEBUG (XendDomainInfo:149) XendDomainInfo.recreate({'max_vcpu_id': 3, 'cpu_time': 185702931522L, 'ssidref': 0, 'hvm': 0, 'shutdown_reason': 255, 'dying': 0, 'online_vcpus': 4, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 17179869180L, 'shutdown': 0, 'mem_kb': 524288L, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'blocked': 0, 'name': 'Domain-0'})
[2010-11-22 18:03:31 7592] INFO (XendDomainInfo:167) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
[2010-11-22 18:03:31 7592] DEBUG (XendDomain:464) Adding Domain: 0
[2010-11-22 18:03:31 7592] DEBUG (XendDomain:398) number of vcpus to use is 0
[2010-11-22 18:03:31 7592] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: VBD.set_device not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: VBD.set_type not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: session.get_all_records not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: event.get_record not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: event.get_all not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: VIF.set_device not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: VIF.set_MAC not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: VIF.set_MTU not found
[2010-11-22 18:03:31 7592] WARNING (XendAPI:705) API call: debug.get_all not found
[2010-11-22 18:03:31 7592] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication has been disabled for this server.
[2010-11-22 18:03:31 7592] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
[2010-11-22 18:06:44 7592] DEBUG (XendDomainInfo:235) XendDomainInfo.restore(['domain', ['domid', '5'], ['cpu_weight', '256'], ['cpu_cap', '0'], ['bootloader'], ['on_crash', 'restart'], ['uuid', '8a1fce68-d1ca-63cf-30a7-24cf2ed548f7'], ['bootloader_args'], ['vcpus', '1'], ['description'], ['name', 'WinXP_HVM_Migrate'], ['cpus', [[]]], ['on_reboot', 'restart'], ['on_poweroff', 'destroy'], ['maxmem', '256'], ['memory', '256'], ['shadow_memory', '3'], ['vcpu_avail', '1'], ['features'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['start_time', '1290420248.36'], ['cpu_time', '0.0'], ['online_vcpus', '1'], ['image', ['hvm', ['kernel'], ['superpages', '0'], ['videoram', '4'], ['hpet', '0'], ['stdvga', '1'], ['vnclisten', '0.0.0.0'], ['loader', '/usr/lib64/xen/boot/hvmloader'], ['xen_platform_pci', '1'], ['rtc_timeoffset', '0'], ['pci', []], ['hap', '1'], ['localtime', '0'], ['timer_mode', '1'], ['vncdisplay', '6'], ['pci_msitranslate', '1'], ['oos', '1'], ['apic', '1'], ['sdl', '0'], ['usbdevice', 'tablet'], ['display', 'localhost:11.0'], ['vpt_align', '1'], ['serial', 'pty'], ['vncunused', '1'], ['soundhw', 'ac97'], ['boot', 'dca'], ['pae', '1'], ['viridian', '0'], ['acpi', '1'], ['vnc', '1'], ['nographic', '0'], ['nomigrate', '0'], ['usb', '0'], ['tsc_mode', '0'], ['guest_os_type', 'default'], ['device_model', '/usr/lib64/xen/bin/qemu-dm'], ['pci_power_mgmt', '0'], ['xauthority', '/home/crilit/.Xauthority'], ['isa', '0'], ['notes', ['SUSPEND_CANCEL', '1']]]], ['status', '2'], ['state', '--p---'], ['store_mfn', '1044476'], ['device', ['vif', ['bridge', 'xenbr0'], ['uuid', 'd02a38fb-c731-2ff7-2496-973be59caeb4'], ['script', '/etc/xen/scripts/vif-bridge'], ['mac', '00:16:3e:54:e1:54'], ['type', 'ioemu'], ['backend', '0']]], ['device', ['console', ['protocol', 'vt100'], ['location', '3'], ['uuid', '44036f50-8832-a662-c587-dda32d49d0e6']]], ['device', ['vbd', ['uuid', '61ba0cc5-b6fe-4a6d-431c-ffd4df5c93af'], ['bootable', '1'], ['dev', 'hda:disk'], ['uname', 'phy:/dev/vg_xen/lv_xp_vm'], ['mode', 'w'], ['backend', '0'], ['VDI']]], ['device', ['vfb', ['vncunused', '1'], ['vnc', '1'], ['uuid', 'a794b889-6d20-bd59-8ab0-6ddce513fc26'], ['vnclisten', '0.0.0.0'], ['vncdisplay', '6'], ['location', '0.0.0.0:5906']]], ['change_home_server', 'False']])
[2010-11-22 18:06:44 7592] DEBUG (XendDomainInfo:2508) XendDomainInfo.constructDomain
[2010-11-22 18:06:44 7592] DEBUG (balloon:220) Balloon: 3269620 KiB free; need 16384; done.
[2010-11-22 18:06:44 7592] DEBUG (XendDomain:464) Adding Domain: 6
[2010-11-22 18:06:44 7592] DEBUG (XendDomainInfo:3400) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '3', 'uuid': '8a1fce68-d1ca-63cf-30a7-24cf2ed548f7', 'on_reboot': 'restart', 'start_time': '1290420248.36', 'on_poweroff': 'destroy', 'bootloader_args': '', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'bootloader': '', 'image': '(hvm (kernel ) (superpages 0) (videoram 4) (hpet 0) (stdvga 1) (vnclisten 0.0.0.0) (loader /usr/lib64/xen/boot/hvmloader) (xen_platform_pci 1) (rtc_timeoffset 0) (pci ()) (hap 1) (localtime 0) (timer_mode 1) (vncdisplay 6) (pci_msitranslate 1) (oos 1) (apic 1) (sdl 0) (usbdevice tablet) (display localhost:11.0) (vpt_align 1) (serial pty) (vncunused 1) (soundhw ac97) (boot dca) (pae 1) (viridian 0) (acpi 1) (vnc 1) (nographic 0) (nomigrate 0) (usb 0) (tsc_mode 0) (guest_os_type default) (device_model /usr/lib64/xen/bin/qemu-dm) (pci_power_mgmt 0) (xauthority /home/crilit/.Xauthority) (isa 0) (notes (SUSPEND_CANCEL 1)))', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 18:06:44 7592] INFO (XendDomainInfo:2367) createDevice: console : {'protocol': 'vt100', 'location': '3', 'uuid': '44036f50-8832-a662-c587-dda32d49d0e6'}
[2010-11-22 18:06:44 7592] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/6/0'} to /local/domain/6/device/console/0.
[2010-11-22 18:06:44 7592] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/6/device/console/0', 'uuid': '44036f50-8832-a662-c587-dda32d49d0e6', 'frontend-id': '6', 'state': '1', 'location': '3', 'online': '1', 'protocol': 'vt100'} to /local/domain/0/backend/console/6/0.
[2010-11-22 18:06:44 7592] INFO (XendDomainInfo:2367) createDevice: vfb : {'vncunused': '1', 'other_config': {'vncunused': '1', 'vnclisten': '0.0.0.0', 'vnc': '1', 'vncdisplay': '6'}, 'vnc': '1', 'uuid': 'a794b889-6d20-bd59-8ab0-6ddce513fc26', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'location': '0.0.0.0:5906'}
[2010-11-22 18:06:44 7592] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/6/0'} to /local/domain/6/device/vfb/0.
[2010-11-22 18:06:44 7592] DEBUG (DevController:97) DevController: writing {'vncunused': '1', 'domain': 'WinXP_HVM_Migrate', 'vnc': '1', 'uuid': 'a794b889-6d20-bd59-8ab0-6ddce513fc26', 'frontend-id': '6', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'state': '1', 'location': '0.0.0.0:5906', 'online': '1', 'frontend': '/local/domain/6/device/vfb/0'} to /local/domain/0/backend/vfb/6/0.
[2010-11-22 18:06:44 7592] INFO (XendDomainInfo:2367) createDevice: vbd : {'uuid': '61ba0cc5-b6fe-4a6d-431c-ffd4df5c93af', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda:disk', 'uname': 'phy:/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'backend': '0'}
[2010-11-22 18:06:44 7592] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '768', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/6/768'} to /local/domain/6/device/vbd/768.
[2010-11-22 18:06:44 7592] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/6/device/vbd/768', 'uuid': '61ba0cc5-b6fe-4a6d-431c-ffd4df5c93af', 'bootable': '1', 'dev': 'hda', 'state': '1', 'params': '/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'online': '1', 'frontend-id': '6', 'type': 'phy'} to /local/domain/0/backend/vbd/6/768.
[2010-11-22 18:06:44 7592] INFO (XendDomainInfo:2367) createDevice: vif : {'bridge': 'xenbr0', 'uuid': 'd02a38fb-c731-2ff7-2496-973be59caeb4', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:54:e1:54', 'type': 'ioemu', 'backend': '0'}
[2010-11-22 18:06:45 7592] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vif/6/0'} to /local/domain/6/device/vif/0.
[2010-11-22 18:06:45 7592] DEBUG (DevController:97) DevController: writing {'bridge': 'xenbr0', 'domain': 'WinXP_HVM_Migrate', 'handle': '0', 'uuid': 'd02a38fb-c731-2ff7-2496-973be59caeb4', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:54:e1:54', 'frontend-id': '6', 'state': '1', 'online': '1', 'frontend': '/local/domain/6/device/vif/0', 'type': 'ioemu'} to /local/domain/0/backend/vif/6/0.
[2010-11-22 18:06:45 7592] DEBUG (XendDomainInfo:1804) Storing domain details: {'console/port': '3', 'description': '', 'console/limit': '1048576', 'image/suspend-cancel': '1', 'domid': '6', 'vm': '/vm/8a1fce68-d1ca-63cf-30a7-24cf2ed548f7', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'console/type': 'ioemu', 'store/port': '2', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 18:06:45 7592] INFO (XendCheckpoint:268) restore hvm domain 6, apic=1, pae=1
[2010-11-22 18:06:45 7592] DEBUG (image:339) No VNC passwd configured for vfb access
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: boot, val: dca
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: fda, val: None
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: fdb, val: None
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: soundhw, val: ac97
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: localtime, val: 0
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: serial, val: ['pty']
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: std-vga, val: 1
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: isa, val: 0
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: acpi, val: 1
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: usb, val: 0
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: usbdevice, val: tablet
[2010-11-22 18:06:45 7592] DEBUG (image:891) args: gfx_passthru, val: None
[2010-11-22 18:06:45 7592] INFO (image:822) Need to create platform device.[domid:6]
[2010-11-22 18:06:45 7592] DEBUG (XendCheckpoint:286) restore:shadow=0x3, _static_max=0x10000000, _static_min=0x0, 
[2010-11-22 18:06:45 7592] DEBUG (XendCheckpoint:305) [xc_restore]: /usr/lib/xen/bin/xc_restore 15 6 2 3 1 1 1 0
[2010-11-22 18:06:45 7592] INFO (XendCheckpoint:423) xc_domain_restore start: p2m_size = 100000
[2010-11-22 18:06:45 7592] INFO (XendCheckpoint:423) Reloading memory pages:   0%
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) Read 7180 bytes of QEMU data
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) ERROR Internal error: Error when reading batch size
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) ERROR Internal error: error when buffering batch, finishing
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) 
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) Writing 7180 bytes of QEMU data
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) ERROR Internal error: error setting the HVM context
[2010-11-22 18:07:15 7592] INFO (XendCheckpoint:423) Restore exit with rc=1
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:3053) XendDomainInfo.destroy: domid=6
[2010-11-22 18:07:15 7592] ERROR (XendDomainInfo:3067) XendDomainInfo.destroy: domain destruction failed.
Traceback (most recent call last):
  File "/usr/local/lib/python2.6/dist-packages/xen/xend/XendDomainInfo.py", line 3060, in destroy
    xc.domain_pause(self.domid)
Error: (3, 'No such process')
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2416) No device model
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2424) Removing console/0
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2424) Removing vbd/768
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/768
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:2424) Removing vfb/0
[2010-11-22 18:07:15 7592] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2010-11-22 18:07:16 7592] INFO (XendDomain:1107) Domain WinXP_HVM_Migrate (8a1fce68-d1ca-63cf-30a7-24cf2ed548f7) deleted.
[2010-11-22 18:07:16 7592] ERROR (XendCheckpoint:357) /usr/lib/xen/bin/xc_restore 15 6 2 3 1 1 1 0 failed
Traceback (most recent call last):
  File "/usr/local/lib/python2.6/dist-packages/xen/xend/XendCheckpoint.py", line 309, in restore
    forkHelper(cmd, fd, handler.handler, True)
  File "/usr/local/lib/python2.6/dist-packages/xen/xend/XendCheckpoint.py", line 411, in forkHelper
    raise XendError("%s failed" % string.join(cmd))
XendError: /usr/lib/xen/bin/xc_restore 15 6 2 3 1 1 1 0 failed
[2010-11-22 18:07:16 7592] ERROR (XendDomain:1175) Restore failed
Traceback (most recent call last):
  File "/usr/local/lib/python2.6/dist-packages/xen/xend/XendDomain.py", line 1159, in domain_restore_fd
    dominfo = XendCheckpoint.restore(self, fd, paused=paused, relocating=relocating)
  File "/usr/local/lib/python2.6/dist-packages/xen/xend/XendCheckpoint.py", line 358, in restore
    raise exn
XendError: /usr/lib/xen/bin/xc_restore 15 6 2 3 1 1 1 0 failed

[-- Attachment #5: success_qemu-dm-WinXP_HVM_Migrate.log --]
[-- Type: text/plain, Size: 1486 bytes --]

domid: 5
config qemu network with xen bridge for  tap5.0 xenbr0
Using file /dev/vg_xen/lv_xp_vm in read-write mode
Watching /local/domain/0/device-model/5/logdirty/cmd
Watching /local/domain/0/device-model/5/command
char device redirected to /dev/pts/1
qemu_map_cache_init nr_buckets = 10000 size 4194304
shared page at pfn feffd
buffered io page at pfn feffb
Guest uuid = 2ec1afef-ecbd-0cea-684b-96ef3c94bf6c
Time offset set 0
populating video RAM at ff000000
mapping video RAM from ff000000
Register xen platform.
Done register platform.
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is rw state.
xs_read(/local/domain/0/device-model/5/xen_extended_power_mgmt): read error
xs_read(): vncpasswd get error. /vm/2ec1afef-ecbd-0cea-684b-96ef3c94bf6c/vncpasswd.
Log-dirty: no command yet.
I/O request not ready: 0, ptr: 0, port: 0, data: 0, count: 0, size: 0
xs_read(/local/domain/5/log-throttling): read error
qemu: ignoring not-understood drive `/local/domain/5/log-throttling'
medium change watch on `/local/domain/5/log-throttling' - unknown device, ignored
vga s->lfb_addr = f1000000 s->lfb_end = f1400000 
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is rw state.
platform_fixed_ioport: changed ro/rw state of ROM memory area. now is ro state.
vga s->lfb_addr = f1000000 s->lfb_end = f1400000 
mapping vram to f1000000 - f1400000
Log-dirty command enable
dm-command: pause and save state
device model saving state
Log-dirty command disable

[-- Attachment #6: success_xend_receiver_162.log --]
[-- Type: text/plain, Size: 15641 bytes --]

[2010-11-22 17:57:57 7700] INFO (SrvDaemon:332) Xend Daemon started
[2010-11-22 17:57:57 7700] INFO (SrvDaemon:336) Xend changeset: unavailable.
[2010-11-22 17:57:57 7700] INFO (XendNetwork:114) Not recreating missing unmanaged network peth0
[2010-11-22 17:57:58 7700] DEBUG (XendDomainInfo:149) XendDomainInfo.recreate({'max_vcpu_id': 3, 'cpu_time': 276787139532L, 'ssidref': 0, 'hvm': 0, 'shutdown_reason': 255, 'dying': 0, 'online_vcpus': 4, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 17179869180L, 'shutdown': 0, 'mem_kb': 524288L, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'blocked': 0, 'name': 'Domain-0'})
[2010-11-22 17:57:58 7700] INFO (XendDomainInfo:167) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
[2010-11-22 17:57:58 7700] DEBUG (XendDomain:464) Adding Domain: 0
[2010-11-22 17:57:58 7700] DEBUG (XendDomain:398) number of vcpus to use is 0
[2010-11-22 17:57:58 7700] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: VBD.set_device not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: VBD.set_type not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: session.get_all_records not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: event.get_record not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: event.get_all not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: VIF.set_device not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: VIF.set_MAC not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: VIF.set_MTU not found
[2010-11-22 17:57:58 7700] WARNING (XendAPI:705) API call: debug.get_all not found
[2010-11-22 17:57:58 7700] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication has been disabled for this server.
[2010-11-22 17:57:58 7700] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
[2010-11-22 17:59:50 7700] DEBUG (XendDomainInfo:235) XendDomainInfo.restore(['domain', ['domid', '5'], ['cpu_weight', '256'], ['cpu_cap', '0'], ['bootloader'], ['on_crash', 'restart'], ['uuid', '2ec1afef-ecbd-0cea-684b-96ef3c94bf6c'], ['bootloader_args'], ['vcpus', '1'], ['description'], ['name', 'WinXP_HVM_Migrate'], ['cpus', [[]]], ['on_reboot', 'restart'], ['on_poweroff', 'destroy'], ['maxmem', '256'], ['memory', '256'], ['shadow_memory', '3'], ['vcpu_avail', '1'], ['features'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['start_time', '1290419902.2'], ['cpu_time', '0.0'], ['online_vcpus', '1'], ['image', ['hvm', ['kernel'], ['superpages', '0'], ['videoram', '4'], ['hpet', '0'], ['stdvga', '1'], ['vnclisten', '0.0.0.0'], ['loader', '/usr/lib64/xen/boot/hvmloader'], ['xen_platform_pci', '1'], ['rtc_timeoffset', '0'], ['pci', []], ['hap', '1'], ['localtime', '0'], ['timer_mode', '1'], ['vncdisplay', '6'], ['pci_msitranslate', '1'], ['oos', '1'], ['apic', '1'], ['sdl', '0'], ['usbdevice', 'tablet'], ['display', 'localhost:10.0'], ['vpt_align', '1'], ['serial', 'pty'], ['vncunused', '1'], ['soundhw', 'ac97'], ['boot', 'dca'], ['pae', '1'], ['viridian', '0'], ['acpi', '1'], ['vnc', '1'], ['nographic', '0'], ['nomigrate', '0'], ['usb', '0'], ['tsc_mode', '0'], ['guest_os_type', 'default'], ['device_model', '/usr/lib64/xen/bin/qemu-dm'], ['pci_power_mgmt', '0'], ['xauthority', '/home/crilit/.Xauthority'], ['isa', '0'], ['notes', ['SUSPEND_CANCEL', '1']]]], ['status', '2'], ['state', '--p---'], ['store_mfn', '1044476'], ['device', ['vif', ['bridge', 'xenbr0'], ['uuid', '794e37dd-a989-8fa9-fbb6-f4716ad332b1'], ['script', '/etc/xen/scripts/vif-bridge'], ['mac', '00:16:3e:53:76:ea'], ['type', 'ioemu'], ['backend', '0']]], ['device', ['console', ['protocol', 'vt100'], ['location', '3'], ['uuid', '516a5b67-5123-31ea-cf2b-1e697107d985']]], ['device', ['vbd', ['uuid', '858a9d40-7dd2-537c-e302-8aaae156213e'], ['bootable', '1'], ['dev', 'hda:disk'], ['uname', 'phy:/dev/vg_xen/lv_xp_vm'], ['mode', 'w'], ['backend', '0'], ['VDI']]], ['device', ['vfb', ['vncunused', '1'], ['vnc', '1'], ['uuid', '777443ff-8dc1-a402-de0f-a5ae03ae6902'], ['vnclisten', '0.0.0.0'], ['vncdisplay', '6'], ['location', '0.0.0.0:5906']]], ['change_home_server', 'False']])
[2010-11-22 17:59:50 7700] DEBUG (XendDomainInfo:2508) XendDomainInfo.constructDomain
[2010-11-22 17:59:50 7700] DEBUG (balloon:220) Balloon: 3269644 KiB free; need 16384; done.
[2010-11-22 17:59:50 7700] DEBUG (XendDomain:464) Adding Domain: 4
[2010-11-22 17:59:50 7700] DEBUG (XendDomainInfo:3400) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '3', 'uuid': '2ec1afef-ecbd-0cea-684b-96ef3c94bf6c', 'on_reboot': 'restart', 'start_time': '1290419902.2', 'on_poweroff': 'destroy', 'bootloader_args': '', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'bootloader': '', 'image': '(hvm (kernel ) (superpages 0) (videoram 4) (hpet 0) (stdvga 1) (vnclisten 0.0.0.0) (loader /usr/lib64/xen/boot/hvmloader) (xen_platform_pci 1) (rtc_timeoffset 0) (pci ()) (hap 1) (localtime 0) (timer_mode 1) (vncdisplay 6) (pci_msitranslate 1) (oos 1) (apic 1) (sdl 0) (usbdevice tablet) (display localhost:10.0) (vpt_align 1) (serial pty) (vncunused 1) (soundhw ac97) (boot dca) (pae 1) (viridian 0) (acpi 1) (vnc 1) (nographic 0) (nomigrate 0) (usb 0) (tsc_mode 0) (guest_os_type default) (device_model /usr/lib64/xen/bin/qemu-dm) (pci_power_mgmt 0) (xauthority /home/crilit/.Xauthority) (isa 0) (notes (SUSPEND_CANCEL 1)))', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 17:59:50 7700] INFO (XendDomainInfo:2367) createDevice: console : {'protocol': 'vt100', 'location': '3', 'uuid': '516a5b67-5123-31ea-cf2b-1e697107d985'}
[2010-11-22 17:59:50 7700] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/4/0'} to /local/domain/4/device/console/0.
[2010-11-22 17:59:50 7700] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/4/device/console/0', 'uuid': '516a5b67-5123-31ea-cf2b-1e697107d985', 'frontend-id': '4', 'state': '1', 'location': '3', 'online': '1', 'protocol': 'vt100'} to /local/domain/0/backend/console/4/0.
[2010-11-22 17:59:50 7700] INFO (XendDomainInfo:2367) createDevice: vfb : {'vncunused': '1', 'other_config': {'vncunused': '1', 'vnclisten': '0.0.0.0', 'vnc': '1', 'vncdisplay': '6'}, 'vnc': '1', 'uuid': '777443ff-8dc1-a402-de0f-a5ae03ae6902', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'location': '0.0.0.0:5906'}
[2010-11-22 17:59:50 7700] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/4/0'} to /local/domain/4/device/vfb/0.
[2010-11-22 17:59:50 7700] DEBUG (DevController:97) DevController: writing {'vncunused': '1', 'domain': 'WinXP_HVM_Migrate', 'vnc': '1', 'uuid': '777443ff-8dc1-a402-de0f-a5ae03ae6902', 'frontend-id': '4', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'state': '1', 'location': '0.0.0.0:5906', 'online': '1', 'frontend': '/local/domain/4/device/vfb/0'} to /local/domain/0/backend/vfb/4/0.
[2010-11-22 17:59:50 7700] INFO (XendDomainInfo:2367) createDevice: vbd : {'uuid': '858a9d40-7dd2-537c-e302-8aaae156213e', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda:disk', 'uname': 'phy:/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'backend': '0'}
[2010-11-22 17:59:50 7700] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '768', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/4/768'} to /local/domain/4/device/vbd/768.
[2010-11-22 17:59:50 7700] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/4/device/vbd/768', 'uuid': '858a9d40-7dd2-537c-e302-8aaae156213e', 'bootable': '1', 'dev': 'hda', 'state': '1', 'params': '/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'online': '1', 'frontend-id': '4', 'type': 'phy'} to /local/domain/0/backend/vbd/4/768.
[2010-11-22 17:59:50 7700] INFO (XendDomainInfo:2367) createDevice: vif : {'bridge': 'xenbr0', 'uuid': '794e37dd-a989-8fa9-fbb6-f4716ad332b1', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:53:76:ea', 'type': 'ioemu', 'backend': '0'}
[2010-11-22 17:59:50 7700] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vif/4/0'} to /local/domain/4/device/vif/0.
[2010-11-22 17:59:50 7700] DEBUG (DevController:97) DevController: writing {'bridge': 'xenbr0', 'domain': 'WinXP_HVM_Migrate', 'handle': '0', 'uuid': '794e37dd-a989-8fa9-fbb6-f4716ad332b1', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:53:76:ea', 'frontend-id': '4', 'state': '1', 'online': '1', 'frontend': '/local/domain/4/device/vif/0', 'type': 'ioemu'} to /local/domain/0/backend/vif/4/0.
[2010-11-22 17:59:50 7700] DEBUG (XendDomainInfo:1804) Storing domain details: {'console/port': '3', 'description': '', 'console/limit': '1048576', 'image/suspend-cancel': '1', 'domid': '4', 'vm': '/vm/2ec1afef-ecbd-0cea-684b-96ef3c94bf6c', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'console/type': 'ioemu', 'store/port': '2', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 17:59:50 7700] INFO (XendCheckpoint:268) restore hvm domain 4, apic=1, pae=1
[2010-11-22 17:59:50 7700] DEBUG (image:339) No VNC passwd configured for vfb access
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: boot, val: dca
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: fda, val: None
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: fdb, val: None
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: soundhw, val: ac97
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: localtime, val: 0
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: serial, val: ['pty']
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: std-vga, val: 1
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: isa, val: 0
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: acpi, val: 1
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: usb, val: 0
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: usbdevice, val: tablet
[2010-11-22 17:59:50 7700] DEBUG (image:891) args: gfx_passthru, val: None
[2010-11-22 17:59:50 7700] INFO (image:822) Need to create platform device.[domid:4]
[2010-11-22 17:59:50 7700] DEBUG (XendCheckpoint:286) restore:shadow=0x3, _static_max=0x10000000, _static_min=0x0, 
[2010-11-22 17:59:50 7700] DEBUG (XendCheckpoint:305) [xc_restore]: /usr/lib/xen/bin/xc_restore 15 4 2 3 1 1 1 0
[2010-11-22 17:59:50 7700] INFO (XendCheckpoint:423) xc_domain_restore start: p2m_size = 100000
[2010-11-22 17:59:50 7700] INFO (XendCheckpoint:423) Reloading memory pages:   0%
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) Read 5771 bytes of QEMU data
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) Read 1409 bytes of QEMU data
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) ERROR Internal error: Error when reading batch size
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) ERROR Internal error: error when buffering batch, finishing
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) 
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) Writing 7180 bytes of QEMU data
[2010-11-22 18:00:19 7700] INFO (XendCheckpoint:423) Restore exit with rc=0
[2010-11-22 18:00:19 7700] DEBUG (XendCheckpoint:394) store-mfn 1044476
[2010-11-22 18:00:19 7700] DEBUG (XendDomainInfo:2992) XendDomainInfo.completeRestore
[2010-11-22 18:00:19 7700] DEBUG (image:339) No VNC passwd configured for vfb access
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: boot, val: dca
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: fda, val: None
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: fdb, val: None
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: soundhw, val: ac97
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: localtime, val: 0
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: serial, val: ['pty']
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: std-vga, val: 1
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: isa, val: 0
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: acpi, val: 1
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: usb, val: 0
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: usbdevice, val: tablet
[2010-11-22 18:00:19 7700] DEBUG (image:891) args: gfx_passthru, val: None
[2010-11-22 18:00:19 7700] INFO (image:822) Need to create platform device.[domid:4]
[2010-11-22 18:00:19 7700] INFO (image:418) spawning device models: /usr/lib64/xen/bin/qemu-dm ['/usr/lib64/xen/bin/qemu-dm', '-d', '4', '-domain-name', 'WinXP_HVM_Migrate', '-videoram', '4', '-vnc', '0.0.0.0:6', '-vncunused', '-vcpus', '1', '-vcpu_avail', '0x1L', '-boot', 'dca', '-soundhw', 'ac97', '-serial', 'pty', '-std-vga', '-acpi', '-usbdevice', 'tablet', '-net', 'nic,vlan=1,macaddr=00:16:3e:53:76:ea,model=rtl8139', '-net', 'tap,vlan=1,ifname=tap4.0,bridge=xenbr0', '-M', 'xenfv', '-loadvm', '/var/lib/xen/qemu-save.4']
[2010-11-22 18:00:19 7700] INFO (image:467) device model pid: 7996
[2010-11-22 18:00:19 7700] INFO (image:590) waiting for sentinel_fifo
[2010-11-22 18:00:19 7700] DEBUG (XendDomainInfo:1804) Storing domain details: {'console/port': '3', 'description': '', 'console/limit': '1048576', 'store/port': '2', 'vm': '/vm/2ec1afef-ecbd-0cea-684b-96ef3c94bf6c', 'domid': '4', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'store/ring-ref': '1044476', 'console/type': 'ioemu', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 18:00:19 7700] DEBUG (XendDomainInfo:3005) XendDomainInfo.completeRestore done
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices tap2.
[2010-11-22 18:00:19 7700] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vif.
[2010-11-22 18:00:19 7700] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 18:00:19 7700] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vif/4/0/hotplug-status.
[2010-11-22 18:00:19 7700] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vkbd.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices ioports.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices tap.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vif2.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices console.
[2010-11-22 18:00:19 7700] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vscsi.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vbd.
[2010-11-22 18:00:19 7700] DEBUG (DevController:144) Waiting for 768.
[2010-11-22 18:00:19 7700] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/4/768/hotplug-status.
[2010-11-22 18:00:19 7700] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices irq.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vfb.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices pci.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vusb.
[2010-11-22 18:00:19 7700] DEBUG (DevController:139) Waiting for devices vtpm.

[-- Attachment #7: success_xend_sender_164.log --]
[-- Type: text/plain, Size: 17709 bytes --]

[2010-11-22 17:58:02 6968] INFO (SrvDaemon:332) Xend Daemon started
[2010-11-22 17:58:02 6968] INFO (SrvDaemon:336) Xend changeset: unavailable.
[2010-11-22 17:58:02 6968] DEBUG (XendDomainInfo:149) XendDomainInfo.recreate({'max_vcpu_id': 3, 'cpu_time': 141791321561L, 'ssidref': 0, 'hvm': 0, 'shutdown_reason': 255, 'dying': 0, 'online_vcpus': 4, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 17179869180L, 'shutdown': 0, 'mem_kb': 524288L, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'blocked': 0, 'name': 'Domain-0'})
[2010-11-22 17:58:02 6968] INFO (XendDomainInfo:167) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
[2010-11-22 17:58:03 6968] DEBUG (XendDomain:464) Adding Domain: 0
[2010-11-22 17:58:03 6968] DEBUG (XendDomain:398) number of vcpus to use is 0
[2010-11-22 17:58:03 6968] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: VBD.set_device not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: VBD.set_type not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: session.get_all_records not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: event.get_record not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: event.get_all not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: VIF.set_device not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: VIF.set_MAC not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: VIF.set_MTU not found
[2010-11-22 17:58:03 6968] WARNING (XendAPI:705) API call: debug.get_all not found
[2010-11-22 17:58:03 6968] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication has been disabled for this server.
[2010-11-22 17:58:03 6968] INFO (XMLRPCServer:156) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:101) XendDomainInfo.create(['vm', ['name', 'WinXP_HVM_Migrate'], ['memory', 256], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['vcpus', 1], ['oos', 1], ['image', ['hvm', ['kernel', '/usr/lib64/xen/boot/hvmloader'], ['videoram', 4], ['serial', 'pty'], ['acpi', 1], ['apic', 1], ['boot', 'dca'], ['cpuid', []], ['cpuid_check', []], ['device_model', '/usr/lib64/xen/bin/qemu-dm'], ['display', 'localhost:10.0'], ['fda', ''], ['fdb', ''], ['guest_os_type', 'default'], ['hap', 1], ['hpet', 0], ['isa', 0], ['keymap', ''], ['localtime', 0], ['nographic', 0], ['oos', 1], ['pae', 1], ['pci', []], ['pci_msitranslate', 1], ['pci_power_mgmt', 0], ['rtc_timeoffset', 0], ['sdl', 0], ['soundhw', 'ac97'], ['stdvga', 1], ['timer_mode', 1], ['usb', 0], ['usbdevice', 'tablet'], ['vcpus', 1], ['vnc', 1], ['vncdisplay', 6], ['vnclisten', '0.0.0.0'], ['vncunused', 1], ['viridian', 0], ['vpt_align', 1], ['xauthority', '/home/crilit/.Xauthority'], ['xen_platform_pci', 1], ['memory_sharing', 0], ['vncpasswd', 'XXXXXXXX'], ['tsc_mode', 0], ['nomigrate', 0]]], ['s3_integrity', 1], ['device', ['vbd', ['uname', 'phy:/dev/vg_xen/lv_xp_vm'], ['dev', 'hda'], ['mode', 'w']]], ['device', ['vif', ['bridge', 'xenbr0'], ['type', 'ioemu']]]])
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:2508) XendDomainInfo.constructDomain
[2010-11-22 17:58:22 6968] DEBUG (balloon:220) Balloon: 3269620 KiB free; need 16384; done.
[2010-11-22 17:58:22 6968] DEBUG (XendDomain:464) Adding Domain: 5
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:2818) XendDomainInfo.initDomain: 5 256
[2010-11-22 17:58:22 6968] DEBUG (image:339) No VNC passwd configured for vfb access
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: boot, val: dca
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: fda, val: None
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: fdb, val: None
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: soundhw, val: ac97
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: localtime, val: 0
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: serial, val: ['pty']
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: std-vga, val: 1
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: isa, val: 0
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: acpi, val: 1
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: usb, val: 0
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: usbdevice, val: tablet
[2010-11-22 17:58:22 6968] DEBUG (image:891) args: gfx_passthru, val: None
[2010-11-22 17:58:22 6968] INFO (image:822) Need to create platform device.[domid:5]
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:2845) _initDomain:shadow_memory=0x0, memory_static_max=0x10000000, memory_static_min=0x0.
[2010-11-22 17:58:22 6968] INFO (image:182) buildDomain os=hvm dom=5 vcpus=1
[2010-11-22 17:58:22 6968] DEBUG (image:949) domid          = 5
[2010-11-22 17:58:22 6968] DEBUG (image:950) image          = /usr/lib64/xen/boot/hvmloader
[2010-11-22 17:58:22 6968] DEBUG (image:951) store_evtchn   = 2
[2010-11-22 17:58:22 6968] DEBUG (image:952) memsize        = 256
[2010-11-22 17:58:22 6968] DEBUG (image:953) target         = 256
[2010-11-22 17:58:22 6968] DEBUG (image:954) vcpus          = 1
[2010-11-22 17:58:22 6968] DEBUG (image:955) vcpu_avail     = 1
[2010-11-22 17:58:22 6968] DEBUG (image:956) acpi           = 1
[2010-11-22 17:58:22 6968] DEBUG (image:957) apic           = 1
[2010-11-22 17:58:22 6968] INFO (XendDomainInfo:2367) createDevice: vfb : {'vncunused': 1, 'other_config': {'vncunused': 1, 'vnclisten': '0.0.0.0', 'vnc': '1', 'vncdisplay': 6}, 'vnc': '1', 'uuid': '777443ff-8dc1-a402-de0f-a5ae03ae6902', 'vnclisten': '0.0.0.0', 'vncdisplay': 6}
[2010-11-22 17:58:22 6968] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/5/0'} to /local/domain/5/device/vfb/0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:97) DevController: writing {'vncunused': '1', 'domain': 'WinXP_HVM_Migrate', 'vnc': '1', 'uuid': '777443ff-8dc1-a402-de0f-a5ae03ae6902', 'frontend-id': '5', 'vnclisten': '0.0.0.0', 'vncdisplay': '6', 'state': '1', 'online': '1', 'frontend': '/local/domain/5/device/vfb/0'} to /local/domain/0/backend/vfb/5/0.
[2010-11-22 17:58:22 6968] INFO (XendDomainInfo:2367) createDevice: vbd : {'uuid': '858a9d40-7dd2-537c-e302-8aaae156213e', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda', 'uname': 'phy:/dev/vg_xen/lv_xp_vm', 'mode': 'w'}
[2010-11-22 17:58:22 6968] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '768', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/5/768'} to /local/domain/5/device/vbd/768.
[2010-11-22 17:58:22 6968] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/5/device/vbd/768', 'uuid': '858a9d40-7dd2-537c-e302-8aaae156213e', 'bootable': '1', 'dev': 'hda', 'state': '1', 'params': '/dev/vg_xen/lv_xp_vm', 'mode': 'w', 'online': '1', 'frontend-id': '5', 'type': 'phy'} to /local/domain/0/backend/vbd/5/768.
[2010-11-22 17:58:22 6968] INFO (XendDomainInfo:2367) createDevice: vif : {'bridge': 'xenbr0', 'mac': '00:16:3e:53:76:ea', 'type': 'ioemu', 'uuid': '794e37dd-a989-8fa9-fbb6-f4716ad332b1'}
[2010-11-22 17:58:22 6968] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vif/5/0'} to /local/domain/5/device/vif/0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:97) DevController: writing {'bridge': 'xenbr0', 'domain': 'WinXP_HVM_Migrate', 'handle': '0', 'uuid': '794e37dd-a989-8fa9-fbb6-f4716ad332b1', 'script': '/etc/xen/scripts/vif-bridge', 'mac': '00:16:3e:53:76:ea', 'frontend-id': '5', 'state': '1', 'online': '1', 'frontend': '/local/domain/5/device/vif/0', 'type': 'ioemu'} to /local/domain/0/backend/vif/5/0.
[2010-11-22 17:58:22 6968] INFO (image:418) spawning device models: /usr/lib64/xen/bin/qemu-dm ['/usr/lib64/xen/bin/qemu-dm', '-d', '5', '-domain-name', 'WinXP_HVM_Migrate', '-videoram', '4', '-vnc', '0.0.0.0:6', '-vncunused', '-vcpus', '1', '-vcpu_avail', '0x1', '-boot', 'dca', '-soundhw', 'ac97', '-serial', 'pty', '-std-vga', '-acpi', '-usbdevice', 'tablet', '-net', 'nic,vlan=1,macaddr=00:16:3e:53:76:ea,model=rtl8139', '-net', 'tap,vlan=1,ifname=tap5.0,bridge=xenbr0', '-M', 'xenfv']
[2010-11-22 17:58:22 6968] INFO (image:467) device model pid: 7123
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:3400) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '3', 'uuid': '2ec1afef-ecbd-0cea-684b-96ef3c94bf6c', 'on_reboot': 'restart', 'start_time': '1290419902.2', 'on_poweroff': 'destroy', 'bootloader_args': '', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'bootloader': '', 'image': '(hvm (kernel ) (superpages 0) (videoram 4) (hpet 0) (stdvga 1) (vnclisten 0.0.0.0) (loader /usr/lib64/xen/boot/hvmloader) (xen_platform_pci 1) (rtc_timeoffset 0) (pci ()) (hap 1) (localtime 0) (timer_mode 1) (vncdisplay 6) (pci_msitranslate 1) (oos 1) (apic 1) (sdl 0) (usbdevice tablet) (display localhost:10.0) (vpt_align 1) (serial pty) (vncunused 1) (soundhw ac97) (boot dca) (pae 1) (viridian 0) (acpi 1) (vnc 1) (nographic 0) (nomigrate 0) (usb 0) (tsc_mode 0) (guest_os_type default) (device_model /usr/lib64/xen/bin/qemu-dm) (pci_power_mgmt 0) (xauthority /home/crilit/.Xauthority) (isa 0) (notes (SUSPEND_CANCEL 1)))', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 17:58:22 6968] INFO (image:590) waiting for sentinel_fifo
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:1804) Storing domain details: {'console/port': '3', 'description': '', 'console/limit': '1048576', 'store/port': '2', 'vm': '/vm/2ec1afef-ecbd-0cea-684b-96ef3c94bf6c', 'domid': '5', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'store/ring-ref': '1044476', 'console/type': 'ioemu', 'name': 'WinXP_HVM_Migrate'}
[2010-11-22 17:58:22 6968] DEBUG (DevController:95) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/5/0'} to /local/domain/5/device/console/0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:97) DevController: writing {'domain': 'WinXP_HVM_Migrate', 'frontend': '/local/domain/5/device/console/0', 'uuid': '516a5b67-5123-31ea-cf2b-1e697107d985', 'frontend-id': '5', 'state': '1', 'location': '3', 'online': '1', 'protocol': 'vt100'} to /local/domain/0/backend/console/5/0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices tap2.
[2010-11-22 17:58:22 6968] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vif.
[2010-11-22 17:58:22 6968] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vif/5/0/hotplug-status.
[2010-11-22 17:58:22 6968] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vkbd.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices ioports.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices tap.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vif2.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices console.
[2010-11-22 17:58:22 6968] DEBUG (DevController:144) Waiting for 0.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vscsi.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vbd.
[2010-11-22 17:58:22 6968] DEBUG (DevController:144) Waiting for 768.
[2010-11-22 17:58:22 6968] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/5/768/hotplug-status.
[2010-11-22 17:58:22 6968] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices irq.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vfb.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices pci.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vusb.
[2010-11-22 17:58:22 6968] DEBUG (DevController:139) Waiting for devices vtpm.
[2010-11-22 17:58:22 6968] INFO (XendDomain:1206) Domain WinXP_HVM_Migrate (5) unpaused.
[2010-11-22 17:59:50 6968] DEBUG (XendCheckpoint:124) [xc_save]: /usr/lib/xen/bin/xc_save 35 5 0 0 5
[2010-11-22 17:59:50 6968] INFO (XendCheckpoint:423) xc_save: failed to get the suspend evtchn port
[2010-11-22 17:59:50 6968] INFO (XendCheckpoint:423) 
[2010-11-22 18:00:13 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 1   0%\b\b\b\b  5%\b\b\b\b 10%\b\b\b\b 15%\b\b\b\b 20%\b\b\b\b 25%\b\b\b\b 30%\b\b\b\b 35%\b\b\b\b 40%\b\b\b\b 45%\b\b\b\b 50%\b\b\b\b 55%\b\b\b\b 60%\b\b\b\b 65%\b\b\b\b 70%\b\b\b\b 75%\b\b\b\b 80%\b\b\b\b 85%\b\b\b\b 90%\b\b\b\b 95%\r 1: sent 64680, skipped 5976, delta 23556ms, dom0 30%, target 5%, sent 89Mb/s, dirtied 13Mb/s 9700 pages
[2010-11-22 18:00:16 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 2   0%\b\b\b\b  5%\r 2: sent 9132, skipped 550, delta 3066ms, dom0 26%, target 2%, sent 97Mb/s, dirtied 25Mb/s 2405 pages
[2010-11-22 18:00:17 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 3   0%\r 3: sent 1956, skipped 449, delta 686ms, dom0 32%, target 3%, sent 93Mb/s, dirtied 78Mb/s 1638 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 4   0%\r 4: sent 1454, skipped 184, delta 527ms, dom0 25%, target 3%, sent 90Mb/s, dirtied 61Mb/s 985 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 5   0%\r 5: sent 985, skipped 0, delta 341ms, dom0 31%, target 2%, sent 94Mb/s, dirtied 14Mb/s 155 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 6   0%\r 6: sent 155, skipped 0, delta 67ms, dom0 77%, target 0%, sent 75Mb/s, dirtied 478Mb/s 979 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 7   0%\r 7: sent 979, skipped 0, delta 334ms, dom0 23%, target 1%, sent 96Mb/s, dirtied 13Mb/s 140 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 8   0%\r 8: sent 140, skipped 0, delta 21ms, dom0 100%, target 0%, sent 218Mb/s, dirtied 65Mb/s 42 pages
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 9   0%\r 9: sent 42, skipped 0, Start last iteration
[2010-11-22 18:00:18 6968] DEBUG (XendCheckpoint:394) suspend
[2010-11-22 18:00:18 6968] DEBUG (XendCheckpoint:127) In saveInputHandler suspend
[2010-11-22 18:00:18 6968] DEBUG (XendCheckpoint:129) Suspending 5 ...
[2010-11-22 18:00:18 6968] DEBUG (XendDomainInfo:519) XendDomainInfo.shutdown(suspend)
[2010-11-22 18:00:18 6968] DEBUG (XendDomainInfo:1891) XendDomainInfo.handleShutdownWatch
[2010-11-22 18:00:18 6968] INFO (XendDomainInfo:536) HVM save:remote shutdown dom 5!
[2010-11-22 18:00:18 6968] INFO (XendDomainInfo:2088) Domain has shutdown: name=migrating-WinXP_HVM_Migrate id=5 reason=suspend.
[2010-11-22 18:00:18 6968] INFO (XendCheckpoint:135) Domain 5 suspended.
[2010-11-22 18:00:19 6968] INFO (image:538) signalDeviceModel:restore dm state to running
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) SUSPEND shinfo 000fffff
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) delta 300ms, dom0 18%, target 0%, sent 4Mb/s, dirtied 11Mb/s 103 pages
[2010-11-22 18:00:19 6968] DEBUG (XendCheckpoint:144) Written done
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) Saving memory pages: iter 10   0%\r 10: sent 103, skipped 0, delta 15ms, dom0 0%, target 0%, sent 225Mb/s, dirtied 225Mb/s 103 pages
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) Total pages sent= 79626 (0.08x)
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) (of which 0 were fixups)
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) All memory is saved
[2010-11-22 18:00:19 6968] INFO (XendCheckpoint:423) Save exit rc=0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:3053) XendDomainInfo.destroy: domid=5
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2411) Destroying device model
[2010-11-22 18:00:19 6968] INFO (image:615) migrating-WinXP_HVM_Migrate device model terminated
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing console/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing vbd/768
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/768
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing vfb/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2416) No device model
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:2424) Removing vbd/768
[2010-11-22 18:00:19 6968] DEBUG (XendDomainInfo:1286) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/768

[-- Attachment #8: Type: text/plain, Size: 138 bytes --]

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel