Cinder

test_models_sync unit test failures

Bug #2012289 reported by Eric Harney on 2023-03-20

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	Cinder	Fix Released	High	Unassigned

Bug Description

Unit tests for test_migrations test_models_sync are failing in the gate lately, see output below.

From
https://zuul.opendev.org/t/openstack/build/5a35a515dab7498996f46751f775fcce
https://review.opendev.org/c/openstack/cinder/+/875534/2
openstack-tox-py310

==============================
Failed 3 tests - output below:
==============================

cinder.tests.unit.db.test_migrations.TestModelsSyncSQLite.test_models_sync
--------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
Traceback (most recent call last):

File "/home/zuul/src/opendev.org/openstack/cinder/.tox/py310/lib/python3.10/site-packages/oslo_db/sqlalchemy/test_migrations.py", line 494, in test_models_sync
self.fail(

File "/usr/lib/python3.10/unittest/case.py", line 675, in fail
raise self.failureException(msg)

    AssertionError: Models and migration scripts aren't in sync:
[ ( 'remove_index',
    Index('volumes_service_uuid_idx', Column('service_uuid', VARCHAR(length=36), table=<volumes>), Column('deleted', BOOLEAN(), table=<volumes>))),
  ( 'add_index',
    Index('volumes_service_uuid_idx', Column('deleted', Boolean(), table=<volumes>, default=ColumnDefault(False)), Column('service_uuid', String(length=36), table=<volumes>)))]

Captured pythonlogging:
~~~~~~~~~~~~~~~~~~~~~~~
2023-03-20 13:39:51,914 INFO [cinder.db.migration] Applying migration(s)
2023-03-20 13:39:51,916 INFO [alembic.runtime.migration] Context impl SQLiteImpl.
2023-03-20 13:39:51,917 INFO [alembic.runtime.migration] Will assume non-transactional DDL.
2023-03-20 13:39:51,933 INFO [alembic.runtime.migration] Running upgrade -> 921e1a36b076, Initial migration.
2023-03-20 13:39:52,110 INFO [alembic.runtime.migration] Running upgrade 921e1a36b076 -> c92a3e68beed, Make shared_targets nullable
2023-03-20 13:39:52,198 INFO [alembic.runtime.migration] Running upgrade c92a3e68beed -> daa98075b90d, Add resource indexes
2023-03-20 13:39:52,210 INFO [cinder.db.migration] Migration(s) applied
2023-03-20 13:39:52,211 INFO [alembic.runtime.migration] Context impl SQLiteImpl.
2023-03-20 13:39:52,211 INFO [alembic.runtime.migration] Will assume non-transactional DDL.
2023-03-20 13:39:52,475 INFO [alembic.autogenerate.compare] Detected changed index 'volumes_service_uuid_idx' on 'volumes': expression ('service_uuid', 'deleted') to ('deleted', 'service_uuid')

cinder.tests.unit.db.test_migrations.TestModelsSyncMySQL.test_models_sync
-------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
Traceback (most recent call last):

File "/home/zuul/src/opendev.org/openstack/cinder/.tox/py310/lib/python3.10/site-packages/oslo_db/sqlalchemy/test_migrations.py", line 494, in test_models_sync
self.fail(

File "/usr/lib/python3.10/unittest/case.py", line 675, in fail
raise self.failureException(msg)

    AssertionError: Models and migration scripts aren't in sync:
[ ( 'remove_constraint',
    UniqueConstraint(Column('group_type_id', NullType(), table=<group_type_projects>), Column('project_id', NullType(), table=<group_type_projects>), Column('deleted', NullType(), table=<group_type_projects>))),
  ( 'remove_index',
    Index('group_type_id', Column('group_type_id', VARCHAR(length=36), table=<group_type_projects>), Column('project_id', VARCHAR(length=255), table=<group_type_projects>), Column('deleted', TINYINT(display_width=1), table=<group_type_projects>))),
  ( 'remove_constraint',
    UniqueConstraint(Column('project_id', NullType(), table=<quota_usages>), Column('resource', NullType(), table=<quota_usages>), Column('race_preventer', NullType(), table=<quota_usages>))),
  ( 'remove_index',
    Index('project_id', Column('project_id', VARCHAR(length=255), table=<quota_usages>), Column('resource', VARCHAR(length=300), table=<quota_usages>), Column('race_preventer', TINYINT(display_width=1), table=<quota_usages>))),
  ( 'remove_index',
    Index('volumes_service_uuid_idx', Column('service_uuid', VARCHAR(length=36), table=<volumes>), Column('deleted', TINYINT(display_width=1), table=<volumes>))),
  ( 'add_index',
    Index('volumes_service_uuid_idx', Column('deleted', Boolean(), table=<volumes>, default=ColumnDefault(False)), Column('service_uuid', String(length=36), table=<volumes>)))]

Captured pythonlogging:
~~~~~~~~~~~~~~~~~~~~~~~
2023-03-20 13:39:54,377 INFO [cinder.db.migration] Applying migration(s)
2023-03-20 13:39:54,381 INFO [alembic.runtime.migration] Context impl MySQLImpl.
2023-03-20 13:39:54,382 INFO [alembic.runtime.migration] Will assume non-transactional DDL.
2023-03-20 13:39:54,645 INFO [alembic.runtime.migration] Running upgrade -> 921e1a36b076, Initial migration.
2023-03-20 13:40:32,238 INFO [alembic.runtime.migration] Running upgrade 921e1a36b076 -> c92a3e68beed, Make shared_targets nullable
2023-03-20 13:40:32,560 INFO [alembic.runtime.migration] Running upgrade c92a3e68beed -> daa98075b90d, Add resource indexes
2023-03-20 13:40:34,831 INFO [cinder.db.migration] Migration(s) applied
2023-03-20 13:40:34,833 INFO [alembic.runtime.migration] Context impl MySQLImpl.
2023-03-20 13:40:34,833 INFO [alembic.runtime.migration] Will assume non-transactional DDL.
2023-03-20 13:40:35,780 INFO [alembic.autogenerate.compare] Detected NULL on column 'encryption.encryption_id'
2023-03-20 13:40:35,781 INFO [alembic.autogenerate.compare] Detected NULL on column 'encryption.provider'
2023-03-20 13:40:35,781 INFO [alembic.autogenerate.compare] Detected NULL on column 'encryption.control_location'
2023-03-20 13:40:35,791 INFO [alembic.autogenerate.compare] Detected removed unique constraint 'group_type_id' on 'group_type_projects'
2023-03-20 13:40:35,791 INFO [alembic.autogenerate.compare] Detected removed index 'group_type_id' on 'group_type_projects'
2023-03-20 13:40:35,846 INFO [alembic.autogenerate.compare] Detected removed unique constraint 'project_id' on 'quota_usages'
2023-03-20 13:40:35,847 INFO [alembic.autogenerate.compare] Detected removed index 'project_id' on 'quota_usages'
2023-03-20 13:40:36,003 INFO [alembic.autogenerate.compare] Detected changed index 'volumes_service_uuid_idx' on 'volumes': expression ('service_uuid', 'deleted') to ('deleted', 'service_uuid')

cinder.tests.unit.db.test_migrations.TestModelsSyncPostgreSQL.test_models_sync
------------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
Traceback (most recent call last):

File "/home/zuul/src/opendev.org/openstack/cinder/.tox/py310/lib/python3.10/site-packages/oslo_db/sqlalchemy/test_migrations.py", line 494, in test_models_sync
self.fail(

File "/usr/lib/python3.10/unittest/case.py", line 675, in fail
raise self.failureException(msg)

Captured pythonlogging:
~~~~~~~~~~~~~~~~~~~~~~~
2023-03-20 13:41:04,294 INFO [cinder.db.migration] Applying migration(s)
2023-03-20 13:41:04,297 INFO [alembic.runtime.migration] Context impl PostgresqlImpl.
2023-03-20 13:41:04,297 INFO [alembic.runtime.migration] Will assume transactional DDL.
2023-03-20 13:41:04,352 INFO [alembic.runtime.migration] Running upgrade -> 921e1a36b076, Initial migration.
2023-03-20 13:41:07,680 INFO [alembic.runtime.migration] Running upgrade 921e1a36b076 -> c92a3e68beed, Make shared_targets nullable
2023-03-20 13:41:07,766 INFO [alembic.runtime.migration] Running upgrade c92a3e68beed -> daa98075b90d, Add resource indexes
2023-03-20 13:41:07,874 INFO [cinder.db.migration] Migration(s) applied
2023-03-20 13:41:07,876 INFO [alembic.runtime.migration] Context impl PostgresqlImpl.
2023-03-20 13:41:07,876 INFO [alembic.runtime.migration] Will assume transactional DDL.
2023-03-20 13:41:07,911 INFO [alembic.ddl.postgresql] Detected sequence named 'volume_metadata_id_seq' as owned by integer column 'volume_metadata(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,023 INFO [alembic.ddl.postgresql] Detected sequence named 'group_volume_type_mapping_id_seq' as owned by integer column 'group_volume_type_mapping(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,056 INFO [alembic.ddl.postgresql] Detected sequence named 'attachment_specs_id_seq' as owned by integer column 'attachment_specs(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,098 INFO [alembic.ddl.postgresql] Detected sequence named 'reservations_id_seq' as owned by integer column 'reservations(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,165 INFO [alembic.ddl.postgresql] Detected sequence named 'group_type_projects_id_seq' as owned by integer column 'group_type_projects(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,198 INFO [alembic.ddl.postgresql] Detected sequence named 'group_type_specs_id_seq' as owned by integer column 'group_type_specs(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,217 INFO [alembic.ddl.postgresql] Detected sequence named 'volume_type_extra_specs_id_seq' as owned by integer column 'volume_type_extra_specs(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,236 INFO [alembic.ddl.postgresql] Detected sequence named 'clusters_id_seq' as owned by integer column 'clusters(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,250 INFO [alembic.ddl.postgresql] Detected sequence named 'quota_classes_id_seq' as owned by integer column 'quota_classes(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,269 INFO [alembic.ddl.postgresql] Detected sequence named 'volume_admin_metadata_id_seq' as owned by integer column 'volume_admin_metadata(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,286 INFO [alembic.ddl.postgresql] Detected sequence named 'image_volume_cache_entries_id_seq' as owned by integer column 'image_volume_cache_entries(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,319 INFO [alembic.ddl.postgresql] Detected sequence named 'driver_initiator_data_id_seq' as owned by integer column 'driver_initiator_data(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,384 INFO [alembic.ddl.postgresql] Detected sequence named 'volume_glance_metadata_id_seq' as owned by integer column 'volume_glance_metadata(id)', assuming SERIAL and omitting

2023-03-20 13:41:08,434 INFO [alembic.ddl.postgresql] Detected sequence named 'snapshot_metadata_id_seq' as owned by integer column 'snapshot_metadata(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,453 INFO [alembic.ddl.postgresql] Detected sequence named 'workers_id_seq' as owned by integer column 'workers(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,478 INFO [alembic.ddl.postgresql] Detected sequence named 'backup_metadata_id_seq' as owned by integer column 'backup_metadata(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,508 INFO [alembic.ddl.postgresql] Detected sequence named 'volume_type_projects_id_seq' as owned by integer column 'volume_type_projects(id)', assuming SERIAL and omitting
2023-03-20 13:41:08,539 INFO [alembic.autogenerate.compare] D
etected NULL on column 'encryption.encryption_id'
2023-03-20 13:41:08,540 INFO [alembic.autogenerate.compare] Detected NULL on column 'encryption.provider'
2023-03-20 13:41:08,540 INFO [alembic.autogenerate.compare] Detected NULL on column 'encryption.control_location'
2023-03-20 13:41:08,613 INFO [alembic.autogenerate.compare] Detected changed index 'volumes_service_uuid_idx' on 'volumes': expression ('service_uuid', 'deleted') to ('deleted', 'service_uuid')

Tags:

Revision history for this message

Gorka Eguileor (gorka) wrote on 2023-03-21:

Error reported by unit tests seems to be correct, because we have an inconsistency.

In the model we see [1]:
sa.Index('volumes_service_uuid_idx', 'deleted', 'service_uuid'),

While in the migrations we see something different [2][3]:
sa.Index('volumes_service_uuid_idx', 'service_uuid', 'deleted'),

I don't know why we don't see this failure all the time and why it's not reproducible locally.

[1]: https://github.com/openstack/cinder/blob/45fd889c7820135e61bba9dbfd73f81192b6ccc3/cinder/db/sqlalchemy/models.py#L317
[2]: https://github.com/openstack/cinder/blob/45fd889c7820135e61bba9dbfd73f81192b6ccc3/cinder/db/migrations/versions/921e1a36b076_initial.py#L232
[3]: https://github.com/openstack/cinder/blob/45fd889c7820135e61bba9dbfd73f81192b6ccc3/cinder/db/legacy_migrations/versions/135_cinder_init.py#L212

Eric Harney (eharney) on 2023-03-24

Changed in cinder:
importance:	Undecided → High

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-03-24: Fix proposed to cinder (master)

Fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/cinder/+/878554

Changed in cinder:
status:	New → In Progress

Revision history for this message

Dr. Jens Harbott (j-harbott) wrote on 2023-03-25:

The failure is related to the alembic bump in the linked reqs patch.

-alembic===1.8.1
+alembic===1.10.2

Confirmed locally that the proposed fix solves this.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-20: Fix merged to cinder (master)

Reviewed: https://review.opendev.org/c/openstack/cinder/+/878554
Committed: https://opendev.org/openstack/cinder/commit/b261fa205b7f956a8eecbcffe6703c8d7de4e418
Submitter: "Zuul (22348)"
Branch: master

commit b261fa205b7f956a8eecbcffe6703c8d7de4e418
Author: Eric Harney <email address hidden>
Date: Fri Mar 24 14:04:05 2023 -0400

DB: Align volumes_service_uuid index in model with migration

The migration specifies a column order of
('service_uuid', 'deleted'), make the model use the same order.

Closes-Bug: #2012289
Change-Id: I2332bf4657761076c3d72e41d089ec014e73fb52

Changed in cinder:
status:	In Progress → Fix Released

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-09-14: Fix included in openstack/cinder 23.0.0.0rc1

This issue was fixed in the openstack/cinder 23.0.0.0rc1 release candidate.

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.