Flask-migrate: Error on flask db upgrade

[guillermohs9]

Hi! I'm trying to implement flask_migrate on my project. I use app factory pattern and followed the instructions from the blog. After setting "FLASK_APP=run.py", flask db init works fine and creates every file as expected. I create a test model, run flask db migrate, and the script is generated just fine. But when I run flask db upgrade, I get an error:

(venv) [guillermo@arch softalq]$ flask db upgrade
/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask_sqlalchemy/__init__.py:835: FSADeprecationWarning: SQLALCHEMY_TRACK_MODIFICATIONS adds significant overhead and will be disabled by default in the future. Set it to True or False to suppress this warning.
'SQLALCHEMY_TRACK_MODIFICATIONS adds significant overhead and '
INFO [alembic.runtime.migration] Context impl MySQLImpl.
INFO [alembic.runtime.migration] Will assume non-transactional DDL.
INFO [alembic.runtime.migration] Running upgrade -> cc85dbd830d7, empty message
Traceback (most recent call last):
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1284, in _execute_context
cursor, statement, parameters, context
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
cursor.execute(statement, parameters)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 517, in query
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 732, in _read_query_result
result.read()
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 1075, in read
first_packet = self.connection._read_packet()
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 657, in _read_packet
packet_header = self._read_bytes(4)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 707, in _read_bytes
CR.CR_SERVER_LOST, "Lost connection to MySQL server during query")
pymysql.err.OperationalError: (2013, 'Lost connection to MySQL server during query')

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

Traceback (most recent call last):
File "/home/guillermo/PycharmProjects/softalq/venv/bin/flask", line 10, in
sys.exit(main())
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask/cli.py", line 967, in main
cli.main(args=sys.argv[1:], prog_name="python -m flask" if as_module else None)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask/cli.py", line 586, in main
return super(FlaskGroup, self).main(args, kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 782, in main
rv = self.invoke(ctx)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 1259, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 1259, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 1066, in invoke
return ctx.invoke(self.callback, *ctx.params)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 610, in invoke
return callback(args, *kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/decorators.py", line 21, in new_func
return f(get_current_context(), args, *kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask/cli.py", line 426, in decorator
return __ctx.invoke(f, args, *kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/click/core.py", line 610, in invoke
return callback(args, *kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask_migrate/cli.py", line 134, in upgrade
_upgrade(directory, revision, sql, tag, x_arg)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask_migrate/__init__.py", line 96, in wrapped
f(args, *kwargs)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/flask_migrate/__init__.py", line 271, in upgrade
command.upgrade(config, revision, sql=sql, tag=tag)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/command.py", line 298, in upgrade
script.run_env()
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/script/base.py", line 489, in run_env
util.load_python_file(self.dir, "env.py")
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/util/pyfiles.py", line 98, in load_python_file
module = load_module_py(module_id, path)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/util/compat.py", line 184, in load_module_py
spec.loader.exec_module(module)
File "", line 728, in exec_module
File "", line 219, in _call_with_frames_removed
File "migrations/env.py", line 96, in
run_migrations_online()
File "migrations/env.py", line 90, in run_migrations_online
context.run_migrations()
File "", line 8, in run_migrations
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/runtime/environment.py", line 846, in run_migrations
self.get_context().run_migrations(kw)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/runtime/migration.py", line 520, in run_migrations
step.migration_fn(*kw)
File "/home/guillermo/PycharmProjects/softalq/migrations/versions/cc85dbd830d7_.py", line 21, in upgrade
op.drop_column('datos', 'test')
File "", line 8, in drop_column
File "", line 3, in drop_column
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/operations/ops.py", line 2049, in drop_column
return operations.invoke(op)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/operations/base.py", line 374, in invoke
return fn(self, operation)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/operations/toimpl.py", line 81, in drop_column
operation.table_name, column, schema=operation.schema, *operation.kw
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/ddl/impl.py", line 240, in drop_column
self._exec(base.DropColumn(table_name, column, schema=schema))
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/alembic/ddl/impl.py", line 140, in _exec
return conn.execute(construct, multiparams, *params)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1020, in execute
return meth(self, multiparams, params)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/sql/ddl.py", line 72, in _execute_on_connection
return connection._execute_ddl(self, multiparams, params)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1082, in _execute_ddl
compiled,
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1324, in _execute_context
e, statement, parameters, cursor, context
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1518, in _handle_dbapi_exception
sqlalchemy_exception, with_traceback=exc_info[2], from_=e
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/util/compat.py", line 178, in raise_
raise exception
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1284, in _execute_context
cursor, statement, parameters, context
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
cursor.execute(statement, parameters)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 517, in query
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 732, in _read_query_result
result.read()
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 1075, in read
first_packet = self.connection._read_packet()
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 657, in _read_packet
packet_header = self._read_bytes(4)
File "/home/guillermo/PycharmProjects/softalq/venv/lib/python3.7/site-packages/pymysql/connections.py", line 707, in _read_bytes
CR.CR_SERVER_LOST, "Lost connection to MySQL server during query")
sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
[SQL: ALTER TABLE datos DROP COLUMN test]
(Background on this error at: http://sqlalche.me/e/e3q8)

The changes are reflected to the db, but if I make another change in models.py and try to do another flask db migrate, it reports the db is not up to date. I'm using Mariadb on Arch Linux, latest SQLAlchemy and Flask_migrate with Python 3.7. I hope I've given enough info.
Cheers

[miguelgrinberg]

I think this happens because MySQL is running queries that run for longer than the timeout you have configured. See https://anothercoffee.net/fix-error-code-2013-lost-connection-mysql-server-query/ for some ideas on how to debug and address this problem.

[guillermohs9]

I tried making the configuration changes in the server, and tried passing different configuration parameters to SQLAlchemy such as SQLALCHEMY_POOL_RECYCLE to adapt them to the timeout on the server, all without success.

Maybe It's worth mentioning that I'm using flask-sqlalchemy and that with no other configuration than the DB URI and setting TRACK_MODIFICATIONS to False, everything is default and was working ok with the same server before trying to do migrations.

[miguelgrinberg]

@guillermohs9 how big is your database? I assume some change you are trying to make in your migration script takes a very long time, longer than your timeout setting.

[guillermohs9]

Currently, 26 tables, some bigger than others, obviously. I tried setting every variable that had %timeout% to 1000% its default value, but the issue persists.

[miguelgrinberg]

What is your migration trying to do? Have you measure how long it takes from the time you start the upgrade command until the time you get the error?

[guillermohs9]

I added a test column to one of the tables, and I also tried adding a small test table. In both cases, the error shows up almost instantly, stays for a split second on running upgrade, and the traceback shows up. This is the output of time flask db upgrade (stripped the error):

real    0m2,909s
user    0m1,225s
sys     0m0,137s

[miguelgrinberg]

I was just going over the possible issues in this page and the only one that can possibly match your case is one where the connection takes too long. Have you tried increasing the connection timeout , as suggested in this docs page?

[guillermohs9]

I tried setting connect_timeout, net_read_timeout and net_write_timeout to 6000 (defaults are 10, 30 and 60 respectively). Still no luck. I will try to set up the server on a vm and make it mysql not mariadb. Although I've never had issues with the server with this app or any other app in the past.

[guillermohs9]

Hi Miguel, after trying out several drivers (pymysql, mysql-connector) and various parameters, I set up an Ubuntu VM and with that MySQL server worked out of the box. So after a thorough readup online, I got flask db upgrade working with Mariadb using these values (still don't know if any of them is insanely large, but hey, it works):

SET GLOBAL max_allowed_packet = 1024 * 1024 * 256; set global net_write_timeout = 6000; set global net_read_timeout = 6000; set global connect_timeout = 6000; set global max_allowed_packet = 67108864; set global slave_net_timeout = 6000; set global thread_pool_idle_timeout = 6000;

I'm still to add this to the config file. I also had to add the lines:

LimitNOFILE=10000
LimitMEMLOCK=10000

to the file /usr/lib/systemd/system/mariadb.service.

Thanks for your help! I can now use flask-migrate withouth issues.