[Xen-users] Unable to boot domU on a particular machine: Waiting for device /dev/hda1 to appear

["Tenbusch, Markus" <markus.tenbusch@xxxxxx>]

Hi all,

we are currently facing a very strange problem. We have several
identical blades running Xen on SLES10 SP1. All blades use the same
operating system image (cloned). The OS-images for our guest domains are
stored on LUNs on our storage array accessed via iSCSI. We attach the
iSCSI Luns on different blades and use a line such as

--- snip ---
disk = [ 'phy:sde1,hda1,w', 'phy:sde2,hda2,w',]
--- snip ----

to attach the iSCSI LUNs to a guest domain. This works perfectly on most
of our blades, but there is one particular blade, on which booting of
guest domains is not possible anymore, although it worked before: When I
try to boot a domain on this blade, the following error occurs

--- snip ---
Waiting for device /dev/hda1 to appear: .........not found -- exiting to
/bin/sh
--- snip ----

I have absolutely no clue why this happens, because the blade is 100%
identical to our other blades, runs the same OS-image (Xen on SLES10
SP1). It doesn't make a difference, which iSCSI Lun (domU) I try to
start, they all fail with the same error message. I am using the same
config-file on all blades. I can perfectly attach the iSCSI LUN to dom0
and even mount the rootfs in dom0, so there doesn't seem to be a iSCSI
related problem. None of the common log files shows any errors/warnings,
that are different from the messages I get when I start the guest domain
on other blades. 

To wrap this up: I think the problem must be related to this particular
blade, since I re-imaged the blade, because I expected the Xen/OS
configuration to be corrupt in some way. But this didn't solve the
problem. I can use the same LUN and the same config-file to boot the
guest domain on other blades without any hassle. 

Any idea how I can find out, what is going wrong?

If you need further information on the setup or the configuration,
please let me know.

Cheers,
Markus

Output of xen-console during startup:
--- snip ---
Bootdata ok (command line is root=/dev/hda1 ro console=xvc0 5)
Linux version 2.6.16.43-0.5-xen (geeko@buildhost) (gcc version 4.1.2
20070115 (prerelease) (SUSE Linux)) #1 SMP Mon Mar 19 08:28:24 UTC 2007
BIOS-provided physical RAM map:
 Xen: 0000000000000000 - 00000000bc000000 (usable)
No mptable found.
Built 1 zonelists
Kernel command line: root=/dev/hda1 ro console=xvc0 5
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 131072 bytes)
Xen reported: 2605.910 MHz processor.
Console: colour dummy device 80x25
Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
Software IO TLB disabled
Memory: 2998784k/3080192k available (1902k kernel code, 72720k reserved,
799k data, 160k init)
Calibrating delay using timer specific routine.. 6516.22 BogoMIPS
(lpj=13032458)
Security Framework v1.0.0 initialized
Mount-cache hash table entries: 256
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 1024K (64 bytes/line)
checking if image is initramfs... it is
Freeing initrd memory: 8296k freed
Brought up 1 CPUs
migration_cost=0
DMI not present or invalid.
Grant table initialized
NET: Registered protocol family 16
Brought up 1 CPUs
PCI: setting up Xen PCI frontend stub
ACPI: Subsystem revision 20060127
ACPI: Interpreter disabled.
xen_mem: Initialising balloon driver.
Setting mem allocation to 3072000 kiB
PCI: System does not support PCI
PCI: System does not support PCI
IA32 emulation $Id: sys_ia32.c,v 1.32 2002/03/24 13:02:28 ak Exp $
audit: initializing netlink socket (disabled)
audit(1184927556.129:1): initialized
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
Initializing Cryptographic API
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
rtc: IRQ 8 is not free.
Non-volatile memory driver v1.2
i8042.c: No controller found.
RAMDISK driver initialized: 16 RAM disks of 128000K size 1024 blocksize
Xen virtual console successfully installed as xvc0
Event-channel device installed.
mice: PS/2 mouse device common for all mice
input: PC Speaker as /class/input/input0
md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: bitmap version 4.39
NET: Registered protocol family 2
IP route cache hash table entries: 131072 (order: 8, 1048576 bytes)
TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
TCP: Hash tables configured (established 262144 bind 65536)
TCP reno registered
NET: Registered protocol family 1
XENBUS: Device with no driver: device/vbd/769
XENBUS: Device with no driver: device/vbd/770
XENBUS: Device with no driver: device/vif/0
XENBUS: Device with no driver: device/console/0
Starting udevd
Creating devices
Loading reiserfs
Waiting for device /dev/hda1 to appear:
..............................not found -- exiting to /bin/sh
--- snip ---

Output of /var/log/messages during startup
--- snip ---
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: add
XENBUS_PATH=backend/vbd/16/769
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: add
XENBUS_PATH=backend/vbd/16/770
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/vif-bridge: online
XENBUS_PATH=backend/vif/16/0
Jul 20 11:51:03 blr18c1s1e0 kernel: device vif16.0 entered promiscuous
mode
Jul 20 11:51:03 blr18c1s1e0 kernel: ADDRCONF(NETDEV_UP): vif16.0: link
is not ready
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/vif-bridge:
Successful vif-bridge online for vif16.0, bridge xenbr0.
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/vif-bridge: Writing
backend/vif/16/0/hotplug-status connected to xenstore.
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: Writing
backend/vbd/16/770/physical-device 8:12 to xenstore.
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: Writing
backend/vbd/16/770/hotplug-status connected to xenstore.
Jul 20 11:51:03 blr18c1s1e0 ifup:     vif16.0
Jul 20 11:51:03 blr18c1s1e0 ifup:               No configuration found
for vif16.0
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: Writing
backend/vbd/16/769/physical-device 8:11 to xenstore.
Jul 20 11:51:03 blr18c1s1e0 logger: /etc/xen/scripts/block: Writing
backend/vbd/16/769/hotplug-status connected to xenstore.
--- snip ---


Output of /var/log/xen/xend.log
--- snip ---
[2007-07-20 11:59:15 xend.XendDomainInfo 4165] DEBUG (XendDomainInfo:94)
XendDomainInfo.create(['vm', ['name', 'sapxn101'], ['memory', 3000],
['vcpus', 1], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'],
['image', ['linux', ['kernel', '/boot/vmlinuz-xen'], ['ramdisk',
'/boot/initrd-xen'], ['root', '/dev/hda1 ro'], ['args', 'console=xvc0
5']]], ['device', ['vbd', ['uname', 'phy:sdb1'], ['dev', 'hda1'],
['mode', 'w']]], ['device', ['vbd', ['uname', 'phy:sdb2'], ['dev',
'hda2'], ['mode', 'w']]], ['device', ['vif', ['bridge', 'xenbr0'],
['mac', 'aa:00:00:00:01:01']]]])
[2007-07-20 11:59:15 xend.XendConfig 4165] WARNING (XendConfig:616)
Unconverted key: cpus
[2007-07-20 11:59:15 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:1346) XendDomainInfo.constructDomain
[2007-07-20 11:59:15 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:1392) XendDomainInfo.initDomain: 17 256
[2007-07-20 11:59:15 xend 4165] DEBUG (balloon:146) Balloon: 3072880 KiB
free; need 3072000; done.
[2007-07-20 11:59:15 xend 4165] INFO (image:126) buildDomain os=linux
dom=17 vcpus=1
[2007-07-20 11:59:15 xend 4165] DEBUG (image:224) domid          = 17
[2007-07-20 11:59:15 xend 4165] DEBUG (image:225) memsize        = 3000
[2007-07-20 11:59:15 xend 4165] DEBUG (image:226) image          =
/boot/vmlinuz-xen
[2007-07-20 11:59:15 xend 4165] DEBUG (image:227) store_evtchn   = 1
[2007-07-20 11:59:15 xend 4165] DEBUG (image:228) console_evtchn = 2
[2007-07-20 11:59:15 xend 4165] DEBUG (image:229) cmdline        =
root=/dev/hda1 ro console=xvc0 5
[2007-07-20 11:59:15 xend 4165] DEBUG (image:230) ramdisk        =
/boot/initrd-xen
[2007-07-20 11:59:15 xend 4165] DEBUG (image:231) vcpus          = 1
[2007-07-20 11:59:15 xend 4165] DEBUG (image:232) features       =
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] INFO
(XendDomainInfo:1251) createDevice: vbd : {'uname': 'phy:sdb1',
'driver': 'paravirtualised', 'mode': 'w', 'dev': 'hda1', 'uuid':
'1d937881-667b-0261-2f62-c094e24b7ad0'}
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:115) DevController:
writing {'backend-id': '0', 'virtual-device': '769', 'device-type':
'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/17/769'}
to /local/domain/17/device/vbd/769.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:117) DevController:
writing {'domain': 'sapxn101', 'frontend':
'/local/domain/17/device/vbd/769', 'uuid':
'1d937881-667b-0261-2f62-c094e24b7ad0', 'dev': 'hda1', 'state': '1',
'params': 'sdb1', 'mode': 'w', 'online': '1', 'frontend-id': '17',
'type': 'phy'} to /local/domain/0/backend/vbd/17/769.
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] INFO
(XendDomainInfo:1251) createDevice: vbd : {'uname': 'phy:sdb2',
'driver': 'paravirtualised', 'mode': 'w', 'dev': 'hda2', 'uuid':
'b4c5ad90-c05e-1d6a-b2c8-25fb3b902910'}
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:115) DevController:
writing {'backend-id': '0', 'virtual-device': '770', 'device-type':
'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/17/770'}
to /local/domain/17/device/vbd/770.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:117) DevController:
writing {'domain': 'sapxn101', 'frontend':
'/local/domain/17/device/vbd/770', 'uuid':
'b4c5ad90-c05e-1d6a-b2c8-25fb3b902910', 'dev': 'hda2', 'state': '1',
'params': 'sdb2', 'mode': 'w', 'online': '1', 'frontend-id': '17',
'type': 'phy'} to /local/domain/0/backend/vbd/17/770.
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] INFO
(XendDomainInfo:1251) createDevice: vif : {'bridge': 'xenbr0', 'mac':
'aa:00:00:00:01:01', 'uuid': '8630d7ae-c522-5f43-fdc3-d986c98df6ae'}
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:115) DevController:
writing {'backend-id': '0', 'mac': 'aa:00:00:00:01:01', 'handle': '0',
'state': '1', 'backend': '/local/domain/0/backend/vif/17/0'} to
/local/domain/17/device/vif/0.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:117) DevController:
writing {'bridge': 'xenbr0', 'domain': 'sapxn101', 'handle': '0',
'uuid': '8630d7ae-c522-5f43-fdc3-d986c98df6ae', 'script':
'/etc/xen/scripts/vif-bridge', 'state': '1', 'frontend':
'/local/domain/17/device/vif/0', 'mac': 'aa:00:00:00:01:01', 'online':
'1', 'frontend-id': '17'} to /local/domain/0/backend/vif/17/0.
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:1782) Storing VM details: {'on_xend_stop': 'ignore',
'shadow_memory': '0', 'uuid': '6759994c-34ff-ecf6-4d29-7195e4649a8f',
'name': 'sapxn101', 'on_reboot': 'restart', 'start_time':
'1184929156.18', 'on_poweroff': 'destroy', 'on_xend_start': 'ignore',
'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1',
'vcpu_avail': '1', 'memory': '3000', 'image': "(linux (kernel
/boot/vmlinuz-xen) (ramdisk /boot/initrd-xen) (args 'root=/dev/hda1 ro
console=xvc0 5') (root '/dev/hda1 ro'))", 'maxmem': '3000'}
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:786) Storing domain details: {'console/ring-ref':
'2025040', 'console/port': '2', 'name': 'sapxn101', 'console/limit':
'1048576', 'vm': '/vm/6759994c-34ff-ecf6-4d29-7195e4649a8f', 'domid':
'17', 'cpu/0/availability': 'online', 'memory/target': '3072000',
'store/ring-ref': '2025041', 'store/port': '1'}
[2007-07-20 11:59:16 xend 4165] DEBUG (XendDomain:429) Adding Domain: 17
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:115) DevController:
writing {'state': '1', 'backend-id': '0', 'backend':
'/local/domain/0/backend/console/17/0'} to
/local/domain/17/device/console/0.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:117) DevController:
writing {'domain': 'sapxn101', 'protocol': 'vt100', 'uuid':
'd81fd114-0453-7c49-52e4-f3038452f688', 'frontend':
'/local/domain/17/device/console/0', 'state': '1', 'location': '2',
'online': '1', 'frontend-id': '17'} to
/local/domain/0/backend/console/17/0.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices vif.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:153) Waiting for 0.
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:786) Storing domain details: {'console/ring-ref':
'2025040', 'console/port': '2', 'name': 'sapxn101', 'console/limit':
'1048576', 'vm': '/vm/6759994c-34ff-ecf6-4d29-7195e4649a8f', 'domid':
'17', 'cpu/0/availability': 'online', 'memory/target': '3072000',
'store/ring-ref': '2025041', 'store/port': '1'}
[2007-07-20 11:59:16 xend.XendDomainInfo 4165] DEBUG
(XendDomainInfo:853) XendDomainInfo.handleShutdownWatch
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:524)
hotplugStatusCallback /local/domain/0/backend/vif/17/0/hotplug-status.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:524)
hotplugStatusCallback /local/domain/0/backend/vif/17/0/hotplug-status.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:538)
hotplugStatusCallback 1.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices usb.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices vbd.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:153) Waiting for
769.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:524)
hotplugStatusCallback /local/domain/0/backend/vbd/17/769/hotplug-status.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:538)
hotplugStatusCallback 1.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:153) Waiting for
770.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:524)
hotplugStatusCallback /local/domain/0/backend/vbd/17/770/hotplug-status.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:524)
hotplugStatusCallback /local/domain/0/backend/vbd/17/770/hotplug-status.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:538)
hotplugStatusCallback 1.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices irq.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices vkbd.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices vfb.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices console.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:153) Waiting for 0.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices pci.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices ioports.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices tap.
[2007-07-20 11:59:16 xend 4165] DEBUG (DevController:148) Waiting for
devices vtpm.
--- snip ---

I do not attach the config-file, because it doesn't seem to problem. As
stated above, I can use the same config-file to start the domU on
different blades without problems. If you need the output of a different
log file, please let me know!

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