Hi,
Am 16.12.2025 um 11:35 schrieb Christopher Moules via Nauthilus-users nauthilus-users@lists.nauthilus.org:
Hello, We are trying to deploy Nauthilus as a replacement to some legacy software, initially as a nginx ‘auth_http’ service. Initially, we are working with a configuration based on your “Getting started” example: https://nauthilus.org/docs/about/getting-started#basic-configuration We have 2 backends: LDAP and Redis Cache (KeyDB in practice): backends: - cache - ldap # Or "lua" if using Lua backend All testing performed worked fine. After going into production, we had a small but significant percentage of connections that were failed with: status_message="Invalid login or password" passdb_backend=unknown Initially, it looked like they were just “valid” failed logins, but we received a number of tickets so we looked closer at the logs. We noted that the affected logins/accounts had this “passdb_backend=unknown” as opposed to “passdb_backend=ldap” or “passdb_backend=cache”. Performing debugging with cURL and the “?mode=no-auth” we are able to get ‘positive’ results and seeing that the users are found in the LDAP DB. We are unable to see why for some requests Nauthilus is not finding the user. Some anonymised debug logs: Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.813Z level=NOTICE msg="Processing incoming request" instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD mode=auth protocol=imap oidc_cid=N/A local_ip=N/A port=N/A client_ip=213.135.240.182 client_port=N/A client_host=N/A tls_protocol=N/A tls_cipher=N/A auth_method=plain username=user@example.org user_agent=N/A client_id=N/A uri_path=/api/v1/auth/nginx Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.814Z level=DEBUG msg="Creating new PassDBResult object" instance=nauthilus debug_module=auth function=main.main.InitPassDBResultPool.func1 Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.814Z level=DEBUG msg=debug instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD passdb=cache username=user@example.org passdb_result="{Authenticated:false UserFound:false BackendName: AccountField: TOTPSecretField: TOTPRecoveryField: UniqueUserIDField: DisplayNameField: Backend:unknown Attributes:map[] AdditionalFeatures:map[]}" debug_module=auth function=github.com/croessner/nauthilus/server/core.ProcessPassDBResult Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.814Z level=DEBUG msg=debug instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD passdb=cache result="Authenticated='false' UserFound='false' BackendName='' AccountField='' TOTPSecretField='' TOTPRecoveryField='' UniqueUserIDField='' DisplayNameField='' Backend='unknown' Attributes='map[]' AdditionalFeatures='map[]'" debug_module=auth function=github.com/croessner/nauthilus/server/core.VerifyPasswordPipeline Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.814Z level=DEBUG msg="Creating new PassDBResult object" instance=nauthilus debug_module=auth function=main.main.InitPassDBResultPool.func1 Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.814Z level=DEBUG msg="Connection #1 is free, using it" instance=nauthilus pool=lookup session=36vDhQLfWoARPq7WaDfRnO2hJKD debug_module=ldap function=github.com/croessner/nauthilus/server/backend/ldappool.(*ldapPoolImpl).logConnectionUsage Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.815Z level=DEBUG msg=debug instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD passdb=ldap username=user@example.org passdb_result="{Authenticated:false UserFound:false BackendName: AccountField: TOTPSecretField: TOTPRecoveryField: UniqueUserIDField: DisplayNameField: Backend:unknown Attributes:map[] AdditionalFeatures:map[]}" debug_module=auth function=github.com/croessner/nauthilus/server/core.ProcessPassDBResult Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.815Z level=DEBUG msg=debug instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD passdb=ldap result="Authenticated='false' UserFound='false' BackendName='' AccountField='' TOTPSecretField='' TOTPRecoveryField='' UniqueUserIDField='' DisplayNameField='' Backend='unknown' Attributes='map[]' AdditionalFeatures='map[]'" debug_module=auth function=github.com/croessner/nauthilus/server/core.VerifyPasswordPipeline Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.815Z level=NOTICE msg="Authentication request has failed" instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD mode=auth backend_name=N/A protocol=imap oidc_cid=N/A local_ip=N/A port=N/A client_ip=213.135.240.182 client_port=N/A client_host=N/A tls_protocol=N/A tls_cipher=N/A auth_method=plain username=user@example.org passdb_backend=unknown current_password_retries=1 account_passwords_seen=0 total_passwords_seen=0 user_agent=N/A client_id=N/A brute_force_bucket=N/A feature=N/A status_message="Invalid login or password" uri_path=/api/v1/auth/nginx authenticated=fail authz=true authn=false latency=2.075ms Dec 16 09:44:29 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T09:44:29.815Z level=INFO msg="HTTP request" instance=nauthilus session=36vDhQLfWoARPq7WaDfRnO2hJKD client_ip=192.168.0.5http_method=GET protocol=HTTP/1.0 http_status=200 latency=2.395ms user_agent=N/A tls_protocol=N/A tls_cipher=N/A uri_path=/api/v1/auth/nginx auth_method=none Testing the same user with cURL: curl -v -H "Auth-User: user@example.org" -H "Auth-Method: plain" -H "Auth-Protocol: imap" http://192.168.0.6:9443/api/v1/auth/nginx?mode=no-auth
- Trying 192.168.0.6:9443...
- Connected to 192.168.0.6 (192.168.0.6) port 9443
- using HTTP/1.x
GET /api/v1/auth/nginx?mode=no-auth HTTP/1.1 Host: 192.168.0.6:9443 User-Agent: curl/8.14.1 Accept: */* Auth-User: user@example.org Auth-Method: plain Auth-Protocol: imap
- Request completely sent off
< HTTP/1.1 200 OK < Auth-Port: 143 < Auth-Server: 192.168.0.5 < Auth-Status: OK < Auth-User: user@example.org < X-Nauthilus-Memory-Cache: Miss < X-Nauthilus-Session: 36vI2lUpJrwOrrrJinFYMMSpxab < Date: Tue, 16 Dec 2025 10:20:13 GMT < Content-Length: 0 < * Connection #0 to host 192.168.0.6 left intact The equivalent logs for the cURL request: Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.238Z level=DEBUG msg="mode=no-auth" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab debug_module=auth function=github.com/croessner/nauthilus/server/core.(*AuthState).SetOperationMode Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.238Z level=NOTICE msg="Processing incoming request" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab mode=no-auth protocol=imap oidc_cid=N/A local_ip=N/A port=N/A client_ip=N/A client_port=N/A client_host=N/A tls_protocol=N/A tls_cipher=N/A auth_method=plain username=user@example.org user_agent=curl/8.14.1 client_id=N/A uri_path=/api/v1/auth/nginx Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.239Z level=DEBUG msg="Creating new PassDBResult object" instance=nauthilus debug_module=auth function=main.main.InitPassDBResultPool.func1 Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.240Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab passdb=cache username=user@example.org passdb_result="{Authenticated:false UserFound:false BackendName: AccountField: TOTPSecretField: TOTPRecoveryField: UniqueUserIDField: DisplayNameField: Backend:unknown Attributes:map[] AdditionalFeatures:map[]}" debug_module=auth function=github.com/croessner/nauthilus/server/core.ProcessPassDBResult Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.240Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab passdb=cache result="Authenticated='false' UserFound='false' BackendName='' AccountField='' TOTPSecretField='' TOTPRecoveryField='' UniqueUserIDField='' DisplayNameField='' Backend='unknown' Attributes='map[]' AdditionalFeatures='map[]'" debug_module=auth function=github.com/croessner/nauthilus/server/core.VerifyPasswordPipeline Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.240Z level=DEBUG msg="Creating new PassDBResult object" instance=nauthilus debug_module=auth function=main.main.InitPassDBResultPool.func1 Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.240Z level=DEBUG msg="Connection #1 is free, using it" instance=nauthilus pool=lookup session=36vI2lUpJrwOrrrJinFYMMSpxab debug_module=ldap function=github.com/croessner/nauthilus/server/backend/ldappool.(*ldapPoolImpl).logConnectionUsage Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.241Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab filter="(&(|(uid=user@example.org)(mailLocalAddress=user@example.org))(!(expirationdate=*))(!(pwdAccountLockedTime=*)))" debug_module=ldap function=github.com/croessner/nauthilus/server/backend/ldappool.(*LDAPConnectionImpl).Search Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.241Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab passdb=ldap username=user@example.org passdb_result="{Authenticated:true UserFound:true BackendName:__meta_default__ AccountField:uid TOTPSecretField: TOTPRecoveryField: UniqueUserIDField: DisplayNameField:uid Backend:ldap Attributes:map[dn:[uid=user@example.org,ou=mailboxes,o=webhost4.pt.lu,dmdName=confixx] uid:[user@example.org] userPassword:[{crypt}$1$Yx8idnJk$mT7J7kAFNRGMMBEnC3aYs.]] AdditionalFeatures:map[]}" debug_module=auth function=github.com/croessner/nauthilus/server/core.ProcessPassDBResult Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.241Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab passdb=ldap result="Authenticated='true' UserFound='true' BackendName='__meta_default__' AccountField='uid' TOTPSecretField='' TOTPRecoveryField='' UniqueUserIDField='' DisplayNameField='uid' Backend='ldap' Attributes='map[dn:[uid=user@example.org,ou=mailboxes,o=webhost4.pt.lu,dmdName=confixx] uid:[user@example.org] userPassword:[{crypt}$1$Yx8idnJk$mT7J7kAFNRGMMBEnC3aYs.]]' AdditionalFeatures='map[]'" debug_module=auth function=github.com/croessner/nauthilus/server/core.VerifyPasswordPipeline Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.242Z level=DEBUG msg="Save password history to redis" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab type=bktype.PositivePasswordCache debug_module=cache function=github.com/croessner/nauthilus/server/backend.SaveUserDataToRedis Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.243Z level=DEBUG msg=debug instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab redis="Fields set: 4" debug_module=cache function=github.com/croessner/nauthilus/server/backend.SaveUserDataToRedis Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.243Z level=DEBUG msg="Stored positive cache to redis" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab key=nt:UCP:mail:user@example.org Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.243Z level=NOTICE msg="Authentication request was successful" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab mode=no-auth backend_name=__meta_default__ protocol=imap oidc_cid=N/A local_ip=N/A port=N/A client_ip=N/A client_port=N/A client_host=N/A tls_protocol=N/A tls_cipher=N/A auth_method=plain username=user@example.org passdb_backend=ldap current_password_retries=0 account_passwords_seen=0 total_passwords_seen=0 user_agent=curl/8.14.1 client_id=N/A brute_force_bucket=N/A feature=N/A status_message=OK uri_path=/api/v1/auth/nginx authenticated=N/A authz=true authn=true latency=4.740ms Dec 16 10:20:13 hostpack-nauthilus-01 nauthilus[68703]: time=2025-12-16T10:20:13.245Z level=INFO msg="HTTP request" instance=nauthilus session=36vI2lUpJrwOrrrJinFYMMSpxab client_ip=192.168.0.5 http_method=GET protocol=HTTP/1.1 http_status=200 latency=4.853ms user_agent=curl/8.14.1 tls_protocol=N/A tls_cipher=N/A uri_path=/api/v1/auth/nginx auth_method=none Here it can be seen that the LDAP query returns a HIT (UserFound:true & passdb_backend=ldap) where as above (failing request) there seems to be a MISS (UserFound:false & passdb_backend=unknown).
I had some issues in 1.10.x and <1.11.4 with Request-deduplication.
If you use 1.10.x, can you set server.dedup.in_process_enabled to false or better give 1.11.4 a try.
Kind regards
Christian Rößner
Rößner-Network-Solutions Zertifizierter ITSiBe / CISO Marburger Str. 70a, 36304 Alsfeld Mobil: +49 171 9905345 USt-IdNr.: DE225643613, https://roessner.website PGP fingerprint: 658D 1342 B762 F484 2DDF 1E88 38A5 4346 D727 94E5