blkif migration problem

blkif migration problem

[Cristian Zamfir]

[-- Attachment #1: Type: text/plain, Size: 990 bytes --]


Hi,

We are attempting to migrate blkif devices backed by drbd devices. We 
have used a similar approach to the vTPM migration. Complete migration 
seems to go without errors on both source and destination. The migrated 
machine responds to external network queries like ping, arping, nmap but 
I cannot ssh into it. Also, when using xm console, I get get these 
messages before the login prompt:

vbd vbd-769: 16 Device in use; refusing to close
netfront: device eth0 has flipping receive path.

... then the  machine hangs after inputing the login username.

My guess is that even though the hotplug scripts returned successfully 
for the vbd device (according to the xend.log bellow), the vbd did not 
migrate successfully and the dom0 machine cannot read anything from the 
disk.

Do you have any suggestion on what the problem might be and where and 
how to look for more debugging information?

Attached are the xend.logs for the source and the destination.

Thank you.

Cristian




[-- Attachment #2: xend.log.dst --]
[-- Type: text/plain, Size: 9555 bytes --]

[2006-12-04 17:22:53 xend 2674] INFO (SrvDaemon:283) Xend Daemon started
[2006-12-04 17:22:53 xend 2674] INFO (SrvDaemon:287) Xend changeset: unavailable .
[2006-12-04 17:22:53 xend.XendDomainInfo 2674] DEBUG (XendDomainInfo:212) XendDomainInfo.recreate({'paused': 0, 'cpu_time': 8725777156L, 'ssidref': 0, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'shutdown_reason': 0, 'dying': 0, 'dom': 0, 'mem_kb': 254720, 'maxmem_kb': -4, 'max_vcpu_id': 0, 'crashed': 0, 'running': 1, 'shutdown': 0, 'online_vcpus': 1, 'blocked': 0})
[2006-12-04 17:22:53 xend.XendDomainInfo 2674] INFO (XendDomainInfo:224) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000.
[2006-12-04 17:22:53 xend.XendDomainInfo 2674] WARNING (XendDomainInfo:246) No vm path in store for existing domain 0
[2006-12-04 17:22:53 xend.XendDomainInfo 2674] DEBUG (XendDomainInfo:712) Storing VM details: {'shadow_memory': '0', 'uuid': '00000000-0000-0000-0000-000000000000', 'on_reboot': 'restart', 'on_poweroff': 'destroy', 'name': 'Domain-0', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'memory': '249', 'on_crash': 'restart', 'maxmem': '249'}
[2006-12-04 17:22:53 xend.XendDomainInfo 2674] DEBUG (XendDomainInfo:747) Storing domain details: {'cpu/0/availability': 'online', 'memory/target': '254976', 'name': 'Domain-0', 'console/limit': '1048576', 'vm': '/vm/00000000-0000-0000-0000-000000000000', 'domid': '0'}
[2006-12-04 17:22:53 xend 2674] DEBUG (XendDomain:153) number of vcpus to use is 0
[2006-12-04 17:22:53 xend.XendDomainInfo 2684] DEBUG (XendDomainInfo:933) XendDomainInfo.handleShutdownWatch
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:265) XendDomainInfo.restore(['domain', ['domid', '3'], ['uuid', '3be156ff-6298-0d86-0b94-27c58262f4c0'], ['vcpus', '1'], ['vcpu_avail', '1'], ['cpu_weight', '1.0'], ['memory', '232'], ['shadow_memory', '0'], ['maxmem', '232'], ['features'], ['name', 'vm01'], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['image', ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']]], ['device', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]], ['device', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']]], ['state', '------'], ['shutdown_reason', 'poweroff'], ['cpu_time', '0.891476194'], ['online_vcpus', '1'], ['up_time', '85.1114499569'], ['start_time', '1165253683.61'], ['store_mfn', '4781'], ['console_mfn', '4780']])
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:296) parseConfig: config is ['domain', ['domid', '3'], ['uuid', '3be156ff-6298-0d86-0b94-27c58262f4c0'], ['vcpus', '1'], ['vcpu_avail', '1'], ['cpu_weight', '1.0'], ['memory', '232'], ['shadow_memory', '0'], ['maxmem', '232'], ['features'], ['name', 'vm01'], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['image', ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']]], ['device', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]], ['device', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']]], ['state', '------'], ['shutdown_reason', 'poweroff'], ['cpu_time', '0.891476194'], ['online_vcpus', '1'], ['up_time', '85.1114499569'], ['start_time', '1165253683.61'], ['store_mfn', '4781'], ['console_mfn', '4780']]
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:395) parseConfig: result is {'shadow_memory': 0, 'uuid': '3be156ff-6298-0d86-0b94-27c58262f4c0', 'on_crash': 'restart', 'on_reboot': 'restart', 'localtime': None, 'image': ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']], 'on_poweroff': 'destroy', 'bootloader_args': None, 'cpus': None, 'name': 'vm01', 'backend': [], 'vcpus': 1, 'cpu_weight': 1.0, 'features': None, 'vcpu_avail': 1, 'memory': 232, 'device': [('vif', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]), ('vbd', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']])], 'bootloader': None, 'cpu': None, 'maxmem': 232}
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:1253) XendDomainInfo.construct: None
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:712) Storing VM details: {'shadow_memory': '0', 'uuid': '3be156ff-6298-0d86-0b94-27c58262f4c0', 'on_reboot': 'restart', 'image': '(linux (kernel /boot/vmlinuz-2.6-xenU) (ip 130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off) (root /dev/hda1))', 'on_poweroff': 'destroy', 'name': 'vm01', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'memory': '232', 'on_crash': 'restart', 'maxmem': '232'}
[2006-12-04 17:35:26 xend 3030] DEBUG (DevController:110) DevController: writing {'backend-id': '0', 'mac': '00:16:3E:F6:BB:01', 'handle': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/1/0'} to /local/domain/1/device/vif/0.
[2006-12-04 17:35:26 xend 3030] DEBUG (DevController:112) DevController: writing {'domain': 'vm01', 'handle': '0', 'script': '/etc/xen/scripts/vif-bridge', 'state': '1', 'frontend': '/local/domain/1/device/vif/0', 'mac': '00:16:3E:F6:BB:01', 'online': '1', 'frontend-id': '1'} to /local/domain/0/backend/vif/1/0.
[2006-12-04 17:35:26 xend 3030] DEBUG (DevController:110) DevController: writing {'backend-id': '0', 'virtual-device': '769', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/1/769'} to /local/domain/1/device/vbd/769.
[2006-12-04 17:35:26 xend 3030] DEBUG (DevController:112) DevController: writing {'domain': 'vm01', 'frontend': '/local/domain/1/device/vbd/769', 'dev': 'hda1', 'state': '1', 'params': 'drbd1', 'mode': 'w', 'online': '1', 'frontend-id': '1', 'type': 'phy'} to /local/domain/0/backend/vbd/1/769.
[2006-12-04 17:35:26 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:747) Storing domain details: {'console/port': '2', 'name': 'vm01', 'console/limit': '1048576', 'vm': '/vm/3be156ff-6298-0d86-0b94-27c58262f4c0', 'domid': '1', 'cpu/0/availability': 'online', 'memory/target': '237568', 'store/port': '1'}
[2006-12-04 17:35:26 xend 3030] DEBUG (balloon:127) Balloon: 770752 KiB free; need 245760; done.
[2006-12-04 17:35:26 xend 3030] DEBUG (XendCheckpoint:155) [xc_restore]: /usr/lib/xen/bin/xc_restore 4 1 61440 1 2
[2006-12-04 17:35:27 xend 3039] ERROR (XendCheckpoint:236) xc_linux_restore start: max_pfn = f000
[2006-12-04 17:35:27 xend 3039] ERROR (XendCheckpoint:236) Increased domain reservation by 3c000 KB
[2006-12-04 17:35:27 xend 3039] ERROR (XendCheckpoint:236) Reloading memory pages:   0%
[2006-12-04 17:35:48 xend 3030] DEBUG (XendCheckpoint:209) store-mfn 4781
[2006-12-04 17:35:48 xend 3030] DEBUG (XendCheckpoint:209) console-mfn 4780
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) Received all pages (0 races)
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) \b\b\b\b100%
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) Memory reloaded.
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) Decreased reservation by 2094 pages
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) Domain ready to be built.
[2006-12-04 17:35:48 xend 3039] ERROR (XendCheckpoint:236) Restore exit with rc=0
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices vif.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:149) Waiting for 0.
[2006-12-04 17:35:48 xend 2684] DEBUG (DevController:464) hotplugStatusCallback /local/domain/0/backend/vif/1/0/hotplug-status.
[2006-12-04 17:35:48 xend 2684] DEBUG (DevController:479) hotplugStatusCallback 1.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices usb.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices vbd.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:149) Waiting for 769.
[2006-12-04 17:35:48 xend 2684] DEBUG (DevController:464) hotplugStatusCallback /local/domain/0/backend/vbd/1/769/hotplug-status.
[2006-12-04 17:35:48 xend 2684] DEBUG (DevController:479) hotplugStatusCallback 1.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices irq.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices pci.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices ioports.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices tap.
[2006-12-04 17:35:48 xend 3030] DEBUG (DevController:143) Waiting for devices vtpm.
[2006-12-04 17:35:48 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:672) XendDomainInfo.completeRestore
[2006-12-04 17:35:48 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:747) Storing domain details: {'console/ring-ref': '4780', 'console/port': '2', 'name': 'vm01', 'console/limit': '1048576', 'vm': '/vm/3be156ff-6298-0d86-0b94-27c58262f4c0', 'domid': '1', 'cpu/0/availability': 'online', 'memory/target': '237568', 'store/ring-ref': '4781', 'store/port': '1'}
[2006-12-04 17:35:48 xend.XendDomainInfo 3030] DEBUG (XendDomainInfo:682) XendDomainInfo.completeRestore done
[2006-12-04 17:35:48 xend.XendDomainInfo 2684] DEBUG (XendDomainInfo:933) XendDomainInfo.handleShutdownWatch

[-- Attachment #3: xend.log.src --]
[-- Type: application/x-wais-source, Size: 20586 bytes --]

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

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

blkif migration problem

[Cristian Zamfir]

[-- Attachment #1: Type: text/plain, Size: 1375 bytes --]


Hi,

I am trying to live migrate blkif devices backed by drbd devices and I 
am struggling with a problem for a few days now. The problem is that 
after migration, the domU machine cannot load any new programs into 
memory. The ssh connection survives migration and I can run programs 
that are already in the memory but not something that needs to be loaded 
from the disk.

I am currently testing with an almost idle machine and I am triggering 
the drive migration after the domain is suspended, in step 2, from: 
XendCheckpoint.py: dominfo.migrateDevices(network, dst, 
DEV_MIGRATE_STEP2, domain_name).

However, I also tried before the domain is suspended from step 1 
(dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP1, domain_name))
and everything works fine, except that there is the obvious possibility 
of loosing some writes to the disk because the domain is not suspended yet.

After migration, when I reattach a console I get this message:
"vbd vbd-769: 16 Device in use; refusing to close"
This is from the blkfront.c backend_changed() function but I cannot 
figure out why this error occurs.

 From the xend.logs and dmesg on the source and destination attached 
bellow I cannot spot any errors. I am using xen 3.0.3.

Any kind of ideas will be greatly appreciated as I am a beginner with 
developing and debugging xen.
Thank you very much.














[-- Attachment #2: dmesg_dest --]
[-- Type: text/plain, Size: 1277 bytes --]

#dmesg on the destination

[97198.550035] DEV: registering device: ID = 'vif-10-0'
[97198.550304] PM: Adding info for xen-backend:vif-10-0
[97198.550312] bus xen-backend: add device vif-10-0
[97198.550318] xen-backend: Matched Device vif-10-0 with Driver vif
[97198.553322] CLASS: registering class device: ID = 'vif10.0'
[97198.553350] class_uevent - name = vif10.0
[97198.555781] bound device 'vif-10-0' to driver 'vif'
[97198.555792] xen-backend: Bound Device vif-10-0 to Driver vif
[97198.564861] DEV: registering device: ID = 'vbd-10-769'
[97198.565066] PM: Adding info for xen-backend:vbd-10-769
[97198.565073] bus xen-backend: add device vbd-10-769
[97198.565077] xen-backend: Matched Device vbd-10-769 with Driver vbd
[97198.566590] bound device 'vbd-10-769' to driver 'vbd'
[97198.566600] xen-backend: Bound Device vbd-10-769 to Driver vbd
[97198.890187] device vif10.0 entered promiscuous mode
[97199.101015] vbd vbd-10-769: 2 creating vbd structure
[97219.554243] drbd1: Secondary/Primary --> Secondary/Secondary
[97219.565465] drbd1: Secondary/Secondary --> Primary/Secondary
[97220.340039] xenbr0: port 3(vif10.0) entering learning state
[97220.350034] xenbr0: topology change detected, propagating
[97220.350057] xenbr0: port 3(vif10.0) entering forwarding state

[-- Attachment #3: dmesg_source --]
[-- Type: text/plain, Size: 769 bytes --]

#dmesg on the source

[97567.392392] drbd1: Primary/Secondary --> Secondary/Secondary
[97567.464148] drbd1: Secondary/Secondary --> Secondary/Primary
[97567.634964] DEV: Unregistering device. ID = 'vif-15-0'
[97567.634986] bus xen-backend: remove device vif-15-0
[97567.658033] xenbr0: port 3(vif15.0) entering disabled state
[97567.698110] device vif15.0 left promiscuous mode
[97567.698152] xenbr0: port 3(vif15.0) entering disabled state
[97567.719202] class_uevent - name = vif15.0
[97567.719440] device class 'vif15.0': release.
[97567.758982] PM: Removing info for xen-backend:vif-15-0
[97567.760113] DEV: Unregistering device. ID = 'vbd-15-769'
[97567.760133] bus xen-backend: remove device vbd-15-769
[97567.760465] PM: Removing info for xen-backend:vbd-15-769

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #4: xend_dst.log --]
[-- Type: text/x-log; name="xend_dst.log", Size: 7982 bytes --]

#xend.log for the destination

[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:265) XendDomainInfo.restore(['domain', ['domid', '15'], ['uuid', 'e5aed08a-0834-0f98-5d82-5a64fde20c4d'], ['vcpus', '1'], ['vcpu_avail', '1'], ['cpu_weight', '1.0'], ['memory', '232'], ['shadow_memory', '0'], ['maxmem', '232'], ['features'], ['name', 'vm01'], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['image', ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']]], ['device', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]], ['device', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']]], ['state', '--p---'], ['shutdown_reason', 'poweroff'], ['cpu_time', '0.0'], ['online_vcpus', '1'], ['up_time', '109.739135981'], ['start_time', '1165505462.6'], ['store_mfn', '238994'], ['console_mfn', '241198']])
[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:296) parseConfig: config is ['domain', ['domid', '15'], ['uuid', 'e5aed08a-0834-0f98-5d82-5a64fde20c4d'], ['vcpus', '1'], ['vcpu_avail', '1'], ['cpu_weight', '1.0'], ['memory', '232'], ['shadow_memory', '0'], ['maxmem', '232'], ['features'], ['name', 'vm01'], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['image', ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']]], ['device', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]], ['device', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']]], ['state', '--p---'], ['shutdown_reason', 'poweroff'], ['cpu_time', '0.0'], ['online_vcpus', '1'], ['up_time', '109.739135981'], ['start_time', '1165505462.6'], ['store_mfn', '238994'], ['console_mfn', '241198']]
[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:395) parseConfig: result is {'shadow_memory': 0, 'uuid': 'e5aed08a-0834-0f98-5d82-5a64fde20c4d', 'on_crash': 'restart', 'on_reboot': 'restart', 'localtime': None, 'image': ['linux', ['kernel', '/boot/vmlinuz-2.6-xenU'], ['ip', '130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off'], ['root', '/dev/hda1']], 'on_poweroff': 'destroy', 'bootloader_args': None, 'cpus': None, 'name': 'vm01', 'backend': [], 'vcpus': 1, 'cpu_weight': 1.0, 'features': None, 'vcpu_avail': 1, 'memory': 232, 'device': [('vif', ['vif', ['backend', '0'], ['script', 'vif-bridge'], ['mac', '00:16:3E:F6:BB:01']]), ('vbd', ['vbd', ['backend', '0'], ['dev', 'hda1:disk'], ['uname', 'phy:drbd1'], ['mode', 'w']])], 'bootloader': None, 'cpu': None, 'maxmem': 232}
[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:1253) XendDomainInfo.construct: None
[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:712) Storing VM details: {'shadow_memory': '0', 'uuid': 'e5aed08a-0834-0f98-5d82-5a64fde20c4d', 'on_reboot': 'restart', 'image': '(linux (kernel /boot/vmlinuz-2.6-xenU) (ip 130.209.253.132:1.2.3.4:130.209.240.48:255.255.240.0:raoul.dcs.gla.ac.uk:eth0:off) (root /dev/hda1))', 'on_poweroff': 'destroy', 'name': 'vm01', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'memory': '232', 'on_crash': 'restart', 'maxmem': '232'}
[2006-12-07 15:32:15 xend 7200] DEBUG (DevController:110) DevController: writing {'backend-id': '0', 'mac': '00:16:3E:F6:BB:01', 'handle': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/10/0'} to /local/domain/10/device/vif/0.
[2006-12-07 15:32:15 xend 7200] DEBUG (DevController:112) DevController: writing {'domain': 'vm01', 'handle': '0', 'script': '/etc/xen/scripts/vif-bridge', 'state': '1', 'frontend': '/local/domain/10/device/vif/0', 'mac': '00:16:3E:F6:BB:01', 'online': '1', 'frontend-id': '10'} to /local/domain/0/backend/vif/10/0.
[2006-12-07 15:32:15 xend 7200] DEBUG (DevController:110) DevController: writing {'backend-id': '0', 'virtual-device': '769', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/10/769'} to /local/domain/10/device/vbd/769.
[2006-12-07 15:32:15 xend 7200] DEBUG (DevController:112) DevController: writing {'domain': 'vm01', 'frontend': '/local/domain/10/device/vbd/769', 'dev': 'hda1', 'state': '1', 'params': 'drbd1', 'mode': 'w', 'online': '1', 'frontend-id': '10', 'type': 'phy'} to /local/domain/0/backend/vbd/10/769.
[2006-12-07 15:32:15 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:747) Storing domain details: {'console/port': '2', 'name': 'vm01', 'console/limit': '1048576', 'vm': '/vm/e5aed08a-0834-0f98-5d82-5a64fde20c4d', 'domid': '10', 'cpu/0/availability': 'online', 'memory/target': '237568', 'store/port': '1'}
[2006-12-07 15:32:15 xend 7200] DEBUG (balloon:127) Balloon: 770548 KiB free; need 245760; done.
[2006-12-07 15:32:15 xend 7200] DEBUG (XendCheckpoint:169) [xc_restore]: /usr/lib/xen/bin/xc_restore 4 10 61440 1 2
[2006-12-07 15:32:15 xend 7209] ERROR (XendCheckpoint:250) xc_linux_restore start: max_pfn = f000
[2006-12-07 15:32:15 xend 7209] ERROR (XendCheckpoint:250) Increased domain reservation by 3c000 KB
[2006-12-07 15:32:15 xend 7209] ERROR (XendCheckpoint:250) Reloading memory pages:   0%
[2006-12-07 15:32:36 xend 7200] DEBUG (XendCheckpoint:223) store-mfn 45516
[2006-12-07 15:32:36 xend 7200] DEBUG (XendCheckpoint:223) console-mfn 45335
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) Received all pages (0 races)
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) \b\b\b\b100%
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) Memory reloaded.
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) Decreased reservation by 2096 pages
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) Domain ready to be built.
[2006-12-07 15:32:36 xend 7209] ERROR (XendCheckpoint:250) Restore exit with rc=0
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices vif.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:149) Waiting for 0.
[2006-12-07 15:32:37 xend 3013] DEBUG (DevController:464) hotplugStatusCallback /local/domain/0/backend/vif/10/0/hotplug-status.
[2006-12-07 15:32:37 xend 3013] DEBUG (DevController:479) hotplugStatusCallback 1.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices usb.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices vbd.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:149) Waiting for 769.
[2006-12-07 15:32:37 xend 3013] DEBUG (DevController:464) hotplugStatusCallback /local/domain/0/backend/vbd/10/769/hotplug-status.
[2006-12-07 15:32:37 xend 3013] DEBUG (DevController:479) hotplugStatusCallback 1.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices irq.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices pci.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices ioports.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices tap.
[2006-12-07 15:32:37 xend 7200] DEBUG (DevController:143) Waiting for devices vtpm.
[2006-12-07 15:32:37 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:672) XendDomainInfo.completeRestore
[2006-12-07 15:32:37 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:747) Storing domain details: {'console/ring-ref': '45335', 'console/port': '2', 'name': 'vm01', 'console/limit': '1048576', 'vm': '/vm/e5aed08a-0834-0f98-5d82-5a64fde20c4d', 'domid': '10', 'cpu/0/availability': 'online', 'memory/target': '237568', 'store/ring-ref': '45516', 'store/port': '1'}
[2006-12-07 15:32:37 xend.XendDomainInfo 7200] DEBUG (XendDomainInfo:682) XendDomainInfo.completeRestore done
[2006-12-07 15:32:37 xend.XendDomainInfo 3013] DEBUG (XendDomainInfo:933) XendDomainInfo.handleShutdownWatch

[-- Attachment #5: xend_src.log --]
[-- Type: text/x-log, Size: 15444 bytes --]

#xend.log for the source


[2006-12-07 15:32:52 xend 9776] INFO (blkif:168) Request to network-migrate device to rangatira. step=0.
[2006-12-07 15:32:52 xend 9776] DEBUG (balloon:127) Balloon: 533304 KiB free; need 2048; done.
[2006-12-07 15:32:52 xend 9776] INFO (blkif:168) Request to network-migrate device to rangatira. step=1.

[2006-12-07 15:32:52 xend 9776] DEBUG (XendCheckpoint:83) [xc_save]: /usr/lib/xen/bin/xc_save 19 15 0 0 1
[2006-12-07 15:32:52 xend 9785] ERROR (XendCheckpoint:242) Had 0 unexplained entries in p2m table
[2006-12-07 15:32:53 xend 9785] ERROR (XendCheckpoint:242) Saving memory pages: iter 1   0%\b\b\b\b  5%PT Race: [10000000,909] pte=bed063, mfn=00000bed
[2006-12-07 15:32:59 xend 9785] ERROR (XendCheckpoint:242) \b\b\b\b 10%\b\b\b\b 15%\b\b\b\b 20%\b\b\b\b 25%\b\b\b\b 31%PT Race: [10000000,0] pte=1d8063, mfn=000001d8
[2006-12-07 15:32:59 xend 9785] ERROR (XendCheckpoint:242) PT Race: [10000000,1] pte=1d9063, mfn=000001d9
[2006-12-07 15:32:59 xend 9785] ERROR (XendCheckpoint:242) PT Race: [10000000,2] pte=1da063, mfn=000001da
[2006-12-07 15:32:59 xend 9785] ERROR (XendCheckpoint:242) PT Race: [10000000,3] pte=1db063, mfn=000001db
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) \b\b\b\b 36%\b\b\b\b 41%\b\b\b\b 46%\b\b\b\b 51%\b\b\b\b 57%\b\b\b\b 62%\b\b\b\b 67%\b\b\b\b 72%\b\b\b\b 77%\b\b\b\b 83%\b\b\b\b 88%\b\b\b\b 93%\b\b\b\b 98%
 1: sent 59188, skipped 203, delta 20756ms, dom0 10%, target 0%, sent 93Mb/s, dirtied 0Mb/s 238 pages
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Saving memory pages: iter 2   0%netbuf race: iter 2, pfn e422. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e42c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e064. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e079. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 7e2. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e498. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e4c0. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e0d6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e4e2. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e510. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e514. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 7c6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 59d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e5be. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e5bf. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn ddc4. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn dde6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 5f1. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn de0c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn de10. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 612. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e235. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e638. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e63a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 63c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e63e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e646. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e647. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 648. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e661. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e662. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e664. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 666. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 66f. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 670. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn de7c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn de7d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e691. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e694. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 696. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 69a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e69a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 69c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 69e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 6bc. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 7fb. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e6e4. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 6e6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 6ec. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 6ed. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn deee. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn deef. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e711. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 713. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn e726. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 132c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 73e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 743. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 76b. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 76d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 79f. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 2, pfn 7a0. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) 2: sent 176, skipped 0, delta 64ms, dom0 34%, target 0%, sent 90Mb/s, dirtied 29Mb/s 58 pages
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Saving memory pages: iter 3   0%
 3: sent 58, skipped 0, delta 16ms, dom0 18%, target 0%, sent 118Mb/s, dirtied 83Mb/s 41 pages
[2006-12-07 15:33:13 xend 9776] DEBUG (XendCheckpoint:215) suspend
[2006-12-07 15:33:13 xend 9776] DEBUG (XendCheckpoint:86) In saveInputHandler suspend
[2006-12-07 15:33:13 xend 9776] DEBUG (XendCheckpoint:88) Suspending 15 ...
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Saving memory pages: iter 4   0%
 4: sent 41, skipped 0, Start last iteration
[2006-12-07 15:33:13 xend.XendDomainInfo 9225] DEBUG (XendDomainInfo:933) XendDomainInfo.handleShutdownWatch
[2006-12-07 15:33:13 xend.XendDomainInfo 9225] DEBUG (XendDomainInfo:933) XendDomainInfo.handleShutdownWatch
[2006-12-07 15:33:13 xend.XendDomainInfo 9225] INFO (XendDomainInfo:892) Domain has shutdown: name=migrating-vm01 id=15 reason=suspend.
[2006-12-07 15:33:13 xend 9776] INFO (blkif:168) Request to network-migrate device to rangatira. step=2.




[2006-12-07 15:33:13 xend 9776] INFO (XendCheckpoint:94) Domain 15 suspended.
[2006-12-07 15:33:13 xend 9776] INFO (blkif:168) Request to network-migrate device to rangatira. step=3.

[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) SUSPEND shinfo 00000bed eip c01013a7 edx 000054b5
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) delta 277ms, dom0 71%, target 0%, sent 4Mb/s, dirtied 17Mb/s 145 pages
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Saving memory pages: iter 5   0%netbuf race: iter 5, pfn e422. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e42c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e064. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 7e2. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e0d6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e4e2. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e510. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 59d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e5be. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e5bf. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn dde6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 5f1. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn de0c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn de10. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e235. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e63a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 63c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e63e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e646. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 648. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e661. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e662. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e664. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 666. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 66f. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 670. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn de7d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e691. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 696. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 69a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e69a. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 69c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 69e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 6bc. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 7fb. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 6e6. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn deee. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn deef. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e711. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 713. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn e726. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 132c. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 73e. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 743. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 76b. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 76d. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 79f. mfn ffffffff
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) netbuf race: iter 5, pfn 7a0. mfn ffffffff
[2006-12-07 15:33:13 xend 9776] DEBUG (XendCheckpoint:99) Written done
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) 5: sent 145, skipped 0, delta 42ms, dom0 42%, target 0%, sent 113Mb/s, dirtied 113Mb/s 145 pages
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Total pages sent= 59608 (0.97x)
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) (of which 0 were fixups)
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) All memory is saved
[2006-12-07 15:33:13 xend 9785] ERROR (XendCheckpoint:242) Save exit rc=0
[2006-12-07 15:33:13 xend.XendDomainInfo 9776] DEBUG (XendDomainInfo:1457) XendDomainInfo.destroyDomain(15)
[2006-12-07 15:33:13 xend.XendDomainInfo 9776] INFO (XendDomainInfo:1555) Dev 769 still active, looping...
[2006-12-07 15:33:13 xend.XendDomainInfo 9776] INFO (XendDomainInfo:1555) Dev 769 still active, looping...
[2006-12-07 15:33:13 xend.XendDomainInfo 9776] INFO (XendDomainInfo:1555) Dev 769 still active, looping...
[2006-12-07 15:33:13 xend.XendDomainInfo 9776] INFO (XendDomainInfo:1555) Dev 769 still active, looping...

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

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

Re: blkif migration problem

[Ewan Mellor]

On Thu, Dec 07, 2006 at 03:47:39PM +0000, Cristian Zamfir wrote:

> 
> Hi,
> 
> I am trying to live migrate blkif devices backed by drbd devices and I 
> am struggling with a problem for a few days now. The problem is that 
> after migration, the domU machine cannot load any new programs into 
> memory. The ssh connection survives migration and I can run programs 
> that are already in the memory but not something that needs to be loaded 
> from the disk.
> 
> I am currently testing with an almost idle machine and I am triggering 
> the drive migration after the domain is suspended, in step 2, from: 
> XendCheckpoint.py: dominfo.migrateDevices(network, dst, 
> DEV_MIGRATE_STEP2, domain_name).
> 
> However, I also tried before the domain is suspended from step 1 
> (dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP1, domain_name))
> and everything works fine, except that there is the obvious possibility 
> of loosing some writes to the disk because the domain is not suspended yet.
> 
> After migration, when I reattach a console I get this message:
> "vbd vbd-769: 16 Device in use; refusing to close"
> This is from the blkfront.c backend_changed() function but I cannot 
> figure out why this error occurs.

I believe that this means that the frontend has seen that the backend is
tearing down, but since the device is still mounted inside the guest, it's
refusing.  I don't think that the frontend ought to see the backend tear down
at all -- the guest ought to be suspended before you tear down the backend
device.

When you say that you are "triggering the drive migration", what does that
involve?  Why would the frontend see the store contents change at all at this
point?

Have you tried a localhost migration?  This would be easier, because you don't
actually need to move the disk of course, so you can get half your signalling
tested before moving on to the harder problem.

Ewan.

Re: blkif migration problem

[Cristian Zamfir]

Ewan Mellor wrote:
> On Thu, Dec 07, 2006 at 03:47:39PM +0000, Cristian Zamfir wrote:
> 
>> Hi,
>>
>> I am trying to live migrate blkif devices backed by drbd devices and I 
>> am struggling with a problem for a few days now. The problem is that 
>> after migration, the domU machine cannot load any new programs into 
>> memory. The ssh connection survives migration and I can run programs 
>> that are already in the memory but not something that needs to be loaded 
>> from the disk.
>>
>> I am currently testing with an almost idle machine and I am triggering 
>> the drive migration after the domain is suspended, in step 2, from: 
>> XendCheckpoint.py: dominfo.migrateDevices(network, dst, 
>> DEV_MIGRATE_STEP2, domain_name).
>>
>> However, I also tried before the domain is suspended from step 1 
>> (dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP1, domain_name))
>> and everything works fine, except that there is the obvious possibility 
>> of loosing some writes to the disk because the domain is not suspended yet.
>>
>> After migration, when I reattach a console I get this message:
>> "vbd vbd-769: 16 Device in use; refusing to close"
>> This is from the blkfront.c backend_changed() function but I cannot 
>> figure out why this error occurs.
> 
> I believe that this means that the frontend has seen that the backend is
> tearing down, but since the device is still mounted inside the guest, it's
> refusing.  I don't think that the frontend ought to see the backend tear down
> at all -- the guest ought to be suspended before you tear down the backend
> device.
> 

I am triggering the migration in DEV_MIGRATE_STEP2, which is right after 
the domain was suspended, as far as I can tell from the python code in 
XendCheckpoint.py:

dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP1, domain_name)
....
....
def saveInputHandler(line, tochild):
            log.debug("In saveInputHandler %s", line)
            if line == "suspend":
                 log.debug("Suspending %d ...", dominfo.getDomid())
                 dominfo.shutdown('suspend')
                 dominfo.waitForShutdown()
                 dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP2,
                                       domain_name)
                 log.info("Domain %d suspended.", dominfo.getDomid())
                 dominfo.migrateDevices(network, dst, DEV_MIGRATE_STEP3,
                                        domain_name)


"Triggering the migration" involves dominfo.migrateDevices(..) calling 
my script in /etc/xen/scripts. This script checks that the drive at the 
source and the replica at the destination are in sync and then switches 
their roles (the one on the source becomes secondary and the one on the 
destination becomes primary). But since the guest is suspended at this 
point, I don't understand why should the frontend see any change.

I found that DRBD drives are not quite usable when they are in secondary 
state, only the primary one should be mounted. For instance, when trying 
to mount a drbd device in secondary state I get this error:
#mount -r -t reiserfs /dev/drbd1 /mnt/vm
mount: /dev/drbd1 already mounted or /mnt/vm busy

Therefore, could this error happen on the destination, during restore 
while waiting for backends to set up, if the drive is in secondary state?

I also don't understand why everything works if I migrate the hard drive 
in DEV_MIGRATE_STEP1. The only error I get in this case is reiserfs 
complainig about some writes that failed, but everything besides this 
seems ok.


I cannot really try localhost migration because I think drbd only works 
with two machines, but I have tested most of my code outside xen and it 
worked.

Thank you very much for your help.



> When you say that you are "triggering the drive migration", what does that
> involve?  Why would the frontend see the store contents change at all at this
> point?
> 
> Have you tried a localhost migration?  This would be easier, because you don't
> actually need to move the disk of course, so you can get half your signalling
> tested before moving on to the harder problem.
> 
> Ewan.