[Xen-devel] blkif migration problem

[Cristian Zamfir <zamf@xxxxxxxxxxxxx>]

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



[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) 100%
[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: xend.log.src
Description: WAIS Source

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