[Xen-devel] hotplug error after several starting multiple VMs

[Cris Daniluk <cris.daniluk@xxxxxxxxx>]

Okay, trying a new combination of Xen release/dom0. I'm running
OpenSLES 11.3 with dist kernel 2.6.34-12-xen using dist
4.0.0_21091_05-6.6.  In general, behavior is good and I am able to
fire and put VMs under load. However, I'm running into hotplug errors
after starting around 20 VMs. I've had very poor results trying to
research this problem given the overwhelming number of people who see
the error message when configuring Xen for the first time, so I'm not
sure where to begin debugging. Everything is running under a single
bridge and I'm using Xen's network-bridge script to manage it. Once I
get into this state, I can't start new VMs, but I can continue to work
with the VMs that are already running. The error is as follows:

linux:/etc/xen/shared/domains # xm create test13
Using config file "./test13".
Error: Device 0 (vif) could not be connected. Hotplug scripts not working.


The xend.log output is below. Nothing is logged to xen-hotplug.log.


(XEN) cpupool_add_domain(dom=25,pool=0) n_dom 20
[2010-08-26 21:02:33 4957] DEBUG (XendDomainInfo:103)
XendDomainInfo.create(['vm', ['name', 'test13'], ['memory', 1024],
['on_reboot', 'restart'], ['on_crash', 'restart'], ['on_xend_start',
'ignore'], ['on_xend_stop', 'ignore'], ['vcpus', 1], ['oos', 1],
['bootloader', '/usr/bin/pygrub'], ['bootloader_args', '-q'],
['image', ['linux', ['videoram', 4], ['tsc_mode', 0], ['nomigrate',
0]]], ['s3_integrity', 1], ['device', ['vbd', ['uname',
'phy:vg_moreover/lv_test_13'], ['dev', 'xvda'], ['mode', 'w']]],
['device', ['vif', ['ip', '192.168.198.62'], ['mac',
'A2:01:02:01:03:13'], ['vifname', 'test13']]]])
[2010-08-26 21:02:33 4957] DEBUG (XendDomainInfo:2543)
XendDomainInfo.constructDomain
[2010-08-26 21:02:33 4957] DEBUG (balloon:239) Balloon: 20835020 KiB
free; need 16384; done.
[2010-08-26 21:02:33 4957] DEBUG (XendDomain:465) Adding Domain: 25
[2010-08-26 21:02:33 4957] DEBUG (XendDomainInfo:2871)
XendDomainInfo.initDomain: 25 256
[2010-08-26 21:02:33 9710] DEBUG (XendBootloader:130) Launching
bootloader as ['/usr/bin/pygrub',
'--output=/var/run/xend/boot/xenbl.24187', '-q',
'/dev/vg_moreover/lv_test_13'].
[2010-08-26 21:02:33 4957] DEBUG (XendDomainInfo:2898)
_initDomain:shadow_memory=0x0, memory_static_max=0x40000000,
memory_static_min=0x0.
[2010-08-26 21:02:33 4957] INFO (image:182) buildDomain os=linux dom=25 vcpus=1
[2010-08-26 21:02:33 4957] DEBUG (image:732) domid          = 25
[2010-08-26 21:02:33 4957] DEBUG (image:733) memsize        = 1024
[2010-08-26 21:02:33 4957] DEBUG (image:734) image          =
/var/run/xend/boot/boot_kernel.HkUPPL
[2010-08-26 21:02:33 4957] DEBUG (image:735) store_evtchn   = 1
[2010-08-26 21:02:33 4957] DEBUG (image:736) console_evtchn = 2
[2010-08-26 21:02:33 4957] DEBUG (image:737) cmdline        = ro
root=/dev/vg_primary/lv_base console=xvc0
[2010-08-26 21:02:33 4957] DEBUG (image:738) ramdisk        =
/var/run/xend/boot/boot_ramdisk.YhgUfY
[2010-08-26 21:02:33 4957] DEBUG (image:739) vcpus          = 1
[2010-08-26 21:02:33 4957] DEBUG (image:740) features       =
[2010-08-26 21:02:33 4957] DEBUG (image:741) flags          = 0
[2010-08-26 21:02:33 4957] DEBUG (image:742) superpages     = 0
[2010-08-26 21:02:34 4957] INFO (XendDomainInfo:2402) createDevice:
vbd : {'uuid': '7bcd27fe-b092-45d7-8edc-3aa23ed655a1', 'bootable': 1,
'driver': 'paravirtualised', 'dev': 'xvda', 'uname':
'phy:vg_moreover/lv_test_13', 'mode': 'w'}
[2010-08-26 21:02:34 4957] DEBUG (DevController:95) DevController:
writing {'virtual-device': '51712', 'device-type': 'disk', 'protocol':
'x86_64-abi', 'backend-id': '0', 'state': '1', 'backend':
'/local/domain/0/backend/vbd/25/51712'} to
/local/domain/25/device/vbd/51712.
[2010-08-26 21:02:34 4957] DEBUG (DevController:97) DevController:
writing {'domain': 'test13', 'frontend':
'/local/domain/25/device/vbd/51712', 'uuid':
'7bcd27fe-b092-45d7-8edc-3aa23ed655a1', 'bootable': '1', 'dev':
'xvda', 'state': '1', 'params': 'vg_moreover/lv_test_13', 'mode': 'w',
'online': '1', 'frontend-id': '25', 'type': 'phy'} to
/local/domain/0/backend/vbd/25/51712.
[2010-08-26 21:02:34 4957] INFO (XendDomainInfo:2402) createDevice:
vif : {'ip': '192.168.198.62', 'mac': 'A2:01:02:01:03:13', 'vifname':
'test13', 'uuid': 'e0e5b831-1400-4997-96a6-e06435754ae1'}
[2010-08-26 21:02:34 4957] DEBUG (DevController:95) DevController:
writing {'mac': 'A2:01:02:01:03:13', 'handle': '0', 'protocol':
'x86_64-abi', 'backend-id': '0', 'state': '1', 'backend':
'/local/domain/0/backend/vif/25/0'} to /local/domain/25/device/vif/0.
[2010-08-26 21:02:34 4957] DEBUG (DevController:97) DevController:
writing {'domain': 'test13', 'handle': '0', 'uuid':
'e0e5b831-1400-4997-96a6-e06435754ae1', 'script':
'/etc/xen/scripts/vif-bridge', 'ip': '192.168.198.62', 'mac':
'A2:01:02:01:03:13', 'frontend-id': '25', 'state': '1', 'vifname':
'test13', 'online': '1', 'frontend': '/local/domain/25/device/vif/0'}
to /local/domain/0/backend/vif/25/0.
[2010-08-26 21:02:34 4957] DEBUG (XendDomainInfo:3470) Storing VM
details: {'on_xend_stop': 'ignore', 'pool_name': 'Pool-0',
'shadow_memory': '0', 'uuid': '5d80c325-8a74-28c5-06fd-80484da1b7e3',
'on_reboot': 'restart', 'start_time': '1282870954.52', 'on_poweroff':
'destroy', 'bootloader_args': '-q', 'on_xend_start': 'ignore',
'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1',
'vcpu_avail': '1', 'bootloader': '/usr/bin/pygrub', 'image': "(linux
(kernel ) (superpages 0) (videoram 4) (pci ()) (nomigrate 0) (tsc_mode
0) (notes (FEATURES
'writable_page_tables|writable_descriptor_tables|auto_translated_physmap|pae_pgdir_above_4gb|supervisor_mode_kernel')
(VIRT_BASE 18446744071562067968) (GUEST_VERSION 2.6) (PADDR_OFFSET
18446744071562067968) (GUEST_OS linux) (HYPERCALL_PAGE
18446744071564189696) (LOADER generic) (ENTRY 18446744071564165120)
(XEN_VERSION xen-3.0)))", 'name': 'test13'}
[2010-08-26 21:02:34 4957] DEBUG (XendDomainInfo:1835) Storing domain
details: {'console/ring-ref': '5688553', 'image/entry':
'18446744071564165120', 'console/port': '2', 'store/ring-ref':
'5688554', 'image/loader': 'generic', 'vm':
'/vm/5d80c325-8a74-28c5-06fd-80484da1b7e3',
'control/platform-feature-multiprocessor-suspend': '1',
'image/guest-os': 'linux',
'image/features/writable-descriptor-tables': '1', 'image/virt-base':
'18446744071562067968', 'memory/target': '1048576',
'image/guest-version': '2.6', 'image/features/supervisor-mode-kernel':
'1', 'description': '', 'console/limit': '1048576',
'image/paddr-offset': '18446744071562067968', 'image/hypercall-page':
'18446744071564189696', 'cpu/0/availability': 'online',
'image/features/pae-pgdir-above-4gb': '1',
'image/features/writable-page-tables': '1', 'console/type':
'xenconsoled', 'image/features/auto-translated-physmap': '1', 'name':
'test13', 'domid': '25', 'image/xen-version': 'xen-3.0', 'store/port':
'1'}
[2010-08-26 21:02:34 4957] DEBUG (DevController:95) DevController:
writing {'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0',
'backend': '/local/domain/0/backend/console/25/0'} to
/local/domain/25/device/console/0.
[2010-08-26 21:02:34 4957] DEBUG (DevController:97) DevController:
writing {'domain': 'test13', 'frontend':
'/local/domain/25/device/console/0', 'uuid':
'b9c40186-2de9-8fce-2aa5-57311a33797e', 'frontend-id': '25', 'state':
'1', 'location': '2', 'online': '1', 'protocol': 'vt100'} to
/local/domain/0/backend/console/25/0.
[2010-08-26 21:02:34 4957] DEBUG (XendDomainInfo:1922)
XendDomainInfo.handleShutdownWatch
[2010-08-26 21:02:34 4957] DEBUG (DevController:139) Waiting for devices tap2.
[2010-08-26 21:02:34 4957] DEBUG (DevController:139) Waiting for devices vif.
[2010-08-26 21:02:34 4957] DEBUG (DevController:144) Waiting for 0.
[2010-08-26 21:02:34 4957] DEBUG (DevController:653)
hotplugStatusCallback /local/domain/0/backend/vif/25/0/hotplug-status.
(XEN) cpupool_rm_domain(dom=25,pool=0) n_dom 19
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:3111)
XendDomainInfo.destroy: domid=25
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2446) Destroying device model
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2453) Releasing devices
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2459) Removing vif/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:1289)
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2459) Removing console/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:1289)
XendDomainInfo.destroyDevice: deviceClass = console, device =
console/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2459) Removing vbd/51712
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:1289)
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2451) No device model
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2453) Releasing devices
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2459) Removing vif/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:1289)
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:2459) Removing vbd/51712
[2010-08-26 21:04:14 4957] DEBUG (XendDomainInfo:1289)
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712

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