broken ldap cached session after "failed to execute flow"

[calbrecht]

broken ldap cached session after "failed to execute flow"

[calbrecht]

@d-schiffner @BeryJu could it be that this comparison

authentik/internal/outpost/ldap/bind/memory/memory.go

Line 58 in 60c8837

if flags == nil {

needs the same refactoring as that comparison

authentik/internal/outpost/ldap/search/memory/memory.go

Line 78 in 7cedc84

if flag == nil || (flag.UserInfo == nil && flag.UserPk == flags.InvalidUserPK) {

which was added in #6096

Although i do not speak go, i can see that there is a change of behavior which i can imagine to cause the caching of an assumably (by interpreting the behavior without understanding) broken session. Are you able to see the point?

[calbrecht]

While this was happening for a dovecot service user and therefore affecting all users wanting to authenticate their Mailclient, it now happened for a specific human user again.

On the mailer server:

Jun 07 11:34:46 mailer dovecot[3423100]: imap-login: Disconnected: Connection closed (auth failed, 3 attempts in 15 secs): user=<redacted>, method=PLAIN, rip=redacted, lip=redacted, TLS, session=<redacted>

On authentik server:

Jun 07 11:34:31 authentik ldap[479322]: {"attributes":["mail"],"baseDN":"ou=users,dc=goauthentik,dc=io","bindDN":"cn=service,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Search request","filter":"(&(objectClass=inetOrgPerson)(!(goauthentikio-user-service-account=true))(!(cn=redacted))(mail=redacted))","level":"info","requestId":"c6b5810c-bc60-4350-ace8-37db980102fb","scope":"Whole Subtree","timestamp":"2024-06-07T11:34:31Z","took-ms":3}
Jun 07 11:34:31 authentik server[1810923]: {"auth_via": "unauthenticated", "domain_url": "redacted", "event": "/api/v3/flows/executor/no-mfa-authentication-flow/?query=goauthentik.io%252Foutpost%252Fldap%3Dtrue", "host": "redacted", "level": "info", "logger": "authentik.asgi", "method": "GET", "pid": 1810923, "remote": "redacted", "request_id": "c0ff07646d3b493b839658311946f513", "runtime": 133, "schema_name": "public", "scheme": "https", "status": 200, "timestamp": "2024-06-07T11:34:31.987917", "user": "", "user_agent": "goauthentik.io/outpost/2024.4.2"}
Jun 07 11:34:31 authentik server[1810923]: {"event": "Error while closing socket [Errno 9] Bad file descriptor", "level": "info", "logger": "gunicorn.error", "timestamp": 1717760071.9952555}
Jun 07 11:34:31 authentik server[479321]: {"error":"read unix @->/tmp/authentik-core.sock: read: connection reset by peer","event":"failed to proxy to backend","level":"warning","logger":"authentik.router","timestamp":"2024-06-07T11:34:31Z"}
Jun 07 11:34:31 authentik server[479321]: {"error":"websocket: close 1012","event":"ws read error","level":"warning","logger":"authentik.outpost.ak-api-controller","loop":"ws-handler","timestamp":"2024-06-07T11:34:31Z"}
Jun 07 11:34:31 authentik ldap[479322]: {"error":"websocket: close 1012","event":"ws read error","level":"warning","logger":"authentik.outpost.ak-api-controller","loop":"ws-handler","timestamp":"2024-06-07T11:34:31Z"}
Jun 07 11:34:32 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","client":"redacted","error":"failed to submit challenge 502 Bad Gateway","event":"failed to execute flow","level":"warning","requestId":"eaa4bc9b-24cf-4726-816d-a6a1eae2558a","timestamp":"2024-06-07T11:34:31Z"}
Jun 07 11:34:32 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Bind request","level":"info","requestId":"eaa4bc9b-24cf-4726-816d-a6a1eae2558a","timestamp":"2024-06-07T11:34:31Z","took-ms":178}

Followed by authenticated from session

Jun 07 11:34:38 authentik ldap[479322]: {"attributes":["mail"],"baseDN":"ou=users,dc=goauthentik,dc=io","bindDN":"cn=service,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Search request","filter":"(&(objectClass=inetOrgPerson)(!(goauthentikio-user-service-account=true))(!(cn=redacted))(mail=redacted))","level":"info","requestId":"b179953b-a46c-40c6-af84-efeaf84986e0","scope":"Whole Subtree","timestamp":"2024-06-07T11:34:38Z","took-ms":3}
Jun 07 11:34:38 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","event":"authenticated from session","level":"info","logger":"authentik.outpost.ldap.binder.session","timestamp":"2024-06-07T11:34:38Z"}
Jun 07 11:34:38 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Bind request","level":"info","requestId":"b5528cb6-91ab-4b67-aa7f-d79f47f0fa34","timestamp":"2024-06-07T11:34:38Z","took-ms":0}
Jun 07 11:34:44 authentik ldap[479322]: {"attributes":["mail"],"baseDN":"ou=users,dc=goauthentik,dc=io","bindDN":"cn=service,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Search request","filter":"(&(objectClass=inetOrgPerson)(!(goauthentikio-user-service-account=true))(!(cn=redacted))(mail=redacted))","level":"info","requestId":"46eeae49-265e-401b-a1b1-75b48634bde3","scope":"Whole Subtree","timestamp":"2024-06-07T11:34:44Z","took-ms":3}
Jun 07 11:34:44 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","event":"authenticated from session","level":"info","logger":"authentik.outpost.ldap.binder.session","timestamp":"2024-06-07T11:34:44Z"}
Jun 07 11:34:44 authentik ldap[479322]: {"bindDN":"cn=redacted,ou=users,dc=goauthentik,dc=io","client":"redacted","event":"Bind request","level":"info","requestId":"06bddd3f-46b3-406c-8ffd-ed9b33d431d8","timestamp":"2024-06-07T11:34:44Z","took-ms":0}