http://bugzilla.xensource.com/bugzilla/show_bug.cgi?id=1027
Summary: very slow domU creation
Product: Xen
Version: unstable
Platform: x86-64
OS/Version: Linux-2.6
Status: NEW
Severity: critical
Priority: P2
Component: Tools
AssignedTo: xen-bugs@xxxxxxxxxxxxxxxxxxx
ReportedBy: tejasvia@xxxxxxxxx
First a little information about my setup:
I have a RHEL4 AMD64 based box that I use to run Xen VM's. I was previously
running the pre-3.1 unstable sources (2.6.16 kernel) and things seemed to be
working fine upto a point where I could start as many as 60 VM's on this box
that has 8GB of physical mem. I used to use the blktap driver for exporting
the filesystem images (thanks to the fix of
http://bugzilla.xensource.com/bugzilla/show_bug.cgi?id=743)
I recently synced up to the latest unstable sources having the 2.6.18 kernel.
Apart from issues with the blktap driver (which I shall log a separate bug
for), I am seeing very long domU create times. (in the order of 4 minutes per
domU). I see xenstored & the hotplug scripts chewing a lot of CPU. SInce blktap
appears broken, I am using the loop driver to load images. (but will
eventually need to shift to blktap to start 60 VM's)
Given that I start ~60 VM's, this long startup time is going to make my wait
for VM's to start very long. Can somebody please let me know if this is a known
issue or a necessary side-effect of some other change ?
The following is a sample log of an "xm create" of the first domU on the
machine:
=========
2007-07-16 15:26:43 3842] DEBUG (XendDomainInfo:1430)
XendDomainInfo.constructDomain
[2007-07-16 15:26:43 3842] DEBUG (balloon:114) Balloon: 307952 KiB free; need
2048; done.
[2007-07-16 15:26:43 3842] DEBUG (XendDomain:434) Adding Domain: 13
[2007-07-16 15:26:43 3842] DEBUG (XendDomainInfo:1493)
XendDomainInfo.initDomain: 13 256
[2007-07-16 15:26:43 3842] DEBUG (XendDomainInfo:1524)
_initDomain:shadow_memory=0x0, memory_static_max=0x640
0000, memory_static_min=0x0.
[2007-07-16 15:26:43 3842] DEBUG (balloon:114) Balloon: 307944 KiB free; need
102400; done.
[2007-07-16 15:26:43 3842] INFO (image:128) buildDomain os=linux dom=13 vcpus=2
[2007-07-16 15:26:43 3842] DEBUG (image:197) domid = 13
[2007-07-16 15:26:43 3842] DEBUG (image:198) memsize = 100
[2007-07-16 15:26:43 3842] DEBUG (image:199) image =
/usr0/VM/vmlinuz-2.6.16.13-xen
[2007-07-16 15:26:43 3842] DEBUG (image:200) store_evtchn = 1
[2007-07-16 15:26:43 3842] DEBUG (image:201) console_evtchn = 2
[2007-07-16 15:26:43 3842] DEBUG (image:202) cmdline = root=/dev/hda1 ro
selinux=0 3
[2007-07-16 15:26:43 3842] DEBUG (image:203) ramdisk =
[2007-07-16 15:26:43 3842] DEBUG (image:204) vcpus = 2
[2007-07-16 15:26:43 3842] DEBUG (image:205) features =
[2007-07-16 15:26:43 3842] INFO (XendDomainInfo:1333) createDevice: vbd :
{'uuid': '5c5018d8-8cd1-a10d-427c-1
c1f97ab1613', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda1',
'uname': 'file:/usr0/VM/compute-1-8-
vm30/compute-1-8-vm30-fs.img', 'mode': 'w'}
[2007-07-16 15:26:43 3842] DEBUG (DevController:115) DevController: writing
{'virtual-device': '769', 'device
-type': 'disk', 'protocol': 'x86_64-abi', 'backend-id': '0', 'state': '1',
'backend': '/local/domain/0/backen
d/vbd/13/769'} to /local/domain/13/device/vbd/769.
[2007-07-16 15:26:43 3842] DEBUG (DevController:117) DevController: writing
{'domain': 'compute-1-8-vm30', 'f
rontend': '/local/domain/13/device/vbd/769', 'uuid':
'5c5018d8-8cd1-a10d-427c-1c1f97ab1613', 'dev': 'hda1', '
state': '1', 'params': '/usr0/VM/compute-1-8-vm30/compute-1-8-vm30-fs.img',
'mode': 'w', 'online': '1', 'fron
tend-id': '13', 'type': 'file'} to /local/domain/0/backend/vbd/13/769.
[2007-07-16 15:26:43 3842] INFO (XendDomainInfo:1333) createDevice: vbd :
{'uuid': '004530ee-279f-ca09-29ce-3
6e95e29f62c', 'bootable': 0, 'driver': 'paravirtualised', 'dev': 'hda2',
'uname': 'file:/usr0/VM/compute-1-8-
vm30/compute-1-8-vm30-swap.img', 'mode': 'w'}
[2007-07-16 15:26:43 3842] DEBUG (DevController:115) DevController: writing
{'virtual-device': '770', 'device
-type': 'disk', 'protocol': 'x86_64-abi', 'backend-id': '0', 'state': '1',
'backend': '/local/domain/0/backen
d/vbd/13/770'} to /local/domain/13/device/vbd/770.
[2007-07-16 15:26:43 3842] DEBUG (DevController:117) DevController: writing
{'domain': 'compute-1-8-vm30', 'f
rontend': '/local/domain/13/device/vbd/770', 'uuid':
'004530ee-279f-ca09-29ce-36e95e29f62c', 'dev': 'hda2', '
state': '1', 'params': '/usr0/VM/compute-1-8-vm30/compute-1-8-vm30-swap.img',
'mode': 'w', 'online': '1', 'fr
ontend-id': '13', 'type': 'file'} to /local/domain/0/backend/vbd/13/770.
[2007-07-16 15:26:43 3842] INFO (XendDomainInfo:1333) createDevice: vbd :
{'uuid': '24ff2f58-1b1f-2718-bf39-a
0eaa07d76a8', 'bootable': 0, 'driver': 'paravirtualised', 'dev': 'hda3',
'uname': 'file:/usr0/VM/nonw.img', '
mode': 'r'}
[2007-07-16 15:26:43 3842] DEBUG (DevController:115) DevController: writing
{'virtual-device': '771', 'device
-type': 'disk', 'protocol': 'x86_64-abi', 'backend-id': '0', 'state': '1',
'backend': '/local/domain/0/backen
d/vbd/13/771'} to /local/domain/13/device/vbd/771.
[2007-07-16 15:26:43 3842] DEBUG (DevController:117) DevController: writing
{'domain': 'compute-1-8-vm30', 'f
rontend': '/local/domain/13/device/vbd/771', 'uuid':
'24ff2f58-1b1f-2718-bf39-a0eaa07d76a8', 'dev': 'hda3', '
state': '1', 'params': '/usr0/VM/nonw.img', 'mode': 'r', 'online': '1',
'frontend-id': '13', 'type': 'file'}
to /local/domain/0/backend/vbd/13/771.
[2007-07-16 15:26:43 3842] INFO (XendDomainInfo:1333) createDevice: vif :
{'mac': '00:16:3e:37:29:82', 'uuid'
: '24120c27-5db4-a5fb-264b-2fba7a79b836'}
[2007-07-16 15:26:50 3842] DEBUG (DevController:115) DevController: writing
{'mac': '00:16:3e:37:29:82', 'han
dle': '0', 'protocol': 'x86_64-abi', 'backend-id': '0', 'state': '1',
'backend': '/local/domain/0/backend/vif
/13/0'} to /local/domain/13/device/vif/0.
[2007-07-16 15:26:50 3842] DEBUG (DevController:117) DevController: writing
{'domain': 'compute-1-8-vm30', 'h
andle': '0', 'uuid': '24120c27-5db4-a5fb-264b-2fba7a79b836', 'script':
'/etc/xen/scripts/vif-bridge', 'state'
: '1', 'frontend': '/local/domain/13/device/vif/0', 'mac': '00:16:3e:37:29:82',
'online': '1', 'frontend-id':
'13', 'type': 'netfront'} to /local/domain/0/backend/vif/13/0.
[2007-07-16 15:26:56 3842] DEBUG (XendDomainInfo:1981) Storing VM details:
{'on_xend_stop': 'ignore', 'shadow
_memory': '0', 'uuid': 'c0a52e8b-0712-edb3-85aa-552c4fb3779f', 'on_reboot':
'restart', 'start_time': '1184614
010.78', 'on_poweroff': 'destroy', 'on_xend_start': 'ignore', 'on_crash':
'restart', 'xend/restart_count': '0
', 'vcpus': '2', 'vcpu_avail': '3', 'image': "(linux (kernel
/usr0/VM/vmlinuz-2.6.16.13-xen) (args 'root=/dev
/hda1 ro selinux=0 3') (notes (FEATURES
'writable_page_tables|writable_descriptor_tables|auto_translated_phys
map|pae_pgdir_above_4gb|supervisor_mode_kernel') (VIRT_BASE -2147483648)
(GUEST_VERSION 2.6) (PADDR_OFFSET -2
147483648) (GUEST_OS linux) (HYPERCALL_PAGE -2145361920) (LOADER generic)
(SUSPEND_CANCEL 1) (ENTRY -21453864
96) (XEN_VERSION xen-3.0)))", 'name': 'compute-1-8-vm30'}
[2007-07-16 15:27:02 3842] DEBUG (XendDomainInfo:838) Storing domain details:
{'console/ring-ref': '2210012',
'image/entry': '-2145386496', 'console/port': '2', 'store/ring-ref':
'2210013', 'image/loader': 'generic', '
vm': '/vm/c0a52e8b-0712-edb3-85aa-552c4fb3779f',
'control/platform-feature-multiprocessor-suspend': '1', 'ima
ge/guest-os': 'linux', 'cpu/1/availability': 'online',
'image/features/writable-descriptor-tables': '1', 'ima
ge/virt-base': '-2147483648', 'memory/target': '102400', 'image/guest-version':
'2.6', 'image/features/superv
isor-mode-kernel': '1', 'console/limit': '1048576', 'image/paddr-offset':
'-2147483648', 'image/hypercall-pag
e': '-2145361920', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online',
'image/features/pae-pgdir-abo
ve-4gb': '1', 'image/features/writable-page-tables': '1',
'image/features/auto-translated-physmap': '1', 'nam
e': 'compute-1-8-vm30', 'domid': '13', 'image/xen-version': 'xen-3.0',
'store/port': '1'}
[2007-07-16 15:27:27 3842] DEBUG (DevController:115) DevController: writing
{'protocol': 'x86_64-abi', 'state
': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/13/0'}
to /local/domain/13/device/cons
ole/0.
[2007-07-16 15:27:27 3842] DEBUG (DevController:117) DevController: writing
{'domain': 'compute-1-8-vm30', 'p
rotocol': 'vt100', 'uuid': '4617b955-87a8-c9e3-638a-616d0bd28b67', 'frontend':
'/local/domain/13/device/conso
le/0', 'state': '1', 'location': '2', 'online': '1', 'frontend-id': '13'} to
/local/domain/0/backend/console/
13/0.
[2007-07-16 15:27:41 3842] DEBUG (XendDomainInfo:838) Storing domain details:
{'console/ring-ref': '2210012',
'image/entry': '-2145386496', 'console/port': '2', 'store/ring-ref':
'2210013', 'image/loader': 'generic', '
vm': '/vm/c0a52e8b-0712-edb3-85aa-552c4fb3779f',
'control/platform-feature-multiprocessor-suspend': '1', 'ima
ge/guest-os': 'linux', 'cpu/1/availability': 'online',
'image/features/writable-descriptor-tables': '1', 'ima
ge/virt-base': '-2147483648', 'memory/target': '102400', 'image/guest-version':
'2.6', 'image/features/superv
isor-mode-kernel': '1', 'console/limit': '1048576', 'image/paddr-offset':
'-2147483648', 'image/hypercall-pag
e': '-2145361920', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online',
'image/features/pae-pgdir-abo
ve-4gb': '1', 'image/features/writable-page-tables': '1',
'image/features/auto-translated-physmap': '1', 'nam
e': 'compute-1-8-vm30', 'domid': '13', 'image/xen-version': 'xen-3.0',
'store/port': '1'}
[2007-07-16 15:28:43 3842] DEBUG (XendDomainInfo:922)
XendDomainInfo.handleShutdownWatch
[2007-07-16 15:29:41 3842] DEBUG (DevController:148) Waiting for devices vif.
[2007-07-16 15:29:44 3842] DEBUG (DevController:153) Waiting for 0.
[2007-07-16 15:29:49 3842] DEBUG (DevController:541) hotplugStatusCallback
/local/domain/0/backend/vif/13/0/h
otplug-status.
[2007-07-16 15:29:51 3842] DEBUG (DevController:555) hotplugStatusCallback 1.
[2007-07-16 15:29:53 3842] DEBUG (DevController:148) Waiting for devices usb.
[2007-07-16 15:29:56 3842] DEBUG (DevController:148) Waiting for devices vbd.
[2007-07-16 15:29:58 3842] DEBUG (DevController:153) Waiting for 769.
[2007-07-16 15:30:03 3842] DEBUG (DevController:541) hotplugStatusCallback
/local/domain/0/backend/vbd/13/769
/hotplug-status.
[2007-07-16 15:30:03 3842] DEBUG (DevController:555) hotplugStatusCallback 1.
[2007-07-16 15:30:05 3842] DEBUG (DevController:153) Waiting for 770.
[2007-07-16 15:30:08 3842] DEBUG (DevController:541) hotplugStatusCallback
/local/domain/0/backend/vbd/13/770
/hotplug-status.
[2007-07-16 15:30:10 3842] DEBUG (DevController:555) hotplugStatusCallback 1.
[2007-07-16 15:30:12 3842] DEBUG (DevController:153) Waiting for 771.
[2007-07-16 15:30:17 3842] DEBUG (DevController:541) hotplugStatusCallback
/local/domain/0/backend/vbd/13/771
/hotplug-status.
[2007-07-16 15:30:20 3842] DEBUG (DevController:555) hotplugStatusCallback 1.
[2007-07-16 15:30:22 3842] DEBUG (DevController:148) Waiting for devices irq.
[2007-07-16 15:30:24 3842] DEBUG (DevController:148) Waiting for devices vkbd.
[2007-07-16 15:30:27 3842] DEBUG (DevController:148) Waiting for devices vfb.
[2007-07-16 15:30:29 3842] DEBUG (DevController:148) Waiting for devices
console.
[2007-07-16 15:30:31 3842] DEBUG (DevController:153) Waiting for 0.
[2007-07-16 15:30:31 3842] DEBUG (DevController:148) Waiting for devices pci.
[2007-07-16 15:30:34 3842] DEBUG (DevController:148) Waiting for devices
ioports.
[2007-07-16 15:30:36 3842] DEBUG (DevController:148) Waiting for devices tap.
[2007-07-16 15:30:38 3842] DEBUG (DevController:148) Waiting for devices vtpm.
[2007-07-16 15:30:41 3842] INFO (XendDomain:1120) Domain compute-1-8-vm30 (13)
unpaused.
--
Configure bugmail:
http://bugzilla.xensource.com/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
_______________________________________________
Xen-bugs mailing list
Xen-bugs@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-bugs
|