GlusterFS: errors when trying to boot instance from cloned volume

[Dafna Ron]

I am working with gluster as cinder's backend on 2 computes for Havana.
when I try to boot an instance from a cloned volume (cinder create 10 --source-volid f7416ba6-af45-47d3-a333-478447a1ab54 --display-name from_vol1) we get a rootwrap error in volumes log and the instance moves to status ERROR.

more info that might be helpful, I tried booting an instance from a newly created volume and a volume created from image and instance is started correctly.
This error is for cloned from volume only.

[root@cougar06 ~(keystone_admin)]# nova list
+--------------------------------------+------+--------+------------+-------------+----------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+------+--------+------------+-------------+----------+
| 4dc50e69-9d84-4b19-b7ec-4bf0628d751b | na | ERROR | None | NOSTATE | |
+--------------------------------------+------+--------+------------+-------------+----------+
[root@cougar06 ~(keystone_admin)]#

2013-10-24 16:44:00.413 2483 ERROR cinder.openstack.common.rpc.common [req-26521926-e9cb-4308-aacd-425ba2a1932a a660044c9b074450aaa45fba0d641fcc e27aae2598b94dca88cd0408406e0848] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data\n **args)\n', ' File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch\n return getattr(proxyobj, method)(ctxt, **kwargs)\n', ' File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 808, in wrapper\n return func(self, *args, **kwargs)\n', ' File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 605, in initialize_connection\n conn_info = self.driver.initialize_connection(volume, connector)\n', ' File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 851, in initialize_connection\n info = self._qemu_img_info(path)\n', ' File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 132, in _qemu_img_info\n info = image_utils.qemu_img_info(path)\n', ' File "/usr/lib/python2.6/site-packages/cinder/image/image_utils.py", line 191, in qemu_img_info\n out, err = utils.execute(*cmd, run_as_root=True)\n', ' File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 142, in execute\n return processutils.execute(*cmd, **kwargs)\n', ' File "/usr/lib/python2.6/site-packages/cinder/openstack/common/processutils.py", line 173, in execute\n cmd=\' \'.join(cmd))\n', 'ProcessExecutionError: Unexpected error while running command.\nCommand: sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C LANG=C qemu-img info /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452\nExit code: 1\nStdout: \'\'\nStderr: "Could not open \'/var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452\': No such file or directory\\n"\n']
2013-10-24 16:44:04.763 2483 ERROR cinder.openstack.common.rpc.amqp [req-53eb21ec-fdee-44f4-85fe-37ea71ebf1a1 a660044c9b074450aaa45fba0d641fcc e27aae2598b94dca88cd0408406e0848] Exception during message handling
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp **args)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 808, in wrapper
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 605, in initialize_connection
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp conn_info = self.driver.initialize_connection(volume, connector)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 851, in initialize_connection
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp info = self._qemu_img_info(path)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 132, in _qemu_img_info
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp info = image_utils.qemu_img_info(path)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/image/image_utils.py", line 191, in qemu_img_info
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp out, err = utils.execute(*cmd, run_as_root=True)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 142, in execute
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp return processutils.execute(*cmd, **kwargs)
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/processutils.py", line 173, in execute
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp cmd=' '.join(cmd))
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp ProcessExecutionError: Unexpected error while running command.
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C LANG=C qemu-img info /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp Exit code: 1
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp Stdout: ''
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp Stderr: "Could not open '/var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452': No such file or directory\n"
2013-10-24 16:44:04.763 2483 TRACE cinder.openstack.common.rpc.amqp
2013-10-24 16:44:04.765 2483 ERROR cinder.openstack.common.rpc.common [req-53eb21ec-fdee-44f4-85fe-37ea71ebf1a1 a660044c9b074450aaa45fba0d641fcc e27aae2598b94dca88cd0408406e0848] Returning exception Unexpected error while running command.
Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C LANG=C qemu-img info /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452
Exit code: 1
Stdout: ''
Stderr: "Could not open '/var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452': No such file or directory\n" to caller

the volume does appear as if it exists and available in cinder list

[root@cougar06 ~(keystone_admin)]# cinder list
/usr/lib/python2.6/site-packages/babel/__init__.py:33: UserWarning: Module backports was already imported from /usr/lib64/python2.6/site-packages/backports/__init__.pyc, but /usr/lib/python2.6/site-packages is being added to sys.path
  from pkg_resources import get_distribution, ResolutionError
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
| ID | Status | Display Name | Size | Volume Type | Bootable | Attached to |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
| 0466799b-0810-4c69-a894-0f395fe89452 | available | from_vol | 10 | None | true | |
| 1e36f3ac-27ef-46ea-b5fa-686c4da9f449 | available | test | 10 | None | false | |
| 5d658297-5037-4203-9482-b072a2bc7526 | available | from_vol1 | 10 | None | true | |
| f7416ba6-af45-47d3-a333-478447a1ab54 | available | from_img | 10 | None | true | |
| f9d6b98f-8394-4a01-9424-f23897382d87 | available | dafna | 10 | None | false | |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
[root@cougar06 ~(keystone_admin)]#

but if I look under mnt its not there:

root@cougar06 ~(keystone_admin)]# ls -l /var/lib/cinder/
conversion/ mnt/ .novaclient/ tmp/
[root@cougar06 ~(keystone_admin)]# ls -l /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-
volume-1e36f3ac-27ef-46ea-b5fa-686c4da9f449 volume-f9d6b98f-8394-4a01-9424-f23897382d87
volume-f7416ba6-af45-47d3-a333-478447a1ab54 volume-f9d6b98f-8394-4a01-9424-f23897382d87.24804bb3-3846-45f8-8f24-5320e6d57184
volume-f7416ba6-af45-47d3-a333-478447a1ab54-clone volume-f9d6b98f-8394-4a01-9424-f23897382d87.73262c7c-e762-44cf-85d4-14693ab0dd31
volume-f7416ba6-af45-47d3-a333-478447a1ab54.info volume-f9d6b98f-8394-4a01-9424-f23897382d87.info
[root@cougar06 ~(keystone_admin)]# ls -l /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-^C

[Thierry Carrez (ttx)]

The error is not with rootwrap.

Cinder calls (as root) "qemu-img info /var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452"

and that fails for the following reason:
"Could not open '/var/lib/cinder/mnt/792e7ed79ec67a83b6a55e1479a7c82f/volume-0466799b-0810-4c69-a894-0f395fe89452': No such file or directory"

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/53735

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/53735
Committed: http://github.com/openstack/cinder/commit/bfb66019edd197141ea1462ba78dd27a2ed0e40d
Submitter: Jenkins
Branch: master

commit bfb66019edd197141ea1462ba78dd27a2ed0e40d
Author: Eric Harney <email address hidden>
Date: Thu Oct 24 16:18:54 2013 -0400

    GlusterFS: set correct filename when cloning volume

    When cloning a volume, the volume[name] field was populated
    with incorrect data, resulting in an unexpected filename containing
    the volume data. This results in failures of later operations on
    that cloned volume.

    Change-Id: I067ed44cebdc8e91e9ded326953fd0c99d003f05
    Closes-Bug: #1244238

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/havana
Review: https://review.openstack.org/53897

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/53897
Committed: http://github.com/openstack/cinder/commit/1f99a044580286bf0d927cc7fc7ce3378653aef0
Submitter: Jenkins
Branch: stable/havana

commit 1f99a044580286bf0d927cc7fc7ce3378653aef0
Author: Eric Harney <email address hidden>
Date: Thu Oct 24 16:18:54 2013 -0400

    GlusterFS: set correct filename when cloning volume

    When cloning a volume, the volume[name] field was populated
    with incorrect data, resulting in an unexpected filename containing
    the volume data. This results in failures of later operations on
    that cloned volume.

    Change-Id: I067ed44cebdc8e91e9ded326953fd0c99d003f05
    Closes-Bug: #1244238
    (cherry picked from commit bfb66019edd197141ea1462ba78dd27a2ed0e40d)