cinder rbd volume create error yet volume marked as available

[Edward Hope-Morley]

I have created a volume using incorrect cephx credentials. The RBD create failed as expected but the volume was still marked as available in the database by cinder.

2013-04-04 13:27:53 DEBUG [cinder.volume.manager] volume volume-8652c60b-fa45-43c0-be4d-f0415890e43a: creating lv of size 1G
2013-04-04 13:27:53 INFO [cinder.volume.manager] volume volume-8652c60b-fa45-43c0-be4d-f0415890e43a: creating
2013-04-04 13:27:53 DEBUG [cinder.utils] Running cmd (subprocess): rbd --help
2013-04-04 13:27:53 DEBUG [cinder.utils] Running cmd (subprocess): rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format
2013-04-04 13:27:53 DEBUG [cinder.utils] Result was 1
2013-04-04 13:27:53 ERROR [cinder.volume.driver] Recovering from a failed execute. Try number 1
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/cinder/volume/driver.py", line 90, in _try_execute
    self._execute(*command, **kwargs)
  File "/usr/lib/python2.7/dist-packages/cinder/utils.py", line 190, in execute
    cmd=' '.join(cmd))
ProcessExecutionError: Unexpected error while running command.
Command: rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format
Exit code: 1
Stdout: ''
Stderr: "2013-04-04 13:27:53.775829 7f9f4142d780 0 librados: client.cinder authentication error (1) Operation not permitted\nrbd: couldn't connect to the cluster!\n"
2013-04-04 13:27:54 DEBUG [cinder.utils] Running cmd (subprocess): rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format
2013-04-04 13:27:54 DEBUG [cinder.utils] Result was 1
2013-04-04 13:27:54 ERROR [cinder.volume.driver] Recovering from a failed execute. Try number 2
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/cinder/volume/driver.py", line 90, in _try_execute
    self._execute(*command, **kwargs)
  File "/usr/lib/python2.7/dist-packages/cinder/utils.py", line 190, in execute
    cmd=' '.join(cmd))
ProcessExecutionError: Unexpected error while running command.
Command: rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format
Exit code: 1
Stdout: ''
Stderr: "2013-04-04 13:27:54.808940 7fe419195780 0 librados: client.cinder authentication error (1) Operation not permitted\nrbd: couldn't connect to the cluster!\n"
2013-04-04 13:27:58 DEBUG [cinder.utils] Running cmd (subprocess): rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format
2013-04-04 13:27:58 DEBUG [cinder.utils] Result was 1
2013-04-04 13:27:58 DEBUG [cinder.volume.manager] volume 8652c60b-fa45-43c0-be4d-f0415890e43a: re-scheduling create_volume attempt 1
2013-04-04 13:27:58 DEBUG [cinder.openstack.common.rpc.amqp] Making asynchronous cast on cinder-scheduler...
2013-04-04 13:27:58 DEBUG [cinder.openstack.common.rpc.amqp] UNIQUE_ID is b61bdf76479d4277a4413747217c204b.
2013-04-04 13:27:58 ERROR [cinder.volume.manager] Error: ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 251, in create_volume\n image_location)\n', ' File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 168, in _create_volume\n model_update = self.driver.create_volume(volume_ref)\n', ' File "/usr/lib/python2.7/dist-packages/cinder/volume/drivers/rbd.py", line 117, in create_volume\n self._try_execute(*args)\n', ' File "/usr/lib/python2.7/dist-packages/cinder/volume/driver.py", line 90, in _try_execute\n self._execute(*command, **kwargs)\n', ' File "/usr/lib/python2.7/dist-packages/cinder/utils.py", line 190, in execute\n cmd=\' \'.join(cmd))\n', 'ProcessExecutionError: Unexpected error while running command.\nCommand: rbd create --pool volumes --size 1024 volume-8652c60b-fa45-43c0-be4d-f0415890e43a --new-format\nExit code: 1\nStdout: \'\'\nStderr: "2013-04-04 13:27:58.840719 7f5c14afe780 0 librados: client.cinder authentication error (1) Operation not permitted\\nrbd: couldn\'t connect to the cluster!\\n"\n']
2013-04-04 13:27:58 DEBUG [cinder.volume.manager] volume volume-8652c60b-fa45-43c0-be4d-f0415890e43a: creating export
2013-04-04 13:27:58 INFO [cinder.volume.manager] volume volume-8652c60b-fa45-43c0-be4d-f0415890e43a: created successfully

[Edward Hope-Morley (hopem)]

This bug was raised on Ubuntu Precise 12.04 for cinder-volume 1:2013.1~rc3-0ubuntu1~cloud0

[Josh Durgin (jdurgin)]

This is probably the same underlying issue as bug #1159027

[Edward Hope-Morley (hopem)]

jdurgin: agreed. #1159027 does prevent the volume from entering the 'available' state but it only partially fixes the whole problem since I notice that the volume then stays in 'creating' state indefinitely. I presume we would want the volume to go to 'error' after a finite number of re-schedules?

[David Medberry (med)]

does bug #1164857 also fix the underlying "creating" state here?

[John Griffith (john-griffith)]

Any Ceph folks able to confirm if this is a duplicate and if it's fixed or not?

[John Griffith (john-griffith)]

marking incomplete as it's just been sitting idle for months

[Jon Bernard (jbernard)]

It looks like this is no longer a bug. If either the user or password are incorrect, cinder-volume will faill to initailze the backend when conneting to the cluster. If the user and password are correct but capabilities do not allow volume creation to occur, then we get permission denied and the created volume immediately enters the 'error' state.