DB Migration fails due to possible race in session handling

[mmnelemane]

"aimctl db-migration upgrade head" fails at reading aim_vmm_domains table. The error is as below:

INFO [alembic.runtime.migration] Context impl PostgresqlImpl.
INFO [alembic.runtime.migration] Will assume transactional DDL.
INFO [alembic.runtime.migration] Running upgrade -> 40855b7eb958, Create tables for Tenant and BridgeDomain
INFO [alembic.runtime.migration] Running upgrade 40855b7eb958 -> 72fa5bce100b, Create TenantTree table
INFO [alembic.runtime.migration] Running upgrade 72fa5bce100b -> accfe645090a, Create Agent table
INFO [alembic.runtime.migration] Running upgrade accfe645090a -> 7349fa0a2ad8, Create table for subnet, vrf, app-profile and EPG.
INFO [alembic.runtime.migration] Running upgrade 7349fa0a2ad8 -> faade1155a0a, Create Status and Fault model
INFO [alembic.runtime.migration] Running upgrade faade1155a0a -> 3ef7607a41b0, Create tables for contracts and filters
INFO [alembic.runtime.migration] Running upgrade 3ef7607a41b0 -> 74f15b6aee51, Create endpoint table
INFO [alembic.runtime.migration] Running upgrade 74f15b6aee51 -> ab9b4e196100, Create Config Model
INFO [alembic.runtime.migration] Running upgrade ab9b4e196100 -> 1249face3348, Create tables for VMM and Physical Domains.
INFO [alembic.runtime.migration] Running upgrade 1249face3348 -> 8e313fbeb93b, Tables for L3out
INFO [alembic.runtime.migration] Running upgrade 8e313fbeb93b -> 07113feba145, Tables for L3out clones in AIM LIB
INFO [alembic.runtime.migration] Running upgrade 07113feba145 -> d8abdb89ba66, Create table for HostLinks and EPG static-paths.
INFO [alembic.runtime.migration] Running upgrade d8abdb89ba66 -> d38c07b36c11, Table for saved L3Out in AIM lib
INFO [alembic.runtime.migration] Running upgrade d38c07b36c11 -> abf7bb5a4100, Create tables for security groups
INFO [alembic.runtime.migration] Running upgrade abf7bb5a4100 -> babbefa38870, Add conntrack column
INFO [alembic.runtime.migration] Running upgrade babbefa38870 -> dc598e78e318, Add tables for service graph
INFO [alembic.runtime.migration] Running upgrade dc598e78e318 -> 7838968744ce, Table for OpflexDevice
INFO [alembic.runtime.migration] Running upgrade 7838968744ce -> aceb1ac13668, Create tables for VMM Policies.
CRITI [aim] DBError: (psycopg2.ProgrammingError) relation "aim_vmm_domains" does not exist
LINE 2: FROM aim_vmm_domains
^
[SQL: 'SELECT aim_vmm_domains.type AS aim_vmm_domains_type, aim_vmm_domains.name AS aim_vmm_domains_name \nFROM aim_vmm_domains']
Traceback (most recent call last):
File "/usr/bin/aimctl", line 10, in
sys.exit(aimctl())
File "/usr/lib/python2.7/site-packages/aim/tools/services/cli.py", line 21, in aimctl
shell.run()
File "/usr/lib/python2.7/site-packages/aim/tools/cli/shell.py", line 27, in run
aim(auto_envvar_prefix='AIM')
File "/usr/lib/python2.7/site-packages/click/core.py", line 716, in call
return self.main(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/click/core.py", line 696, in main
rv = self.invoke(ctx)
File "/usr/lib/python2.7/site-packages/click/core.py", line 1060, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/usr/lib/python2.7/site-packages/click/core.py", line 1060, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/usr/lib/python2.7/site-packages/click/core.py", line 889, in invoke
return ctx.invoke(self.callback, **ctx.params)
File "/usr/lib/python2.7/site-packages/click/core.py", line 534, in invoke
return callback(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/click/decorators.py", line 17, in new_func
return f(get_current_context(), *args, **kwargs)
File "/usr/lib/python2.7/site-packages/aim/tools/cli/commands/db_migration.py", line 62, in upgrade
ctx.obj['manager'].upgrade(version)
File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/migration_cli/manager.py", line 67, in upgrade
results.append(plugin.upgrade(revision))
File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/migration_cli/ext_alembic.py", line 55, in upgrade
return alembic.command.upgrade(self.config, version or 'head')
File "/usr/lib/python2.7/site-packages/alembic/command.py", line 174, in upgrade
script.run_env()
File "/usr/lib/python2.7/site-packages/alembic/script/base.py", line 407, in run_env
util.load_python_file(self.dir, 'env.py')
File "/usr/lib/python2.7/site-packages/alembic/util/pyfiles.py", line 93, in load_python_file
module = load_module_py(module_id, path)
File "/usr/lib/python2.7/site-packages/alembic/util/compat.py", line 79, in load_module_py
mod = imp.load_source(module_id, path, fp)
File "/usr/lib/python2.7/site-packages/aim/db/migration/alembic_migrations/env.py", line 97, in
run_migrations_online()
File "/usr/lib/python2.7/site-packages/aim/db/migration/alembic_migrations/env.py", line 92, in run_migrations_online
context.run_migrations()
File "", line 8, in run_migrations
File "/usr/lib/python2.7/site-packages/alembic/runtime/environment.py", line 797, in run_migrations
self.get_context().run_migrations(**kw)
File "/usr/lib/python2.7/site-packages/alembic/runtime/migration.py", line 312, in run_migrations
step.migration_fn(**kw)
File "/usr/lib/python2.7/site-packages/aim/db/migration/alembic_migrations/versions/aceb1ac13668_vmm_policy.py", line 62, in upgrade
for vmm in session.query(old_vmm_table).all():
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2613, in all
return list(self)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2761, in iter
return self._execute_and_instances(context)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2776, in _execute_and_instances
result = conn.execute(querycontext.statement, self._params)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
return meth(self, multiparams, params)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
return connection._execute_clauseelement(self, multiparams, params)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
compiled_sql, distilled_params
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
context)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
util.raise_from_cause(newraise, exc_info)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 202, in raise_from_cause
reraise(type(exception), exception, tb=exc_tb, cause=cause)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
context)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
cursor.execute(statement, parameters)
DBError: (psycopg2.ProgrammingError) relation "aim_vmm_domains" does not exist
LINE 2: FROM aim_vmm_domains
^
[SQL: 'SELECT aim_vmm_domains.type AS aim_vmm_domains_type, aim_vmm_domains.name AS aim_vmm_domains_name \nFROM aim_vmm_domains']

The table "aim_vmm_domains" is expected to be created and available from a previous step (ab9b4e196100 -> 1249face3348). This is seen when using a postgres backend.

The postgres logs attached shows that there is a new DB session started while the previous session is committed which could be the cause of the issue. A proper session handling might fix the issue.

Attachment:
postgresql.log-201806211158.txt

[irathore]

I had already responded directly to engineer. Our DB migration does create the table.
Here is my response from email.

I just did some looking and this is what I found out. In your output

INFO [alembic.runtime.migration] Running upgrade ab9b4e196100 ->
1249face3348, Create tables for VMM and Physical Domains.

Here in the 1249face3348

https://github.com/noironetworks/aci-integration-module/blob/master/aim/db/
migration/alembic_migrations/versions/1249face3348_domains.py

def upgrade():

        op.create_table(
            'aim_vmm_domains',
            sa.Column('type', sa.String(64), nullable=False),
            sa.Column('name', sa.String(64), nullable=False),
            sa.PrimaryKeyConstraint('type', 'name'))

So if it is not being created it maybe a postgress issue.

[aplanas]

I think that what is missing in the description is that this issue happens during the first migration, from scratch (no data in the database). What happens is:

1. alembic create the initial transaction
2. start the migrations inside this transactions, in the original connection
3. at this point the commit is not done yet
4. aceb1ac13668_vmm_policy create a new connection to the dababase to get all the data from aim_vmm_domains, to make some later conversions

Is in point 4 where it fails, as is a new connection outside the original transaction, so there is no aim_vmm_domains table yet for this second connection.

So this bug can be reproduced every time we create the data from scratch (from an empty database)