Roznoshchik / Lurnby

A tool for active reading and personal knowledge management
https://www.lurnby.com
BSD 3-Clause "New" or "Revised" License
680 stars 18 forks source link

DB Connection Timeout Issue #30

Closed sharedphysics closed 2 years ago

sharedphysics commented 2 years ago

There is an issue when if you leave a screen open for too long, the database connection will close before the app connection closes. If someone tries to do something on that page, they will get an error that looks like this:

image

The log for this issue is:

Exception on /app/articles [GET]
Traceback (most recent call last):
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1283, in _execute_context
   self.dialect.do_execute(
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
   cursor.execute(statement, parameters)
psycopg2.OperationalError: terminating connection due to administrator command
SSL connection has been closed unexpectedly

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/app.py", line 2447, in wsgi_app
   response = self.full_dispatch_request()
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/app.py", line 1952, in full_dispatch_request
   rv = self.handle_user_exception(e)
 File "/app/.heroku/python/lib/python3.9/site-packages/flask_cors/extension.py", line 165, in wrapped_function
   return cors_after_request(app.make_response(f(*args, **kwargs)))
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/app.py", line 1821, in handle_user_exception
   reraise(exc_type, exc_value, tb)
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/_compat.py", line 39, in reraise
   raise value
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/app.py", line 1948, in full_dispatch_request
   rv = self.preprocess_request()
 File "/app/.heroku/python/lib/python3.9/site-packages/flask/app.py", line 2242, in preprocess_request
   rv = func()
 File "/app/app/__init__.py", line 75, in before_request_func
   if current_user.is_authenticated:
 File "/app/.heroku/python/lib/python3.9/site-packages/werkzeug/local.py", line 432, in __get__
   obj = instance._get_current_object()
 File "/app/.heroku/python/lib/python3.9/site-packages/werkzeug/local.py", line 554, in _get_current_object
   return self.__local()  # type: ignore
 File "/app/.heroku/python/lib/python3.9/site-packages/flask_login/utils.py", line 26, in <lambda>
   current_user = LocalProxy(lambda: _get_user())
 File "/app/.heroku/python/lib/python3.9/site-packages/flask_login/utils.py", line 346, in _get_user
   current_app.login_manager._load_user()
 File "/app/.heroku/python/lib/python3.9/site-packages/flask_login/login_manager.py", line 329, in _load_user
   user = self._load_user_from_remember_cookie(cookie)
 File "/app/.heroku/python/lib/python3.9/site-packages/flask_login/login_manager.py", line 372, in _load_user_from_remember_cookie
   user = self._user_callback(user_id)
 File "/app/app/models.py", line 135, in load_user
   return User.query.get(int(id))
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 1021, in get
   return self._get_impl(ident, loading.load_on_pk_identity)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 1138, in _get_impl
   return db_load_fn(self, primary_key_identity)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 287, in load_on_pk_identity
   return q.one()
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 3436, in one
   ret = self.one_or_none()
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 3405, in one_or_none
   ret = list(self)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 3481, in __iter__
   return self._execute_and_instances(context)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 3506, in _execute_and_instances
   result = conn.execute(querycontext.statement, self._params)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1020, in execute
   return meth(self, multiparams, params)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 298, in _execute_on_connection
   return connection._execute_clauseelement(self, multiparams, params)
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1133, in _execute_clauseelement
   ret = self._execute_context(
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1323, in _execute_context
   self._handle_dbapi_exception(
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1517, in _handle_dbapi_exception
   util.raise_(
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 178, in raise_
   raise exception
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1283, in _execute_context
   self.dialect.do_execute(
 File "/app/.heroku/python/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
   cursor.execute(statement, parameters)
sqlalchemy.exc.OperationalError: (psycopg2.OperationalError) terminating connection due to administrator command
SSL connection has been closed unexpectedly

[SQL: SELECT "user".id AS user_id, "user".goog_id AS user_goog_id, "user".firstname AS user_firstname, "user".username AS user_username, "user".email AS user_email, "user".password_hash AS user_password_hash, "user".admin AS user_admin, "user".test_account AS user_test_account, "user".deleted AS user_deleted, "user".suggestion_id AS user_suggestion_id, "user".account_created_date AS user_account_created_date, "user".last_active AS user_last_active, "user".last_action AS user_last_action, "user".tos AS user_tos, "user".token AS user_token, "user".token_expiration AS user_token_expiration, "user".preferences AS user_preferences, "user".add_by_email AS user_add_by_email, "user".review_count AS user_review_count
FROM "user"
WHERE "user".id = %(param_1)s]
[parameters: {'param_1': 9}]
(Background on this error at: http://url2468.lurnby.com/ls/click?upn=O95o0jN-2F92mJdpf7ZhEbgLXtFoI7wvvm0Nlb71SAqYc7I4OlCr9vuEBttZ6PLGT1WNJK_-2FZKyCIFGBlWZyR9dtbwHIdOuvcuQq8Y2fMr-2B-2FbeShjLyosNNioPDJzhSgpKKo74YFbAenDCCE7-2Bkqr8yx5SEv084ovLO1u39hYHllO4yfmmzrwczMZ24bimgvQg0j9VfPKhsZ6407LPtIKOe92SaPIyJNjOYcQUjO5GidlprUpwSgFJX1-2FmYyDnyXm5ii6-2BzSv3dLzcrWZIMfMen51r0Zw-3D-3D

I saw an issue with Recommended Systems that was extremely similar, and the solution was outlined here: https://blog.stigok.com/2021/02/28/sqlalchemy-postgres-ssl-eof-detected.html

Ultimately, it was to include a pool_pre_ping configuration in the config.py file. It looks like this:

SQLALCHEMY_ENGINE_OPTIONS = {"pool_pre_ping": True}

Here's how it works:

The reasons for the SSL SYSCALL error: EOF detected is that the client (ORM) thinks that the TCP connection is still up, but the server has already hung up without saying so. The client then starts sending a query down the pipe and when it does, it notices the connection is broken, resulting in a sudden EOF.

What pool_pre_ping does is to test the connection before attempting to execute the actual query. This comes with an extra round-trip for all queries, but at least in my small-scale application this doesn’t matter at all. Behind the scenes, it sends a query similar to SELECT 1 to sort of ping the database. If it succeeds it follows up with the actual query you wanted to send – if it fails it recycles the connection along with all other connections established earlier than the connection it tried, and establishes a new one before sending the query again.