goauthentik / authentik

The authentication glue you need.
https://goauthentik.io
Other
13.29k stars 887 forks source link

property_mapping_exception - InvalidCursorName:"_django_curs_..." does not exist #6807

Closed gcarrarom closed 1 year ago

gcarrarom commented 1 year ago

Description

I've upgraded Authentik from 2023.8.1 to 2023.8.2 and it came up with this error after the upgrade. There seems to be a cursor that wasn't committed to the Database during the upgrade and it's now not found when trying to read some data.

After the upgrade, the system seems to be working fine on all applications and authentication, but it will not show data properly when navigating to it. It is taking many refreshes to get data to appear on Authentik due to errors.

Here's an example when loading the user interface:

Request URL: https://auth.fancywhale.ca/api/v3/core/users/me/
Request Method: GET
Status Code: 500

After a few refreshes, it just works:

Request URL: https://auth.fancywhale.ca/api/v3/core/users/me/
Request Method: GET
Status Code: 200

Reproducing

I am not sure how to reproduce this, but I assume it's something of my environment.

  1. Helm repo update
  2. Helm upgrade to 2023.8.2
  3. Wait for the exception.

It could be related to something else? Another way to reproduce the 500 errors is just loading the pages and it'll throw this exception from time to time - only happening after the upgrade to 2023.8.2:

  1. Upgrade to 2023.8.2
  2. Request the landing user page
  3. Refresh to see 500 errors or 200 errors inconsistently.

Expected Behaviour

No exceptions and the database should self-heal in the case of exceptions as such.

Screenshots

Admin page load with missing information: landing Failing to load objects in the outposts: outposts Outposts showing after clicking refresh a couple of times: outposts2

Logs

identity/authentik-server-6595dbbd78-gj8l6[authentik]: {"event": "Internal Server Error: /api/v3/core/users/me/", "exception": [{"exc_type": "ProgrammingError", "exc_value": "cursor \"_django_curs_139729622255296_sync_1\" already exists", "frames": [{"filename": "/usr/local/lib/python3.11/site-packages/asgiref/sync.py", "line": "", "lineno": 534, "locals": {"__traceback_hide__": "True", "args": "'(functools.partial(<function response_for_exception at 0x7f15ae7bd440>, <ASGIReq'+119", "current_thread": "<Thread(ThreadPoolExecutor-1135_0, started 139729639040704)>", "exc_info": "'(<class \\'django.db.utils.ProgrammingError\\'>, ProgrammingError(\\'cursor \"_django_c'+83", "func": "<built-in method run of _contextvars.Context object at 0x7f1588341a80>", "kwargs": "{}", "loop": "<uvloop.Loop running=True closed=False debug=False>", "parent_set": "True", "self": "<asgiref.sync.SyncToAsync object at 0x7f1588134990>", "source_task": "None"}, "name": "thread_handler"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/core/handlers/exception.py", "line": "", "lineno": 42, "locals": {"exc": "ProgrammingError('cursor \"_django_curs_139729622255296_sync_1\" already exists')", "get_response": "'<bound method BaseHandler._get_response_async of <django.core.handlers.asgi.ASGI'+34", "request": "<ASGIRequest: GET '/api/v3/core/users/me/'>"}, "name": "inner"}, {"filename": "/usr/local/lib/python3.11/site-packages/asgiref/sync.py", "line": "", "lineno": 534, "locals": {"__traceback_hide__": "True", "args": "'(functools.partial(<bound method BaseHandler.process_exception_by_middleware of '+194", "current_thread": "<Thread(ThreadPoolExecutor-1133_0, started 139729622255296)>", "exc_info": "'(<class \\'django.db.utils.ProgrammingError\\'>, ProgrammingError(\\'cursor \"_django_c'+83", "func": "<built-in method run of _contextvars.Context object at 0x7f1588342a80>", "kwargs": "{}", "loop": "<uvloop.Loop running=True closed=False debug=False>", "parent_set": "False", "self": "<asgiref.sync.SyncToAsync object at 0x7f158812a410>", "source_task": "None"}, "name": "thread_handler"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/core/handlers/base.py", "line": "", "lineno": 253, "locals": {"callback": "<function UserViewSet at 0x7f15a33d0860>", "callback_args": "()", "callback_kwargs": "{}", "middleware_method": "<asgiref.sync.SyncToAsync object at 0x7f15a36ed050>", "request": "<ASGIRequest: GET '/api/v3/core/users/me/'>", "response": "None", "self": "<django.core.handlers.asgi.ASGIHandler object at 0x7f15a38f5790>", "wrapped_callback": "<asgiref.sync.SyncToAsync object at 0x7f158829e610>"}, "name": "_get_response_async"}, {"filename": "/usr/local/lib/python3.11/site-packages/asgiref/sync.py", "line": "", "lineno": 479, "locals": {"__traceback_hide__": "True", "args": "(<ASGIRequest: GET '/api/v3/core/users/me/'>,)", "child": "\"functools.partial(<function UserViewSet at 0x7f15a0407e20>, <ASGIRequest: GET '/\"+24", "context": "<_contextvars.Context object at 0x7f15885788c0>", "executor": "<asgiref.current_thread_executor.CurrentThreadExecutor object at 0x7f1588352e90>", "func": "<built-in method run of _contextvars.Context object at 0x7f15885788c0>", "kwargs": "{}", "loop": "<uvloop.Loop running=True closed=False debug=False>", "self": "<asgiref.sync.SyncToAsync object at 0x7f158829e610>"}, "name": "__call__"}, {"filename": "/usr/local/lib/python3.11/site-packages/asgiref/current_thread_executor.py", "line": "", "lineno": 40, "locals": {"__traceback_hide__": "True", "self": "None"}, "name": "run"}, {"filename": "/usr/local/lib/python3.11/site-packages/asgiref/sync.py", "line": "", "lineno": 538, "locals": {"__traceback_hide__": "True", "args": "\"(functools.partial(<function UserViewSet at 0x7f15a0407e20>, <ASGIRequest: GET '\"+27", "current_thread": "<Thread(ThreadPoolExecutor-1133_0, started 139729622255296)>", "exc_info": "(None, None, None)", "func": "<built-in method run of _contextvars.Context object at 0x7f15885788c0>", "kwargs": "{}", "loop": "<uvloop.Loop running=True closed=False debug=False>", "parent_set": "False", "self": "<asgiref.sync.SyncToAsync object at 0x7f158829e610>", "source_task": "None"}, "name": "thread_handler"}, {"filename": "/usr/local/lib/python3.11/site-packages/sentry_sdk/integrations/django/views.py", "line": "", "lineno": 84, "locals": {"args": "()", "callback": "<function UserViewSet at 0x7f15a33d0860>", "hub": "<sentry_sdk.hub.Hub object at 0x7f158811fd50>", "kwargs": "{}", "request": "<ASGIRequest: GET '/api/v3/core/users/me/'>", "sentry_scope": "<Scope id=0x7f158836d000 name=asgi>"}, "name": "sentry_wrapped_callback"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/views/decorators/csrf.py", "line": "", "lineno": 56, "locals": {"args": "(<ASGIRequest: GET '/api/v3/core/users/me/'>,)", "kwargs": "{}", "view_func": "<function UserViewSet at 0x7f15a33d07c0>"}, "name": "wrapper_view"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/viewsets.py", "line": "", "lineno": 125, "locals": {"action": "user_me", "actions": "{'get': 'user_me', 'head': 'user_me'}", "args": "()", "cls": "<class 'authentik.core.api.users.UserViewSet'>", "handler": "'<bound method UserViewSet.user_me of <authentik.core.api.users.UserViewSet objec'+21", "initkwargs": "\"{'pagination_class': None, 'filter_backends': [], 'name': 'User me', 'descriptio\"+178", "kwargs": "{}", "method": "head", "request": "<ASGIRequest: GET '/api/v3/core/users/me/'>", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "view"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/views.py", "line": "", "lineno": 509, "locals": {"args": "()", "handler": "'<bound method UserViewSet.user_me of <authentik.core.api.users.UserViewSet objec'+21", "kwargs": "{}", "request": "<rest_framework.request.Request: GET '/api/v3/core/users/me/'>", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "dispatch"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/views.py", "line": "", "lineno": 469, "locals": {"context": "\"{'view': <authentik.core.api.users.UserViewSet object at 0x7f158812a290>, 'args'\"+94", "exc": "ProgrammingError('cursor \"_django_curs_139729622255296_sync_1\" already exists')", "exception_handler": "<function exception_handler at 0x7f15a69e3a60>", "response": "None", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "handle_exception"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/views.py", "line": "", "lineno": 480, "locals": {"exc": "ProgrammingError('cursor \"_django_curs_139729622255296_sync_1\" already exists')", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "raise_uncaught_exception"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/views.py", "line": "", "lineno": 506, "locals": {"args": "()", "handler": "'<bound method UserViewSet.user_me of <authentik.core.api.users.UserViewSet objec'+21", "kwargs": "{}", "request": "<rest_framework.request.Request: GET '/api/v3/core/users/me/'>", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "dispatch"}, {"filename": "/authentik/core/api/users.py", "line": "", "lineno": 489, "locals": {"context": "{'request': <rest_framework.request.Request: GET '/api/v3/core/users/me/'>}", "request": "<rest_framework.request.Request: GET '/api/v3/core/users/me/'>", "self": "<authentik.core.api.users.UserViewSet object at 0x7f158812a290>"}, "name": "user_me"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/serializers.py", "line": "", "lineno": 555, "locals": {"__class__": "<class 'rest_framework.serializers.Serializer'>", "self": "\"UserSelfSerializer(context={'request': <rest_framework.request.Request: GET '/ap\"+1158"}, "name": "data"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/serializers.py", "line": "", "lineno": 253, "locals": {"self": "\"UserSelfSerializer(context={'request': <rest_framework.request.Request: GET '/ap\"+1158"}, "name": "data"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/serializers.py", "line": "", "lineno": 509, "locals": {"attribute": "True", "check_for_none": "True", "field": "BooleanField(read_only=True)", "fields": "<generator object Serializer._readable_fields at 0x7f15883bd970>", "instance": "<SimpleLazyObject: <User: fancygui>>", "ret": "\"OrderedDict([('pk', 4), ('username', 'fancygui'), ('name', '***NAME REDACTED***\"+30", "self": "\"UserSelfSerializer(context={'request': <rest_framework.request.Request: GET '/ap\"+1158"}, "name": "to_representation"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/fields.py", "line": "", "lineno": 446, "locals": {"instance": "<SimpleLazyObject: <User: fancygui>>", "self": "BooleanField(read_only=True)"}, "name": "get_attribute"}, {"filename": "/usr/local/lib/python3.11/site-packages/rest_framework/fields.py", "line": "", "lineno": 96, "locals": {"attr": "is_superuser", "attrs": "['is_superuser']", "instance": "<SimpleLazyObject: <User: fancygui>>"}, "name": "get_attribute"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/utils/functional.py", "line": "", "lineno": 268, "locals": {"_wrapped": "<User: fancygui>", "args": "('is_superuser',)", "func": "<built-in function getattr>", "self": "<SimpleLazyObject: <User: fancygui>>"}, "name": "inner"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/utils/functional.py", "line": "", "lineno": 57, "locals": {"cls": "<class 'authentik.core.models.User'>", "instance": "<User: fancygui>", "self": "<django.utils.functional.cached_property object at 0x7f15aba1cb10>"}, "name": "__get__"}, {"filename": "/authentik/core/models.py", "line": "", "lineno": 211, "locals": {"self": "<User: fancygui>"}, "name": "is_superuser"}, {"filename": "/authentik/core/models.py", "line": "", "lineno": 163, "locals": {"self": "<User: fancygui>"}, "name": "all_groups"}, {"filename": "/authentik/core/models.py", "line": "", "lineno": 163, "locals": {".0": "<generator object QuerySet._iterator at 0x7f15883708c0>"}, "name": "<genexpr>"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", "line": "", "lineno": 516, "locals": {"chunk_size": "None", "iterable": "<django.db.models.query.FlatValuesListIterable object at 0x7f158812afd0>", "self": "\"<QuerySet [UUID('4a4b5cb5-234e-4745-ab19-71dc502b23dc'), UUID('7bf6cb72-632d-4e9\"+529", "use_chunked_fetch": "True"}, "name": "_iterator"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", "line": "", "lineno": 285, "locals": {"compiler": "\"<SQLCompiler model=Group connection=<DatabaseWrapper vendor='postgresql' alias='\"+26", "queryset": "\"<QuerySet [UUID('4a4b5cb5-234e-4745-ab19-71dc502b23dc'), UUID('7bf6cb72-632d-4e9\"+529", "self": "<django.db.models.query.FlatValuesListIterable object at 0x7f158812afd0>"}, "name": "__iter__"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", "line": "", "lineno": 1513, "locals": {"chunk_size": "2000", "chunked_fetch": "True", "results": "None", "self": "\"<SQLCompiler model=Group connection=<DatabaseWrapper vendor='postgresql' alias='\"+26", "tuple_expected": "False"}, "name": "results_iter"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", "line": "", "lineno": 1562, "locals": {"chunk_size": "2000", "chunked_fetch": "True", "cursor": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "params": "(4,)", "result_type": "multi", "self": "\"<SQLCompiler model=Group connection=<DatabaseWrapper vendor='postgresql' alias='\"+26", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "execute_sql"}, {"filename": "/usr/local/lib/python3.11/site-packages/sentry_sdk/integrations/django/__init__.py", "line": "", "lineno": 616, "locals": {"hub": "<sentry_sdk.hub.Hub object at 0x7f158811fd50>", "params": "(4,)", "real_execute": "<function CursorWrapper.execute at 0x7f15afc0af20>", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "span": "'<Span(op=\\'db\\', description:\\'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"aut'+326", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "execute"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", "line": "", "lineno": 67, "locals": {"params": "(4,)", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "execute"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", "line": "", "lineno": 80, "locals": {"context": "\"{'connection': <DatabaseWrapper vendor='postgresql' alias='default'>, 'cursor': \"+66", "executor": "'<bound method CursorWrapper._execute of <django.db.backends.utils.CursorWrapper '+26", "many": "False", "params": "(4,)", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "_execute_with_wrappers"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", "line": "", "lineno": 84, "locals": {"ignored_wrapper_args": "\"(False, {'connection': <DatabaseWrapper vendor='postgresql' alias='default'>, 'c\"+75", "params": "(4,)", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "_execute"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/utils.py", "line": "", "lineno": 91, "locals": {"db_exc_type": "<class 'psycopg.ProgrammingError'>", "dj_exc_type": "<class 'django.db.utils.ProgrammingError'>", "dj_exc_value": "ProgrammingError('cursor \"_django_curs_139729622255296_sync_1\" already exists')", "exc_type": "<class 'psycopg.errors.DuplicateCursor'>", "exc_value": "DuplicateCursor('cursor \"_django_curs_139729622255296_sync_1\" already exists')", "self": "<django.db.utils.DatabaseErrorWrapper object at 0x7f1588298890>", "traceback": "<traceback object at 0x7f158822eb80>"}, "name": "__exit__"}, {"filename": "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", "line": "", "lineno": 89, "locals": {"ignored_wrapper_args": "\"(False, {'connection': <DatabaseWrapper vendor='postgresql' alias='default'>, 'c\"+75", "params": "(4,)", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "_execute"}, {"filename": "/usr/local/lib/python3.11/site-packages/psycopg/server_cursor.py", "line": "", "lineno": 294, "locals": {"binary": "None", "kwargs": "{}", "params": "(4,)", "query": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172", "self": "\"<psycopg.ServerCursor '_django_curs_139729622255296_sync_1' [closed] [IDLE] (hos\"+60"}, "name": "execute"}], "is_cause": false, "syntax_error": null}, {"exc_type": "DuplicateCursor", "exc_value": "cursor \"_django_curs_139729622255296_sync_1\" already exists", "frames": [{"filename": "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", "line": "", "lineno": 89, "locals": {"ignored_wrapper_args": "\"(False, {'connection': <DatabaseWrapper vendor='postgresql' alias='default'>, 'c\"+75", "params": "(4,)", "self": "<django.db.backends.utils.CursorWrapper object at 0x7f15880e7d90>", "sql": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172"}, "name": "_execute"}, {"filename": "/usr/local/lib/python3.11/site-packages/psycopg/server_cursor.py", "line": "", "lineno": 294, "locals": {"binary": "None", "kwargs": "{}", "params": "(4,)", "query": "'SELECT \"authentik_core_group\".\"group_uuid\" FROM \"authentik_core_group\" INNER JOI'+172", "self": "\"<psycopg.ServerCursor '_django_curs_139729622255296_sync_1' [closed] [IDLE] (hos\"+60"}, "name": "execute"}], "is_cause": true, "syntax_error": null}], "level": "error", "logger
identity/authentik-server-6595dbbd78-gj8l6[authentik]: ": "django.request", "timestamp": 1694180316.135083}
identity/authentik-server-6595dbbd78-gj8l6[authentik]: {"auth_via": "session", "event": "/api/v3/core/users/me/", "host": "auth.fancywhale.ca", "level": "info", "logger": "authentik.asgi", "method": "GET", "pid": 9062, "remote": "10.88.108.1", "request_id": "44837c8919544d6caa0a6541b6db4f19", "runtime": 58, "scheme": "https", "status": 500, "timestamp": "2023-09-08T13:38:36.151257", "user": "fancygui", "user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36"}
identity/authentik-server-6595dbbd78-fhbmx[authentik]: {"event":"/if/admin/assets/fonts/RedHatText/RedHatText-Medium.woff2","host":"auth.fancywhale.ca","level":"info","logger":"authentik.router","method":"GET","remote":"10.88.108.1","runtime":"0.509","scheme":"http","size":29049,"status":200,"timestamp":"2023-09-08T13:38:36Z","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36"}

Version and deployment

strifel commented 1 year ago

We had the same issue, we fixed it by setting pool_mode to session in the pgbouncer

strifel commented 1 year ago

We found out that we had not set use_pgbouncer config option. Setting that helped and we could remove the pool_mode pgbouncer setting

gcarrarom commented 1 year ago

Amazing! Thanks a bunch guys! For future reference, I've just added the following to the root of my values file for authentik k8s deployment:

env:
  AUTHENTIK_POSTGRESQL__USE_PGBOUNCER: true