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).

Might anybody have any insight as to why the one case is working and the other not.
Again, this is not for all requests, the majority is working, however a significant number are failing with “passdb_backend=unknown”.

 

Thanks and Regards,

 

Chris M.

ptlogo
Ce message et toutes les pièces jointes (ci-après le "message") sont établis à l'intention exclusive de ses destinataires.
Ils peuvent contenir des informations confidentielles, protégées le cas échéant par le secret professionnel (article 41 de la loi du 5 avril 1993 relative au secteur financier).
Si vous recevez ce message par erreur, merci de le détruire et d'en avertir immédiatement l'expéditeur.
Toute utilisation de ce message non conforme à sa destination, toute diffusion ou toute publication, totale ou partielle, est interdite, sauf autorisation expresse.
Tous les avis ou opinions présentés sont exclusivement ceux de l’auteur et ne représentent pas nécessairement ceux de POST Luxembourg.
Internet ne permettant pas d'assurer l'intégrité de ce message, POST Luxembourg décline toute responsabilité au titre de ce message, dans l'hypothèse où il aurait été modifié.