barbican scenarios do not take soft deletion logic into account and take a long time to complete while waiting for secret deletion timeouts to happen

Bug #1819284 reported by Dmitrii Shcherbakov on 2019-03-09
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Rally
Undecided
chenhb

Bug Description

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).

A "workaround" is to set resource_deletion_timeout to a smaller value.

$ cat ~/.rally/rally.conf
[openstack]
resource_deletion_timeout = 20

description: updated
chenhb (chen-haibing1) on 2019-04-20
Changed in rally:
assignee: nobody → chenhb (chen-haibing1)
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers