tortoise / aerich

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

Asyncpg connection pool error #192

Open malikovss opened 3 years ago

malikovss commented 3 years ago

I'm facing error with aerich. aerich==0.5.7 asyncpg==0.24.0

Traceback (most recent call last):
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/bin/aerich", line 8, in <module>
    sys.exit(main())
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/cli.py", line 258, in main
    cli()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/cli.py", line 36, in wrapper
    loop.run_until_complete(Tortoise.close_connections())
  File "uvloop/loop.pyx", line 1501, in uvloop.loop.Loop.run_until_complete
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/__init__.py", line 610, in close_connections
    await asyncio.gather(*tasks)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 114, in close
    await self._close()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 107, in _close
    await asyncio.wait_for(self._pool.close(), 10)
  File "/usr/lib/python3.8/asyncio/tasks.py", line 494, in wait_for
    return fut.result()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py", line 689, in close
    await asyncio.gather(*close_coros)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py", line 235, in close
    await self._con.close()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/connection.py", line 1104, in close
    await self._protocol.close(timeout)
  File "asyncpg/protocol/protocol.pyx", line 561, in close
RuntimeError: Task <Task pending name='Task-17' coro=<PoolConnectionHolder.close() running at /home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py:235> cb=[gather.<locals>._done_callback() at /usr/lib/python3.8/asyncio/tasks.py:769]> got Future <Future pending cb=[Protocol._on_waiter_completed()]> attached to a different loop

Another error when aerich upgrade

ubuntu@ip-172-31-33-93:~/nbot/namazuzbot$ aerich upgrade
Traceback (most recent call last):
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/bin/aerich", line 8, in <module>
    sys.exit(main())
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/cli.py", line 258, in main
    cli()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/cli.py", line 33, in wrapper
    loop.run_until_complete(f(*args, **kwargs))
  File "uvloop/loop.pyx", line 1501, in uvloop.loop.Loop.run_until_complete
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/cli.py", line 102, in upgrade
    migrated = await command.upgrade()
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/aerich/__init__.py", line 42, in upgrade
    exists = await Aerich.exists(version=version_file, app=self.app)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/queryset.py", line 959, in _execute
    result, _ = await self._db.execute_query(str(self.query))
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 36, in translate_exceptions_
    return await func(self, *args)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/backends/asyncpg/client.py", line 177, in execute_query
    return len(rows), rows
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/tortoise/backends/base/client.py", line 300, in __aexit__
    await self.pool.release(self.connection)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py", line 654, in release
    return await asyncio.shield(ch.release(timeout))
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py", line 216, in release
    raise ex
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/pool.py", line 206, in release
    await self._con.reset(timeout=budget)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/connection.py", line 1137, in reset
    await self.execute(reset_query, timeout=timeout)
  File "/home/ubuntu/env/ptime-lA1YRgHY-py3.8/lib/python3.8/site-packages/asyncpg/connection.py", line 295, in execute
    return await self._protocol.query(query, timeout)
  File "asyncpg/protocol/protocol.pyx", line 301, in query
  File "asyncpg/protocol/protocol.pyx", line 664, in asyncpg.protocol.protocol.BaseProtocol._check_state
asyncpg.exceptions._base.InterfaceError: cannot perform operation: another operation is in progress
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
malikovss commented 3 years ago

@long2ice can you help me please?

s3rius commented 2 years ago

I have the same issue. @long2ice, can you please check?

VasilevAlexandr97 commented 2 years ago

I have the same issue. postgresql 13.4, python 3.9.7, aerich 0.5.8

s3rius commented 2 years ago

I found a temporary workaround. You can simply uninstall uvloop.

But, I think this problem must be fixed.

I've tried different versions of uvloop, but it didn't solve the problem. The problem appeared even when I installed uvloop as a part of tortoise-orm, by using "[accel]" extra flag in the installation command.

w-A-L-L-e commented 1 year ago

I'm not having this with aerich migrations. However it does happen when using aerich queries inside a background_task from fastapi. Uninstalling uvloop (not putting it in requirements.txt) does not help however :(.

Everything runs fine in the background_task but then the first following regular request throws this error:

INFO:     172.21.0.1:45402 - "GET /sip_profiles HTTP/1.1" 500 Internal Server Error
fit-backend-backend-1  | ERROR:    Exception in ASGI application
fit-backend-backend-1  | Traceback (most recent call last):
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/uvicorn/protocols/http/httptools_impl.py", line 435, in run_asgi
fit-backend-backend-1  |     result = await app(  # type: ignore[func-returns-value]
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/uvicorn/middleware/proxy_headers.py", line 78, in __call__
fit-backend-backend-1  |     return await self.app(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/fastapi/applications.py", line 208, in __call__
fit-backend-backend-1  |     await super().__call__(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/applications.py", line 112, in __call__
fit-backend-backend-1  |     await self.middleware_stack(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/middleware/errors.py", line 181, in __call__
fit-backend-backend-1  |     raise exc from None
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/middleware/errors.py", line 159, in __call__
fit-backend-backend-1  |     await self.app(scope, receive, _send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/middleware/cors.py", line 86, in __call__
fit-backend-backend-1  |     await self.simple_response(scope, receive, send, request_headers=headers)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/middleware/cors.py", line 142, in simple_response
fit-backend-backend-1  |     await self.app(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/exceptions.py", line 82, in __call__
fit-backend-backend-1  |     raise exc from None
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/exceptions.py", line 71, in __call__
fit-backend-backend-1  |     await self.app(scope, receive, sender)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/routing.py", line 580, in __call__
fit-backend-backend-1  |     await route.handle(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/routing.py", line 241, in handle
fit-backend-backend-1  |     await self.app(scope, receive, send)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/starlette/routing.py", line 52, in app
fit-backend-backend-1  |     response = await func(request)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/fastapi/routing.py", line 209, in app
fit-backend-backend-1  |     solved_result = await solve_dependencies(
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/fastapi/dependencies/utils.py", line 550, in solve_dependencies
fit-backend-backend-1  |     solved = await call(**sub_values)
fit-backend-backend-1  |   File "/app/src/auth/jwthandler.py", line 94, in get_current_user
fit-backend-backend-1  |     user = await UserOutSchema.from_queryset_single(
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/contrib/pydantic/base.py", line 100, in from_queryset_single
fit-backend-backend-1  |     return cls.from_orm(await queryset.prefetch_related(*fetch_fields))
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/queryset.py", line 1008, in _execute
fit-backend-backend-1  |     instance_list = await self._db.executor_class(
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/backends/base/executor.py", line 131, in execute_select
fit-backend-backend-1  |     _, raw_results = await self.db.execute_query(query.get_sql())
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/backends/base_postgres/client.py", line 34, in _translate_exceptions
fit-backend-backend-1  |     return await self._translate_exceptions(func, *args, **kwargs)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/backends/asyncpg/client.py", line 82, in _translate_exceptions
fit-backend-backend-1  |     return await func(self, *args, **kwargs)
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/backends/asyncpg/client.py", line 129, in execute_query
fit-backend-backend-1  |     async with self.acquire_connection() as connection:
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/tortoise/backends/base/client.py", line 328, in __aenter__
fit-backend-backend-1  |     self.connection = await self.pool.acquire()
fit-backend-backend-1  |   File "/usr/local/lib/python3.9/site-packages/asyncpg/pool.py", line 621, in _acquire
fit-backend-backend-1  |     raise exceptions.InterfaceError('pool is closing')
fit-backend-backend-1  | asyncpg.exceptions._base.InterfaceError: pool is closing

After that requests return to normal. Is there some way to fix this by putting something like asyncpg close explicitly somewhere?

w-A-L-L-e commented 1 year ago

Ok found a workaround. For anyone also bumping into this. Don't use .save() on a model as this gets you into this pool is closing exception happening.


    batch = await Batch.get(id=batch_id)
    sip_creation = await BatchStatus.get(status="sip_creation")
    batch.status_id = sip_creation.id
    await batch.save()

Replaced with new code:

  sip_creation = await BatchStatus.get(status="sip_creation")
    await Batch.filter(id=batch_id).update(
        status_id=sip_creation.id
    )

Both make an update in the database however the second one works perfectly in a background task. The first one does not. Also we need to use multiple uvicorn/gunicorn workers.

Nevermind. When the task is larger, it still happens :(

Basically whenever a background task is still using the database while a new request comes in we get this:

 self.connection = await self.pool.acquire()
 File "/usr/local/lib/python3.9/site-packages/asyncpg/pool.py", line 621, in _acquire
   raise exceptions.InterfaceError('pool is closing')
asyncpg.exceptions._base.InterfaceError: pool is closing