Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Internal server error & Lack of retries on Agents when server is failing #9323

Closed
4 tasks done
eudyptula opened this issue Apr 25, 2023 · 9 comments
Closed
4 tasks done
Labels
bug Something isn't working

Comments

@eudyptula
Copy link
Contributor

First check

  • I added a descriptive title to this issue.
  • I used the GitHub search to find a similar issue and didn't find it.
  • I searched the Prefect documentation for this issue.
  • I checked that this issue is related to Prefect and not one of its dependencies.

Bug summary

With Prefect 2.10.4, we're still seeing Internal Server Errors on the Prefect API from the agents, causing our flows to fail on a regular basis:

12:25:01.188 | ERROR   | Flow run 'uptight-quail' - Crash detected! Execution was interrupted by an unexpected exception: PrefectHTTPStatusError: Server error '500 Internal Server Error' for url 'http://.../api/task_runs'

Attached a stacktrace from the server below, from a couple of minutes earlier (closest I could find).

I assume this still happens when the DB cannot keep up and the retry code you added have retried too many times.

  1. Do you have sufficient delay in the retry code or is it just retrying a couple of times in quick succession ?

  2. If the Prefect API fails with 500 Internal Server Error, wouldn't it make sense for the Agent to wait a little while and then retry instead of just giving up at first attempt?

We been really struggling to get Prefect to run our semi-critical control systems reliably, and spending way too many manhours on platform upgrades & maintenance. Was hoping that Prefect would make our lives easier, not the other way around. Do hope you have some plans for reaching a stable release soon?

Reproduction

# Flow that started 40 tasks

Error

Apr 24 12:23:03 prefect-next sh[148160]: 12:23:03.082 | ERROR   | prefect.server.services.flowrunnotifications - Unexpected error in: TimeoutError()
Apr 24 12:23:03 prefect-next sh[148160]: Traceback (most recent call last):
Apr 24 12:23:03 prefect-next sh[148160]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
Apr 24 12:23:03 prefect-next sh[148160]:     return fut.result()
Apr 24 12:23:03 prefect-next sh[148160]: asyncio.exceptions.CancelledError
Apr 24 12:23:03 prefect-next sh[148160]: The above exception was the direct cause of the following exception:
Apr 24 12:23:03 prefect-next sh[148160]: Traceback (most recent call last):
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/services/loop_service.py", line 78, in start
Apr 24 12:23:03 prefect-next sh[148160]:     await self.run_once()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/dependencies.py", line 119, in async_wrapper
Apr 24 12:23:03 prefect-next sh[148160]:     return await fn(*args, **kwargs)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/services/flow_run_notifications.py", line 38, in run_once
Apr 24 12:23:03 prefect-next sh[148160]:     notifications = await db.get_flow_run_notifications_from_queue(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/interface.py", line 329, in get_flow_run_notifications_from_queue
Apr 24 12:23:03 prefect-next sh[148160]:     return await self.queries.get_flow_run_notifications_from_queue(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/query_components.py", line 664, in get_flow_run_notifications_from_queue
Apr 24 12:23:03 prefect-next sh[148160]:     result = await session.execute(notification_details_stmt)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/ext/asyncio/session.py", line 214, in execute
Apr 24 12:23:03 prefect-next sh[148160]:     result = await greenlet_spawn(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 126, in greenlet_spawn
Apr 24 12:23:03 prefect-next sh[148160]:     result = context.throw(*sys.exc_info())
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1713, in execute
Apr 24 12:23:03 prefect-next sh[148160]:     conn = self._connection_for_bind(bind)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Apr 24 12:23:03 prefect-next sh[148160]:     return self._transaction._connection_for_bind(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Apr 24 12:23:03 prefect-next sh[148160]:     conn = bind.connect()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/future/engine.py", line 406, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return super(Engine, self).connect()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return self._connection_cls(self, close_with_result=close_with_result)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
Apr 24 12:23:03 prefect-next sh[148160]:     else engine.raw_connection()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Apr 24 12:23:03 prefect-next sh[148160]:     return self._wrap_pool_connect(self.pool.connect, _connection)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Apr 24 12:23:03 prefect-next sh[148160]:     return fn()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 327, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return _ConnectionFairy._checkout(self)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 894, in _checkout
Apr 24 12:23:03 prefect-next sh[148160]:     fairy = _ConnectionRecord.checkout(pool)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 493, in checkout
Apr 24 12:23:03 prefect-next sh[148160]:     rec = pool._do_get()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 145, in _do_get
Apr 24 12:23:03 prefect-next sh[148160]:     with util.safe_reraise():
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 24 12:23:03 prefect-next sh[148160]:     compat.raise_(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 24 12:23:03 prefect-next sh[148160]:     raise exception
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
Apr 24 12:23:03 prefect-next sh[148160]:     return self._create_connection()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 273, in _create_connection
Apr 24 12:23:03 prefect-next sh[148160]:     return _ConnectionRecord(self)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 388, in __init__
Apr 24 12:23:03 prefect-next sh[148160]:     self.__connect()
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 690, in __connect
Apr 24 12:23:03 prefect-next sh[148160]:     with util.safe_reraise():
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 24 12:23:03 prefect-next sh[148160]:     compat.raise_(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 24 12:23:03 prefect-next sh[148160]:     raise exception
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 686, in __connect
Apr 24 12:23:03 prefect-next sh[148160]:     self.dbapi_connection = connection = pool._invoke_creator(self)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/create.py", line 574, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return dialect.connect(*cargs, **cparams)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 598, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return self.dbapi.connect(*cargs, **cparams)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 780, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     await_only(self.asyncpg.connect(*arg, **kw)),
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
Apr 24 12:23:03 prefect-next sh[148160]:     return current.driver.switch(awaitable)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
Apr 24 12:23:03 prefect-next sh[148160]:     value = await result
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connection.py", line 2092, in connect
Apr 24 12:23:03 prefect-next sh[148160]:     return await connect_utils._connect(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 895, in _connect
Apr 24 12:23:03 prefect-next sh[148160]:     raise last_error
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 881, in _connect
Apr 24 12:23:03 prefect-next sh[148160]:     return await _connect_addr(
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 773, in _connect_addr
Apr 24 12:23:03 prefect-next sh[148160]:     return await __connect_addr(params, timeout, True, *args)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 831, in __connect_addr
Apr 24 12:23:03 prefect-next sh[148160]:     await compat.wait_for(connected, timeout=timeout)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/compat.py", line 56, in wait_for
Apr 24 12:23:03 prefect-next sh[148160]:     return await asyncio.wait_for(fut, timeout)
Apr 24 12:23:03 prefect-next sh[148160]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
Apr 24 12:23:03 prefect-next sh[148160]:     raise exceptions.TimeoutError() from exc
Apr 24 12:23:03 prefect-next sh[148160]: asyncio.exceptions.TimeoutError

Versions

Version:             2.10.4
API version:         0.8.4
Python version:      3.10.6
Git commit:          b6d0433a
Built:               Thu, Apr 13, 2023 5:34 PM
OS/Arch:             linux/x86_64
Profile:             default
Server type:         server

Additional context

No response

@eudyptula eudyptula added bug Something isn't working status:triage labels Apr 25, 2023
@eudyptula
Copy link
Contributor Author

After having spent more time looking into this, am I right in the following?

  1. Running a couple of flows with many simultaneous tasks in each, creates a lot of calls to the API (state updates, logging, etc.). Each of these calls is then a query on the database.
  2. All of these does not get queued before they hit the database connection pool, on which the setting PREFECT_API_DATABASE_CONNECTION_TIMEOUT controls how long they will wait for a connection. The default value of this is only 5 sec.

If all queuing is done in the connection pool with only a 5 sec. timeout, this could explain our issue (at least turning it up seems to help, but am still testing atm.).

@zanieb
Copy link
Contributor

zanieb commented Apr 25, 2023

Hi! Sorry to hear you're having a tough time. Please try to remember we're a small team with a lot of objectives. Maintaining your own server is not trivial at scale.

We do not retry on 500 internal server errors by default because it is not guaranteed to be idempotent. You can use PREFECT_CLIENT_RETRY_EXTRA_CODES to add it to the retryable error codes which may help a lot with your intermittent server errors.

status.HTTP_429_TOO_MANY_REQUESTS,
status.HTTP_503_SERVICE_UNAVAILABLE,
status.HTTP_502_BAD_GATEWAY,
*PREFECT_CLIENT_RETRY_EXTRA_CODES.value(),

If your database is under heavy load, you may indeed benefit from increasing the PREFECT_API_DATABASE_CONNECTION_TIMEOUT and PREFECT_API_DATABASE_TIMEOUT and perhaps the PREFECT_API_REQUEST_TIMEOUT.

Note the server side stack trace you provided is not for the task_runs route, it's for the flow run notification service. It'd be helpful to get the logs for the route that actually crashed the flow.

Are you running replicas of the API? Are you using something to manage the Postgres connection pool e.g. pgbouncer?

@eudyptula
Copy link
Contributor Author

Hmm, yea, I see the mismatch in logs now - sorry about that. Can't seem to find any matching errors in the server logs right now. Will try to reproduce it later so I hopefully have matching logs.

Also I notice that in the Prefect code (begin_task_map in engine.py) that tasks, created with map, seems to be created one by one. This means one API call and one DB insert query per task created - and we do have a couple of flows that creates 5000 tasks. I assume it's a similar thing with logging, cancelling, etc. You guys really should consider batch processing/inserting these instead.

No replications of PostgreSQL, just running an instance, dedicated to Prefect, as a docker container on the same server as prefect. No extra pooling neither, but that should be all handled inside Prefect by sqlalchemy/asyncpg so I don't really see there should be a need to.

@eudyptula
Copy link
Contributor Author

eudyptula commented Apr 26, 2023

Increase timeouts does seem to help us a lot, I tried to set them back to default to reproduce the stack trace, and this time I got the following (but it does seem to be a load issue, so I suppose that the API call will vary from time to time:

Agent:

Apr 26 08:26:54 prefect-next sh[146907]: 08:26:53.953 | ERROR   | Task run 'Determine sun factors for location' - Crash detected! Execution was interrupted by an unexpected exception: PrefectHTTPStatusError: Server error '500 Internal Server Error' for url 'http://.../api/flow_runs/62ee921d-c617-4abe-941e-860d3a95c507'

Server

Apr 26 08:26:39 prefect-next sh[146881]: 08:26:39.448 | WARNING | prefect.server.services.flowrunnotifications - FlowRunNotifications took 5.661177 seconds to run, which is longer than its loop interval of 4 seconds.
Apr 26 08:26:53 prefect-next sh[146881]: 08:26:53.866 | ERROR   | prefect.server - Encountered exception in request:
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return fut.result()
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.CancelledError
Apr 26 08:26:53 prefect-next sh[146881]: The above exception was the direct cause of the following exception:
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 24, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await responder(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 44, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, self.send_with_gzip)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
Apr 26 08:26:53 prefect-next sh[146881]:     response = await func(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/utilities/server.py", line 103, in handle_response_scoped_depends
Apr 26 08:26:53 prefect-next sh[146881]:     response = await default_handler(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 237, in app
Apr 26 08:26:53 prefect-next sh[146881]:     raw_response = await run_endpoint_function(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 163, in run_endpoint_function
Apr 26 08:26:53 prefect-next sh[146881]:     return await dependant.call(**values)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/api/flow_runs.py", line 166, in read_flow_run
Apr 26 08:26:53 prefect-next sh[146881]:     flow_run = await models.flow_runs.read_flow_run(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/dependencies.py", line 119, in async_wrapper
Apr 26 08:26:53 prefect-next sh[146881]:     return await fn(*args, **kwargs)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/models/flow_runs.py", line 158, in read_flow_run
Apr 26 08:26:53 prefect-next sh[146881]:     result = await session.execute(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/ext/asyncio/session.py", line 214, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     result = await greenlet_spawn(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 126, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     result = context.throw(*sys.exc_info())
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1713, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     conn = self._connection_for_bind(bind)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     return self._transaction._connection_for_bind(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     conn = bind.connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/future/engine.py", line 406, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return super(Engine, self).connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self._connection_cls(self, close_with_result=close_with_result)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     else engine.raw_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return self._wrap_pool_connect(self.pool.connect, _connection)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Apr 26 08:26:53 prefect-next sh[146881]:     return fn()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 327, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionFairy._checkout(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 894, in _checkout
Apr 26 08:26:53 prefect-next sh[146881]:     fairy = _ConnectionRecord.checkout(pool)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 493, in checkout
Apr 26 08:26:53 prefect-next sh[146881]:     rec = pool._do_get()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 145, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     return self._create_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 273, in _create_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionRecord(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 388, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     self.__connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 690, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 686, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     self.dbapi_connection = connection = pool._invoke_creator(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/create.py", line 574, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return dialect.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 598, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self.dbapi.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 780, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     await_only(self.asyncpg.connect(*arg, **kw)),
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
Apr 26 08:26:53 prefect-next sh[146881]:     return current.driver.switch(awaitable)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     value = await result
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connection.py", line 2092, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await connect_utils._connect(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 895, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     raise last_error
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 881, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await _connect_addr(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 773, in _connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     return await __connect_addr(params, timeout, True, *args)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 831, in __connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     await compat.wait_for(connected, timeout=timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/compat.py", line 56, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return await asyncio.wait_for(fut, timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     raise exceptions.TimeoutError() from exc
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.TimeoutError
Apr 26 08:26:53 prefect-next sh[146881]: Exception in ASGI application
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 429, in run_asgi
Apr 26 08:26:53 prefect-next sh[146881]:     result = await app(  # type: ignore[func-returns-value]
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 78, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     return await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/message_logger.py", line 86, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc from None
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/message_logger.py", line 82, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, inner_receive, inner_send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await super().__call__(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.middleware_stack(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/cors.py", line 84, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 443, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await super().__call__(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.middleware_stack(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 24, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await responder(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 44, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, self.send_with_gzip)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
Apr 26 08:26:53 prefect-next sh[146881]:     response = await func(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/utilities/server.py", line 103, in handle_response_scoped_depends
Apr 26 08:26:53 prefect-next sh[146881]:     response = await default_handler(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 237, in app
Apr 26 08:26:53 prefect-next sh[146881]:     raw_response = await run_endpoint_function(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 163, in run_endpoint_function
Apr 26 08:26:53 prefect-next sh[146881]:     return await dependant.call(**values)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/api/flow_runs.py", line 166, in read_flow_run
Apr 26 08:26:53 prefect-next sh[146881]:     flow_run = await models.flow_runs.read_flow_run(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/dependencies.py", line 119, in async_wrapper
Apr 26 08:26:53 prefect-next sh[146881]:     return await fn(*args, **kwargs)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/models/flow_runs.py", line 158, in read_flow_run
Apr 26 08:26:53 prefect-next sh[146881]:     result = await session.execute(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/ext/asyncio/session.py", line 214, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     result = await greenlet_spawn(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 126, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     result = context.throw(*sys.exc_info())
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1713, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     conn = self._connection_for_bind(bind)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     return self._transaction._connection_for_bind(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     conn = bind.connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/future/engine.py", line 406, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return super(Engine, self).connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self._connection_cls(self, close_with_result=close_with_result)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     else engine.raw_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return self._wrap_pool_connect(self.pool.connect, _connection)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Apr 26 08:26:53 prefect-next sh[146881]:     return fn()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 327, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionFairy._checkout(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 894, in _checkout
Apr 26 08:26:53 prefect-next sh[146881]:     fairy = _ConnectionRecord.checkout(pool)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 493, in checkout
Apr 26 08:26:53 prefect-next sh[146881]:     rec = pool._do_get()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 145, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     return self._create_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 273, in _create_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionRecord(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 388, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     self.__connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 690, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 686, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     self.dbapi_connection = connection = pool._invoke_creator(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/create.py", line 574, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return dialect.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 598, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self.dbapi.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 780, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     await_only(self.asyncpg.connect(*arg, **kw)),
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
Apr 26 08:26:53 prefect-next sh[146881]:     return current.driver.switch(awaitable)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     value = await result
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connection.py", line 2092, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await connect_utils._connect(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 895, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     raise last_error
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 881, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await _connect_addr(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 773, in _connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     return await __connect_addr(params, timeout, True, *args)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 831, in __connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     await compat.wait_for(connected, timeout=timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/compat.py", line 56, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return await asyncio.wait_for(fut, timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     raise exceptions.TimeoutError() from exc
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.TimeoutError
Apr 26 08:26:53 prefect-next sh[146881]: 08:26:53.895 | ERROR   | prefect.server - Encountered exception in request:
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return fut.result()
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.CancelledError
Apr 26 08:26:53 prefect-next sh[146881]: The above exception was the direct cause of the following exception:
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 24, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await responder(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 44, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, self.send_with_gzip)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
Apr 26 08:26:53 prefect-next sh[146881]:     response = await func(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/utilities/server.py", line 103, in handle_response_scoped_depends
Apr 26 08:26:53 prefect-next sh[146881]:     response = await default_handler(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 237, in app
Apr 26 08:26:53 prefect-next sh[146881]:     raw_response = await run_endpoint_function(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 163, in run_endpoint_function
Apr 26 08:26:53 prefect-next sh[146881]:     return await dependant.call(**values)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/api/task_runs.py", line 52, in create_task_run
Apr 26 08:26:53 prefect-next sh[146881]:     model = await models.task_runs.create_task_run(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/dependencies.py", line 119, in async_wrapper
Apr 26 08:26:53 prefect-next sh[146881]:     return await fn(*args, **kwargs)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/models/task_runs.py", line 63, in create_task_run
Apr 26 08:26:53 prefect-next sh[146881]:     await session.execute(insert_stmt)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/ext/asyncio/session.py", line 214, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     result = await greenlet_spawn(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 126, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     result = context.throw(*sys.exc_info())
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1713, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     conn = self._connection_for_bind(bind)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     return self._transaction._connection_for_bind(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     conn = bind.connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/future/engine.py", line 406, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return super(Engine, self).connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self._connection_cls(self, close_with_result=close_with_result)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     else engine.raw_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return self._wrap_pool_connect(self.pool.connect, _connection)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Apr 26 08:26:53 prefect-next sh[146881]:     return fn()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 327, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionFairy._checkout(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 894, in _checkout
Apr 26 08:26:53 prefect-next sh[146881]:     fairy = _ConnectionRecord.checkout(pool)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 493, in checkout
Apr 26 08:26:53 prefect-next sh[146881]:     rec = pool._do_get()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 145, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     return self._create_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 273, in _create_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionRecord(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 388, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     self.__connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 690, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 686, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     self.dbapi_connection = connection = pool._invoke_creator(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/create.py", line 574, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return dialect.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 598, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self.dbapi.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 780, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     await_only(self.asyncpg.connect(*arg, **kw)),
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
Apr 26 08:26:53 prefect-next sh[146881]:     return current.driver.switch(awaitable)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     value = await result
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connection.py", line 2092, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await connect_utils._connect(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 895, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     raise last_error
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 881, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await _connect_addr(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 773, in _connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     return await __connect_addr(params, timeout, True, *args)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 831, in __connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     await compat.wait_for(connected, timeout=timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/compat.py", line 56, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return await asyncio.wait_for(fut, timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     raise exceptions.TimeoutError() from exc
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.TimeoutError
Apr 26 08:26:53 prefect-next sh[146881]: Exception in ASGI application
Apr 26 08:26:53 prefect-next sh[146881]: Traceback (most recent call last):
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 429, in run_asgi
Apr 26 08:26:53 prefect-next sh[146881]:     result = await app(  # type: ignore[func-returns-value]
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 78, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     return await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/message_logger.py", line 86, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc from None
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/uvicorn/middleware/message_logger.py", line 82, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, inner_receive, inner_send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await super().__call__(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.middleware_stack(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/cors.py", line 84, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 443, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await super().__call__(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.middleware_stack(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, _send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 24, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await responder(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/gzip.py", line 44, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, self.send_with_gzip)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise exc
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, sender)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     raise e
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
Apr 26 08:26:53 prefect-next sh[146881]:     await route.handle(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
Apr 26 08:26:53 prefect-next sh[146881]:     await self.app(scope, receive, send)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
Apr 26 08:26:53 prefect-next sh[146881]:     response = await func(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/utilities/server.py", line 103, in handle_response_scoped_depends
Apr 26 08:26:53 prefect-next sh[146881]:     response = await default_handler(request)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 237, in app
Apr 26 08:26:53 prefect-next sh[146881]:     raw_response = await run_endpoint_function(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/fastapi/routing.py", line 163, in run_endpoint_function
Apr 26 08:26:53 prefect-next sh[146881]:     return await dependant.call(**values)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/api/task_runs.py", line 52, in create_task_run
Apr 26 08:26:53 prefect-next sh[146881]:     model = await models.task_runs.create_task_run(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/database/dependencies.py", line 119, in async_wrapper
Apr 26 08:26:53 prefect-next sh[146881]:     return await fn(*args, **kwargs)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/prefect/server/models/task_runs.py", line 63, in create_task_run
Apr 26 08:26:53 prefect-next sh[146881]:     await session.execute(insert_stmt)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/ext/asyncio/session.py", line 214, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     result = await greenlet_spawn(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 126, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     result = context.throw(*sys.exc_info())
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1713, in execute
Apr 26 08:26:53 prefect-next sh[146881]:     conn = self._connection_for_bind(bind)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     return self._transaction._connection_for_bind(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Apr 26 08:26:53 prefect-next sh[146881]:     conn = bind.connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/future/engine.py", line 406, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return super(Engine, self).connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self._connection_cls(self, close_with_result=close_with_result)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     else engine.raw_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return self._wrap_pool_connect(self.pool.connect, _connection)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Apr 26 08:26:53 prefect-next sh[146881]:     return fn()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 327, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionFairy._checkout(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 894, in _checkout
Apr 26 08:26:53 prefect-next sh[146881]:     fairy = _ConnectionRecord.checkout(pool)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 493, in checkout
Apr 26 08:26:53 prefect-next sh[146881]:     rec = pool._do_get()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 145, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
Apr 26 08:26:53 prefect-next sh[146881]:     return self._create_connection()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 273, in _create_connection
Apr 26 08:26:53 prefect-next sh[146881]:     return _ConnectionRecord(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 388, in __init__
Apr 26 08:26:53 prefect-next sh[146881]:     self.__connect()
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 690, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     with util.safe_reraise():
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
Apr 26 08:26:53 prefect-next sh[146881]:     compat.raise_(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
Apr 26 08:26:53 prefect-next sh[146881]:     raise exception
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/pool/base.py", line 686, in __connect
Apr 26 08:26:53 prefect-next sh[146881]:     self.dbapi_connection = connection = pool._invoke_creator(self)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/create.py", line 574, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return dialect.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 598, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return self.dbapi.connect(*cargs, **cparams)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 780, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     await_only(self.asyncpg.connect(*arg, **kw)),
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
Apr 26 08:26:53 prefect-next sh[146881]:     return current.driver.switch(awaitable)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
Apr 26 08:26:53 prefect-next sh[146881]:     value = await result
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connection.py", line 2092, in connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await connect_utils._connect(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 895, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     raise last_error
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 881, in _connect
Apr 26 08:26:53 prefect-next sh[146881]:     return await _connect_addr(
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 773, in _connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     return await __connect_addr(params, timeout, True, *args)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/connect_utils.py", line 831, in __connect_addr
Apr 26 08:26:53 prefect-next sh[146881]:     await compat.wait_for(connected, timeout=timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/srv/prefect-2.10.4/lib/python3.10/site-packages/asyncpg/compat.py", line 56, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     return await asyncio.wait_for(fut, timeout)
Apr 26 08:26:53 prefect-next sh[146881]:   File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
Apr 26 08:26:53 prefect-next sh[146881]:     raise exceptions.TimeoutError() from exc
Apr 26 08:26:53 prefect-next sh[146881]: asyncio.exceptions.TimeoutError

@eudyptula
Copy link
Contributor Author

Okay, on top of increasing timeouts and setting retries - I also discovered that switching to DaskTaskRunner (default settings) seems to help a lot - I'm guessing it's because it limits the number of simultaneous task runs to the number of cores available.

@zanieb
Copy link
Contributor

zanieb commented Apr 26, 2023

Thanks for the additional information!

Some notes:

  • Batching task run creation is on our roadmap
  • We already batch sending logs
  • Sounds like adding a limiter to the concurrent task runner would be helpful for this case

@eudyptula
Copy link
Contributor Author

Limiter will be very helpful.

For now we're on the SequentialTaskRunner as we did not have much success with the Dask one. Kept dockers running with 100% CPU. Didn't spend the time to debug that issue, just switched to the Sequential instead. Seems to do the job for now, but may give some issues in scalability - but that'll be a challenge for the future.

@github-actions
Copy link
Contributor

github-actions bot commented Jun 1, 2023

This issue is stale because it has been open 30 days with no activity. To keep this issue open remove stale label or comment.

@github-actions
Copy link
Contributor

This issue was closed because it has been stale for 14 days with no activity. If this issue is important or you have more to add feel free to re-open it.

@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Jun 15, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants