Target volume type is still in use

[Lee Yarwood]

https://zuul.opendev.org/t/openstack/build/bcac611ced014730b937ac9cdb54325f/log/logs/grenade.sh.txt#50087

2020-12-07 22:18:42.408 | Failed to delete volume type with name or ID 'cinder_grenade_encrypted_type': Target volume type is still in use. (HTTP 400) (Request-ID: req-ef8b701c-81c0-4b53-aeab-5e04422e869a)

[Lee Yarwood (lyarwood)]

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Target%20volume%20type%20is%20still%20in%20use%5C%22%20AND%20tags%3A%5C%22grenade.sh.txt%5C%22

Only 1 hit in the last 10 days.

[Lee Yarwood (lyarwood)]

Adding cinder as there isn't an obvious race in the test, if anything there seems to be a clear ~4 seconds or so betwee the volume being removed and the type:

https://zuul.opendev.org/t/openstack/build/bcac611ced014730b937ac9cdb54325f/log/logs/screen-c-vol.txt#6180

Dec 07 22:18:38.798924 ubuntu-bionic-ovh-gra1-0022103214 cinder-volume[11297]: DEBUG cinder.manager [req-e28cfdbe-f48c-4663-a2e8-e539e151a8af req-1fc05427-fba5-4d08-8372-67c0c648016e cinder_grenade None] Notifying Schedulers of capabilities ... {{(pid=11924) _publish_service_capabilities /opt/stack/new/cinder/cinder/manager.py:192}}
Dec 07 22:18:38.806441 ubuntu-bionic-ovh-gra1-0022103214 cinder-volume[11297]: INFO cinder.volume.manager [req-e28cfdbe-f48c-4663-a2e8-e539e151a8af req-1fc05427-fba5-4d08-8372-67c0c648016e cinder_grenade None] Deleted volume successfully.
Dec 07 22:18:38.814547 ubuntu-bionic-ovh-gra1-0022103214 cinder-volume[11297]: DEBUG cinder.coordination [req-e28cfdbe-f48c-4663-a2e8-e539e151a8af req-1fc05427-fba5-4d08-8372-67c0c648016e cinder_grenade None] Lock "/opt/stack/data/cinder/cinder-2b691f50-9232-4cae-9295-4a0931ab3e14-delete_volume" released by "delete_volume" :: held 3.011s {{(pid=11924) _synchronized /opt/stack/new/cinder/cinder/coordination.py:162}}

https://zuul.opendev.org/t/openstack/build/bcac611ced014730b937ac9cdb54325f/log/logs/screen-c-api.txt#5620

Dec 07 22:18:42.344780 ubuntu-bionic-ovh-gra1-0022103214 <email address hidden>[10439]: INFO cinder.api.openstack.wsgi [req-5bea5a3b-091a-444e-80fb-9146d5f4aebe req-ef8b701c-81c0-4b53-aeab-5e04422e869a admin admin] DELETE http://149.202.164.1/volume/v2/bf3724d5b9ef49bcbb7dd6d73b40cafc/types/9aad8653-6dbd-4405-9495-c3160d895356
[..]
Dec 07 22:18:42.403241 ubuntu-bionic-ovh-gra1-0022103214 <email address hidden>[10439]: ERROR cinder.db.sqlalchemy.api [req-5bea5a3b-091a-444e-80fb-9146d5f4aebe req-ef8b701c-81c0-4b53-aeab-5e04422e869a admin admin] VolumeType 9aad8653-6dbd-4405-9495-c3160d895356 deletion failed, VolumeType in use.

[Brian Rosmaita (brian-rosmaita)]

I'll take a look at this. I've seen this before when the image cache is enabled (not saying that's what's happening here, though).

[Lee Yarwood (lyarwood)]

Okay hit this again and this time it looks more like an issue with grenade not waiting until the volumes have been removed correctly. I'll push an update now.

https://zuul.opendev.org/t/openstack/build/bf7cd5ed54324b4dbdc1a59ed4bd74f3/log/logs/screen-c-api.txt

Dec 17 13:38:19.922285 ubuntu-bionic-ovh-bhs1-0022252682 <email address hidden>[20113]: INFO cinder.api.openstack.wsgi [req-347bc12d-73bd-4ba2-b25f-3b15eb7d7dba req-923f124a-4197-4fa5-9994-199b0e4fbf77 cinder_grenade cinder_grenade] http://158.69.75.24/volume/v2/6175a27a74e547808396a21fc6174eed/volumes/3b480911-cc3f-494f-bf2d-bdbaa347cac6 returned with HTTP 202
Dec 17 13:38:19.923499 ubuntu-bionic-ovh-bhs1-0022252682 <email address hidden>[20113]: [pid: 20115|app: 0|req: 19/36] 158.69.75.24 () {60 vars in 1389 bytes} [Thu Dec 17 13:38:19 2020] DELETE /volume/v2/6175a27a74e547808396a21fc6174eed/volumes/3b480911-cc3f-494f-bf2d-bdbaa347cac6 => generated 0 bytes in 67 msecs (HTTP/1.1 202) 4 headers in 169 bytes (1 switches on core 0)

https://zuul.opendev.org/t/openstack/build/bf7cd5ed54324b4dbdc1a59ed4bd74f3/log/logs/subnode-2/screen-c-vol.txt

Dec 17 13:38:29.887651 ubuntu-bionic-ovh-bhs1-0022252683 cinder-volume[25567]: INFO cinder.volume.manager [req-347bc12d-73bd-4ba2-b25f-3b15eb7d7dba req-923f124a-4197-4fa5-9994-199b0e4fbf77 cinder_grenade None] Deleted volume successfully.

[Lee Yarwood (lyarwood)]

https://review.opendev.org/c/openstack/grenade/+/767569

[Martin Kopec (mkopec)]

https://review.opendev.org/c/openstack/grenade/+/767569 got merged.

[Brian Rosmaita (brian-rosmaita)]

Looks like the grenade patch fixed this problem. Closing as not a cinder issue.