search

IACR / latex-submit

Web server to receive uploaded LaTeX and execute it in a docker container.
GNU Affero General Public License v3.0
11 stars 0 forks source link

errors from SQLAlchemy 2.0 #48

Closed kmccurley closed 11 months ago

kmccurley commented 11 months ago

I've seen a couple of times where the server generates a 500 error. One of the apache logs shows:

Thu Sep 21 21:47:40.581039 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._sock.sendall(data), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581042 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] ConnectionResetError: [Errno 104] Connection reset by peer, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581045 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581050 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] During handling of the above exception, another exception occurred:, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581059 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581065 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] Traceback (most recent call last):, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581070 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1968, in _exec_single_context, refe\
rer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581076 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self.dialect.do_execute(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581082 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/default.py", line 920, in do_execute, referer: htt\
ps://publish.iacr.org/
[Thu Sep 21 21:47:40.581087 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     cursor.execute(statement, parameters), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581092 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/cursors.py", line 153, in execute, referer: https://publish.\
iacr.org/
[Thu Sep 21 21:47:40.581111 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     result = self._query(query), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581117 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/cursors.py", line 322, in _query, referer: https://publish.i\
acr.org/
[Thu Sep 21 21:47:40.581123 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     conn.query(q), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581128 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 557, in query, referer: https://publis\
h.iacr.org/
[Thu Sep 21 21:47:40.581134 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._execute_command(COMMAND.COM_QUERY, sql), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581139 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 861, in _execute_command, referer: htt\
ps://publish.iacr.org/
[Thu Sep 21 21:47:40.581145 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._write_bytes(packet), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581150 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 806, in _write_bytes, referer: https:/\
/publish.iacr.org/
[Thu Sep 21 21:47:40.581155 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     raise err.OperationalError(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581161 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] pymysql.err.OperationalError: (2006, "MySQL server has gone away (ConnectionResetError(104, 'Connection reset by pe\
er'))"), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581166 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581172 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] The above exception was the direct cause of the following exception:, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581177 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581182 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] Traceback (most recent call last):, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581188 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/flask/app.py", line 2525, in wsgi_app, referer: https://publish.iacr\
.org/
[Thu Sep 21 21:47:40.581193 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     response = self.full_dispatch_request(), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581198 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/flask/app.py", line 1822, in full_dispatch_request, referer: https:/\
/publish.iacr.org/
[Thu Sep 21 21:47:40.581204 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     rv = self.handle_user_exception(e), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581209 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/flask/app.py", line 1820, in full_dispatch_request, referer: https:/\
/publish.iacr.org/
[Thu Sep 21 21:47:40.581215 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     rv = self.dispatch_request(), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581228 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/flask/app.py", line 1796, in dispatch_request, referer: https://publ\
ish.iacr.org/
[Thu Sep 21 21:47:40.581233 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581239 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/var/www/wsgi/latex-submit/webapp/routes.py", line 67, in show_submit_version, referer: https://publish.iac\
r.org/
[Thu Sep 21 21:47:40.581244 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     paper_status = db.session.execute(sql).scalar_one_or_none(), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581250 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/orm/scoping.py", line 724, in execute, referer: https://p\
ublish.iacr.org/
[Thu Sep 21 21:47:40.581256 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return self._proxied.execute(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581261 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/orm/session.py", line 2232, in execute, referer: https://\
publish.iacr.org/
[Thu Sep 21 21:47:40.581267 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return self._execute_internal(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581277 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/orm/session.py", line 2127, in _execute_internal, referer\
: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581283 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     result: Result[Any] = compile_state_cls.orm_execute_statement(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581288 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/orm/context.py", line 293, in orm_execute_statement, refe\
rer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581293 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     result = conn.execute(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581299 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1413, in execute, referer: https://\
publish.iacr.org/
[Thu Sep 21 21:47:40.581305 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return meth(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581312 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/sql/elements.py", line 483, in _execute_on_connection, re\
ferer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581319 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return connection._execute_clauseelement(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581325 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1637, in _execute_clauseelement, re\
ferer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581332 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     ret = self._execute_context(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581338 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1846, in _execute_context, referer:\
 https://publish.iacr.org/
[Thu Sep 21 21:47:40.581354 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     return self._exec_single_context(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581360 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1987, in _exec_single_context, refe\
rer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581366 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._handle_dbapi_exception(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581373 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 2344, in _handle_dbapi_exception, r\
eferer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581379 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     raise sqlalchemy_exception.with_traceback(exc_info[2]) from e, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581386 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/base.py", line 1968, in _exec_single_context, refe\
rer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581392 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self.dialect.do_execute(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581398 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/sqlalchemy/engine/default.py", line 920, in do_execute, referer: htt\
ps://publish.iacr.org/
[Thu Sep 21 21:47:40.581404 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     cursor.execute(statement, parameters), referer: https://publish.iacr.org/
Thu Sep 21 21:47:40.581410 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/cursors.py", line 153, in execute, referer: https://publish.\
iacr.org/
[Thu Sep 21 21:47:40.581490 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     result = self._query(query), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581497 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/cursors.py", line 322, in _query, referer: https://publish.i\
acr.org/
[Thu Sep 21 21:47:40.581504 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     conn.query(q), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581510 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 557, in query, referer: https://publis\
h.iacr.org/
[Thu Sep 21 21:47:40.581517 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._execute_command(COMMAND.COM_QUERY, sql), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581524 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 861, in _execute_command, referer: htt\
ps://publish.iacr.org/
[Thu Sep 21 21:47:40.581530 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     self._write_bytes(packet), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581536 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]   File "/usr/local/lib/python3.9/dist-packages/pymysql/connections.py", line 806, in _write_bytes, referer: https:/\
/publish.iacr.org/
[Thu Sep 21 21:47:40.581543 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494]     raise err.OperationalError(, referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581557 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (2006, "MySQL server has gone away (ConnectionReset\
Error(104, 'Connection reset by peer'))"), referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581564 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] [SQL: SELECT paper_status.id, paper_status.paperid, paper_status.email, paper_status.submitted, paper_status.accept\
ed, paper_status.status, paper_status.issue_id , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581571 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] FROM paper_status , referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581577 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] WHERE paper_status.paperid = %(paperid_1)s], referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581583 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] [parameters: {'paperid_1': 't7k1mz3v'}], referer: https://publish.iacr.org/
[Thu Sep 21 21:47:40.581589 2023] [wsgi:error] [pid 1264078:tid 139674332878592] [client 73.71.110.42:57494] (Background on this error at: https://sqlalche.me/e/20/e3q8), referer: https://publish.iacr.org/

If I reload the page 15 seconds later, it works without a problem. This may be due to some change in how SQLAlchemy caches database connections (we recently switched to using mysql).

kmccurley commented 11 months ago

This may be related to this comment which links to here and mentions how connections might just "go away" after 8 hours. It's weird to me that we need to take special action if the database hasn't been touched in 8 hours, but that's SQLAlchemy for you.💩 I tried adding pool_pre_ping=True to create_engine in __init__.py and we'll see if the problem goes away.