Incubator-superset: Build fails on Postgres DB

[ahsanshah]

Make sure these boxes are checked before submitting your issue - thank you!

• [X ] I have checked the superset logs for python stacktraces and included it here as text if any
• [X ] I have reproduced the issue with at least the latest released version of superset
• [X ] I have checked the issue tracker for the same issue and I haven't found one similar

Superset version

master (0.25

Expected results)

Build should complete with a Postgres v10 DB

Actual results

Build fails with the following error:

INFO [alembic.runtime.migration] Running upgrade 956a063c52b3 -> 1226819ee0e3, Fix wrong constraint on table columns
WARNI [root] Could not find or drop constraint on columns
Traceback (most recent call last):
File "/usr/local/lib/python3.4/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
context)
File "/usr/local/lib/python3.4/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
cursor.execute(statement, parameters)
psycopg2.InternalError: current transaction is aborted, commands ignored until end of transaction block
sqlalchemy.exc.InternalError: (psycopg2.InternalError) current transaction is aborted, commands ignored until end of transaction block
[SQL: "UPDATE alembic_version SET version_num='1226819ee0e3' WHERE alembic_version.version_num = '956a063c52b3'"] (Background on this error at: http://sqlalche.me/e/2j85)

Steps to reproduce

Follow steps in https://github.com/apache/incubator-superset/blob/master/CONTRIBUTING.md for setting up DEV environment.

Note that this build runs fine with branch 0.25.5.

[mistercrunch]

Mmh, is this a new installation or an actual upgrade? That db migration is nearly 2 years old, I'm surprised you'd be the first to report this. And we build against postrgres at every commit...

[ahsanshah]

Its a new installation. The only thing perhaps to note is that we are using Docker. This is similar to this PR: https://github.com/apache/incubator-superset/pull/4193.

Is it safe to assume that the "master" branch build should succeed or shall we only use the "release" branches. As I mentioned, the release branches build fine on Postgres. We have successfully built Superset on prior release branches using Docker.

[mistercrunch]

master has been stable and should build just fine, you can point to the latest release tag as well.

I'm thinking this is related to your Postgres version. I'd try matching whatever version we use against travis.

[villebro]

Just hit the same issue when doing clean install on Docker against Postgres 10, will investigate.

[ahsanshah]

I am also investigating. I tried postgres 9.6 and 10. Out of curiosity how can I confirm what version Travis CI is using. I could not find a version add-on defined in travis.yml. I don't believe this is a postgres version issue but for reference does superset have a recommended version on which it is certified?

[villebro]

That whole 1226819ee0e3 migration seems slightly redundant, looking at the CI output seems it's the only migration giving off a warning. Just guessing here, but perhaps the exception coming from drop_constraint() or create_foreign_key() is somehow causing problems in alembic.op, despite being caught? The sqlalchemy link seems to indicate that the cursor has been lost or transaction rolled back as a consequence of the erroneous statement..

https://github.com/apache/incubator-superset/blob/875d0b5ad29ca69f1cad44257688f02072e9f75e/superset/migrations/versions/1226819ee0e3_fix_wrong_constraint_on_table_columns.py#L30-L42

[villebro]

By the looks of it we'll be hitting the same error at least in migration 3b626e2a6783, as there is a similar try-catch lurking there.

[mistercrunch]

Oh so the build actually doesn't fail? Presumably it just warns and perhaps leaves undesired constraints behind.

Note that alembic has issues around indeterministic constraints names on some engines.

I haven't dug in but it's possible that the migrations that actually created those wrong constraints have been altered (or should be if they haven't) to prevent creating them in the first place to avoid the issue on new builds, resulting in this exception. But we still need to attempt fixing those for environment that were above that migration at the time it was fixed.

[villebro]

No, the build does fail. There is the warning that is logged when the exception is caught, but the exception invalidates the cursor, after which the next statement fails.

It looks like these migrations are remnants of some old migrations that have since been deleted/changed. As this effectively makes it impossible to make a fresh install of Superset using a Postgres backend with current stable dependencies (my hunch is that this is something brought about by psycopg2 having changed transaction defaults in the 2.7.4 version), I would suggest fixing these migrations so that they don't cause exceptions.

Btw, where can the exact specs for the python 3.6 Postgres CI confs be found? Just curious to understand why CI isn't catching this, as it's running a fresh install every time.

[mistercrunch]

Per requirements-dev.txt, psycopg2==2.7.4 and it looks like we use whatever default version is used on travis which appears to be PostgreSQL v9.2 from the logs

[villebro]

Results from three different tests with identical configurations (Postgres 10.3 backend):
master: migrating from scratch reported warnings but finished successfully
0.25.5 tag: migration fails on first warning (see log below).
0.24.0 tag: same as master, ie. a few warnings, but no errors.

So this is not caused by the Postgres db version. I also ran a test where I first installed 0.24.0, initialized the database, then built a new 0.25.5 container, and ran the incremental migrations against the database from the 0.24.0 version, which finished without trouble. So this seems to only affect the 0.25 branch.

Full log from the 0.25.5 migration process:

INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
INFO  [alembic.runtime.migration] Will assume transactional DDL.
INFO  [alembic.runtime.migration] Running upgrade  -> 4e6a06bad7a8, Init
INFO  [alembic.runtime.migration] Running upgrade 4e6a06bad7a8 -> 5a7bad26f2a7, empty message
INFO  [alembic.runtime.migration] Running upgrade 5a7bad26f2a7 -> 1e2841a4128, empty message
INFO  [alembic.runtime.migration] Running upgrade 1e2841a4128 -> 2929af7925ed, TZ offsets in data sources
INFO  [alembic.runtime.migration] Running upgrade 2929af7925ed -> 289ce07647b, Add encrypted password field
INFO  [alembic.runtime.migration] Running upgrade 289ce07647b -> 1a48a5411020, adding slug to dash
INFO  [alembic.runtime.migration] Running upgrade 1a48a5411020 -> 315b3f4da9b0, adding log model
INFO  [alembic.runtime.migration] Running upgrade 315b3f4da9b0 -> 55179c7f25c7, sqla_descr
INFO  [alembic.runtime.migration] Running upgrade 55179c7f25c7 -> 12d55656cbca, is_featured
INFO  [alembic.runtime.migration] Running upgrade 12d55656cbca -> 2591d77e9831, user_id
INFO  [alembic.runtime.migration] Running upgrade 2591d77e9831 -> 8e80a26a31db, empty message
INFO  [alembic.runtime.migration] Running upgrade 8e80a26a31db -> 7dbf98566af7, empty message
INFO  [alembic.runtime.migration] Running upgrade 7dbf98566af7 -> 43df8de3a5f4, empty message
INFO  [alembic.runtime.migration] Running upgrade 43df8de3a5f4 -> d827694c7555, css templates
INFO  [alembic.runtime.migration] Running upgrade d827694c7555 -> 430039611635, log more
INFO  [alembic.runtime.migration] Running upgrade 430039611635 -> 18e88e1cc004, making audit nullable
INFO  [alembic.runtime.migration] Running upgrade 18e88e1cc004 -> 836c0bf75904, cache_timeouts
INFO  [alembic.runtime.migration] Running upgrade 18e88e1cc004 -> a2d606a761d9, adding favstar model
INFO  [alembic.runtime.migration] Running upgrade a2d606a761d9, 836c0bf75904 -> d2424a248d63, empty message
INFO  [alembic.runtime.migration] Running upgrade d2424a248d63 -> 763d4b211ec9, fixing audit fk
INFO  [alembic.runtime.migration] Running upgrade d2424a248d63 -> 1d2ddd543133, log dt
INFO  [alembic.runtime.migration] Running upgrade 1d2ddd543133, 763d4b211ec9 -> fee7b758c130, empty message
INFO  [alembic.runtime.migration] Running upgrade fee7b758c130 -> 867bf4f117f9, Adding extra field to Database model
INFO  [alembic.runtime.migration] Running upgrade 867bf4f117f9 -> bb51420eaf83, add schema to table model
INFO  [alembic.runtime.migration] Running upgrade bb51420eaf83 -> b4456560d4f3, change_table_unique_constraint
INFO  [alembic.runtime.migration] Running upgrade b4456560d4f3 -> 4fa88fe24e94, owners_many_to_many
INFO  [alembic.runtime.migration] Running upgrade 4fa88fe24e94 -> c3a8f8611885, Materializing permission
INFO  [alembic.runtime.migration] Running upgrade c3a8f8611885 -> f0fbf6129e13, Adding verbose_name to tablecolumn
INFO  [alembic.runtime.migration] Running upgrade f0fbf6129e13 -> 956a063c52b3, adjusting key length
INFO  [alembic.runtime.migration] Running upgrade 956a063c52b3 -> 1226819ee0e3, Fix wrong constraint on table columns
WARNI [root] Could not find or drop constraint on `columns`
Loaded your LOCAL configuration at [/superset/superset_config.py]
Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
    context)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/default.py", line 508, in do_execute
    cursor.execute(statement, parameters)
psycopg2.InternalError: current transaction is aborted, commands ignored until end of transaction block


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/bin/superset", line 15, in <module>
    manager.run()
  File "/usr/local/lib/python3.5/dist-packages/flask_script/__init__.py", line 417, in run
    result = self.handle(argv[0], argv[1:])
  File "/usr/local/lib/python3.5/dist-packages/flask_script/__init__.py", line 386, in handle
    res = handle(*args, **config)
  File "/usr/local/lib/python3.5/dist-packages/flask_script/commands.py", line 216, in __call__
    return self.run(*args, **kwargs)
  File "/usr/local/lib/python3.5/dist-packages/flask_migrate/__init__.py", line 259, in upgrade
    command.upgrade(config, revision, sql=sql, tag=tag)
  File "/usr/local/lib/python3.5/dist-packages/alembic/command.py", line 254, in upgrade
    script.run_env()
  File "/usr/local/lib/python3.5/dist-packages/alembic/script/base.py", line 427, in run_env
    util.load_python_file(self.dir, 'env.py')
  File "/usr/local/lib/python3.5/dist-packages/alembic/util/pyfiles.py", line 81, in load_python_file
    module = load_module_py(module_id, path)
  File "/usr/local/lib/python3.5/dist-packages/alembic/util/compat.py", line 83, in load_module_py
    spec.loader.exec_module(module)
  File "<frozen importlib._bootstrap_external>", line 665, in exec_module
  File "<frozen importlib._bootstrap>", line 222, in _call_with_frames_removed
  File "/usr/local/lib/python3.5/dist-packages/superset/migrations/env.py", line 103, in <module>
    run_migrations_online()
  File "/usr/local/lib/python3.5/dist-packages/superset/migrations/env.py", line 96, in run_migrations_online
    context.run_migrations()
  File "<string>", line 8, in run_migrations
  File "/usr/local/lib/python3.5/dist-packages/alembic/runtime/environment.py", line 836, in run_migrations
    self.get_context().run_migrations(**kw)
  File "/usr/local/lib/python3.5/dist-packages/alembic/runtime/migration.py", line 337, in run_migrations
    head_maintainer.update_to_step(step)
  File "/usr/local/lib/python3.5/dist-packages/alembic/runtime/migration.py", line 540, in update_to_step
    self._update_version(from_, to_)
  File "/usr/local/lib/python3.5/dist-packages/alembic/runtime/migration.py", line 500, in _update_version
    == literal_column("'%s'" % from_))
  File "/usr/local/lib/python3.5/dist-packages/alembic/ddl/impl.py", line 118, in _exec
    return conn.execute(construct, *multiparams, **params)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 948, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement
    compiled_sql, distilled_params
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context
    context)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 1413, in _handle_dbapi_exception
    exc_info
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/util/compat.py", line 186, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
    context)
  File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/engine/default.py", line 508, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.InternalError: (psycopg2.InternalError) current transaction is aborted, commands ignored until end of transaction block
 [SQL: "UPDATE alembic_version SET version_num='1226819ee0e3' WHERE alembic_version.version_num = '956a063c52b3'"] (Background on this error at: http://sqlalche.me/e/2j85)

[ahsanshah]

I assume per the above messages we can rule out Docker or Postgres version being the culprit and builds work fine on MySQL? Not familiar yet with the TRAVIS CI build but going to get caught up on that. I suppose my question is, would mySQL be the more "recommended" option for the Superset Metadata DB?

[villebro]

I agree @ahsanshah, there's definitely been some regression between 0.24 and upcoming 0.26 (master) that makes migrations oversensitive to exceptions. I have a PR in the makings for cleaning out any cruft out of the old migrations, will try to get it done asap. This of course doesn't address the oversensitivity issue, but makes it a non-issue, as there shouldn't be any warnings left to fail the migrations.

[villebro]

@ahsanshah, wrt to the recommended backend, just looking at CI logs it seems that mysql is the only backend out of sqlite, mysql and postgres that doesn't produce any warnings. So perhaps that's serves as some indication of stability. But going forward I think this should be seen as an isolated regression rather than an indication of postgres being deprecated.

[ahsanshah]

Thank you. Will retry build on MySQL for the time being.

[mistercrunch]

I cannot reproduce, but can you try this patch? https://github.com/apache/incubator-superset/pull/5125

[villebro]

The problem here seems to be discrepancies between requirements.txt and setup.py, in this case the most recent stable version of flask-appbuilder (1.11.1) and what is defined in requirements.txt (1.10.0). I think it would be wise to have a CI test that relies only on the deps defined in setup.py, as that's what pip will ultimately be using.

[xiaohanyu]

Same problem here, with both postgres 9.6 and 10.0

[fordguo]

@villebro indeed .
I use the flask-appbuilder (1.10.0) successfully.

[mistercrunch]

Here's a quick fix https://github.com/apache/incubator-superset/pull/5133

[ahsanshah]

Confirmed fix works.