volume is not deleted in cinder db

[Adalberto Medeiros]

I have the IBM v7000 Storwize storage connected to the controller server and cinder configured to manage it.

I'm running openstack grizzly, on Fedora 19, installed by packstack.

I added one volume, it successfully created the volume on the san storage.
 When i tried to delete it, it deletes the volume from the storage but not from cinder database (keeps it in "deleting" state).

The failure and debug info (from cinder/volume.log)

2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] leave: do_setup
2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] enter: check_for_setup_error
2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] leave: check_for_setup_error
2013-08-07 14:39:32 DEBUG [cinder.utils] backend <module 'cinder.db.sqlalchemy.api' from '/usr/lib/python2.7/site-packages/cinder/db/sqlalchemy/api.pyc'>
2013-08-07 14:39:32 DEBUG [cinder.volume.manager] Re-exporting 1 volumes
2013-08-07 14:39:32 INFO [cinder.volume.manager] volume volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8: skipping export
2013-08-07 14:39:32 DEBUG [cinder.volume.manager] Resuming any in progress delete operations
2013-08-07 14:39:32 INFO [cinder.volume.manager] Resuming delete on volume: b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:32 INFO [cinder.volume.manager] volume volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8: deleting
2013-08-07 14:39:32 INFO [cinder.volume.manager] Clear capabilities
2013-08-07 14:39:32 DEBUG [cinder.volume.manager] volume volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8: removing export
2013-08-07 14:39:32 DEBUG [cinder.volume.manager] volume volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8: deleting
2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] enter: _delete_vdisk: vdisk volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] enter: _is_vdisk_defined: vdisk volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:32 DEBUG [cinder.volume.drivers.storwize_svc] enter: _execute_command_and_parse_attributes: command lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:32 DEBUG [cinder.utils] Running cmd (SSH): lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:32 DEBUG [cinder.utils] Result was 1
2013-08-07 14:39:32 ERROR [cinder.volume.drivers.san.san] Unexpected error while running command.
Command: lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
Exit code: 1
Stdout: ''
Stderr: 'CMMVC5754E The specified object does not exist, or the name supplied does not meet the naming rules.\n'
2013-08-07 14:39:33 ERROR [cinder.volume.drivers.san.san] Error running SSH command: lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2013-08-07 14:39:33 ERROR [cinder.volume.drivers.storwize_svc] CLI Exception output:
 command: lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
 stdout:
 stderr: CMMVC5754E The specified object does not exist, or the name supplied does not meet the naming rules.

2013-08-07 14:39:33 DEBUG [cinder.volume.drivers.storwize_svc] leave: _is_vdisk_defined: vdisk volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8 with False
2013-08-07 14:39:33 INFO [cinder.volume.drivers.storwize_svc] warning: Tried to delete vdisk volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8 but it does not exist.
2013-08-07 14:39:33 DEBUG [cinder.quota] Created reservations ['279b2eaf-ad09-433d-a095-dd9c9d908fe8', 'f7f978e3-adf0-4641-91ca-7b60fd90feeb']
2013-08-07 14:39:33 ERROR [cinder.service] Unhandled exception
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cinder/service.py", line 224, in _start_child
    self._child_process(wrap.server)
  File "/usr/lib/python2.7/site-packages/cinder/service.py", line 201, in _child_process
    launcher.run_server(server)
  File "/usr/lib/python2.7/site-packages/cinder/service.py", line 95, in run_server
    server.start()
  File "/usr/lib/python2.7/site-packages/cinder/service.py", line 342, in start
    self.manager.init_host()
  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 157, in init_host
    self.delete_volume(ctxt, volume['id'])
  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 439, in delete_volume
    self.db.volume_glance_metadata_delete_by_volume(context, volume_id)
  File "/usr/lib/python2.7/site-packages/cinder/db/api.py", line 457, in volume_glance_metadata_delete_by_volume
    return IMPL.volume_glance_metadata_delete_by_volume(context, volume_id)
  File "/usr/lib/python2.7/site-packages/cinder/db/sqlalchemy/api.py", line 123, in wrapper
    return f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/cinder/db/sqlalchemy/api.py", line 1744, in volume_glance_metadata_delete_by_volume
    'updated_at': literal_column('updated_at')})
  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2505, in update
    update_op.exec_()
  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 812, in exec_
    self._do_pre_synchronize()
  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 863, in _do_pre_synchronize
    "Could not evaluate current criteria in Python. "
InvalidRequestError: Could not evaluate current criteria in Python. Specify 'fetch' or False for the synchronize_session parameter.

relevant cinder.conf info:

storwize_svc_volpool_name=pub-cloud
#storwize_svc_vol_rsize=2%
storwize_svc_vol_warning=0
storwize_svc_vol_autoexpand=true
storwize_svc_vol_grainsize=256
storwize_svc_vol_compression=false
storwize_svc_vol_easytier=true
storwize_svc_flashcopy_timeout=120
san_ip=9.114.219.37
san_login=****
san_password=****
san_clustername=Cinder
san_is_local=false
volume_driver=cinder.volume.drivers.storwize_svc.StorwizeSVCDriver

[Avishay Traeger (avishay-il)]

Hi Adalberto,
There seem to be two issues here:
1. The driver cannot find the volume. Is it in fact there? What is the output of:
    lsvdisk -bytes -delim ! volume-b221d0c6-c1dd-488a-a80d-ffb27163adf8
2. There is an issue not related to the driver when Cinder calls self.db.volume_glance_metadata_delete_by_volume. I will look into this.

[Adalberto Medeiros (adalbas)]

Avishay,

1- Yes, the volume got deleted, what explains the message: 'CMMVC5754E The specified object does not exist, or the name supplied does not meet the naming rules.\n'

2-As you suggest,, i can look at what changed in the specific function. I also found some info around about the error
"InvalidRequestError: Could not evaluate current criteria in Python. Specify 'fetch' or False for the synchronize_session parameter."
http://stackoverflow.com/questions/7892618/sqlalchemy-delete-subquery
http://docs.sqlalchemy.org/en/rel_0_8/orm/query.html#sqlalchemy.orm.query.Query.de
I ll check if those might apply.

[Adalberto Medeiros (adalbas)]

From debugging this, sqlalchemy does not handle this exception if it tries to update an empty row.

This means that volume_create did not added volume_glance_metadata data when creating a base volume and, when trying to delete it, it didn't handle the returned exception.

Proposing a patch to change this at the cinder manager level.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/41768
Committed: http://github.com/openstack/cinder/commit/8b35b1d714444a385a200e3e006ce3af84dae3c9
Submitter: Jenkins
Branch: master

commit 8b35b1d714444a385a200e3e006ce3af84dae3c9
Author: Adalberto Medeiros <email address hidden>
Date: Tue Aug 13 14:50:24 2013 -0400

    Fix volume_glance_metadata deletion

    If volume_glance_metadata does not exist for a certain volume,
    it returns an exception and does not delete volume from db.
    Avoid deleting it if it does not exist.

    Bug: 1209367
    Change-Id: Ia607ec5ecfc115c1a593f14236ee93158938a8da

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/grizzly
Review: https://review.openstack.org/43933

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/43933
Committed: http://github.com/openstack/cinder/commit/bd47a4f4ec5340b93c9878670c6b06883adb1b92
Submitter: Jenkins
Branch: stable/grizzly

commit bd47a4f4ec5340b93c9878670c6b06883adb1b92
Author: Adalberto Medeiros <email address hidden>
Date: Tue Aug 27 14:19:09 2013 -0400

    Fix volume_glance_metadata deletion (backport)

    Backport patch https://review.openstack.org/#/c/41768/ and
    its dependency: https://review.openstack.org/#/c/41601/
    (no snapshot handling exception, for this is not trivial
    due to specific havana changes)

    If volume_glance_metadata does not exist for a certain volume,
    it returns an exception and does not delete volume from db.
    Avoid deleting it if it does not exist.

    Fixes bug: 1209367

    Change-Id: Icb34c90b13aac1e92b4645c3016127a2d4b8af6f