0

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 idlein status, never idle in transactionor 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?

5
  • I suggest you to check your pooling settings. (psycopg2 pool settings or maybe there is a pgbouncer in between.)
    – Sahap Asci
    May 23, 2023 at 16:22
  • That first-shown error message sounds like some follow-on error from an earlier error (probably because your app has broken error handling). Look further back in the log file to identify the originating error.
    – jjanes
    May 23, 2023 at 16:52
  • 1
    You ask about "so many idle connections" but also say "Never seen more than 4-5 idle connections". Is 4-5 so many? What do idle connections have to do with your originally stated error message?
    – jjanes
    May 23, 2023 at 16:58
  • @SahapAsci thanks, will check. May 24, 2023 at 17:17
  • @jjanes the stack trace you see there is what we get from DataDog, we have some Flask endpoint that makes a request to fetch data from that table and simply fails because of the issue described in there. We're already surrounded that with try ... except so if it fails we rollback but I'm not super happy with that approach either. As for my comment on the "many connections", what I meant is that if its normal to see connections piling up as idle. From what I've read, idle means that the connection has been disrupted for whatever reason. May 24, 2023 at 17:17

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Browse other questions tagged or ask your own question.