[Bug 2067815] [NEW] dbmanage sync fails to run

Billy Olsen 2067815 at bugs.launchpad.net
Sun Jun 2 01:31:44 UTC 2024


Public bug reported:

The SQLAlchemy scripts for Caracal watcher fails to run due to errors in
the generated SQL migrations.

This occurs when the `watcher db-manage sync` scripts are run to create
the database or migrate the database.

Patches have been merged recently upstream
-https://review.opendev.org/c/openstack/watcher/+/918500

Example stack trace below:

2024-06-01 16:58:29.918774 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Context impl SQLiteImpl.
2024-06-01 16:58:29.918801 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
2024-06-01 16:58:29.918830 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade  -> 001, ocata release
2024-06-01 16:58:29.918852 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade 001 -> 0f6042416884, Add apscheduler_jobs table to store background jobs
2024-06-01 16:58:29.919273 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade 0f6042416884 -> d098df6021e2, Add cron support for audit table
2024-06-01 16:58:29.919326 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 CRITI [python-watcher] Unhandled error
2024-06-01 16:58:29.919361 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 Traceback (most recent call last):
2024-06-01 16:58:29.919390 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
2024-06-01 16:58:29.919416 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.dialect.do_execute(
2024-06-01 16:58:29.919837 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute
2024-06-01 16:58:29.919866 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     cursor.execute(statement, parameters)
2024-06-01 16:58:29.919881 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 sqlite3.OperationalError: near "ALTER": syntax error
2024-06-01 16:58:29.919905 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60
2024-06-01 16:58:29.919922 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 The above exception was the direct cause of the following exception:
2024-06-01 16:58:29.919936 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60
2024-06-01 16:58:29.921865 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 Traceback (most recent call last):
2024-06-01 16:58:29.921930 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/bin/watcher-db-manage", line 10, in <module>
2024-06-01 16:58:29.921963 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     sys.exit(main())
2024-06-01 16:58:29.921984 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/cmd/dbmanage.py", line 157, in main
2024-06-01 16:58:29.921998 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     CONF.command.func()
2024-06-01 16:58:29.922539 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/cmd/dbmanage.py", line 38, in upgrade
2024-06-01 16:58:29.922659 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     migration.upgrade(CONF.command.revision)
2024-06-01 16:58:29.922699 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/migration.py", line 36, in upgrade
2024-06-01 16:58:29.922731 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return get_backend().upgrade(version)
2024-06-01 16:58:29.922763 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/migration.py", line 57, in upgrade
2024-06-01 16:58:29.922794 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     alembic.command.upgrade(config, revision)
2024-06-01 16:58:29.923468 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/command.py", line 403, in upgrade
2024-06-01 16:58:29.923523 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     script.run_env()
2024-06-01 16:58:29.923570 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/script/base.py", line 583, in run_env
2024-06-01 16:58:29.923587 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     util.load_python_file(self.dir, "env.py")
2024-06-01 16:58:29.923601 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 95, in load_python_file
2024-06-01 16:58:29.923752 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     module = load_module_py(module_id, path)
2024-06-01 16:58:29.923779 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 113, in load_module_py
2024-06-01 16:58:29.923793 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     spec.loader.exec_module(module)  # type: ignore
2024-06-01 16:58:29.923807 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<frozen importlib._bootstrap_external>", line 883, in exec_module
2024-06-01 16:58:29.923821 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
2024-06-01 16:58:29.924427 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/env.py", line 54, in <module>
2024-06-01 16:58:29.924457 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     run_migrations_online()
2024-06-01 16:58:29.924473 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/env.py", line 51, in run_migrations_online
2024-06-01 16:58:29.924488 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     context.run_migrations()
2024-06-01 16:58:29.924502 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 8, in run_migrations
2024-06-01 16:58:29.925251 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/runtime/environment.py", line 948, in run_migrations
2024-06-01 16:58:29.925318 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.get_context().run_migrations(**kw)
2024-06-01 16:58:29.925363 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/runtime/migration.py", line 627, in run_migrations
2024-06-01 16:58:29.925422 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     step.migration_fn(**kw)
2024-06-01 16:58:29.925451 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/versions/d098df6021e2_cron_support_for_audit.py", line 17, in upgrade
2024-06-01 16:58:29.925912 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     op.alter_column('audits', 'interval', existing_type=sa.String(36),
2024-06-01 16:58:29.925943 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 8, in alter_column
2024-06-01 16:58:29.925974 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 3, in alter_column
2024-06-01 16:58:29.925992 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/ops.py", line 1943, in alter_column
2024-06-01 16:58:29.926011 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return operations.invoke(alt)
2024-06-01 16:58:29.926467 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/base.py", line 445, in invoke
2024-06-01 16:58:29.926520 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return fn(self, operation)
2024-06-01 16:58:29.926557 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/toimpl.py", line 53, in alter_column
2024-06-01 16:58:29.926657 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     operations.impl.alter_column(
2024-06-01 16:58:29.926693 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 241, in alter_column
2024-06-01 16:58:29.926723 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self._exec(
2024-06-01 16:58:29.927343 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 207, in _exec
2024-06-01 16:58:29.927404 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return conn.execute(construct, multiparams)
2024-06-01 16:58:29.927431 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1385, in execute
2024-06-01 16:58:29.927456 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return meth(self, multiparams, params, _EMPTY_EXECUTION_OPTS)
2024-06-01 16:58:29.927481 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/sql/ddl.py", line 80, in _execute_on_connection
2024-06-01 16:58:29.927945 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return connection._execute_ddl(
2024-06-01 16:58:29.928006 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1477, in _execute_ddl
2024-06-01 16:58:29.928082 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     ret = self._execute_context(
2024-06-01 16:58:29.928116 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context
2024-06-01 16:58:29.928146 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self._handle_dbapi_exception(
2024-06-01 16:58:29.928629 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 2132, in _handle_dbapi_exception
2024-06-01 16:58:29.928670 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     util.raise_(newraise, with_traceback=exc_info[2], from_=e)
2024-06-01 16:58:29.928700 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/util/compat.py", line 211, in raise_
2024-06-01 16:58:29.928734 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     raise exception
2024-06-01 16:58:29.928760 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
2024-06-01 16:58:29.929397 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.dialect.do_execute(
2024-06-01 16:58:29.929457 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute
2024-06-01 16:58:29.929526 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     cursor.execute(statement, parameters)
2024-06-01 16:58:29.929565 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) near "ALTER": syntax error
2024-06-01 16:58:29.929591 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 [SQL: ALTER TABLE audits ALTER COLUMN interval DROP NOT NULL]
2024-06-01 16:58:29.929615 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 (Background on this error at: https://sqlalche.me/e/14/e3q8)

** Affects: watcher
     Importance: Undecided
         Status: New

** Affects: watcher (Ubuntu)
     Importance: Undecided
         Status: New

** Also affects: watcher
   Importance: Undecided
       Status: New

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to watcher in Ubuntu.
https://bugs.launchpad.net/bugs/2067815

Title:
  dbmanage sync fails to run

Status in watcher:
  New
Status in watcher package in Ubuntu:
  New

Bug description:
  The SQLAlchemy scripts for Caracal watcher fails to run due to errors
  in the generated SQL migrations.

  This occurs when the `watcher db-manage sync` scripts are run to
  create the database or migrate the database.

  Patches have been merged recently upstream
  -https://review.opendev.org/c/openstack/watcher/+/918500

  Example stack trace below:

  2024-06-01 16:58:29.918774 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Context impl SQLiteImpl.
  2024-06-01 16:58:29.918801 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
  2024-06-01 16:58:29.918830 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade  -> 001, ocata release
  2024-06-01 16:58:29.918852 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade 001 -> 0f6042416884, Add apscheduler_jobs table to store background jobs
  2024-06-01 16:58:29.919273 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 INFO  [alembic.runtime.migration] Running upgrade 0f6042416884 -> d098df6021e2, Add cron support for audit table
  2024-06-01 16:58:29.919326 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 CRITI [python-watcher] Unhandled error
  2024-06-01 16:58:29.919361 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 Traceback (most recent call last):
  2024-06-01 16:58:29.919390 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
  2024-06-01 16:58:29.919416 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.dialect.do_execute(
  2024-06-01 16:58:29.919837 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute
  2024-06-01 16:58:29.919866 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     cursor.execute(statement, parameters)
  2024-06-01 16:58:29.919881 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 sqlite3.OperationalError: near "ALTER": syntax error
  2024-06-01 16:58:29.919905 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60
  2024-06-01 16:58:29.919922 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 The above exception was the direct cause of the following exception:
  2024-06-01 16:58:29.919936 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60
  2024-06-01 16:58:29.921865 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 Traceback (most recent call last):
  2024-06-01 16:58:29.921930 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/bin/watcher-db-manage", line 10, in <module>
  2024-06-01 16:58:29.921963 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     sys.exit(main())
  2024-06-01 16:58:29.921984 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/cmd/dbmanage.py", line 157, in main
  2024-06-01 16:58:29.921998 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     CONF.command.func()
  2024-06-01 16:58:29.922539 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/cmd/dbmanage.py", line 38, in upgrade
  2024-06-01 16:58:29.922659 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     migration.upgrade(CONF.command.revision)
  2024-06-01 16:58:29.922699 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/migration.py", line 36, in upgrade
  2024-06-01 16:58:29.922731 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return get_backend().upgrade(version)
  2024-06-01 16:58:29.922763 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/migration.py", line 57, in upgrade
  2024-06-01 16:58:29.922794 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     alembic.command.upgrade(config, revision)
  2024-06-01 16:58:29.923468 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/command.py", line 403, in upgrade
  2024-06-01 16:58:29.923523 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     script.run_env()
  2024-06-01 16:58:29.923570 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/script/base.py", line 583, in run_env
  2024-06-01 16:58:29.923587 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     util.load_python_file(self.dir, "env.py")
  2024-06-01 16:58:29.923601 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 95, in load_python_file
  2024-06-01 16:58:29.923752 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     module = load_module_py(module_id, path)
  2024-06-01 16:58:29.923779 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 113, in load_module_py
  2024-06-01 16:58:29.923793 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     spec.loader.exec_module(module)  # type: ignore
  2024-06-01 16:58:29.923807 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<frozen importlib._bootstrap_external>", line 883, in exec_module
  2024-06-01 16:58:29.923821 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  2024-06-01 16:58:29.924427 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/env.py", line 54, in <module>
  2024-06-01 16:58:29.924457 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     run_migrations_online()
  2024-06-01 16:58:29.924473 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/env.py", line 51, in run_migrations_online
  2024-06-01 16:58:29.924488 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     context.run_migrations()
  2024-06-01 16:58:29.924502 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 8, in run_migrations
  2024-06-01 16:58:29.925251 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/runtime/environment.py", line 948, in run_migrations
  2024-06-01 16:58:29.925318 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.get_context().run_migrations(**kw)
  2024-06-01 16:58:29.925363 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/runtime/migration.py", line 627, in run_migrations
  2024-06-01 16:58:29.925422 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     step.migration_fn(**kw)
  2024-06-01 16:58:29.925451 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/watcher/db/sqlalchemy/alembic/versions/d098df6021e2_cron_support_for_audit.py", line 17, in upgrade
  2024-06-01 16:58:29.925912 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     op.alter_column('audits', 'interval', existing_type=sa.String(36),
  2024-06-01 16:58:29.925943 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 8, in alter_column
  2024-06-01 16:58:29.925974 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "<string>", line 3, in alter_column
  2024-06-01 16:58:29.925992 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/ops.py", line 1943, in alter_column
  2024-06-01 16:58:29.926011 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return operations.invoke(alt)
  2024-06-01 16:58:29.926467 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/base.py", line 445, in invoke
  2024-06-01 16:58:29.926520 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return fn(self, operation)
  2024-06-01 16:58:29.926557 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/operations/toimpl.py", line 53, in alter_column
  2024-06-01 16:58:29.926657 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     operations.impl.alter_column(
  2024-06-01 16:58:29.926693 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 241, in alter_column
  2024-06-01 16:58:29.926723 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self._exec(
  2024-06-01 16:58:29.927343 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 207, in _exec
  2024-06-01 16:58:29.927404 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return conn.execute(construct, multiparams)
  2024-06-01 16:58:29.927431 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1385, in execute
  2024-06-01 16:58:29.927456 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return meth(self, multiparams, params, _EMPTY_EXECUTION_OPTS)
  2024-06-01 16:58:29.927481 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/sql/ddl.py", line 80, in _execute_on_connection
  2024-06-01 16:58:29.927945 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     return connection._execute_ddl(
  2024-06-01 16:58:29.928006 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1477, in _execute_ddl
  2024-06-01 16:58:29.928082 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     ret = self._execute_context(
  2024-06-01 16:58:29.928116 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context
  2024-06-01 16:58:29.928146 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self._handle_dbapi_exception(
  2024-06-01 16:58:29.928629 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 2132, in _handle_dbapi_exception
  2024-06-01 16:58:29.928670 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     util.raise_(newraise, with_traceback=exc_info[2], from_=e)
  2024-06-01 16:58:29.928700 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/util/compat.py", line 211, in raise_
  2024-06-01 16:58:29.928734 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     raise exception
  2024-06-01 16:58:29.928760 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
  2024-06-01 16:58:29.929397 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     self.dialect.do_execute(
  2024-06-01 16:58:29.929457 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60   File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute
  2024-06-01 16:58:29.929526 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60     cursor.execute(statement, parameters)
  2024-06-01 16:58:29.929565 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) near "ALTER": syntax error
  2024-06-01 16:58:29.929591 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 [SQL: ALTER TABLE audits ALTER COLUMN interval DROP NOT NULL]
  2024-06-01 16:58:29.929615 | focal-medium | 2024-06-01 16:58:29 [ERROR] unit-watcher-0.log: 2024-06-01 16:58:17 WARNING unit.watcher/0.shared-db-relation-changed logger.go:60 (Background on this error at: https://sqlalche.me/e/14/e3q8)

To manage notifications about this bug go to:
https://bugs.launchpad.net/watcher/+bug/2067815/+subscriptions




More information about the Ubuntu-openstack-bugs mailing list