← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 2125840] [NEW] Cinder: Multiattach volume locks doesn't work as expected

 

Public bug reported:

The attachment state manager[1] uses threading locks which doesn't work well when multiple processes are working on the same image-volume resource.
With the glance uwsgi deployment model, each glance process is independent of the other and doesn't recognize the locks acquired/released in other processes since they are threading locks.
This could be problematic if two different processes think it's OK to disconnect volume from the host when the other process is writing using the same image-volume.

We can handle this by replacing the threading locks with process
locks/file locks to be shared across all glance processes but a simpler
and more straightforward way is to rely on Cinder DB information
regarding attachments and decide if we want to disconnect the volume or
not (>1 attachment on same host).

Nova handles this by counting number of attachments on same host[2] but it's not trivial for the glance case since we don't have information about the host of the attachment.
We can get this from volume info but cinder currently doesn't expose this information for non-admins[3].

Following is the reproducer:
I've a devstack master setup with 4 glance workers
stack    1126342  0.0  0.1  61476 17232 ?        Ss   14:16   0:00 glance-apiuWSGI master
stack    1126345  0.1  0.9 587312 150444 ?       Sl   14:16   0:02 glance-apiuWSGI worker 1
stack    1126346  0.1  0.9 513496 150124 ?       Sl   14:16   0:02 glance-apiuWSGI worker 2
stack    1126347  0.1  0.9 587296 150404 ?       Sl   14:16   0:02 glance-apiuWSGI worker 3
stack    1126348  0.1  0.9 595216 158088 ?       Sl   14:16   0:02 glance-apiuWSGI worker 4

With the following diff[4], I was able to see the issue:

With the logs[5], you can see multiple attach and detach requests overlapping, not to mention that attach and detach acquire same lock so even those requests shouldn't overlap.
Here are two examples of two attach requests overlapping with different PIDs

1.
PID 1126347
PID 1126345

Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}

2.
PID 1126348
PID 1126346

Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}      
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126346]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126346) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}

[1] https://github.com/openstack/glance_store/blob/111b04f54573933bf193f819f9e216c97e68de96/glance_store/common/attachment_state_manager.py
[2] https://github.com/openstack/nova/blob/b99a882366251f88d145e27312b94692e0b2266f/nova/virt/libvirt/driver.py#L2051
[3] https://github.com/openstack/cinder/blob/8064195521f9f511f630ff63b5dde1e88ff53e18/cinder/api/v2/views/volumes.py#L131-L132
[4] 
diff --git a/glance_store/common/attachment_state_manager.py b/glance_store/common/attachment_state_manager.py
index 04cad12..81ef166 100644
--- a/glance_store/common/attachment_state_manager.py
+++ b/glance_store/common/attachment_state_manager.py
@@ -187,6 +187,7 @@ class _AttachmentState(object):
         with self._get_locked(volume_id) as vol_attachment:
 
             try:
+                LOG.debug("++++ LOCKING for attaching volume %s", volume_id)
                 attachment = self.volume_api.attachment_create(
                     client, volume_id, mode=mode)
             except Exception:
@@ -197,6 +198,7 @@ class _AttachmentState(object):
 
             vol_attachment.add_attachment(attachment['id'], host)
 
+        LOG.debug("++++ UNLOCKING after attaching volume %s", volume_id)
         LOG.debug('_AttachmentState.attach for volume_id=%(volume_id)s '
                   'and attachment_id=%(attachment_id)s completed successfully',
                   {'volume_id': volume_id, 'attachment_id': attachment['id']})
@@ -222,6 +224,7 @@ class _AttachmentState(object):
                   {'volume_id': volume_id, 'attachment_id': attachment_id})
         with self._get_locked(volume_id) as vol_attachment:
             try:
+                LOG.debug("---- LOCKING for detaching volume %s", volume_id)
                 vol_attachment.remove_attachment(attachment_id, host)
             except KeyError:
                 LOG.warning(_LW("Request to remove attachment "
@@ -230,8 +233,10 @@ class _AttachmentState(object):
                             {'volume_id': volume_id, 'host': host})
 
             if not vol_attachment.in_use():
+                LOG.debug("**** INSIDE CHECK FOR disconnect volume %s", volume_id)
                 conn.disconnect_volume(device)
                 del self.volumes[volume_id]
+            LOG.debug("**** OUTSIDE CHECK FOR disconnect volume %s", volume_id)
             self.volume_api.attachment_delete(client, attachment_id)
 
             LOG.debug('_AttachmentState.detach for volume %(volume_id)s '
@@ -239,6 +244,7 @@ class _AttachmentState(object):
                       'successfully',
                       {'volume_id': volume_id,
                        'attachment_id': attachment_id})
+        LOG.debug("---- UNLOCKING for detaching volume %s", volume_id)
 
 
 __manager__ = _AttachmentStateManager(HOST)


[5] 
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}  
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ UNLOCKING after attachi
ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ LOCKING for attaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}      
Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126346]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126346) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
Sep 27 14:18:08 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ---- LOCKING for detaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}  
Sep 27 14:18:08 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] **** INSIDE CHECK FOR discon
nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
Sep 27 14:18:09 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] **** OUTSIDE CHECK FOR disco
nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
Sep 27 14:18:09 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ UNLOCKING after attachi
ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
Sep 27 14:18:11 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ---- UNLOCKING for detaching
 volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
Sep 27 14:18:11 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ++++ LOCKING for attaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}
Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ---- LOCKING for detaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] **** INSIDE CHECK FOR discon
nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] **** OUTSIDE CHECK FOR disco
nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
Sep 27 14:18:17 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ UNLOCKING after attachi
ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
Sep 27 14:18:19 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ---- UNLOCKING for detaching
 volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ---- LOCKING for detaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] **** INSIDE CHECK FOR discon
nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] **** OUTSIDE CHECK FOR disco
nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
Sep 27 14:18:25 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ++++ UNLOCKING after attachi
ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
Sep 27 14:18:27 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}
Sep 27 14:18:27 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ---- UNLOCKING for detaching
 volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
Sep 27 14:18:33 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ UNLOCKING after attachi
ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ---- LOCKING for detaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] **** INSIDE CHECK FOR discon
nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] **** OUTSIDE CHECK FOR disco
nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
Sep 27 14:18:37 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ---- UNLOCKING for detaching
 volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
Sep 27 14:18:48 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ---- LOCKING for detaching v
olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
Sep 27 14:18:48 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] **** INSIDE CHECK FOR discon
nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
Sep 27 14:18:49 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] **** OUTSIDE CHECK FOR disco
nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
Sep 27 14:18:51 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ---- UNLOCKING for detaching
 volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}

** Affects: glance-store
     Importance: Undecided
         Status: New

** Project changed: glance => glance-store

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/2125840

Title:
  Cinder: Multiattach volume locks doesn't work as expected

Status in glance_store:
  New

Bug description:
  The attachment state manager[1] uses threading locks which doesn't work well when multiple processes are working on the same image-volume resource.
  With the glance uwsgi deployment model, each glance process is independent of the other and doesn't recognize the locks acquired/released in other processes since they are threading locks.
  This could be problematic if two different processes think it's OK to disconnect volume from the host when the other process is writing using the same image-volume.

  We can handle this by replacing the threading locks with process
  locks/file locks to be shared across all glance processes but a
  simpler and more straightforward way is to rely on Cinder DB
  information regarding attachments and decide if we want to disconnect
  the volume or not (>1 attachment on same host).

  Nova handles this by counting number of attachments on same host[2] but it's not trivial for the glance case since we don't have information about the host of the attachment.
  We can get this from volume info but cinder currently doesn't expose this information for non-admins[3].

  Following is the reproducer:
  I've a devstack master setup with 4 glance workers
  stack    1126342  0.0  0.1  61476 17232 ?        Ss   14:16   0:00 glance-apiuWSGI master
  stack    1126345  0.1  0.9 587312 150444 ?       Sl   14:16   0:02 glance-apiuWSGI worker 1
  stack    1126346  0.1  0.9 513496 150124 ?       Sl   14:16   0:02 glance-apiuWSGI worker 2
  stack    1126347  0.1  0.9 587296 150404 ?       Sl   14:16   0:02 glance-apiuWSGI worker 3
  stack    1126348  0.1  0.9 595216 158088 ?       Sl   14:16   0:02 glance-apiuWSGI worker 4

  With the following diff[4], I was able to see the issue:

  With the logs[5], you can see multiple attach and detach requests overlapping, not to mention that attach and detach acquire same lock so even those requests shouldn't overlap.
  Here are two examples of two attach requests overlapping with different PIDs

  1.
  PID 1126347
  PID 1126345

  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}

  2.
  PID 1126348
  PID 1126346

  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}      
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126346]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126346) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}

  [1] https://github.com/openstack/glance_store/blob/111b04f54573933bf193f819f9e216c97e68de96/glance_store/common/attachment_state_manager.py
  [2] https://github.com/openstack/nova/blob/b99a882366251f88d145e27312b94692e0b2266f/nova/virt/libvirt/driver.py#L2051
  [3] https://github.com/openstack/cinder/blob/8064195521f9f511f630ff63b5dde1e88ff53e18/cinder/api/v2/views/volumes.py#L131-L132
  [4] 
  diff --git a/glance_store/common/attachment_state_manager.py b/glance_store/common/attachment_state_manager.py
  index 04cad12..81ef166 100644
  --- a/glance_store/common/attachment_state_manager.py
  +++ b/glance_store/common/attachment_state_manager.py
  @@ -187,6 +187,7 @@ class _AttachmentState(object):
           with self._get_locked(volume_id) as vol_attachment:
   
               try:
  +                LOG.debug("++++ LOCKING for attaching volume %s", volume_id)
                   attachment = self.volume_api.attachment_create(
                       client, volume_id, mode=mode)
               except Exception:
  @@ -197,6 +198,7 @@ class _AttachmentState(object):
   
               vol_attachment.add_attachment(attachment['id'], host)
   
  +        LOG.debug("++++ UNLOCKING after attaching volume %s", volume_id)
           LOG.debug('_AttachmentState.attach for volume_id=%(volume_id)s '
                     'and attachment_id=%(attachment_id)s completed successfully',
                     {'volume_id': volume_id, 'attachment_id': attachment['id']})
  @@ -222,6 +224,7 @@ class _AttachmentState(object):
                     {'volume_id': volume_id, 'attachment_id': attachment_id})
           with self._get_locked(volume_id) as vol_attachment:
               try:
  +                LOG.debug("---- LOCKING for detaching volume %s", volume_id)
                   vol_attachment.remove_attachment(attachment_id, host)
               except KeyError:
                   LOG.warning(_LW("Request to remove attachment "
  @@ -230,8 +233,10 @@ class _AttachmentState(object):
                               {'volume_id': volume_id, 'host': host})
   
               if not vol_attachment.in_use():
  +                LOG.debug("**** INSIDE CHECK FOR disconnect volume %s", volume_id)
                   conn.disconnect_volume(device)
                   del self.volumes[volume_id]
  +            LOG.debug("**** OUTSIDE CHECK FOR disconnect volume %s", volume_id)
               self.volume_api.attachment_delete(client, attachment_id)
   
               LOG.debug('_AttachmentState.detach for volume %(volume_id)s '
  @@ -239,6 +244,7 @@ class _AttachmentState(object):
                         'successfully',
                         {'volume_id': volume_id,
                          'attachment_id': attachment_id})
  +        LOG.debug("---- UNLOCKING for detaching volume %s", volume_id)
   
   
   __manager__ = _AttachmentStateManager(HOST)

  
  [5] 
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ LOCKING for attaching volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}  
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ++++ UNLOCKING after attachi
  ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ LOCKING for attaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}      
  Sep 27 14:18:03 rdhasman-glance-cinder devstack@g-api.service[1126346]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126346) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}       
  Sep 27 14:18:08 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ---- LOCKING for detaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}  
  Sep 27 14:18:08 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] **** INSIDE CHECK FOR discon
  nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
  Sep 27 14:18:09 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] **** OUTSIDE CHECK FOR disco
  nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
  Sep 27 14:18:09 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ++++ UNLOCKING after attachi
  ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
  Sep 27 14:18:11 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-fc1e7d6d-0782-4640-b52a-aa7dc3f2b4a4 admin admin] ---- UNLOCKING for detaching
   volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
  Sep 27 14:18:11 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ++++ LOCKING for attaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}
  Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ---- LOCKING for detaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
  Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] **** INSIDE CHECK FOR discon
  nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
  Sep 27 14:18:16 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] **** OUTSIDE CHECK FOR disco
  nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
  Sep 27 14:18:17 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ++++ UNLOCKING after attachi
  ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
  Sep 27 14:18:19 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-04c4e0ca-b4f3-4142-b7f5-72d089bd394c admin admin] ---- UNLOCKING for detaching
   volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
  Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ---- LOCKING for detaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
  Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] **** INSIDE CHECK FOR discon
  nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
  Sep 27 14:18:24 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] **** OUTSIDE CHECK FOR disco
  nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
  Sep 27 14:18:25 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ++++ UNLOCKING after attachi
  ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
  Sep 27 14:18:27 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ LOCKING for attaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:190}}
  Sep 27 14:18:27 rdhasman-glance-cinder devstack@g-api.service[1126348]: DEBUG glance_store.common.attachment_state_manager [None req-b7ddde39-715b-4dd6-9b98-95e53d003b36 admin admin] ---- UNLOCKING for detaching
   volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126348) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
  Sep 27 14:18:33 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ++++ UNLOCKING after attachi
  ng volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) attach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:201}}
  Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ---- LOCKING for detaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
  Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] **** INSIDE CHECK FOR discon
  nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
  Sep 27 14:18:34 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] **** OUTSIDE CHECK FOR disco
  nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
  Sep 27 14:18:37 rdhasman-glance-cinder devstack@g-api.service[1126345]: DEBUG glance_store.common.attachment_state_manager [None req-404adb88-8eda-4937-b2f9-ac1128d0b52e admin admin] ---- UNLOCKING for detaching
   volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126345) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}
  Sep 27 14:18:48 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ---- LOCKING for detaching v
  olume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:227}}
  Sep 27 14:18:48 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] **** INSIDE CHECK FOR discon
  nect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:236}}
  Sep 27 14:18:49 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] **** OUTSIDE CHECK FOR disco
  nnect volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:239}}
  Sep 27 14:18:51 rdhasman-glance-cinder devstack@g-api.service[1126347]: DEBUG glance_store.common.attachment_state_manager [None req-b9a53b1d-7582-417e-ab01-86ce067a62a5 admin admin] ---- UNLOCKING for detaching
   volume 62db8429-94b9-4f32-aff8-042f030b40c5 {{(pid=1126347) detach /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/common/attachment_state_manager.py:247}}

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance-store/+bug/2125840/+subscriptions