Worker crashes on psycopg.OperationalError #13147
Description
Describe the bug
At some point, the authentik worker crashed and did not handle the error gracefully. Not exactly sure what's the root cause. The only change in recent behavior is restarting one of my external reverse proxy servers and authentik might have hit it mid connection reset as the prometheus endpoint is protected by an outpost.
To Reproduce
Steps to reproduce the behavior:
- Restart a server I suppose?
Expected behavior
The error is handled gracefully and the worker does not crash. I suppose it completely crashed as the admin ui / internal monitoring showed 0 active workers and restarting fixed the issue.
Screenshots
If applicable, add screenshots to help explain your problem.
Logs
A command which might help (?) 10.102.3.3 is the IP of the authentik server. Might be related by my second log post:
authentik=# SELECT pid, usename, state, query, query_start, client_addr FROM pg_stat_activity ORDER BY query_start DESC;
pid | usename | state | query | query_start | client_addr
--------+-----------+--------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------------------------+-------------
32 | authentik | | | |
28 | | | | |
30 | | | | |
31 | | | | |
27 | | | | |
410770 | authentik | active | SELECT pid, usename, state, query, query_start, client_addr FROM pg_stat_activity ORDER BY query_start DESC; | 2025-02-21 03:15:57.00575+00 |
410582 | authentik | idle | SELECT "authentik_events_systemtask"."expires", "authentik_events_systemtask"."expiring", "authentik_events_systemtask"."uuid", "authentik_events_systemtask"."name", "authentik_events_systemtask"."uid", "authentik_events_systemtask"."start_timestamp", "authentik_events_systemtask"."finish_timestamp", "authentik_events_systemtask"."duration", "authentik_events_systemtask"."status", "authentik_events_systemtask"."description", "authentik_events_systemtask"."messages", "authentik_events_systemtask"."task_call_module", "authentik_events_systemtask"."task_call_func", "authentik_events_systemtask"."task_call_args", "authentik_events_systemtask"."task_call_kwargs" FROM "authentik_events_systemtask" WHERE ("authentik_events_systemtask"."name" = 'notification_cleanup' AND "authentik_events_systemtask"."uid" IS NULL) ORDER BY "authentik_events_systemtask"."uuid" ASC LIMIT 1 | 2025-02-21 03:13:06.67694+00 | 10.102.3.3
(7 rows)
authentik=#
After restarting I get another stack trace:
{"action": "system_exception", "client_ip": null, "context": {"message": "Traceback (most recent call last):\n File \"/ak-root/venv/lib/python3.12/site-packages/celery/app/trace.py\", line 545, in trace_task\n task_after_return(\n File \"/authentik/events/system_tasks.py\", line 86, in after_return\n DBSystemTask.objects.update_or_create(\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/manager.py\", line 87, in manager_method\n return getattr(self.get_queryset(), name)(*args, **kwargs)\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 986, in update_or_create\n obj, created = self.select_for_update().get_or_create(\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 948, in get_or_create\n return self.get(**kwargs), False\n ^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 652, in get\n raise self.model.MultipleObjectsReturned(\nauthentik.events.models.MultipleObjectsReturned: get() returned more than one SystemTask -- it returned 2!", "task_id": "f8f06241-167d-4692-b216-719feaefbd9d"}, "domain_url": null, "event": "Created Event", "level": "info", "logger": "authentik.events.models", "pid": 612, "schema_name": "public", "timestamp": "2025-02-21T03:23:12.365879", "user": {}}
{"domain_url": null, "event": "Task published", "level": "info", "logger": "authentik.root.celery", "pid": 612, "schema_name": "public", "task_id": "49b0510c673540cf87654bc798f88ca3", "task_name": "authentik.events.tasks.event_notification_handler", "timestamp": "2025-02-21T03:23:12.371856"}
{"event": "/ak-root/venv/lib/python3.12/site-packages/celery/app/trace.py:662: RuntimeWarning: Exception raised outside body: MultipleObjectsReturned('get() returned more than one SystemTask -- it returned 2!'):\nTraceback (most recent call last):\n File \"/ak-root/venv/lib/python3.12/site-packages/celery/app/trace.py\", line 545, in trace_task\n task_after_return(\n File \"/authentik/events/system_tasks.py\", line 86, in after_return\n DBSystemTask.objects.update_or_create(\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/manager.py\", line 87, in manager_method\n return getattr(self.get_queryset(), name)(*args, **kwargs)\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 986, in update_or_create\n obj, created = self.select_for_update().get_or_create(\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 948, in get_or_create\n return self.get(**kwargs), False\n ^^^^^^^^^^^^^^^^^^\n File \"/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py\", line 652, in get\n raise self.model.MultipleObjectsReturned(\nauthentik.events.models.SystemTask.MultipleObjectsReturned: get() returned more than one SystemTask -- it returned 2!\n\n warn(RuntimeWarning(\n", "level": "warning", "logger": "py.warnings", "timestamp": 1740108192.3749003}
{"domain_url": null, "event": "Task failure", "exc": "MultipleObjectsReturned('get() returned more than one SystemTask -- it returned 2!')", "level": "warning", "logger": "authentik.root.celery", "pid": 7, "schema_name": "public", "task_id": "f8f06241167d4692b216719feaefbd9d", "timestamp": "2025-02-21T03:23:12.396682"}
Original stack trace
Process Beat:
Traceback (most recent call last):
File "/ak-root/venv/lib/python3.12/site-packages/billiard/process.py", line 323, in _bootstrap
self.run()
File "/ak-root/venv/lib/python3.12/site-packages/celery/beat.py", line 718, in run
self.service.start(embedded_process=True)
File "/ak-root/venv/lib/python3.12/site-packages/celery/beat.py", line 643, in start
interval = self.scheduler.tick()
^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/celery/beat.py", line 353, in tick
self.apply_entry(entry, producer=self.producer)
File "/authentik/tenants/scheduler.py", line 22, in apply_entry
return super().apply_entry(entry, producer)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/tenant_schemas_celery/scheduler.py", line 94, in apply_entry
"all" if entry.tenant_schemas is None else str(len(tenants)),
^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py", line 382, in __len__
self._fetch_all()
File "/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py", line 1928, in _fetch_all
self._result_cache = list(self._iterable_class(self))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django/db/models/query.py", line 91, in __iter__
results = compiler.execute_sql(
^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django/db/models/sql/compiler.py", line 1560, in execute_sql
cursor = self.connection.cursor()
^^^^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django/utils/asyncio.py", line 26, in inner
return func(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django/db/backends/base/base.py", line 316, in cursor
return self._cursor()
^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/django_tenants/postgresql_backend/base.py", line 171, in _cursor
cursor_for_search_path.execute('SET search_path = {0}'.format(','.join(formatted_search_paths)))
File "/ak-root/venv/lib/python3.12/site-packages/django_prometheus/db/common.py", line 69, in execute
return super().execute(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/ak-root/venv/lib/python3.12/site-packages/psycopg/cursor.py", line 97, in execute
raise ex.with_traceback(None)
psycopg.OperationalError: consuming input failed: terminating connection due to administrator command
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
Version and Deployment (please complete the following information):
- authentik version: 2024.12.3
- Deployment: compose
Additional context
Add any other context about the problem here.