Comment 0 for bug 1819284

Revision history for this message
Dmitrii Shcherbakov (dmitriis) wrote :

rally-openstack commit used: 992419828496abe48a6dedc71416ea8bebb87e77

In the outputs below a cleanup process started at 17:53:07.080 and secret objects were marked as deleted_at at 17:53:15 with deleted == 1. They are still present as entries in the database though due to the soft deletion logic in used Barbican. As a result rally_openstack.cleanup.manager waits for a long time (10 minutes == CONF.openstack.resource_deletion_timeout) before finally timing out on resource deletion and successfully completing a task.

https://github.com/openstack/barbican/blob/stable/rocky/doc/source/admin/database_cleaning.rst
"Entries in the Barbican database are soft deleted and can build up over time. These entries can be cleaned up with the clean up command. The command can be used with a cron job to clean the database automatically on intervals."
"The command `barbican-manage db clean` can be used to clean up the database. By default, it will remove soft deletions that are at least 90 days old since deletion"

2019-03-09 17:53:05.305 938 INFO rally.task.context [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | Context admin_cleanup@openstack setup() finished in 0.00 msec
2019-03-09 17:53:05.332 1095 INFO rally.task.runner [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | ITER: 1 START
2019-03-09 17:53:06.477 1095 INFO rally.task.runner [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | ITER: 1 END: OK
2019-03-09 17:53:06.480 1095 INFO rally.task.runner [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | ITER: 2 START
2019-03-09 17:53:07.059 1095 INFO rally.task.runner [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | ITER: 2 END: OK
2019-03-09 17:53:07.080 938 INFO rally.task.context [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | Context admin_cleanup@openstack cleanup() started
2019-03-09 18:03:09.460 938 WARNING rally_openstack.cleanup.manager [-] Resource deletion failed, timeout occurred for barbican.secrets: http://10.232.7.67:9312/v1/secrets/c674455f-3889-4313-b460-5c3dbdd773af.
2019-03-09 18:03:09.512 938 WARNING rally_openstack.cleanup.manager [-] Resource deletion failed, timeout occurred for barbican.secrets: http://10.232.7.67:9312/v1/secrets/33f94ec9-a7ae-4530-80d7-5287ee9b2d87.
2019-03-09 18:03:10.216 938 INFO rally.task.context [-] Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a | Context admin_cleanup@openstack cleanup() finished in 10.05 min

# ...

Task a4cb0e22-6d11-4fe4-bb7b-cb3ff82dd69a has 0 error(s)
--------------------------------------------------------------------------------

+---------------------------------------------------------------------------------------------------------------------------+
| Response Times (sec) |
+------------------------+-----------+--------------+--------------+--------------+-----------+-----------+---------+-------+
| Action | Min (sec) | Median (sec) | 90%ile (sec) | 95%ile (sec) | Max (sec) | Avg (sec) | Success | Count |
+------------------------+-----------+--------------+--------------+--------------+-----------+-----------+---------+-------+
| barbican.create_secret | 0.528 | 0.813 | 1.04 | 1.069 | 1.097 | 0.813 | 100.0% | 2 |
| barbican.list_secrets | 0.045 | 0.047 | 0.049 | 0.049 | 0.049 | 0.047 | 100.0% | 2 |
| total | 0.578 | 0.86 | 1.086 | 1.114 | 1.142 | 0.86 | 100.0% | 2 |
| -> duration | 0.578 | 0.86 | 1.086 | 1.114 | 1.142 | 0.86 | 100.0% | 2 |
| -> idle_duration | 0.0 | 0.0 | 0.0 | 0.0 | 0.0 | 0.0 | 100.0% | 2 |
+------------------------+-----------+--------------+--------------+--------------+-----------+-----------+---------+-------+

mysql> select * from secrets where id = '33f94ec9-a7ae-4530-80d7-5287ee9b2d87' or id = 'c674455f-3889-4313-b460-5c3dbdd773af';
+--------------------------------------+---------------------+---------------------+---------------------+---------+--------+---------------------------+-------------+------------+-----------+------------+------+----------------------------------+--------------------------------------+
| id | created_at | updated_at | deleted_at | deleted | status | name | secret_type | expiration | algorithm | bit_length | mode | creator_id | project_id |
+--------------------------------------+---------------------+---------------------+---------------------+---------+--------+---------------------------+-------------+------------+-----------+------------+------+----------------------------------+--------------------------------------+
| 33f94ec9-a7ae-4530-80d7-5287ee9b2d87 | 2019-03-09 17:53:13 | 2019-03-09 17:53:15 | 2019-03-09 17:53:15 | 1 | ACTIVE | s_rally_27f25241_fhhg2H44 | opaque | NULL | NULL | NULL | NULL | ee466a2722304b529ce58178daa6fc7e | 50803ebc-30c9-4a6f-8715-d072b3d7930c |
| c674455f-3889-4313-b460-5c3dbdd773af | 2019-03-09 17:53:14 | 2019-03-09 17:53:15 | 2019-03-09 17:53:15 | 1 | ACTIVE | s_rally_27f25241_8TXdRVNb | opaque | NULL | NULL | NULL | NULL | ee466a2722304b529ce58178daa6fc7e | 50803ebc-30c9-4a6f-8715-d072b3d7930c |
+--------------------------------------+---------------------+---------------------+---------------------+---------+--------+---------------------------+-------------+------------+-----------+------------+------+----------------------------------+--------------------------------------+
2 rows in set (0.00 sec)

The project set up by rally is gone although the entries are still present. '50803ebc-30c9-4a6f-8715-d072b3d7930c' is used as a project id for all deleted entries regardless of the test run (I have done several and all of them use that ID).