We're running a Flask application with RDS Aurora Postgres and we've started to experience the following issue:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1202, in _execute_context
conn = self._revalidate_connection()
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 470, in _revalidate_connection
"Can't reconnect until invalid "
sqlalchemy.exc.InvalidRequestError: Can't reconnect until invalid transaction is rolled back
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 2077, in wsgi_app
response = self.full_dispatch_request()
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1525, in full_dispatch_request
rv = self.handle_user_exception(e)
File "/usr/local/lib/python3.7/site-packages/ddtrace/contrib/flask/helpers.py", line 25, in wrapper
return func(pin, wrapped, instance, args, kwargs)
File "/usr/local/lib/python3.7/site-packages/ddtrace/contrib/flask/helpers.py", line 36, in wrapper
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1523, in full_dispatch_request
rv = self.dispatch_request()
File "/usr/local/lib/python3.7/site-packages/ddtrace/contrib/flask/helpers.py", line 25, in wrapper
return func(pin, wrapped, instance, args, kwargs)
File "/usr/local/lib/python3.7/site-packages/ddtrace/contrib/flask/patch.py", line 489, in _traced_request
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1509, in dispatch_request
return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
File "/usr/local/lib/python3.7/site-packages/ddtrace/contrib/flask/wrappers.py", line 25, in trace_func
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/plentyservice/auth.py", line 71, in wrapper
return f(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/query.py", line 3373, in all
return list(self)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/query.py", line 3535, in __iter__
return self._execute_and_instances(context)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/query.py", line 3560, in _execute_and_instances
result = conn.execute(querycontext.statement, self._params)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1011, in execute
return meth(self, multiparams, params)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/sql/elements.py", line 298, in _execute_on_connection
return connection._execute_clauseelement(self, multiparams, params)
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1130, in _execute_clauseelement
distilled_params,
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1207, in _execute_context
e, util.text_type(statement), parameters, None, None
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1511, in _handle_dbapi_exception
sqlalchemy_exception, with_traceback=exc_info[2], from_=e
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
raise exception
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1202, in _execute_context
conn = self._revalidate_connection()
File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 470, in _revalidate_connection
"Can't reconnect until invalid "
sqlalchemy.exc.StatementError: (sqlalchemy.exc.InvalidRequestError) Can't reconnect until invalid transaction is rolled back
And just to be clear, we haven't deployed any code change for more than a month, and this application is running 24/7 and being hit very periodically. Also, it seems only a specific table when retrieving data is causing this (SELECT)
Now, what we tried when the above happened was listing connections with
SELECT * FROM pg_stat_activity ORDER BY backend_start;
OR SELECT * FROM pg_stat_activity ORDER BY xact_start;
And then using PID we would cancel those that were in IDLE status, just a couple comments on that:
- Never seen more than 4-5 idle connections at most.
- Never seen anything else that
idle
in status, neveridle in transaction
or similar
After removing those connections and restarting the application we would see the problem go away, but then, idle connections start to pile up again and we face the same issue above.
Checking Postgres log I nothing relevant other than this:
2023-05-23 05:28:17 UTC:172.22.10.33(44702):[unknown]@[unknown]:[20450]:LOG: incomplete startup packet
2023-05-23 05:51:42 UTC:172.22.1.55(38526):labtestingservice@labtestingservice:[6223]:LOG: could not receive data from client: Connection timed out
2023-05-23 05:58:17 UTC:172.22.10.33(48478):[unknown]@[unknown]:[23669]:LOG: incomplete startup packet
----------------------- END OF LOG ----------------------
From what I've seen that might happen if there is some sort of connectivity issue between client and server, but so far from what we see...haven't seen anything. What is even more strange is that some queries actually return data but they stay as idle afterwards in pg_stat_activity.
We actually have added this configuration option for AWS Postgres RDS:
idle_in_transaction_session_timeout
To something like 5 minutes but I don't think is really going to help given we don't see any connection in that state (only idle
). Might consider using this though
But even so that seems to treat the symptom but not the underlying cause...any pointers?