1.3.20 breaks certain Alembic patterns with ArgumentError: column object already assigned to table

[dtantsur]

Describe the bug
The ironic-inspector project is using two instances of a similar pattern in its alembic migrations: add a column, then load a table, then do some data manipulations. Here is a concise example. This has worked up to and including 1.3.19 and fails in 1.3.20 with ArgumentError.

Expected behavior
I would be happy if it continued to work. Maybe we're doing something exceptionally stupid? Then some guidance is welcome. We are working around the problem by switching to reflection for Table.

To Reproduce
You can do it using the ironic-inspector code tree:

pip3 install --user tox
git clone https://opendev.org/openstack/ironic-inspector
cd ironic-inspector
git checkout 2e6f5ed25b738d186981ad21d13ecc1fbf2828e4 # before the workaround
tox -epy3 -- migrations

Downgrade SQLAlchemy to see it working again:

./.tox/py3/bin/pip install 'SQLAlchemy===1.3.19'
tox -epy3 -- migrations

Error

2020-10-23 12:28:44.148029 | ubuntu-focal |         "  File \"/opt/stack/bifrost/lib/python3.8/site-packages/ironic_inspector/migrations/versions/d00d6e3f38c4_change_created_finished_at_type.py\", line 46, in upgrade",
2020-10-23 12:28:44.148057 | ubuntu-focal |         "    t = sa.table('nodes', started_at, finished_at,",
2020-10-23 12:28:44.148094 | ubuntu-focal |         "  File \"<string>\", line 2, in table",
2020-10-23 12:28:44.148121 | ubuntu-focal |         "  File \"/opt/stack/bifrost/lib/python3.8/site-packages/sqlalchemy/sql/selectable.py\", line 1963, in __init__",
2020-10-23 12:28:44.148149 | ubuntu-focal |         "    self.append_column(c)",
2020-10-23 12:28:44.148210 | ubuntu-focal |         "  File \"/opt/stack/bifrost/lib/python3.8/site-packages/sqlalchemy/sql/selectable.py\", line 1984, in append_column",
2020-10-23 12:28:44.148243 | ubuntu-focal |         "    raise exc.ArgumentError(",
2020-10-23 12:28:44.148278 | ubuntu-focal |         "sqlalchemy.exc.ArgumentError: column object 'temp_started_at' already assigned to table 'nodes'"

Versions.

• OS: Fedora 32, Ubuntu Focal
• Python: 3.8.6, likely other.
• SQLAlchemy: 1.3.20
• Database: N/A
• DBAPI: N/A

Have a nice day!

[zzzeek]

Hi Dmitry -

first off I'm not sure if you're aware, I work on Openstack all day and this is an ironic-inspector bug, so normally what you can do here is make the launchpad bug and then find me on openstack freenode and I can help propose a new gerrit to fix.

the error here is that ironic-inspector is relying upon previously undefined and quite broken behavior which is that column objects allowed themselves to be attached to multiple tables, causing them to behave incorrectly. ironic-inspector will need to modify its code to ensure that each Column object used only against a single table or operation; the alembic op.add_column() operation internally attaches the given column to a table object in order to render the appropriate SQL. so these columns can't be repurposed after the fact.

[zzzeek]

here's a fix to the referenced code:

temp_started_at = lambda: sa.Column("temp_started_at", sa.types.DateTime,
                            nullable=True)
temp_finished_at = lambda: sa.Column("temp_finished_at", sa.types.DateTime,
                             nullable=True)

uuid = sa.Column("uuid", sa.String(36), primary_key=True)

op.add_column("nodes", temp_started_at())
op.add_column("nodes", temp_finished_at())

t = sa.table('nodes', started_at, finished_at,
             temp_started_at(), temp_finished_at(), uuid)

[zzzeek]

also at best this would be an Alembic bug, where alembic could perhaps copy the column before using it for op.add_column().

[dtantsur]

@zzzeek I have indeed entirely forgotten that you work on openstack. Busy time..

Thank you for your explanation, I've applied it to https://review.opendev.org/759420.

[unexceptable]

@zzzeek Hey! We're actually hitting the same error in Gnocchi, but it's kinda unclear as to what the actual cause is, because we don't seem to be reusing things as far as I can find in the code.

This is the issue:
gnocchixyz/gnocchi#1080

And the two migrations that are throw errors are:
sqlalchemy.exc.ArgumentError: column object 'started_at_ts' already assigned to table 'resource' at: https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/5c4f93e5bb4_mysql_float_to_timestamp.py
and
sqlalchemy.exc.ArgumentError: column object 'creator' already assigned to table 'resource' at https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/aba5a217ca9b_merge_created_in_creator.py

[zzzeek]

@zzzeek Hey! We're actually hitting the same error in Gnocchi, but it's kinda unclear as to what the actual cause is, because we don't seem to be reusing things as far as I can find in the code.

This is the issue:
gnocchixyz/gnocchi#1080

And the two migrations that are throw errors are:
sqlalchemy.exc.ArgumentError: column object 'started_at_ts' already assigned to table 'resource' at: https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/5c4f93e5bb4_mysql_float_to_timestamp.py

so just look for combinations of table() and add_column(), for that one it's this:

https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/5c4f93e5bb4_mysql_float_to_timestamp.py#L66

    op.add_column(table_name, temp_col)
    t = sa.sql.table(table_name, existing_col, temp_col)

use a lambda for temp_col:

temp_col = lambda: sa.Column(
                column_name + "_ts",
                sqlalchemy_types.TimestampUTC(),
                nullable=True)
            op.add_column(table_name, temp_col())
            t = sa.sql.table(table_name, existing_col, temp_col())

and
sqlalchemy.exc.ArgumentError: column object 'creator' already assigned to table 'resource' at https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/aba5a217ca9b_merge_created_in_creator.py

right here:

https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/indexer/alembic/versions/aba5a217ca9b_merge_created_in_creator.py#L42

basically anytime you are assigning a Column to a variable:

  my_col = Column(...)
  op.add_column(..., my_col)
  t = table(..., my_col)

change to a lambda:

  my_col = lambda: Column(...)
  op.add_column(..., my_col())
  t = table(..., my_col())

[zzzeek]

we're going to fix this on the Alembic side as well as it's hitting me now too. see sqlalchemy/alembic#753