tortoise / aerich

A database migrations tool for TortoiseORM, ready to production.
https://github.com/tortoise/aerich
Apache License 2.0
841 stars 95 forks source link

Can't upgrade: another operation is in progress #129

Closed Olegt0rr closed 3 years ago

Olegt0rr commented 3 years ago

Can't upgrade new database to the latest version.

How to reproduce

  1. Create any app
  2. Init aerich (creates aerich.ini and migrations folder)
  3. Init db (creates migrations/models/0_datetime_init.sql migration and add line to aerich table with 0 version)
  4. Get new clean database or drop all tables
  5. Run aerich upgrade

Expected behavior

Database filled with tables from migrations/models/ migrations

Real behavior

aerich upgrade

Traceback (most recent call last):
  File "venv/lib/python3.9/site-packages/tortoise/backends/asyncpg/client.py", line 176, in execute_query
    rows = await connection.fetch(*params)
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 583, in fetch
    return await self._execute(
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 1625, in _execute
    result, _ = await self.__execute(
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 1650, in __execute
    return await self._do_execute(
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 1677, in _do_execute
    stmt = await self._get_statement(
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 375, in _get_statement
    statement = await self._protocol.prepare(
  File "asyncpg/protocol/protocol.pyx", line 166, in prepare
RuntimeError: Task <Task pending name='Task-4' coro=<upgrade() running at venv/lib/python3.9/site-packages/aerich/cli.py:108> cb=[run_until_complete.<locals>.done_cb()]> got Future <Future pending cb=[Protocol._on_waiter_completed()]> attached to a different loop

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "venv/bin/aerich", line 8, in <module>
    sys.exit(main())
  File "venv/lib/python3.9/site-packages/aerich/cli.py", line 309, in main
    cli()
  File "venv/lib/python3.9/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "venv/lib/python3.9/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "venv/lib/python3.9/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "venv/lib/python3.9/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "venv/lib/python3.9/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "venv/lib/python3.9/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "venv/lib/python3.9/site-packages/aerich/cli.py", line 38, in wrapper
    loop.run_until_complete(f(*args, **kwargs))
  File "uvloop/loop.pyx", line 1494, in uvloop.loop.Loop.run_until_complete
  File "venv/lib/python3.9/site-packages/aerich/cli.py", line 108, in upgrade
    exists = await Aerich.exists(version=version_file, app=app)
  File "venv/lib/python3.9/site-packages/tortoise/queryset.py", line 959, in _execute
    result, _ = await self._db.execute_query(str(self.query))
  File "venv/lib/python3.9/site-packages/tortoise/backends/asyncpg/client.py", line 36, in translate_exceptions_
    return await func(self, *args)
  File "venv/lib/python3.9/site-packages/tortoise/backends/asyncpg/client.py", line 177, in execute_query
    return len(rows), rows
  File "venv/lib/python3.9/site-packages/asyncpg/pool.py", line 218, in release
    raise ex
  File "venv/lib/python3.9/site-packages/asyncpg/pool.py", line 208, in release
    await self._con.reset(timeout=budget)
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 1311, in reset
    await self.execute(reset_query, timeout=timeout)
  File "venv/lib/python3.9/site-packages/asyncpg/connection.py", line 297, in execute
    return await self._protocol.query(query, timeout)
  File "asyncpg/protocol/protocol.pyx", line 321, in query
  File "asyncpg/protocol/protocol.pyx", line 684, in asyncpg.protocol.protocol.BaseProtocol._check_state
asyncpg.exceptions._base.InterfaceError: cannot perform operation: another operation is in progress

Versions

asyncpg = "^0.22.0"
aerich = "^0.5.0"
tortoise-orm = "^0.16.18"
Olegt0rr commented 3 years ago

@long2ice, could you help me to manage it? I can provide any kind of tests and params you wish :)

Checked on Python 3.8.7 - the same. Command aerich migrate --name new_field crashes too. So, I can't do nothing except init-db...

Seems you are using a shared connection and are attempting to run queries concurrently on it. But you should acquire/release a pool connection for each request. Can't find it the app where is it happens.

long2ice commented 3 years ago

Seem related https://github.com/MagicStack/asyncpg/issues/576

Olegt0rr commented 3 years ago

Seem related MagicStack/asyncpg#576

Sure, it's one of many issues for asyncpg with that exception. If you read already closed issues, you're find the answers:

long2ice commented 3 years ago

I tried in local but success:

aerich             0.5.1
asyncpg            0.22.0
tortoise-orm       0.16.21

Maybe version relate?

Olegt0rr commented 3 years ago

aerich 0.5.1 not found in releases / pypi

long2ice commented 3 years ago

Install it from dev branch

Olegt0rr commented 3 years ago

I've found the reason!

You're reading aerich.ini from default place too, even if I pass -c custom/aerich.ini! My aerich.ini relates to config file linked to the database, so it's lock it!

As a temp solution, I've moved aerich.ini from default path and my app become fixed :)

long2ice commented 3 years ago

If your config is not in default file, you should appoint it in every command first

Olegt0rr commented 3 years ago

If your config is not in default file, you should appoint it in every command first

It's not a reason. As you can see in DEBUG mode, aerich succesfully read aerich table, so config is correct. But still getting troubles...

aerich upgrade
DEBUG:tortoise:Tortoise-ORM startup
    connections: {'default': 'postgres://pguser:pgp***@localhost:5432/cw'}
    apps: {'models': {'models': ['app.models', 'aerich.models'], 'default_connection': 'default'}}
DEBUG:db_client:Created connection pool <asyncpg.pool.Pool object at 0x7fa246fbe2b0> with params: {'host': 'localhost', 'port': 5432, 'user': 'pguser', 'database': 'cw', 'min_size': 1, 'max_size': 5, 'connection_class': <class 'asyncpg.connection.Connection'>, 'loop': None}
DEBUG:db_client:SELECT "id","version","app","content" FROM "aerich" WHERE "app"='models' ORDER BY "id" DESC LIMIT 1: None
DEBUG:db_client:SELECT 1 FROM "aerich" WHERE "version"='0_20210416120641_init.sql' AND "app"='models' LIMIT 1: None
DEBUG:db_client:Closed connection pool None with params: {'host': 'localhost', 'port': 5432, 'user': 'pguser', 'database': 'cw', 'min_size': 1, 'max_size': 5, 'connection_class': <class 'asyncpg.connection.Connection'>, 'loop': None}
INFO:tortoise:Tortoise-ORM shutdown
Traceback (most recent call last):
  File "venv/bin/aerich", line 8, in <module>
    sys.exit(main())
  File "venv/lib/python3.8/site-packages/aerich/cli.py", line 298, in main
    cli()
  File "venv/lib/python3.8/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "venv/lib/python3.8/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "venv/lib/python3.8/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "venv/lib/python3.8/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "venv/lib/python3.8/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "venv/lib/python3.8/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "venv/lib/python3.8/site-packages/aerich/cli.py", line 41, in wrapper
    loop.run_until_complete(f(*args, **kwargs))
  File "uvloop/loop.pyx", line 1494, in uvloop.loop.Loop.run_until_complete
  File "venv/lib/python3.8/site-packages/aerich/cli.py", line 110, in upgrade
    exists = await Aerich.exists(version=version_file, app=app)
  File "venv/lib/python3.8/site-packages/tortoise/queryset.py", line 1038, in _execute
    result, _ = await self._db.execute_query(str(self.query))
  File "venv/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 36, in translate_exceptions_
    return await func(self, *args)
  File "venv/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 177, in execute_query
    return len(rows), rows
  File "venv/lib/python3.8/site-packages/tortoise/backends/base/client.py", line 308, in __aexit__
    await self.pool.release(self.connection)
  File "venv/lib/python3.8/site-packages/asyncpg/pool.py", line 666, in release
    return await asyncio.shield(ch.release(timeout))
  File "venv/lib/python3.8/site-packages/asyncpg/pool.py", line 218, in release
    raise ex
  File "venv/lib/python3.8/site-packages/asyncpg/pool.py", line 208, in release
    await self._con.reset(timeout=budget)
  File "venv/lib/python3.8/site-packages/asyncpg/connection.py", line 1311, in reset
    await self.execute(reset_query, timeout=timeout)
  File "venv/lib/python3.8/site-packages/asyncpg/connection.py", line 297, in execute
    return await self._protocol.query(query, timeout)
  File "asyncpg/protocol/protocol.pyx", line 321, in query
  File "asyncpg/protocol/protocol.pyx", line 684, in asyncpg.protocol.protocol.BaseProtocol._check_state
asyncpg.exceptions._base.InterfaceError: cannot perform operation: another operation is in progress
ERROR:asyncio:Future exception was never retrieved
future: <Future finished exception=ConnectionDoesNotExistError('connection was closed in the middle of operation')>
asyncpg.exceptions.ConnectionDoesNotExistError: connection was closed in the middle of operation
Olegt0rr commented 3 years ago

@long2ice please, reopen it

Seems you are closing connection pool before pool release the connection. Look at the logs in the previous message: message Closed connection pool appears before Tortoise-ORM shutdown

Olegt0rr commented 3 years ago

Also I've found the way to temporary resolve this issue: removing uvloop

iamnalinor commented 7 months ago

I'm expierencing the same problem.

Versions:

aerich 0.7.2
tortoise-orm 0.20.0
asyncpg 0.29.0

As mentioned before, removing uvloop (or not importing it) solves the issue, but it's not the solution I wanted to see. It would be great to re-open the issue.