Celery loses connection when processing scans
I have observed the following in celery logs. The scans seem to die; requires further investigation. <details><summary>Traceback</summary> ```bash [2023-11-08 08:43:01,494: INFO/MainProcess] Task zesje.scans.process_scan[01ed0eca-4eaa-4ac2-98f5-c61888ccbda3] received [2023-11-08 08:43:04,190: ERROR/ForkPoolWorker-2] Task zesje.scans.process_scan[210e63fd-788e-426e-980b-cbe2f6d39c24] raised unexpected: PendingRollbackError("Can't reconnect until invalid transaction is rolled back.") Traceback (most recent call last): File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context self.dialect.do_execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute cursor.execute(statement, parameters) File "/opt/conda/lib/python3.9/site-packages/pymysql/cursors.py", line 153, in execute result = self._query(query) File "/opt/conda/lib/python3.9/site-packages/pymysql/cursors.py", line 322, in _query conn.query(q) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 558, in query self._affected_rows = self._read_query_result(unbuffered=unbuffered) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 822, in _read_query_result result.read() File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 1200, in read first_packet = self.connection._read_packet() File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 739, in _read_packet packet_header = self._read_bytes(4) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 795, in _read_bytes raise err.OperationalError( pymysql.err.OperationalError: (2013, 'Lost connection to MySQL server during query') The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/app/zesje/scans.py", line 100, in _process_scan report_progress(f"Processing page {number} / {total}") File "/app/zesje/scans.py", line 187, in write_scan_status scan = Scan.query.get(scan_id) File "<string>", line 2, in get File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/util/deprecations.py", line 468, in warned return fn(*args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 947, in get return self._get_impl(ident, loading.load_on_pk_identity) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 951, in _get_impl return self.session._get_impl( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2942, in _get_impl instance = self._identity_lookup( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2220, in _identity_lookup return loading.get_from_identity(self, mapper, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 379, in get_from_identity state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1717, in execute result = conn._execute_20(statement, params or {}, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20 return meth(self, args_10style, kwargs_10style, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection return connection._execute_clauseelement( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement ret = self._execute_context( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context self._handle_dbapi_exception( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2134, in _handle_dbapi_exception util.raise_( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 211, in raise_ raise exception File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context self.dialect.do_execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute cursor.execute(statement, parameters) File "/opt/conda/lib/python3.9/site-packages/pymysql/cursors.py", line 153, in execute result = self._query(query) File "/opt/conda/lib/python3.9/site-packages/pymysql/cursors.py", line 322, in _query conn.query(q) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 558, in query self._affected_rows = self._read_query_result(unbuffered=unbuffered) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 822, in _read_query_result result.read() File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 1200, in read first_packet = self.connection._read_packet() File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 739, in _read_packet packet_header = self._read_bytes(4) File "/opt/conda/lib/python3.9/site-packages/pymysql/connections.py", line 795, in _read_bytes raise err.OperationalError( sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query') [SQL: SELECT scan.id AS scan_id, scan.exam_id AS scan_exam_id, scan.name AS scan_name, scan.status AS scan_status, scan.message AS scan_message FROM scan WHERE scan.id = %(pk_1)s] [parameters: {'pk_1': 99}] (Background on this error at: https://sqlalche.me/e/14/e3q8) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/app/zesje/scans.py", line 62, in process_scan _process_scan(scan_id, ExamLayout(scan_type)) File "/app/zesje/scans.py", line 117, in _process_scan report_error(f"Failed to read file {scan.name}: {e}") File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 487, in __get__ return self.impl.get(state, dict_) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 959, in get value = self._fire_loader_callables(state, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 990, in _fire_loader_callables return state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1717, in execute result = conn._execute_20(statement, params or {}, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20 return meth(self, args_10style, kwargs_10style, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection return connection._execute_clauseelement( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement ret = self._execute_context( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1808, in _execute_context conn = self._revalidate_connection() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 650, in _revalidate_connection self._invalid_transaction() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 622, in _invalid_transaction raise exc.PendingRollbackError( sqlalchemy.exc.PendingRollbackError: Can't reconnect until invalid transaction is rolled back. (Background on this error at: https://sqlalche.me/e/14/8s2b) uring handling of the above exception, another exception occurred: Traceback (most recent call last): File "/opt/conda/lib/python3.9/site-packages/celery/app/trace.py", line 477, in trace_task R = retval = fun(*args, **kwargs) File "/app/zesje/factory.py", line 74, in __call__ return TaskBase.__call__(self, *args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/celery/app/trace.py", line 760, in __protected_call__ return self.run(*args, **kwargs) File "/app/zesje/scans.py", line 67, in process_scan write_scan_status(scan_id, "error", "Unexpected error: " + str(error)) File "/app/zesje/scans.py", line 187, in write_scan_status scan = Scan.query.get(scan_id) File "<string>", line 2, in get File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/util/deprecations.py", line 468, in warned return fn(*args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 947, in get return self._get_impl(ident, loading.load_on_pk_identity) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 951, in _get_impl return self.session._get_impl( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2942, in _get_impl instance = self._identity_lookup( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2220, in _identity_lookup return loading.get_from_identity(self, mapper, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 379, in get_from_identity state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1717, in execute result = conn._execute_20(statement, params or {}, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20 return meth(self, args_10style, kwargs_10style, execution_options) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection return connection._execute_clauseelement( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement ret = self._execute_context( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1808, in _execute_context conn = self._revalidate_connection() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 650, in _revalidate_connection self._invalid_transaction() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 622, in _invalid_transaction raise exc.PendingRollbackError( sqlalchemy.exc.PendingRollbackError: Can't reconnect until invalid transaction is rolled back. (Background on this error at: https://sqlalche.me/e/14/8s2b) [2023-11-08 08:43:04,193: ERROR/ForkPoolWorker-1] Task zesje.scans.process_scan[8af7ecc8-d1c2-4632-9cda-7943366758c9] raised unexpected: InvalidRequestError("This session is in 'prepared' state; no further SQL can be emitted within this transaction.") Traceback (most recent call last): File "/app/zesje/scans.py", line 100, in _process_scan report_progress(f"Processing page {number} / {total}") File "/app/zesje/scans.py", line 187, in write_scan_status scan = Scan.query.get(scan_id) File "<string>", line 2, in get File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/util/deprecations.py", line 468, in warned return fn(*args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 947, in get return self._get_impl(ident, loading.load_on_pk_identity) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 951, in _get_impl return self.session._get_impl( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2942, in _get_impl instance = self._identity_lookup( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2220, in _identity_lookup return loading.get_from_identity(self, mapper, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 379, in get_from_identity state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1716, in execute conn = self._connection_for_bind(bind) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1555, in _connection_for_bind return self._transaction._connection_for_bind( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 724, in _connection_for_bind self._assert_active() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 597, in _assert_active raise sa_exc.InvalidRequestError( sqlalchemy.exc.InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction. During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/app/zesje/scans.py", line 62, in process_scan _process_scan(scan_id, ExamLayout(scan_type)) File "/app/zesje/scans.py", line 117, in _process_scan report_error(f"Failed to read file {scan.name}: {e}") File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 487, in __get__ return self.impl.get(state, dict_) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 959, in get value = self._fire_loader_callables(state, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/attributes.py", line 990, in _fire_loader_callables return state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1716, in execute conn = self._connection_for_bind(bind) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1555, in _connection_for_bind return self._transaction._connection_for_bind( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 724, in _connection_for_bind self._assert_active() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 597, in _assert_active raise sa_exc.InvalidRequestError( sqlalchemy.exc.InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction. During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/opt/conda/lib/python3.9/site-packages/celery/app/trace.py", line 477, in trace_task R = retval = fun(*args, **kwargs) File "/app/zesje/factory.py", line 74, in __call__ return TaskBase.__call__(self, *args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/celery/app/trace.py", line 760, in __protected_call__ return self.run(*args, **kwargs) File "/app/zesje/scans.py", line 67, in process_scan write_scan_status(scan_id, "error", "Unexpected error: " + str(error)) File "/app/zesje/scans.py", line 187, in write_scan_status scan = Scan.query.get(scan_id) File "<string>", line 2, in get File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/util/deprecations.py", line 468, in warned return fn(*args, **kwargs) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 947, in get return self._get_impl(ident, loading.load_on_pk_identity) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 951, in _get_impl return self.session._get_impl( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2942, in _get_impl instance = self._identity_lookup( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2220, in _identity_lookup return loading.get_from_identity(self, mapper, key, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 379, in get_from_identity state._load_expired(state, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/state.py", line 712, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 1451, in load_scalar_attributes result = load_on_ident( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 407, in load_on_ident return load_on_pk_identity( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/loading.py", line 530, in load_on_pk_identity session.execute( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1716, in execute conn = self._connection_for_bind(bind) File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1555, in _connection_for_bind return self._transaction._connection_for_bind( File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 724, in _connection_for_bind self._assert_active() File "/opt/conda/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 597, in _assert_active raise sa_exc.InvalidRequestError( sqlalchemy.exc.InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction. ``` </details>
issue