euca-attach-volume failed on centos 5.4 hotplug scripts not working

Hi all,

I have been running a successful eucalyptus setup for quite some time now. My setup consists of two machines one head and other is node. Both running centos 5.4. I am using XEN.

Few days back I tried to practice with the volume thing. I created a volume with the following command:

euca-create-volume --size 3 --zone silinux-cluster02

Then I tried to attach the volume to a running centos 5.3 instance (This filesystem is downloaded from eucalyptus website) using the following command:

euca-attach-volume -i i-4F17090C -d sdc1 vol-59BF062C

Nothing happens for 2 minutes and after that if I check the nc.log and xend.log I see the following:

xend.log
[2010-04-13 10:30:00 xend.XendDomainInfo 20318] DEBUG (XendDomainInfo:631) Checking for duplicate for uname: /dev/etherd/e0.1 [phy:/dev/etherd/e0.1], dev: sdc1, mode: w
[2010-04-13 10:30:00 xend 20318] DEBUG (blkif:27) exception looking up device number for sdc1: [Errno 2] No such file or directory: '/dev/sdc1'
[2010-04-13 10:30:00 xend 20318] DEBUG (blkif:27) exception looking up device number for sda1: [Errno 2] No such file or directory: '/dev/sda1'
[2010-04-13 10:30:00 xend 20318] DEBUG (blkif:27) exception looking up device number for sda2: [Errno 2] No such file or directory: '/dev/sda2'
[2010-04-13 10:30:00 xend 20318] DEBUG (blkif:27) exception looking up device number for sda3: [Errno 2] No such file or directory: '/dev/sda3'
[2010-04-13 10:30:00 xend 20318] DEBUG (blkif:27) exception looking up device number for sdc1: [Errno 2] No such file or directory: '/dev/sdc1'
[2010-04-13 10:30:00 xend 20318] DEBUG (DevController:114) DevController: writing {'virtual-device': '2081', 'device-type': 'disk', 'protocol': 'x86_32-abi', 'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vbd/99/2081'} to /local/domain/99/device/vbd/2081.
[2010-04-13 10:30:00 xend 20318] DEBUG (DevController:116) DevController: writing {'domain': 'i-4CC8098D', 'frontend': '/local/domain/99/device/vbd/2081', 'format': 'raw', 'dev': 'sdc1', 'state': '1', 'params': '/dev/etherd/e0.1', 'mode': 'w', 'online': '1', 'frontend-id': '99', 'type': 'phy'} to /local/domain/0/backend/vbd/99/2081.
[2010-04-13 10:30:00 xend 20318] DEBUG (DevController:164) Waiting for 2081.
[2010-04-13 10:30:00 xend 20318] DEBUG (DevController:509) hotplugStatusCallback /local/domain/0/backend/vbd/99/2081/hotplug-status.
[2010-04-13 10:31:40 xend 20318] ERROR (SrvBase:88) Request device_create failed.
Traceback (most recent call last):
File "/usr/lib/python2.4/site-packages/xen/web/SrvBase.py", line 85, in perform
return op_method(op, req)
File "/usr/lib/python2.4/site-packages/xen/xend/server/SrvDomain.py", line 174, in op_device_create
req)
File "/usr/lib/python2.4/site-packages/xen/xend/server/SrvDomain.py", line 158, in call
return FormFn(fn, args)(req.args)
File "/usr/lib/python2.4/site-packages/xen/xend/Args.py", line 166, in __call__
return self.call_with_form_args(self.fn, fargs, xargs=xargs)
File "/usr/lib/python2.4/site-packages/xen/xend/Args.py", line 138, in call_with_form_args
return fn(*params, **keys)
File "/usr/lib/python2.4/site-packages/xen/xend/XendDomainInfo.py", line 2526, in device_create
self.waitForDevice(dev_type, devid)
File "/usr/lib/python2.4/site-packages/xen/xend/XendDomainInfo.py", line 1423, in waitForDevice
return self.getDeviceController(deviceClass).waitForDevice(devid)
File "/usr/lib/python2.4/site-packages/xen/xend/server/DevController.py", line 170, in waitForDevice
raise VmError("Device %s (%s) could not be connected. "
VmError: Device 2081 (vbd) could not be connected. Hotplug scripts not working.
[2010-04-13 10:31:40 xend 20318] DEBUG (DevController:509) hotplugStatusCallback /local/domain/0/backend/vbd/99/2081/hotplug-status.

nc.log
[Tue Apr 13 10:25:44 2010][003176][EUCADEBUG ] doDescribeInstances() invoked
[Tue Apr 13 10:25:45 2010][003176][EUCAINFO ] doAttachVolume() invoked (id=i-4CC8098D vol=vol-59BF062C remote=/dev/etherd/e0.1 local=sdc)
[Tue Apr 13 10:27:26 2010][003176][EUCAERROR ] libvirt: POST operation failed: xend_post: error from xen daemon: (xend.err 'Device 2080 (vbd) could not be connected. Hotplug scripts not working.') (code=11)
[Tue Apr 13 10:27:26 2010][003176][EUCAERROR ] AttachVolume() failed (err=-1) XML=
[Tue Apr 13 10:27:26 2010][003176][EUCAERROR ] ERROR: doAttachVolume() failed error=1
[Tue Apr 13 10:27:26 2010][003176][EUCADEBUG ] doDescribeResource() invoked

I tried looking for the solution on internet but couldn't find anything useful just for 2 things

They talked about setting /bin/bash in she bang for all hotplug scripts in /etc/xen/scripts/ which I have done but of no use. The /bin/sh which is in she bang right now is symlink to /bin/bash only

The other thing they said was some bug related to xen version in RHEL 5.4 where we need to increase
# Number of seconds xend will wait for device creation
(device-create-timeout 100)

I tried with 10000 but it only increases the time after 10000 seconds it will again give the same error message. The bug was fixed in xen and the version I have got has the fix so I don't see anything useful in doing this. My xen version is,
xen-3.0.3-94.el5

And other software versions
libvirt-0.6.3-20.el5
kernel-xen-2.6.18-164.el5
eucalyptus-1.6.2-1

The RedHat bug I was referring to can be found here
https://bugzilla.redhat.com/show_bug.cgi?id=456926

Please let me know if any other details are needed.

Also note that when I do a fdisk -l inside my VM I don't get information about the partitions and the output is

Disk /dev/sda1: 1049 MB, 1049624576 bytes
255 heads, 63 sectors/track, 127 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

Disk /dev/sda1 doesn't contain a valid partition table

Disk /dev/sda2: 2701 MB, 2701131776 bytes
255 heads, 63 sectors/track, 328 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

Disk /dev/sda2 doesn't contain a valid partition table

Disk /dev/sda3: 536 MB, 536870912 bytes
255 heads, 63 sectors/track, 65 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

Disk /dev/sda3 doesn't contain a valid partition table

I am not sure if that is expected or not.

Regards
Deependra Singh Shekhawat

Thu, 04/15/2010 - 03:59

jeevanullas

Offline

Joined: 02/12/2010

Test fails on a new setup

Hi,

I tried setting up eucalyptus on a brand new setup but this thing again failed for me. Centos 5.4 with XEN. The filesystem image I am using was downloaded from eucalyptus website.

I am not sure as to why I get "Doesn't contain a valid partition table" when I issue a fdisk -l from inside the VM.

Hotplug scripts not working is still the main error for me by the way.

If you have any suggestions do let me know.

Fri, 04/16/2010 - 02:43

Some new findings on xen

If we check the following link
http://wiki.xensource.com/xenwiki/XenCommonProblems

For hotplug scripts not working it says that we need to have the device node registered in dom0. Does it explain why I am not able to get a meaningful output in

fdisk -l

when issued from domU.

My dom0 doesn't have sdaX, it has hda1 , hda2 and hda3. Non-scsi disk. Also after talking to xen folks on IRC I came to know that I first need to create a device node on dom0 before I specify anything on euca-attach-volume. But I believe eucalyptus tries to create a device itself with the following name /dev/etherd/e0.1 but fails to do that.

Let me know if the above finding helps close down this problem

Fri, 04/16/2010 - 23:11

tried same thing on libvirt+kvm

After lot of research in this area I thought of trying this on a brand new setup with KVM and Fedora 12. Booted my instance and attached the volume to it. The nc.log says

[Sat Apr 17 12:31:07 2010][004315][EUCADEBUG ] doDescribeInstances() invoked
[Sat Apr 17 12:31:10 2010][004315][EUCAINFO ] doAttachVolume() invoked (id=i-4C9B0842 vol=vol-5F1D0652 remote=/dev/etherd/e0.1 local=/dev/sdb)
[Sat Apr 17 12:31:10 2010][004315][EUCAINFO ] attached /dev/etherd/e0.1 to sdb in domain i-4C9B0842
[Sat Apr 17 12:31:13 2010][004315][EUCADEBUG ] doDescribeResource() invoked

The euca-describe-volumes on head says

[root@cloudmaster volumes]# euca-describe-volumes
VOLUME vol-5F1D0652 2 silinux-cluster01 in-use 2010-04-17T06:43:38.731Z
ATTACHMENT vol-5F1D0652 i-4C9B0842 unknown,requested:/dev/sdb 2010-04-17T07:09:11.455Z

The volume file can be seen in /opt/eucalyptus/var/lib/eucalyptus/volumes

But I can't see a new device getting created on the VM.

fdisk -l output of VM

-bash-3.2# fdisk -l

Disk /dev/sda: 5384 MB, 5384437760 bytes
4 heads, 32 sectors/track, 82160 cylinders
Units = cylinders of 128 * 512 = 65536 bytes

Device Boot Start End Blocks Id System
/dev/sda1 1 16017 1025024+ 83 Linux
/dev/sda2 16017 71830 3572000+ 83 Linux
/dev/sda3 71830 82160 661183+ 82 Linux swap / Solaris

It should have created device /dev/sdb

Also note that in KVM + Fedora 12 (SATA disk) I am able to see proper partition info using fdisk -l inside VM which was not the case in XEN + Centos 5.4 (ATA disk).

Let me know if you need further details. I am still not able to access the EBS volume inside my running VM.

Wed, 04/21/2010 - 21:16

graziano

Joined: 01/14/2010

Hello, can you check that

Hello,

can you check that your instance has a module acpiphp loaded? Also can you check dmesg on the instance to see if the disk shows up? You should see some messages about a scsi device discovered.

cheers
graziano