+++ This bug was initially created as a clone of Bug #1777906 +++ Description of problem: ()[root@overcloud-controller-01 /]# cat /var/spool/cron/cinder # HEADER: This file was autogenerated at 2019-11-16 08:33:00 +0000 by puppet. # HEADER: While it can still be managed manually, it is definitely not recommended. # HEADER: Note particularly that the comments starting with 'Puppet Name' should # HEADER: not be deleted, as doing so could cause duplicate cron jobs. # Puppet Name: cinder-manage db purge PATH=/bin:/usr/bin:/usr/sbin SHELL=/bin/sh 1 0 * * * cinder-manage db purge 30 >>/var/log/cinder/cinder-rowsflush.log 2>&1 ()[root@overcloud-controller-01 /]# cinder-manage db purge 30 Option "logdir" from group "DEFAULT" is deprecated. Use option "log-dir" from group "DEFAULT". Purge command failed, check cinder-manage logs for more details. ()[root@overcloud-controller-01 /]# cinder-manage logs errors Option "logdir" from group "DEFAULT" is deprecated. Use option "log-dir" from group "DEFAULT". DEPRECATED: The log commands are deprecated since Queens and are not maintained. They will be removed in an upcoming release. /var/log/cinder/cinder-manage.log:- Line 14 : 2019-11-28 14:19:10.181 1649 ERROR cinder.db.sqlalchemy.api [req-f9a046ec-1386-4485-948d-3318cc74982a - - - - -] DBError detected when purging from volumes: (pymysql.err.IntegrityError) (1451, u'Cannot delete or update a parent row: a foreign key constraint fails (`cinder`.`volume_attachment`, CONSTRAINT `volume_attachment_ibfk_1` FOREIGN KEY (`volume_id`) REFERENCES `volumes` (`id`))') [SQL: u'DELETE FROM volumes WHERE volumes.deleted_at < %(deleted_at_1)s'] [parameters: {u'deleted_at_1': datetime.datetime(2019, 10, 29, 14, 19, 6, 707533)}] (Background on this error at: http://sqlalche.me/e/gkpj).: DBReferenceError: (pymysql.err.IntegrityError) (1451, u'Cannot delete or update a parent row: a foreign key constraint fails (`cinder`.`volume_attachment`, CONSTRAINT `volume_attachment_ibfk_1` FOREIGN KEY (`volume_id`) REFERENCES `volumes` (`id`))') [SQL: u'DELETE FROM volumes WHERE volumes.deleted_at < %(deleted_at_1)s'] [parameters: {u'deleted_at_1': datetime.datetime(2019, 10, 29, 14, 19, 6, 707533)}] (Background on this error at: http://sqlalche.me/e/gkpj) Version-Release number of selected component (if applicable): Latest How reproducible: Now Steps to Reproduce: 1. Don't know yet 2. 3. Actual results: Fails to archive deleted rows and they are accumulating until cinder-volume stops working Expected results: Never fails to archive deleted rows Additional info:
According to our records, this should be resolved by openstack-cinder-15.0.2-0.20200123220928.900f769.el8ost. This build is available now.
Verified on: openstack-cinder-15.0.2-0.20200123220928.900f769.el8ost.noarch Created two cinder volumes: (overcloud) [stack@undercloud-0 ~]$ cinder list +--------------------------------------+-----------+------------+------+-------------+----------+-------------+ | ID | Status | Name | Size | Volume Type | Bootable | Attached to | +--------------------------------------+-----------+------------+------+-------------+----------+-------------+ | b35ddb64-8783-46ab-8d08-b40ad456bb02 | available | tshefivol2 | 4 | tripleo | false | | | f3c38fae-3316-4bf0-92ec-9396eb407a2c | available | tshefiVol1 | 1 | tripleo | false | | +--------------------------------------+-----------+------------+------+-------------+----------+-------------+ Deleted both volumes (overcloud) [stack@undercloud-0 ~]$ cinder delete b35ddb64-8783-46ab-8d08-b40ad456bb02 f3c38fae-3316-4bf0-92ec-9396eb407a2c Request to delete volume b35ddb64-8783-46ab-8d08-b40ad456bb02 has been accepted. Request to delete volume f3c38fae-3316-4bf0-92ec-9396eb407a2c has been accepted. On C-vol podman run: cinder-manage db purge 0 Cinder manage log, reports purging 2 rows from DB as expected. 2020-03-30 10:45:04.044 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Purging deleted rows older than age=0 days from table=volumes 2020-03-30 10:45:04.051 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Deleted 2 rows from table=volumes 2020-03-30 10:45:04.052 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Purging deleted rows older than age=0 days from table=volume_types 2020-03-30 10:45:04.055 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Purging deleted rows older than age=0 days from table=reservations 2020-03-30 10:45:04.069 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Deleted 16 rows from table=reservations 2020-03-30 10:45:04.069 480 INFO cinder.db.sqlalchemy.api [req-ed86af05-fd7a-46e0-b925-858f885cff31 - - - - -] Purging deleted rows older than age=0 days from table=group_type_specs Login to the DB check to verify the volumes are absent/purged. Before doing this I created a new volume just to validate that it will show up (none deleted/purged) (overcloud) [stack@undercloud-0 ~]$ cinder create 1 --name postPurge +--------------------------------+--------------------------------------+ | Property | Value | +--------------------------------+--------------------------------------+ | attachments | [] | | availability_zone | nova | | bootable | false | | consistencygroup_id | None | | created_at | 2020-03-30T10:51:59.000000 | | description | None | | encrypted | False | | id | 1f3867b4-9711-4952-bf96-47aba686f695 | | metadata | {} | | migration_status | None | | multiattach | False | | name | postPurge | | os-vol-host-attr:host | None | | os-vol-mig-status-attr:migstat | None | | os-vol-mig-status-attr:name_id | None | | os-vol-tenant-attr:tenant_id | d9bf086d581449209ef3d577d005c241 | | replication_status | None | | size | 1 | | snapshot_id | None | | source_volid | None | | status | creating | | updated_at | None | | user_id | c9eb1629ee8f40d984f228ebb10b2ab3 | | volume_type | tripleo | +--------------------------------+--------------------------------------+ And peeking into DB, we confirm purged worked: MariaDB [cinder]> select * from volumes; +---------------------+---------------------+------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+---------------------------------------+------+-------------------+-----------+---------------+---------------------+---------------------+---------------+--------------+---------------------+-------------------+---------------+-------------+--------------------------------------+--------------+----------+-------------------+----------+-------------------+------------------+--------------------+-----------------------------+-------------------------+---------------------+-------------+-------------+-----------------+--------------+----------+--------------------------------------+----------------+ | created_at | updated_at | deleted_at | deleted | id | ec2_id | user_id | project_id | host | size | availability_zone | status | attach_status | scheduled_at | launched_at | terminated_at | display_name | display_description | provider_location | provider_auth | snapshot_id | volume_type_id | source_volid | bootable | provider_geometry | _name_id | encryption_key_id | migration_status | replication_status | replication_extended_status | replication_driver_data | consistencygroup_id | provider_id | multiattach | previous_status | cluster_name | group_id | service_uuid | shared_targets | +---------------------+---------------------+------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+---------------------------------------+------+-------------------+-----------+---------------+---------------------+---------------------+---------------+--------------+---------------------+-------------------+---------------+-------------+--------------------------------------+--------------+----------+-------------------+----------+-------------------+------------------+--------------------+-----------------------------+-------------------------+---------------------+-------------+-------------+-----------------+--------------+----------+--------------------------------------+----------------+ | 2020-03-30 10:51:59 | 2020-03-30 10:52:00 | NULL | 0 | 1f3867b4-9711-4952-bf96-47aba686f695 | NULL | c9eb1629ee8f40d984f228ebb10b2ab3 | d9bf086d581449209ef3d577d005c241 | hostgroup@tripleo_iscsi#tripleo_iscsi | 1 | nova | available | detached | 2020-03-30 10:52:00 | 2020-03-30 10:52:00 | NULL | postPurge | NULL | NULL | NULL | NULL | f0a0cba0-218a-43df-8512-51cafc1ffe5c | NULL | 0 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | 0 | NULL | NULL | NULL | 96ca701c-8df1-4124-bf17-a3924457bc39 | 0 | +---------------------+---------------------+------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+---------------------------------------+------+-------------------+-----------+---------------+---------------------+---------------------+---------------+--------------+---------------------+-------------------+---------------+-------------+--------------------------------------+--------------+----------+-------------------+----------+-------------------+------------------+--------------------+-----------------------------+-------------------------+---------------------+-------------+-------------+-----------------+--------------+----------+--------------------------------------+----------------+ 1 row in set (0.001 sec) And as expected DB only contains 1 row, the two deleted volumes were purged from BD as expected.
Ok second attempt to verify Tested on: openstack-cinder-15.0.2-0.20200123220928.900f769.el8ost.noarch We need to trigger a unique situation on volume before we try to delete/purge it. 1. Create a volume (overcloud) [stack@undercloud-0 ~]$ cinder create 4 --name Tshefi +--------------------------------+--------------------------------------+ | Property | Value | +--------------------------------+--------------------------------------+ | attachments | [] | | availability_zone | nova | | bootable | false | | consistencygroup_id | None | | created_at | 2020-03-31T07:29:13.000000 | | description | None | | encrypted | False | | id | 16eccaf9-9ca1-4a20-9575-d092fafa250b | | metadata | {} | | migration_status | None | | multiattach | False | | name | Tshefi | | os-vol-host-attr:host | None | | os-vol-mig-status-attr:migstat | None | | os-vol-mig-status-attr:name_id | None | | os-vol-tenant-attr:tenant_id | d9bf086d581449209ef3d577d005c241 | | replication_status | None | | size | 4 | | snapshot_id | None | | source_volid | None | | status | creating | | updated_at | None | | user_id | c9eb1629ee8f40d984f228ebb10b2ab3 | | volume_type | tripleo | +--------------------------------+--------------------------------------+ 2. Set metadata on volume: (overcloud) [stack@undercloud-0 ~]$ cinder metadata 16eccaf9-9ca1-4a20-9575-d092fafa250b set a=b Validate metadata: (overcloud) [stack@undercloud-0 ~]$ cinder show 16eccaf9-9ca1-4a20-9575-d092fafa250b | grep metadata | metadata | a : b | 3. Now manipulate DB, set a "fake" delete date, notice we didn't actuality delete the volume yet: MariaDB [cinder]> update volumes set deleted_at='2020-03-31 07:29:14' where id='16eccaf9-9ca1-4a20-9575-d092fafa250b'; 4. Now lets try to purge record db using: cinder-manage db purge 0 cinder-manage.log reports the below, ignore first few lines we had previously created/deleted volumes on this system. however later at the bottom we see original problem reproduced: rom table=snapshots 2020-03-31 08:01:26.541 16703 INFO cinder.db.sqlalchemy.api [req-580738d1-dbf6-4b85-a2e2-0a80eef6b296 - - - - -] Deleted 17 rows from table=snapshots 2020-03-31 08:01:26.542 16703 INFO cinder.db.sqlalchemy.api [req-580738d1-dbf6-4b85-a2e2-0a80eef6b296 - - - - -] Purging deleted rows older than age=0 days from table=group_volume_type_mapping 2020-03-31 08:01:26.548 16703 INFO cinder.db.sqlalchemy.api [req-580738d1-dbf6-4b85-a2e2-0a80eef6b296 - - - - -] Purging deleted rows older than age=0 days from table=workers 2020-03-31 08:01:26.553 16703 INFO cinder.db.sqlalchemy.api [req-580738d1-dbf6-4b85-a2e2-0a80eef6b296 - - - - -] Purging deleted rows older than age=0 days from table=volumes 2020-03-31 08:01:26.568 16703 ERROR cinder.db.sqlalchemy.api [req-580738d1-dbf6-4b85-a2e2-0a80eef6b296 - - - - -] DBError detected when purging from volumes: (pymysql.err.IntegrityError) (1451, 'Cannot delete or update a parent row: a foreign key constraint fails (`cinder`.`volume_metadata`, CONSTRAINT `volume_metadata_ibfk_1` FOREIGN KEY (`volume_id`) REFERENCES `volumes` (`id`))') [SQL: DELETE FROM volumes WHERE volumes.deleted_at < %(deleted_at_1)s] [parameters: {'deleted_at_1': datetime.datetime(2020, 3, 31, 8, 1, 26, 554222)}] (Background on this error at: http://sqlalche.me/e/gkpj).: oslo_db.exception.DBReferenceError: (pymysql.err.IntegrityError) (1451, 'Cannot delete or update a parent row: a foreign key constraint fails (`cinder`.`volume_metadata`, CONSTRAINT `volume_metadata_ibfk_1` FOREIGN KEY (`volume_id`) REFERENCES `volumes` (`id`))') And well the record still remains in DB -------------+ | 2020-03-31 07:29:13 | 2020-03-31 07:29:14 | 2020-03-31 07:29:14 | 0 | 16eccaf9-9ca1-4a20-9575-d092fafa250b | NULL | c9eb1629ee8f40d984f228ebb10b2ab3 | d9bf086d581449209ef3d577d005c241 | hostgroup@tripleo_iscsi#tripleo_iscsi | 4 | nova | available | detached | 2020-03-31 07:29:14 | 2020-03-31 07:29:14 | NULL | Tshefi | NULL | NULL | NULL | NULL | f0a0cba0-218a-43df-8512-51cafc1ffe5c | NULL | 0 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | 0 | NULL | NULL | NULL | 96ca701c-8df1-4124-bf17-a3924457bc39 | 0 | +----------------- 5. Now lets delete the volume for real: (overcloud) [stack@undercloud-0 ~]$ cinder delete 16eccaf9-9ca1-4a20-9575-d092fafa250b Request to delete volume 16eccaf9-9ca1-4a20-9575-d092fafa250b has been accepted. Cinder list -> null/empty, on DB we still see the row as volume was deleted but not yet purged. 6. Now repurge again: cinder-manage db purge 0 Cinder-manage.log now reports "Deleted 1 rows from table=volume_metadata" and no other error/problem yay! Good to verify for real this time :) tshefi2 2020-03-31 08:10:18.685 16809 DEBUG oslo_db.sqlalchemy.engines [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/engines.py:307 2020-03-31 08:10:18.831 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_glance_metadata 2020-03-31 08:10:18.836 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=snapshot_metadata 2020-03-31 08:10:18.840 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=attachment_specs 2020-03-31 08:10:18.845 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_type_projects 2020-03-31 08:10:18.849 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_type_extra_specs 2020-03-31 08:10:18.854 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_metadata 2020-03-31 08:10:18.862 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Deleted 1 rows from table=volume_metadata 2020-03-31 08:10:18.862 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_attachment 2020-03-31 08:10:18.865 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_admin_metadata 2020-03-31 08:10:18.868 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=transfers 2020-03-31 08:10:18.872 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=snapshots 2020-03-31 08:10:18.876 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=group_volume_type_mapping 2020-03-31 08:10:18.880 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=workers 2020-03-31 08:10:18.884 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volumes 2020-03-31 08:10:18.903 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Deleted 36 rows from table=volumes 2020-03-31 08:10:18.904 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=volume_types 2020-03-31 08:10:18.917 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Deleted 18 rows from table=volume_types 2020-03-31 08:10:18.917 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=reservations 2020-03-31 08:10:18.945 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Deleted 328 rows from table=reservations 2020-03-31 08:10:18.946 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=group_type_specs 2020-03-31 08:10:18.955 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=group_type_projects 2020-03-31 08:10:18.959 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=group_snapshots 2020-03-31 08:10:18.963 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=cgsnapshots 2020-03-31 08:10:18.968 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=backup_metadata 2020-03-31 08:10:18.971 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=services 2020-03-31 08:10:18.974 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=quotas 2020-03-31 08:10:18.977 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=quota_usages 2020-03-31 08:10:18.980 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=quota_classes 2020-03-31 08:10:18.982 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=quality_of_service_specs 2020-03-31 08:10:19.093 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=messages 2020-03-31 08:10:19.098 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=groups 2020-03-31 08:10:19.102 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=group_types 2020-03-31 08:10:19.106 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=encryption 2020-03-31 08:10:19.110 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=consistencygroups 2020-03-31 08:10:19.114 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=clusters 2020-03-31 08:10:19.117 16809 INFO cinder.db.sqlalchemy.api [req-4104acc0-cb6e-49a1-88d8-aae622d7553d - - - - -] Purging deleted rows older than age=0 days from table=backups
Forgot to to mention DB has no rows deleted volume purged as expected. Thanks Rajat for assistance.