Reset database connection before reconnecting when updating export state
Some remote exports still fail to update their final state.
For example [this job](https://arkindex.teklia.com/rq/queues/1/d097b1d8-6da7-46f8-971d-2a272dd7ec81/ failed with:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 89, in _execute
return self.cursor.execute(sql, params)
psycopg2.OperationalError: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/share/arkindex/documents/export/__init__.py", line 129, in update_state
File "/usr/local/lib/python3.10/site-packages/django/db/models/base.py", line 812, in save
self.save_base(
File "/usr/local/lib/python3.10/site-packages/django/db/models/base.py", line 863, in save_base
updated = self._save_table(
File "/usr/local/lib/python3.10/site-packages/django/db/models/base.py", line 976, in _save_table
updated = self._do_update(
File "/usr/local/lib/python3.10/site-packages/django/db/models/base.py", line 1040, in _do_update
return filtered._update(values) > 0
File "/usr/local/lib/python3.10/site-packages/django/db/models/query.py", line 1216, in _update
return query.get_compiler(self.db).execute_sql(CURSOR)
File "/usr/local/lib/python3.10/site-packages/django/db/models/sql/compiler.py", line 1822, in execute_sql
cursor = super().execute_sql(result_type)
File "/usr/local/lib/python3.10/site-packages/django/db/models/sql/compiler.py", line 1398, in execute_sql
cursor.execute(sql, params)
File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/django/__init__.py", line 616, in execute
return real_execute(self, sql, params)
File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 67, in execute
return self._execute_with_wrappers(
File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
return executor(sql, params, many, context)
File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 84, in _execute
with self.db.wrap_database_errors:
File "/usr/local/lib/python3.10/site-packages/django/db/utils.py", line 91, in __exit__
raise dj_exc_value.with_traceback(traceback) from exc_value
File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 89, in _execute
return self.cursor.execute(sql, params)
django.db.utils.OperationalError: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
We can see that the initial exception comes from psycopg2
whereas I'm catching django.db.utils.OperationalError
Unfortunately this is not the same:
>>> import psycopg2
>>> import django.db.utils
>>> psycopg2.OperationalError == django.db.utils.OperationalError
False
Merge request reports
Activity
changed milestone to %Arkindex 1.6.2
added Bug label
requested review from @erouchet
assigned to @babadie
- Resolved by Erwan Rouchet
The original traceback is longer than that and shows that
update_state
did try to reconnect, but could not reconnect. First, it tries to update toDone
, and fails:Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/django/db/backends/utils.py", line 89, in _execute return self.cursor.execute(sql, params) psycopg2.OperationalError: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/share/arkindex/documents/export/__init__.py", line 129, in update_state [...] django.db.utils.OperationalError: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request.
Line 129 calls
.save()
inside thetry
block. We do get a DjangoOperationalError
and the connection just got closed.The rest of the traceback continues with
During handling of the above exception, another exception occurred:
, meaning that we entered anexcept
block. So we did catch the DjangoOperationalError
.During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/share/arkindex/documents/export/__init__.py", line 202, in export_corpus File "/usr/share/arkindex/documents/export/__init__.py", line 132, in update_state File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/django/__init__.py", line 640, in connect _set_db_data(span, self) File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/django/__init__.py", line 657, in _set_db_data cursor_or_db.connection.get_dsn_parameters() psycopg2.InterfaceError: connection already closed
Line 132 is the
.connect()
call, within theexcept
block. This call failed, with apsycopg2.InterfaceError
. So we can't re-open the connection because the connection is closed.This propagates to the global
except Exception
block inexport_corpus
, so now the export fails catastrophically and callsupdate_state
to mark asFailed
instead. This is the second half of the traceback:During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/django/db/backends/base/base.py", line 301, in _cursor return self._prepare_cursor(self.create_cursor(name)) File "/usr/local/lib/python3.10/site-packages/django/utils/asyncio.py", line 26, in inner return func(*args, **kwargs) File "/usr/local/lib/python3.10/site-packages/django/db/backends/postgresql/base.py", line 269, in create_cursor cursor = self.connection.cursor() psycopg2.InterfaceError: connection already closed The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/share/arkindex/documents/export/__init__.py", line 129, in update_state [...] django.db.utils.InterfaceError: connection already closed During handling of the above exception, another exception occurred: Traceback (most recent call last): [...] File "/usr/share/arkindex/documents/export/__init__.py", line 211, in export_corpus File "/usr/share/arkindex/documents/export/__init__.py", line 132, in update_state [...] psycopg2.InterfaceError: connection already closed
Line 211 of
export_corpus
is theupdate_state
to mark asFailed
. We again get the failure of the first.save()
at line 129, then the failure of the.connect()
call at line 132.All of this to say that:
-
We never need to catch
psycopg2.OperationalError
because Django handles it and re-throws its ownOperationalError
all of the time. If you really want to catch it then let's at least catch both psycopg's and Django's errors, and not just psycopg's error, because we will get Django's error. -
The real issue here is that calling
connect()
again does not work, not that we never re-connect.
-
- Resolved by Bastien Abadie
added 10 commits
-
0872e172...902e8b3f - 9 commits from branch
master
- 3d5e241a - Reset active connection
-
0872e172...902e8b3f - 9 commits from branch
enabled an automatic merge when the pipeline for 3d5e241a succeeds