Open Stack

Glance developers,

I am investigating failures with the neutron-tempest-postgres-full periodic job
in Zuul, and it looks like the failing step is actually a database migration for
Glance that occurs during devstack setup.  Pasted below is a representative
example [1].  You can see the same issue causing failures for this neutron
periodic job by looking at the Zuul failures [2]; the error is in
logs/devstacklog.txt.gz.

The last successful job was 2019-08-15T06:07:06; the next one on 2019-08-16
failed.  But there were no changes merged in glance during that time period [3].
So if you could help debug the source of this issue then we can hopefully get
this job - and probably whatever others depend on postgresql - back working.

2019-08-27 06:35:44.963 | INFO  [alembic.runtime.migration] Running upgrade rocky_expand02 -> train_expand01, empty expand for symmetry with train_contract01
2019-08-27 06:35:44.967 | INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
2019-08-27 06:35:44.967 | INFO  [alembic.runtime.migration] Will assume transactional DDL.
2019-08-27 06:35:44.970 | Upgraded database to: train_expand01, current revision(s): train_expand01
2019-08-27 06:35:44.971 | INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
2019-08-27 06:35:44.971 | INFO  [alembic.runtime.migration] Will assume transactional DDL.
2019-08-27 06:35:44.975 | INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
2019-08-27 06:35:44.975 | INFO  [alembic.runtime.migration] Will assume transactional DDL.
2019-08-27 06:35:44.995 | CRITI [glance] Unhandled error
2019-08-27 06:35:44.996 | Traceback (most recent call last):
2019-08-27 06:35:44.996 |   File "/usr/local/bin/glance-manage", line 10, in <module>
2019-08-27 06:35:44.996 |     sys.exit(main())
2019-08-27 06:35:44.996 |   File "/opt/stack/new/glance/glance/cmd/manage.py", line 563, in main
2019-08-27 06:35:44.996 |     return CONF.command.action_fn()
2019-08-27 06:35:44.996 |   File "/opt/stack/new/glance/glance/cmd/manage.py", line 395, in sync
2019-08-27 06:35:44.996 |     self.command_object.sync(CONF.command.version)
2019-08-27 06:35:44.996 |   File "/opt/stack/new/glance/glance/cmd/manage.py", line 166, in sync
2019-08-27 06:35:44.996 |     self.migrate(online_migration=False)
2019-08-27 06:35:44.996 |   File "/opt/stack/new/glance/glance/cmd/manage.py", line 294, in migrate
2019-08-27 06:35:44.996 |     if data_migrations.has_pending_migrations(db_api.get_engine()):
2019-08-27 06:35:44.996 |   File "/opt/stack/new/glance/glance/db/sqlalchemy/alembic_migrations/data_migrations/__init__.py", line 61, in has_pending_migrations
2019-08-27 06:35:44.997 |     return any([x.has_migrations(engine) for x in migrations])
2019-08-27 06:35:44.997 |   File "/opt/stack/new/glance/glance/db/sqlalchemy/alembic_migrations/data_migrations/train_migrate01_backend_to_store.py", line 28, in has_migrations
2019-08-27 06:35:44.997 |     metadata_backend = con.execute(sql_query)
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 982, in execute
2019-08-27 06:35:44.997 |     return self._execute_text(object_, multiparams, params)
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1155, in _execute_text
2019-08-27 06:35:44.997 |     parameters,
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
2019-08-27 06:35:44.997 |     e, statement, parameters, cursor, context
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1464, in _handle_dbapi_exception
2019-08-27 06:35:44.997 |     util.raise_from_cause(newraise, exc_info)
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 398, in raise_from_cause
2019-08-27 06:35:44.997 |     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2019-08-27 06:35:44.997 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
2019-08-27 06:35:44.998 |     cursor, statement, parameters, context
2019-08-27 06:35:44.998 |   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 552, in do_execute
2019-08-27 06:35:44.998 |     cursor.execute(statement, parameters)
2019-08-27 06:35:44.998 | DBError: (psycopg2.errors.UndefinedFunction) function instr(text, unknown) does not exist
2019-08-27 06:35:44.998 | LINE 1: select meta_data from image_locations where INSTR(meta_data,...
2019-08-27 06:35:44.998 |                                                     ^
2019-08-27 06:35:44.998 | HINT:  No function matches the given name and argument types. You might need to add explicit type casts.

Thanks,

Nate

[1] also http://paste.openstack.org/show/765665/ if that is an easier view
[2] http://zuul.openstack.org/builds?project=openstack%2Fneutron&job_name=neutron-tempest-postgres-full&branch=master
[3] https://review.opendev.org/#/q/project:openstack/glance+status:merged