RBD boot from volume weirdness in OpenStack

RBD boot from volume weirdness in OpenStack

[Travis Rhoden]

I've been trying to take advantage of the code additions made by Josh
Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
RBD.  First off, nice work Josh!  I'm hoping you folks can help me out
with something strange I am seeing.  The question may be more
OpenStack related than Ceph, though, but hear me out first.

I created a new volume (to use for boot-from-volume) from an existing
image like so:

#cinder create --display-name uec-test-vol --image-id
699137a2-a864-4a87-98fa-1684d7677044 5

This completes just fine.

Later I try to boot from it, that fails.  Cutting to the chase, here is why:

kvm: -drive file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
kvm: -drive file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
could not open disk image
rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
file or directory

It's weird that creating the volume was successful, but that KVM can't
read it.  Poking around a bit more, it was clear why:

# rbd -n client.novavolume --pool nova-volume ls
<returns nothing>

# rbd -n client.novavolume ls
volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b

Okay, the volume is the "rbd" pool!  That's really weird, though.
Here is the my nova.conf entries:
volume_driver=nova.volume.driver.RBDDriver
rbd_pool=nova-volume
rbd_user=novavolume


AND, here are the log entries from nova-volume.log (cleaned up a little):

rbd create --pool nova-volume --size 5120
volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
rbd import --pool nova-volume /tmp/tmplQUwzt
volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b

I'm not sure why it goes create/delete/import, but regardless all of
that worked.  More importantly, all these commands used --pool
nova-volume.  So how the heck did that RBD end up in the "rbd" pool
instead of the "nova-volume" pool?  Any ideas?

Before I hit "send", I figured I should at least test this myself.  Watch this:

#rbd create -n client.novavolume --pool nova-volume --size 1024 test
# rbd ls -n client.novavolume --pool nova-volume
test
# rbd export -n client.novavolume --pool nova-volume test /tmp/test
Exporting image: 100% complete...done.
# rbd rm -n client.novavolume --pool nova-volume test
Removing image: 100% complete...done.
# rbd import -n client.novavolume --pool nova-volume /tmp/test test
Importing image: 100% complete...done.
# rbd ls -n client.novavolume --pool nova-volume

# rbd ls -n client.novavolume --pool rbd
test


So it seems that "rbd import" doesn't honor the --pool argument?

I am using 0.53 on the backend, but my client is 0.48.2.  I'll upgrade
that and see if that makes a different.

 - Travis

Re: RBD boot from volume weirdness in OpenStack

[Josh Durgin]

On 2012-10-25 08:22, Travis Rhoden wrote:
> I've been trying to take advantage of the code additions made by Josh
> Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
> RBD.  First off, nice work Josh!  I'm hoping you folks can help me 
> out
> with something strange I am seeing.  The question may be more
> OpenStack related than Ceph, though, but hear me out first.
>
> I created a new volume (to use for boot-from-volume) from an existing
> image like so:
>
> #cinder create --display-name uec-test-vol --image-id
> 699137a2-a864-4a87-98fa-1684d7677044 5
>
> This completes just fine.
>
> Later I try to boot from it, that fails.  Cutting to the chase, here 
> is why:
>
> kvm: -drive
> 
> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
> error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
> kvm: -drive
> 
> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
> could not open disk image
> rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
> file or directory
>
> It's weird that creating the volume was successful, but that KVM 
> can't
> read it.  Poking around a bit more, it was clear why:
>
> # rbd -n client.novavolume --pool nova-volume ls
> <returns nothing>
>
> # rbd -n client.novavolume ls
> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>
> Okay, the volume is the "rbd" pool!  That's really weird, though.
> Here is the my nova.conf entries:
> volume_driver=nova.volume.driver.RBDDriver
> rbd_pool=nova-volume
> rbd_user=novavolume
>
>
> AND, here are the log entries from nova-volume.log (cleaned up a 
> little):
>
> rbd create --pool nova-volume --size 5120
> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
> rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
> rbd import --pool nova-volume /tmp/tmplQUwzt
> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>
> I'm not sure why it goes create/delete/import, but regardless all of
> that worked.  More importantly, all these commands used --pool
> nova-volume.  So how the heck did that RBD end up in the "rbd" pool
> instead of the "nova-volume" pool?  Any ideas?
>
> Before I hit "send", I figured I should at least test this myself.  
> Watch this:
>
> #rbd create -n client.novavolume --pool nova-volume --size 1024 test
> # rbd ls -n client.novavolume --pool nova-volume
> test
> # rbd export -n client.novavolume --pool nova-volume test /tmp/test
> Exporting image: 100% complete...done.
> # rbd rm -n client.novavolume --pool nova-volume test
> Removing image: 100% complete...done.
> # rbd import -n client.novavolume --pool nova-volume /tmp/test test
> Importing image: 100% complete...done.
> # rbd ls -n client.novavolume --pool nova-volume
>
> # rbd ls -n client.novavolume --pool rbd
> test
>
>
> So it seems that "rbd import" doesn't honor the --pool argument?

This was true in 0.48, but it should have been fixed in 0.48.2 (and 
0.52).
I'll add a note about this to the docs.

> I am using 0.53 on the backend, but my client is 0.48.2.  I'll 
> upgrade
> that and see if that makes a different.

The ceph-common package in particular should be 0.48.2 or >=0.52.

>  - Travis

Re: RBD boot from volume weirdness in OpenStack

[Travis Rhoden]

Awesome, thanks Josh.  I mispoke -- my client was 0.48.1.  glad
upgrading to 0.48.2 will do the trick!  thanks again.

On Thu, Oct 25, 2012 at 11:42 AM, Josh Durgin <josh.durgin@inktank.com> wrote:
> On 2012-10-25 08:22, Travis Rhoden wrote:
>>
>> I've been trying to take advantage of the code additions made by Josh
>> Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
>> RBD.  First off, nice work Josh!  I'm hoping you folks can help me out
>> with something strange I am seeing.  The question may be more
>> OpenStack related than Ceph, though, but hear me out first.
>>
>> I created a new volume (to use for boot-from-volume) from an existing
>> image like so:
>>
>> #cinder create --display-name uec-test-vol --image-id
>> 699137a2-a864-4a87-98fa-1684d7677044 5
>>
>> This completes just fine.
>>
>> Later I try to boot from it, that fails.  Cutting to the chase, here is
>> why:
>>
>> kvm: -drive
>>
>>
>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>> error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>> kvm: -drive
>>
>>
>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>> could not open disk image
>> rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
>> file or directory
>>
>> It's weird that creating the volume was successful, but that KVM can't
>> read it.  Poking around a bit more, it was clear why:
>>
>> # rbd -n client.novavolume --pool nova-volume ls
>> <returns nothing>
>>
>> # rbd -n client.novavolume ls
>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>
>> Okay, the volume is the "rbd" pool!  That's really weird, though.
>> Here is the my nova.conf entries:
>> volume_driver=nova.volume.driver.RBDDriver
>> rbd_pool=nova-volume
>> rbd_user=novavolume
>>
>>
>> AND, here are the log entries from nova-volume.log (cleaned up a little):
>>
>> rbd create --pool nova-volume --size 5120
>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>> rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>> rbd import --pool nova-volume /tmp/tmplQUwzt
>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>
>> I'm not sure why it goes create/delete/import, but regardless all of
>> that worked.  More importantly, all these commands used --pool
>> nova-volume.  So how the heck did that RBD end up in the "rbd" pool
>> instead of the "nova-volume" pool?  Any ideas?
>>
>> Before I hit "send", I figured I should at least test this myself.  Watch
>> this:
>>
>> #rbd create -n client.novavolume --pool nova-volume --size 1024 test
>> # rbd ls -n client.novavolume --pool nova-volume
>> test
>> # rbd export -n client.novavolume --pool nova-volume test /tmp/test
>> Exporting image: 100% complete...done.
>> # rbd rm -n client.novavolume --pool nova-volume test
>> Removing image: 100% complete...done.
>> # rbd import -n client.novavolume --pool nova-volume /tmp/test test
>> Importing image: 100% complete...done.
>> # rbd ls -n client.novavolume --pool nova-volume
>>
>> # rbd ls -n client.novavolume --pool rbd
>> test
>>
>>
>> So it seems that "rbd import" doesn't honor the --pool argument?
>
>
> This was true in 0.48, but it should have been fixed in 0.48.2 (and 0.52).
> I'll add a note about this to the docs.
>
>
>> I am using 0.53 on the backend, but my client is 0.48.2.  I'll upgrade
>> that and see if that makes a different.
>
>
> The ceph-common package in particular should be 0.48.2 or >=0.52.
>
>>  - Travis
>
>

Re: RBD boot from volume weirdness in OpenStack

[Travis Rhoden]

Josh,

Do you mind if I ask you a few follow-up questions?  I can ask on the
OpenStack ML if needed, but I think you are the most knowledgeable
person for these...

1. To get "efficient volumes from images" (i.e. volumes that are a COW
copy of the image), do the images and volumes need to live in the same
pool?  I have glance configured to use a pool called "glanceimages",
and nova-volume/Cinder uses a second pool called "nova-volume".  Is
this always going to prevent the COW process from working?  If I check
out my volume, I see this:

# rbd -p nova-volume info volume-8c30ee47-5ec3-4600-b332-1bdc2a650837
rbd image 'volume-8c30ee47-5ec3-4600-b332-1bdc2a650837':
	size 220 MB in 55 objects
	order 22 (4096 KB objects)
	block_name_prefix: rb.0.1f04.4ba87ea2
	parent:  (pool -1)

If the COW process is actually working, I think I'll see a parent
other than (pool -1), correct?

I had split glance/cinder into different RADOS pools because I figured
it would give me more flexibility (could set different rep size/crush
rules) and potentially more security (use different cephx
clients/keys.  Glance keys aren't on nova-compute nodes, only glance
node).  But this isn't a strict requirement.

2. Do you know if "raw" is the only disk format accepted for
boot-from-volume?  I did the whole "create volume from image" step,
and my source image was a qcow2.  But when I do the boot-from-volume,
the -disk line contains format=raw.  Not sure how to control that
anymore -- there is no metadata attached to the volume that indicates
if it is qcow2 vs raw.  I'll have to dig into the code and see if
looks for anything.  Thought you might know...

3.  I edited my libvirt XML to saw raw instead of qcow2, and the VM
started to boot!  Hooray!  boot-from-volume over RBD.  But then
console.log shows stuff like:

Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... done.
[    1.044112] EXT4-fs (vda1): mounted filesystem with ordered data
mode. Opts: (null)
Begin: Running /scripts/local-bottom ... [    1.052379] FDC 0 is a S82078B
done.
done.
Begin: Running /scripts/init-bottom ... done.
[    1.156951] Refined TSC clocksource calibration: 2266.803 MHz.
[    1.796114] end_request: I/O error, dev vda, sector 16065
[    1.800018] Buffer I/O error on device vda1, logical block 0
[    1.800018] lost page write due to I/O error on vda1
[    1.805294] EXT4-fs (vda1): re-mounted. Opts: (null)
cloud-init start-local running: Thu, 25 Oct 2012 16:06:34 +0000. up
2.86 seconds^M
no instance data found in start-local^M
[    3.802465] end_request: I/O error, dev vda, sector 1257161
[    3.803629] Buffer I/O error on device vda1, logical block 155137
[    3.804020] Buffer I/O error on device vda1, logical block 155138
....


And that just continues on and obviously the VM is unusable.  Any
thoughts on why that might happen.  You ever run into this during your
testing?

I'm thinking that I probably need to not use UEC images for this -- It
tries to go in and resize the file system and stuff like that.  I
should probably just make a bunch of fixed images (10G, 20G, etc.) and
make volumes from those.  Right now, I'm not even positive that the
RBD has even been formatted with a filesystem.

Regards,

 - Travis

On Thu, Oct 25, 2012 at 11:51 AM, Travis Rhoden <trhoden@gmail.com> wrote:
> Awesome, thanks Josh.  I mispoke -- my client was 0.48.1.  glad
> upgrading to 0.48.2 will do the trick!  thanks again.
>
> On Thu, Oct 25, 2012 at 11:42 AM, Josh Durgin <josh.durgin@inktank.com> wrote:
>> On 2012-10-25 08:22, Travis Rhoden wrote:
>>>
>>> I've been trying to take advantage of the code additions made by Josh
>>> Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
>>> RBD.  First off, nice work Josh!  I'm hoping you folks can help me out
>>> with something strange I am seeing.  The question may be more
>>> OpenStack related than Ceph, though, but hear me out first.
>>>
>>> I created a new volume (to use for boot-from-volume) from an existing
>>> image like so:
>>>
>>> #cinder create --display-name uec-test-vol --image-id
>>> 699137a2-a864-4a87-98fa-1684d7677044 5
>>>
>>> This completes just fine.
>>>
>>> Later I try to boot from it, that fails.  Cutting to the chase, here is
>>> why:
>>>
>>> kvm: -drive
>>>
>>>
>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>> error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>> kvm: -drive
>>>
>>>
>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>> could not open disk image
>>> rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
>>> file or directory
>>>
>>> It's weird that creating the volume was successful, but that KVM can't
>>> read it.  Poking around a bit more, it was clear why:
>>>
>>> # rbd -n client.novavolume --pool nova-volume ls
>>> <returns nothing>
>>>
>>> # rbd -n client.novavolume ls
>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>
>>> Okay, the volume is the "rbd" pool!  That's really weird, though.
>>> Here is the my nova.conf entries:
>>> volume_driver=nova.volume.driver.RBDDriver
>>> rbd_pool=nova-volume
>>> rbd_user=novavolume
>>>
>>>
>>> AND, here are the log entries from nova-volume.log (cleaned up a little):
>>>
>>> rbd create --pool nova-volume --size 5120
>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>> rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>> rbd import --pool nova-volume /tmp/tmplQUwzt
>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>
>>> I'm not sure why it goes create/delete/import, but regardless all of
>>> that worked.  More importantly, all these commands used --pool
>>> nova-volume.  So how the heck did that RBD end up in the "rbd" pool
>>> instead of the "nova-volume" pool?  Any ideas?
>>>
>>> Before I hit "send", I figured I should at least test this myself.  Watch
>>> this:
>>>
>>> #rbd create -n client.novavolume --pool nova-volume --size 1024 test
>>> # rbd ls -n client.novavolume --pool nova-volume
>>> test
>>> # rbd export -n client.novavolume --pool nova-volume test /tmp/test
>>> Exporting image: 100% complete...done.
>>> # rbd rm -n client.novavolume --pool nova-volume test
>>> Removing image: 100% complete...done.
>>> # rbd import -n client.novavolume --pool nova-volume /tmp/test test
>>> Importing image: 100% complete...done.
>>> # rbd ls -n client.novavolume --pool nova-volume
>>>
>>> # rbd ls -n client.novavolume --pool rbd
>>> test
>>>
>>>
>>> So it seems that "rbd import" doesn't honor the --pool argument?
>>
>>
>> This was true in 0.48, but it should have been fixed in 0.48.2 (and 0.52).
>> I'll add a note about this to the docs.
>>
>>
>>> I am using 0.53 on the backend, but my client is 0.48.2.  I'll upgrade
>>> that and see if that makes a different.
>>
>>
>> The ceph-common package in particular should be 0.48.2 or >=0.52.
>>
>>>  - Travis
>>
>>

Re: RBD boot from volume weirdness in OpenStack

[Josh Durgin]

On 10/25/2012 09:27 AM, Travis Rhoden wrote:
> Josh,
>
> Do you mind if I ask you a few follow-up questions?  I can ask on the
> OpenStack ML if needed, but I think you are the most knowledgeable
> person for these...

I don't mind. ceph-devel is fine for these ceph-related questions.

> 1. To get "efficient volumes from images" (i.e. volumes that are a COW
> copy of the image), do the images and volumes need to live in the same
> pool?  I have glance configured to use a pool called "glanceimages",
> and nova-volume/Cinder uses a second pool called "nova-volume".  Is
> this always going to prevent the COW process from working?  If I check
> out my volume, I see this:
>
> # rbd -p nova-volume info volume-8c30ee47-5ec3-4600-b332-1bdc2a650837
> rbd image 'volume-8c30ee47-5ec3-4600-b332-1bdc2a650837':
> 	size 220 MB in 55 objects
> 	order 22 (4096 KB objects)
> 	block_name_prefix: rb.0.1f04.4ba87ea2
> 	parent:  (pool -1)
>
> If the COW process is actually working, I think I'll see a parent
> other than (pool -1), correct?

They can be in different pools. With a COW clone you would see a parent
there. Did you set show_image_direct_url=True for Glance (i.e. 
http://ceph.com/docs/master/rbd/rbd-openstack/#configuring-glance)?

> I had split glance/cinder into different RADOS pools because I figured
> it would give me more flexibility (could set different rep size/crush
> rules) and potentially more security (use different cephx
> clients/keys.  Glance keys aren't on nova-compute nodes, only glance
> node).  But this isn't a strict requirement.

Yeah, that's how it's designed to work. The Glance pool can
be read-only from nova-compute, and Glance doesn't need access
to the pool used for volumes.

> 2. Do you know if "raw" is the only disk format accepted for
> boot-from-volume?  I did the whole "create volume from image" step,
> and my source image was a qcow2.  But when I do the boot-from-volume,
> the -disk line contains format=raw.  Not sure how to control that
> anymore -- there is no metadata attached to the volume that indicates
> if it is qcow2 vs raw.  I'll have to dig into the code and see if
> looks for anything.  Thought you might know...

Raw is the only thing that works by default. Although it's possible
to layer other formats on top of rbd, it's not well tested or
recommended. Now that rbd supports cloning natively, there's not much
benefit to e.g. qcow2 on top of it. The interfaces for QEMU and
libvirt generally don't handle such layered formats well in any case.

> 3.  I edited my libvirt XML to saw raw instead of qcow2, and the VM
> started to boot!  Hooray!  boot-from-volume over RBD.  But then
> console.log shows stuff like:
>
> Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
> Begin: Running /scripts/local-premount ... done.
> [    1.044112] EXT4-fs (vda1): mounted filesystem with ordered data
> mode. Opts: (null)
> Begin: Running /scripts/local-bottom ... [    1.052379] FDC 0 is a S82078B
> done.
> done.
> Begin: Running /scripts/init-bottom ... done.
> [    1.156951] Refined TSC clocksource calibration: 2266.803 MHz.
> [    1.796114] end_request: I/O error, dev vda, sector 16065
> [    1.800018] Buffer I/O error on device vda1, logical block 0
> [    1.800018] lost page write due to I/O error on vda1
> [    1.805294] EXT4-fs (vda1): re-mounted. Opts: (null)
> cloud-init start-local running: Thu, 25 Oct 2012 16:06:34 +0000. up
> 2.86 seconds^M
> no instance data found in start-local^M
> [    3.802465] end_request: I/O error, dev vda, sector 1257161
> [    3.803629] Buffer I/O error on device vda1, logical block 155137
> [    3.804020] Buffer I/O error on device vda1, logical block 155138
> ....
>
>
> And that just continues on and obviously the VM is unusable.  Any
> thoughts on why that might happen.  You ever run into this during your
> testing?

I haven't seen such errors. It may be due to using qcow2 on top of rbd.

> I'm thinking that I probably need to not use UEC images for this -- It
> tries to go in and resize the file system and stuff like that.  I
> should probably just make a bunch of fixed images (10G, 20G, etc.) and
> make volumes from those.  Right now, I'm not even positive that the
> RBD has even been formatted with a filesystem.

UEC images work, but you have to convert them to raw first, as shown here:

http://ceph.com/docs/master/rbd/rbd-openstack/#booting-from-a-block-device

> Regards,
>
>   - Travis
>
> On Thu, Oct 25, 2012 at 11:51 AM, Travis Rhoden <trhoden@gmail.com> wrote:
>> Awesome, thanks Josh.  I mispoke -- my client was 0.48.1.  glad
>> upgrading to 0.48.2 will do the trick!  thanks again.
>>
>> On Thu, Oct 25, 2012 at 11:42 AM, Josh Durgin <josh.durgin@inktank.com> wrote:
>>> On 2012-10-25 08:22, Travis Rhoden wrote:
>>>>
>>>> I've been trying to take advantage of the code additions made by Josh
>>>> Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
>>>> RBD.  First off, nice work Josh!  I'm hoping you folks can help me out
>>>> with something strange I am seeing.  The question may be more
>>>> OpenStack related than Ceph, though, but hear me out first.
>>>>
>>>> I created a new volume (to use for boot-from-volume) from an existing
>>>> image like so:
>>>>
>>>> #cinder create --display-name uec-test-vol --image-id
>>>> 699137a2-a864-4a87-98fa-1684d7677044 5
>>>>
>>>> This completes just fine.
>>>>
>>>> Later I try to boot from it, that fails.  Cutting to the chase, here is
>>>> why:
>>>>
>>>> kvm: -drive
>>>>
>>>>
>>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>>> error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>> kvm: -drive
>>>>
>>>>
>>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>>> could not open disk image
>>>> rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
>>>> file or directory
>>>>
>>>> It's weird that creating the volume was successful, but that KVM can't
>>>> read it.  Poking around a bit more, it was clear why:
>>>>
>>>> # rbd -n client.novavolume --pool nova-volume ls
>>>> <returns nothing>
>>>>
>>>> # rbd -n client.novavolume ls
>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>
>>>> Okay, the volume is the "rbd" pool!  That's really weird, though.
>>>> Here is the my nova.conf entries:
>>>> volume_driver=nova.volume.driver.RBDDriver
>>>> rbd_pool=nova-volume
>>>> rbd_user=novavolume
>>>>
>>>>
>>>> AND, here are the log entries from nova-volume.log (cleaned up a little):
>>>>
>>>> rbd create --pool nova-volume --size 5120
>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>> rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>> rbd import --pool nova-volume /tmp/tmplQUwzt
>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>
>>>> I'm not sure why it goes create/delete/import, but regardless all of
>>>> that worked.  More importantly, all these commands used --pool
>>>> nova-volume.  So how the heck did that RBD end up in the "rbd" pool
>>>> instead of the "nova-volume" pool?  Any ideas?
>>>>
>>>> Before I hit "send", I figured I should at least test this myself.  Watch
>>>> this:
>>>>
>>>> #rbd create -n client.novavolume --pool nova-volume --size 1024 test
>>>> # rbd ls -n client.novavolume --pool nova-volume
>>>> test
>>>> # rbd export -n client.novavolume --pool nova-volume test /tmp/test
>>>> Exporting image: 100% complete...done.
>>>> # rbd rm -n client.novavolume --pool nova-volume test
>>>> Removing image: 100% complete...done.
>>>> # rbd import -n client.novavolume --pool nova-volume /tmp/test test
>>>> Importing image: 100% complete...done.
>>>> # rbd ls -n client.novavolume --pool nova-volume
>>>>
>>>> # rbd ls -n client.novavolume --pool rbd
>>>> test
>>>>
>>>>
>>>> So it seems that "rbd import" doesn't honor the --pool argument?
>>>
>>>
>>> This was true in 0.48, but it should have been fixed in 0.48.2 (and 0.52).
>>> I'll add a note about this to the docs.
>>>
>>>
>>>> I am using 0.53 on the backend, but my client is 0.48.2.  I'll upgrade
>>>> that and see if that makes a different.
>>>
>>>
>>> The ceph-common package in particular should be 0.48.2 or >=0.52.
>>>
>>>>   - Travis
>>>
>>>

Re: RBD boot from volume weirdness in OpenStack

[Travis Rhoden]

Thanks for the pointers Josh.

Stupidly, I had not looked at those docs.  I forgot all about them
since they didn't used to be there.  I was only using OpenStack docs
and not the Ceph ones.  Looks like they are filled with great
information.  You answered all my questions!  Thanks again.

 - Travis

On Thu, Oct 25, 2012 at 1:25 PM, Josh Durgin <josh.durgin@inktank.com> wrote:
> On 10/25/2012 09:27 AM, Travis Rhoden wrote:
>>
>> Josh,
>>
>> Do you mind if I ask you a few follow-up questions?  I can ask on the
>> OpenStack ML if needed, but I think you are the most knowledgeable
>> person for these...
>
>
> I don't mind. ceph-devel is fine for these ceph-related questions.
>
>
>> 1. To get "efficient volumes from images" (i.e. volumes that are a COW
>> copy of the image), do the images and volumes need to live in the same
>> pool?  I have glance configured to use a pool called "glanceimages",
>> and nova-volume/Cinder uses a second pool called "nova-volume".  Is
>> this always going to prevent the COW process from working?  If I check
>> out my volume, I see this:
>>
>> # rbd -p nova-volume info volume-8c30ee47-5ec3-4600-b332-1bdc2a650837
>> rbd image 'volume-8c30ee47-5ec3-4600-b332-1bdc2a650837':
>>         size 220 MB in 55 objects
>>         order 22 (4096 KB objects)
>>         block_name_prefix: rb.0.1f04.4ba87ea2
>>         parent:  (pool -1)
>>
>> If the COW process is actually working, I think I'll see a parent
>> other than (pool -1), correct?
>
>
> They can be in different pools. With a COW clone you would see a parent
> there. Did you set show_image_direct_url=True for Glance (i.e.
> http://ceph.com/docs/master/rbd/rbd-openstack/#configuring-glance)?
>
>
>> I had split glance/cinder into different RADOS pools because I figured
>> it would give me more flexibility (could set different rep size/crush
>> rules) and potentially more security (use different cephx
>> clients/keys.  Glance keys aren't on nova-compute nodes, only glance
>> node).  But this isn't a strict requirement.
>
>
> Yeah, that's how it's designed to work. The Glance pool can
> be read-only from nova-compute, and Glance doesn't need access
> to the pool used for volumes.
>
>
>> 2. Do you know if "raw" is the only disk format accepted for
>> boot-from-volume?  I did the whole "create volume from image" step,
>> and my source image was a qcow2.  But when I do the boot-from-volume,
>> the -disk line contains format=raw.  Not sure how to control that
>> anymore -- there is no metadata attached to the volume that indicates
>> if it is qcow2 vs raw.  I'll have to dig into the code and see if
>> looks for anything.  Thought you might know...
>
>
> Raw is the only thing that works by default. Although it's possible
> to layer other formats on top of rbd, it's not well tested or
> recommended. Now that rbd supports cloning natively, there's not much
> benefit to e.g. qcow2 on top of it. The interfaces for QEMU and
> libvirt generally don't handle such layered formats well in any case.
>
>
>> 3.  I edited my libvirt XML to saw raw instead of qcow2, and the VM
>> started to boot!  Hooray!  boot-from-volume over RBD.  But then
>> console.log shows stuff like:
>>
>> Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
>> done.
>> Begin: Running /scripts/local-premount ... done.
>> [    1.044112] EXT4-fs (vda1): mounted filesystem with ordered data
>> mode. Opts: (null)
>> Begin: Running /scripts/local-bottom ... [    1.052379] FDC 0 is a S82078B
>> done.
>> done.
>> Begin: Running /scripts/init-bottom ... done.
>> [    1.156951] Refined TSC clocksource calibration: 2266.803 MHz.
>> [    1.796114] end_request: I/O error, dev vda, sector 16065
>> [    1.800018] Buffer I/O error on device vda1, logical block 0
>> [    1.800018] lost page write due to I/O error on vda1
>> [    1.805294] EXT4-fs (vda1): re-mounted. Opts: (null)
>> cloud-init start-local running: Thu, 25 Oct 2012 16:06:34 +0000. up
>> 2.86 seconds^M
>> no instance data found in start-local^M
>> [    3.802465] end_request: I/O error, dev vda, sector 1257161
>> [    3.803629] Buffer I/O error on device vda1, logical block 155137
>> [    3.804020] Buffer I/O error on device vda1, logical block 155138
>> ....
>>
>>
>> And that just continues on and obviously the VM is unusable.  Any
>> thoughts on why that might happen.  You ever run into this during your
>> testing?
>
>
> I haven't seen such errors. It may be due to using qcow2 on top of rbd.
>
>
>> I'm thinking that I probably need to not use UEC images for this -- It
>> tries to go in and resize the file system and stuff like that.  I
>> should probably just make a bunch of fixed images (10G, 20G, etc.) and
>> make volumes from those.  Right now, I'm not even positive that the
>> RBD has even been formatted with a filesystem.
>
>
> UEC images work, but you have to convert them to raw first, as shown here:
>
> http://ceph.com/docs/master/rbd/rbd-openstack/#booting-from-a-block-device
>
>
>> Regards,
>>
>>   - Travis
>>
>> On Thu, Oct 25, 2012 at 11:51 AM, Travis Rhoden <trhoden@gmail.com> wrote:
>>>
>>> Awesome, thanks Josh.  I mispoke -- my client was 0.48.1.  glad
>>> upgrading to 0.48.2 will do the trick!  thanks again.
>>>
>>> On Thu, Oct 25, 2012 at 11:42 AM, Josh Durgin <josh.durgin@inktank.com>
>>> wrote:
>>>>
>>>> On 2012-10-25 08:22, Travis Rhoden wrote:
>>>>>
>>>>>
>>>>> I've been trying to take advantage of the code additions made by Josh
>>>>> Durgin to OpenStack Folsom for combining  boot-from-volume and Ceph
>>>>> RBD.  First off, nice work Josh!  I'm hoping you folks can help me out
>>>>> with something strange I am seeing.  The question may be more
>>>>> OpenStack related than Ceph, though, but hear me out first.
>>>>>
>>>>> I created a new volume (to use for boot-from-volume) from an existing
>>>>> image like so:
>>>>>
>>>>> #cinder create --display-name uec-test-vol --image-id
>>>>> 699137a2-a864-4a87-98fa-1684d7677044 5
>>>>>
>>>>> This completes just fine.
>>>>>
>>>>> Later I try to boot from it, that fails.  Cutting to the chase, here is
>>>>> why:
>>>>>
>>>>> kvm: -drive
>>>>>
>>>>>
>>>>>
>>>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>>>> error reading header from volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>> kvm: -drive
>>>>>
>>>>>
>>>>>
>>>>> file=rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b,if=none,id=drive-virtio-disk0,format=raw,cache=none:
>>>>> could not open disk image
>>>>> rbd:nova-volume/volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b: No such
>>>>> file or directory
>>>>>
>>>>> It's weird that creating the volume was successful, but that KVM can't
>>>>> read it.  Poking around a bit more, it was clear why:
>>>>>
>>>>> # rbd -n client.novavolume --pool nova-volume ls
>>>>> <returns nothing>
>>>>>
>>>>> # rbd -n client.novavolume ls
>>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>>
>>>>> Okay, the volume is the "rbd" pool!  That's really weird, though.
>>>>> Here is the my nova.conf entries:
>>>>> volume_driver=nova.volume.driver.RBDDriver
>>>>> rbd_pool=nova-volume
>>>>> rbd_user=novavolume
>>>>>
>>>>>
>>>>> AND, here are the log entries from nova-volume.log (cleaned up a
>>>>> little):
>>>>>
>>>>> rbd create --pool nova-volume --size 5120
>>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>> rbd rm --pool nova-volume volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>> rbd import --pool nova-volume /tmp/tmplQUwzt
>>>>> volume-9f4e4b70-7fbb-4d81-b912-b1c6fcf86c8b
>>>>>
>>>>> I'm not sure why it goes create/delete/import, but regardless all of
>>>>> that worked.  More importantly, all these commands used --pool
>>>>> nova-volume.  So how the heck did that RBD end up in the "rbd" pool
>>>>> instead of the "nova-volume" pool?  Any ideas?
>>>>>
>>>>> Before I hit "send", I figured I should at least test this myself.
>>>>> Watch
>>>>> this:
>>>>>
>>>>> #rbd create -n client.novavolume --pool nova-volume --size 1024 test
>>>>> # rbd ls -n client.novavolume --pool nova-volume
>>>>> test
>>>>> # rbd export -n client.novavolume --pool nova-volume test /tmp/test
>>>>> Exporting image: 100% complete...done.
>>>>> # rbd rm -n client.novavolume --pool nova-volume test
>>>>> Removing image: 100% complete...done.
>>>>> # rbd import -n client.novavolume --pool nova-volume /tmp/test test
>>>>> Importing image: 100% complete...done.
>>>>> # rbd ls -n client.novavolume --pool nova-volume
>>>>>
>>>>> # rbd ls -n client.novavolume --pool rbd
>>>>> test
>>>>>
>>>>>
>>>>> So it seems that "rbd import" doesn't honor the --pool argument?
>>>>
>>>>
>>>>
>>>> This was true in 0.48, but it should have been fixed in 0.48.2 (and
>>>> 0.52).
>>>> I'll add a note about this to the docs.
>>>>
>>>>
>>>>> I am using 0.53 on the backend, but my client is 0.48.2.  I'll upgrade
>>>>> that and see if that makes a different.
>>>>
>>>>
>>>>
>>>> The ceph-common package in particular should be 0.48.2 or >=0.52.
>>>>
>>>>>   - Travis
>>>>
>>>>
>>>>
>

RE: RBD boot from volume weirdness in OpenStack

[Eric_YH_Chen]

Dear Josh and Travis:

I am trying to setup the openstack+ceph environment too, but I am not using devstack.
I deploy the glance, cinder, nova, keystone into different servers.
All the basic function works fine, I can import image, create volume and create virtual machine.
It seems the glance and cinder access ceph block device correctly. (ceph version 0.53)

But when I try to create an volume based on existed images, it failed.
I use the command in http://ceph.com/docs/master/rbd/rbd-openstack/

root@glance:~# glance image-list
+--------------------------------------+---------------------+-------------+------------------+------------+--------+
| ID                                   | Name                | Disk Format | Container Format | Size       | Status |
+--------------------------------------+---------------------+-------------+------------------+------------+--------+
| cad779fc-c851-4581-ac4d-474c3773bf89 | Ubuntu-Precise-Raw  | raw         | bare             | 2147483648 | active |
+--------------------------------------+---------------------+-------------+------------------+------------+--------+

root@glance:~# rbd info -p images cad779fc-c851-4581-ac4d-474c3773bf89
rbd image 'cad779fc-c851-4581-ac4d-474c3773bf89':
        size 2048 MB in 256 objects
        order 23 (8192 KB objects)
        block_name_prefix: rbd_data.28c076755ff
        format: 2
        features: layering

root@cinder:~# cinder create --image-id cad779fc-c851-4581-ac4d-474c3773bf89 10
root@cinder:~# cinder list
+--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+
|                  ID                  |   Status  |  Display Name  | Size | Volume Type |             Attached to              |
+--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+
| b8af3932-b27a-41e4-a2cc-082b78083f79 |   error   |      None      |  10  |     None    |                                      |
+--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+

Do you ever met this error message? Any suggestion is appreciated. 
Furthermore, I do not use cephx authentication, therefore, I didn't setup CEPH_ARGS.
Is it possible to cause this issue?

Thanks!


=============/etc/cinder/cinder.conf =================
[DEFAULT]
rootwrap_config = /etc/cinder/rootwrap.conf
api_paste_confg = /etc/cinder/api-paste.ini
sql_connection = mysql://cinder:password@localhost:3306/cinder
iscsi_helper = tgtadm
volume_name_template = volume-%s
volume_group = cinder-volumes
verbose = True
auth_strategy = keystone
state_path = /var/lib/cinder
volume_driver=cinder.volume.driver.RBDDriver
rabbit_password = password
my_ip = 172.17.123.12
glance_host = 172.17.123.16

== /var/log/cinder/cinder-volume.log ============

2012-10-26 13:48:37 17411 DEBUG cinder.manager [-] Running periodic task VolumeManager._publish_service_capabilities periodic_tasks /usr/lib/python2.7/dist-packages/cinder/manager.py:164
2012-10-26 13:48:37 17411 DEBUG cinder.manager [-] Running periodic task VolumeManager._report_driver_status periodic_tasks /usr/lib/python2.7/dist-packages/cinder/manager.py:164
2012-10-26 13:48:38 17411 DEBUG cinder.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'KeystoneServiceAdmin', u'KeystoneAdmin', u'admin'], u'_context_request_id': u'req-ec369d9d-581e-488b-84f1-e218b03ef1ea', u'_context_quota_class': None, u'args': {u'image_id': u'cad779fc-c851-4581-ac4d-474c3773bf89', u'snapshot_id': None, u'volume_id': u'b8af3932-b27a-41e4-a2cc-082b78083f79'}, u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'_context_project_id': u'eefa301a6a424e7da3d582649ad0e59e', u'_context_timestamp': u'2012-10-26T05:48:37.771007', u'_context_read_deleted': u'no', u'_context_user_id': u'fafd0583de8a4a1b93b924a6b2cb7eb5', u'method': u'create_volume', u'_context_remote_address': u'172.17.123.12'} _safe_log /usr/lib/python2.7/dist-packages/cinder/opensta
 ck/common/rpc/common.py:195
2012-10-26 13:48:38 17411 DEBUG cinder.openstack.common.rpc.amqp [-] unpacked context: {'user_id': u'fafd0583de8a4a1b93b924a6b2cb7eb5', 'roles': [u'KeystoneServiceAdmin', u'KeystoneAdmin', u'admin'], 'timestamp': u'2012-10-26T05:48:37.771007', 'auth_token': '<SANITIZED>', 'remote_address': u'172.17.123.12', 'quota_class': None, 'is_admin': True, 'request_id': u'req-ec369d9d-581e-488b-84f1-e218b03ef1ea', 'project_id': u'eefa301a6a424e7da3d582649ad0e59e', 'read_deleted': u'no'} _safe_log /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
2012-10-26 13:48:38 INFO cinder.volume.manager [req-ec369d9d-581e-488b-84f1-e218b03ef1ea fafd0583de8a4a1b93b924a6b2cb7eb5 eefa301a6a424e7da3d582649ad0e59e] volume volume-b8af3932-b27a-41e4-a2cc-082b78083f79: creating
2012-10-26 13:48:38 DEBUG cinder.volume.manager [req-ec369d9d-581e-488b-84f1-e218b03ef1ea fafd0583de8a4a1b93b924a6b2cb7eb5 eefa301a6a424e7da3d582649ad0e59e] volume volume-b8af3932-b27a-41e4-a2cc-082b78083f79: creating lv of size 10G create_volume /usr/lib/python2.7/dist-packages/cinder/volume/manager.py:133
2012-10-26 13:48:38 17411 ERROR cinder.openstack.common.rpc.amqp [-] Exception during message handling
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 276, in _process_data
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 163, in create_volume
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     volume_ref['id'], {'status': 'error'})
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 146, in create_volume
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     image_location = image_service.get_location(context, image_id)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 194, in get_location
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     _reraise_translated_image_exception(image_id)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 192, in get_location
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     image_meta = client.call(context, 2, 'get', image_id)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 120, in call
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     version)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 106, in _create_onetime_client
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     return _create_glance_client(context, self.host, self.port, version)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 65, in _create_glance_client
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     return glanceclient.Client(str(version), endpoint, **params)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/client.py", line 22, in Client
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     return client_class(*args, **kwargs)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/v2/client.py", line 37, in __init__
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self._get_image_model())
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/v2/client.py", line 40, in _get_image_model
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     schema = self.schemas.get('image')
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/v2/schemas.py", line 53, in get
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     _, raw_schema = self.http_client.json_request('GET', uri)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 187, in json_request
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     resp, body_iter = self._http_request(url, method, **kwargs)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 149, in _http_request
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     conn.request(method, conn_url, **kwargs)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 958, in request
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self._send_request(method, url, body, headers)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 992, in _send_request
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self.endheaders(body)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 954, in endheaders
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self._send_output(message_body)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 814, in _send_output
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self.send(msg)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 776, in send
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self.connect()
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/httplib.py", line 757, in connect
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     self.timeout, self.source_address)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/eventlet/green/socket.py", line 52, in create_connection
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     sock.connect(sa)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 179, in connect
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     timeout_exc=socket.timeout("timed out"))
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/eventlet/hubs/__init__.py", line 119, in trampoline
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     listener = hub.add(hub.WRITE, fileno, current.switch)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/eventlet/hubs/epolls.py", line 46, in add
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     listener = BaseHub.add(self, evtype, fileno, cb)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 126, in add
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     evtype, fileno, evtype))
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp RuntimeError: Second simultaneous write on fileno 8 detected.  Unless you really know what you're doing, make sure that only one greenthread can write any particular socket.  Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_multiple_reader_prevention(False)
2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
2012-10-26 13:49:37 17411 DEBUG cinder.manager [-] Running periodic task VolumeManager._publish_service_capabilities periodic_tasks /usr/lib/python2.7/dist-packages/cinder/manager.py:164
2012-10-26 13:49:37 17411 DEBUG cinder.manager [-] Running periodic task VolumeManager._report_driver_status periodic_tasks /usr/lib/python2.7/dist-packages/cinder/manager.py:164

-----Original Message-----
From: ceph-devel-owner@vger.kernel.org [mailto:ceph-devel-owner@vger.kernel.org] On Behalf Of Travis Rhoden
Sent: Friday, October 26, 2012 1:47 AM
To: Josh Durgin
Cc: ceph-devel
Subject: Re: RBD boot from volume weirdness in OpenStack

Thanks for the pointers Josh.

Stupidly, I had not looked at those docs.  I forgot all about them since they didn't used to be there.  I was only using OpenStack docs and not the Ceph ones.  Looks like they are filled with great information.  You answered all my questions!  Thanks again.

 - Travis

RE: RBD boot from volume weirdness in OpenStack

[Josh Durgin]

On 2012-10-25 22:57, Eric_YH_Chen@wiwynn.com wrote:
> Dear Josh and Travis:
>
> I am trying to setup the openstack+ceph environment too, but I am not
> using devstack.
> I deploy the glance, cinder, nova, keystone into different servers.
> All the basic function works fine, I can import image, create volume
> and create virtual machine.
> It seems the glance and cinder access ceph block device correctly.
> (ceph version 0.53)
>
> But when I try to create an volume based on existed images, it 
> failed.
> I use the command in http://ceph.com/docs/master/rbd/rbd-openstack/
>
> root@glance:~# glance image-list
> 
> +--------------------------------------+---------------------+-------------+------------------+------------+--------+
> | ID                                   | Name                | Disk
> Format | Container Format | Size       | Status |
> 
> +--------------------------------------+---------------------+-------------+------------------+------------+--------+
> | cad779fc-c851-4581-ac4d-474c3773bf89 | Ubuntu-Precise-Raw  | raw
>     | bare             | 2147483648 | active |
> 
> +--------------------------------------+---------------------+-------------+------------------+------------+--------+
>
> root@glance:~# rbd info -p images 
> cad779fc-c851-4581-ac4d-474c3773bf89
> rbd image 'cad779fc-c851-4581-ac4d-474c3773bf89':
>         size 2048 MB in 256 objects
>         order 23 (8192 KB objects)
>         block_name_prefix: rbd_data.28c076755ff
>         format: 2
>         features: layering
>
> root@cinder:~# cinder create --image-id 
> cad779fc-c851-4581-ac4d-474c3773bf89 10
> root@cinder:~# cinder list
> 
> +--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+
> |                  ID                  |   Status  |  Display Name  |
> Size | Volume Type |             Attached to              |
> 
> +--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+
> | b8af3932-b27a-41e4-a2cc-082b78083f79 |   error   |      None      |
> 10  |     None    |                                      |
> 
> +--------------------------------------+-----------+----------------+------+-------------+--------------------------------------+
>
> Do you ever met this error message? Any suggestion is appreciated.
> Furthermore, I do not use cephx authentication, therefore, I didn't
> setup CEPH_ARGS.
> Is it possible to cause this issue?

I haven't seen this error before, but CEPH_ARGS certainly doesn't 
affect it.

> Thanks!
>
>
> =============/etc/cinder/cinder.conf =================
> [DEFAULT]
> rootwrap_config = /etc/cinder/rootwrap.conf
> api_paste_confg = /etc/cinder/api-paste.ini
> sql_connection = mysql://cinder:password@localhost:3306/cinder
> iscsi_helper = tgtadm
> volume_name_template = volume-%s
> volume_group = cinder-volumes
> verbose = True
> auth_strategy = keystone
> state_path = /var/lib/cinder
> volume_driver=cinder.volume.driver.RBDDriver
> rabbit_password = password
> my_ip = 172.17.123.12
> glance_host = 172.17.123.16
>
> == /var/log/cinder/cinder-volume.log ============
>
> 2012-10-26 13:48:37 17411 DEBUG cinder.manager [-] Running periodic
> task VolumeManager._publish_service_capabilities periodic_tasks
> /usr/lib/python2.7/dist-packages/cinder/manager.py:164
> 2012-10-26 13:48:37 17411 DEBUG cinder.manager [-] Running periodic
> task VolumeManager._report_driver_status periodic_tasks
> /usr/lib/python2.7/dist-packages/cinder/manager.py:164
> 2012-10-26 13:48:38 17411 DEBUG cinder.openstack.common.rpc.amqp [-]
> received {u'_context_roles': [u'KeystoneServiceAdmin',
> u'KeystoneAdmin', u'admin'], u'_context_request_id':
> u'req-ec369d9d-581e-488b-84f1-e218b03ef1ea', u'_context_quota_class':
> None, u'args': {u'image_id': u'cad779fc-c851-4581-ac4d-474c3773bf89',
> u'snapshot_id': None, u'volume_id':
> u'b8af3932-b27a-41e4-a2cc-082b78083f79'}, u'_context_auth_token':
> '<SANITIZED>', u'_context_is_admin': True, u'_context_project_id':
> u'eefa301a6a424e7da3d582649ad0e59e', u'_context_timestamp':
> u'2012-10-26T05:48:37.771007', u'_context_read_deleted': u'no',
> u'_context_user_id': u'fafd0583de8a4a1b93b924a6b2cb7eb5', u'method':
> u'create_volume', u'_context_remote_address': u'172.17.123.12'}
> _safe_log
> 
> /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
> 2012-10-26 13:48:38 17411 DEBUG cinder.openstack.common.rpc.amqp [-]
> unpacked context: {'user_id': u'fafd0583de8a4a1b93b924a6b2cb7eb5',
> 'roles': [u'KeystoneServiceAdmin', u'KeystoneAdmin', u'admin'],
> 'timestamp': u'2012-10-26T05:48:37.771007', 'auth_token':
> '<SANITIZED>', 'remote_address': u'172.17.123.12', 'quota_class':
> None, 'is_admin': True, 'request_id':
> u'req-ec369d9d-581e-488b-84f1-e218b03ef1ea', 'project_id':
> u'eefa301a6a424e7da3d582649ad0e59e', 'read_deleted': u'no'} _safe_log
> 
> /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
> 2012-10-26 13:48:38 INFO cinder.volume.manager
> [req-ec369d9d-581e-488b-84f1-e218b03ef1ea
> fafd0583de8a4a1b93b924a6b2cb7eb5 eefa301a6a424e7da3d582649ad0e59e]
> volume volume-b8af3932-b27a-41e4-a2cc-082b78083f79: creating
> 2012-10-26 13:48:38 DEBUG cinder.volume.manager
> [req-ec369d9d-581e-488b-84f1-e218b03ef1ea
> fafd0583de8a4a1b93b924a6b2cb7eb5 eefa301a6a424e7da3d582649ad0e59e]
> volume volume-b8af3932-b27a-41e4-a2cc-082b78083f79: creating lv of
> size 10G create_volume
> /usr/lib/python2.7/dist-packages/cinder/volume/manager.py:133
> 2012-10-26 13:48:38 17411 ERROR cinder.openstack.common.rpc.amqp [-]
> Exception during message handling
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> Traceback (most recent call last):
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File
> 
> "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py",
> line 276, in _process_data
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> rval = self.proxy.dispatch(ctxt, version, method, **args)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File
> 
> "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/dispatcher.py",
> line 145, in dispatch
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> return getattr(proxyobj, method)(ctxt, **kwargs)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", 
> line
> 163, in create_volume
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> volume_ref['id'], {'status': 'error'})
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self.gen.next()
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", 
> line
> 146, in create_volume
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> image_location = image_service.get_location(context, image_id)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line
> 194, in get_location
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> _reraise_translated_image_exception(image_id)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line
> 192, in get_location
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> image_meta = client.call(context, 2, 'get', image_id)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line
> 120, in call
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp     
> version)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line
> 106, in _create_onetime_client
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> return _create_glance_client(context, self.host, self.port, version)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line
> 65, in _create_glance_client
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> return glanceclient.Client(str(version), endpoint, **params)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/client.py", line
> 22, in Client
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> return client_class(*args, **kwargs)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/v2/client.py",
> line 37, in __init__
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self._get_image_model())
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/v2/client.py",
> line 40, in _get_image_model
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> schema = self.schemas.get('image')
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/v2/schemas.py",
> line 53, in get
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> _, raw_schema = self.http_client.json_request('GET', uri)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py",
> line 187, in json_request
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> resp, body_iter = self._http_request(url, method, **kwargs)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py",
> line 149, in _http_request
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> conn.request(method, conn_url, **kwargs)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 958, in request
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self._send_request(method, url, body, headers)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 992, in _send_request
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self.endheaders(body)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 954, in endheaders
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self._send_output(message_body)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 814, in _send_output
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self.send(msg)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 776, in send
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self.connect()
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/httplib.py", line 757, in connect
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> self.timeout, self.source_address)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/eventlet/green/socket.py", 
> line
> 52, in create_connection
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> sock.connect(sa)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 
> 179,
> in connect
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> timeout_exc=socket.timeout("timed out"))
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/eventlet/hubs/__init__.py",
> line 119, in trampoline
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> listener = hub.add(hub.WRITE, fileno, current.switch)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/eventlet/hubs/epolls.py", line
> 46, in add
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> listener = BaseHub.add(self, evtype, fileno, cb)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line
> 126, in add
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> evtype, fileno, evtype))
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> RuntimeError: Second simultaneous write on fileno 8 detected.  Unless
> you really know what you're doing, make sure that only one 
> greenthread
> can write any particular socket.  Consider using a pools.Pool. If you
> do know what you're doing and want to disable this error, call
> eventlet.debug.hub_multiple_reader_prevention(False)
> 2012-10-26 13:48:38 17411 TRACE cinder.openstack.common.rpc.amqp
> 2012-10-26 13:49:37 17411 DEBUG cinder.manager [-] Running periodic
> task VolumeManager._publish_service_capabilities periodic_tasks
> /usr/lib/python2.7/dist-packages/cinder/manager.py:164
> 2012-10-26 13:49:37 17411 DEBUG cinder.manager [-] Running periodic
> task VolumeManager._report_driver_status periodic_tasks
> /usr/lib/python2.7/dist-packages/cinder/manager.py:164

There's nothing rbd-specific in this error - it hasn't reached the 
driver layer yet.
It could occur when creating a volume from an image with any backend.

It looks like some code path is failing to monkey-patch httplib for 
eventlib
properly. Could you file a bug in cinder about this?

Josh

> -----Original Message-----
> From: ceph-devel-owner@vger.kernel.org
> [mailto:ceph-devel-owner@vger.kernel.org] On Behalf Of Travis Rhoden
> Sent: Friday, October 26, 2012 1:47 AM
> To: Josh Durgin
> Cc: ceph-devel
> Subject: Re: RBD boot from volume weirdness in OpenStack
>
> Thanks for the pointers Josh.
>
> Stupidly, I had not looked at those docs.  I forgot all about them
> since they didn't used to be there.  I was only using OpenStack docs
> and not the Ceph ones.  Looks like they are filled with great
> information.  You answered all my questions!  Thanks again.
>
>  - Travis