search

wiltonsr / ldapAuth

An open source Traefik Middleware that enables authentication via LDAP in a similar way to Traefik Enterprise
https://plugins.traefik.io/plugins/628c9eb7ffc0cd18356a979c/ldap-auth
Apache License 2.0
117 stars 10 forks source link

Intermittent authentication failures #15

Closed miminar closed 2 years ago

miminar commented 2 years ago

First of all, thanks a lot for all the work!

Now without further ado: Occasionally - circa once in 6 attempts, the login fails with valid credentials and the user is asked for credential again. The response time is immediate (no timeout).

Middleware configuration:

  ---
  apiVersion: traefik.containo.us/v1alpha1
  kind: Middleware
  metadata:
    annotations:
    name: example-ldap-auth
    namespace: traefik
  spec:
    plugin:
      ldapAuth:
        Attribute: cn
        BaseDn: ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch
        BindDn: cn=proxy_user,ou=admins,ou=bar,ou=auth,o=example,c=ch
        BindPassword: "..."
        Enabled: "true"
        LogLevel: INFO
        Port: 636
        SearchFilter: ({{.Attribute}}={{.Username}})
        URL: ldaps://ldaps.example.com

Errors visible in the log:

ERROR: ldapAuth: 2022/10/06 07:06:53 restricted.go:51: LDAP Result Code 200 "Network Error": ldap: response channel closed
ERROR: ldapAuth: 2022/10/06 07:06:53 restricted.go:51: Authentication failed

time="2022-10-06T07:22:58Z" level=error msg="2022/10/06 07:22:58 Received unexpected message 1, false" module=github.com/wiltonsr/ldapAuth plugin=plugin-ldapAuth
ERROR: ldapAuth: 2022/10/06 07:22:58 restricted.go:51: BindDN Error: LDAP Result Code 200 "Network Error": ldap: response channel closed
ERROR: ldapAuth: 2022/10/06 07:22:58 restricted.go:51: Authentication failed

ERROR: ldapAuth: 2022/10/06 07:38:21 restricted.go:51: BindDN Error: LDAP Result Code 200 "Network Error": ldap: response channel closed
ERROR: ldapAuth: 2022/10/06 07:38:21 restricted.go:51: Authentication failed

ERROR: ldapAuth: 2022/10/06 07:49:49 restricted.go:51: BindDN Error: unable to read LDAP response packet: unexpected EOF
ERROR: ldapAuth: 2022/10/06 07:49:49 restricted.go:51: Authentication failed
ERROR: ldapAuth: 2022/10/06 07:49:49 restricted.go:51: BindDN Error: unable to read LDAP response packet: unexpected EOF
ERROR: ldapAuth: 2022/10/06 07:49:49 restricted.go:51: Authentication failed

INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch
INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authentication succeeded
10.253.58.254 - mminar [07/Oct/2022:14:20:12 +0000] "GET /script.js HTTP/2.0" 200 108434 "-" "-" 27378 "monitoring-alertmanager-alertmanager-foo-bar-example-ch@kubernetes" "http://10.205.243.230:9093" 64ms
INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch
INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch
INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch
ERROR: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: search filter return multiple entries (2)
ERROR: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authentication failed
INFO: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authentication succeeded
10.253.58.254 - - [07/Oct/2022:14:20:12 +0000] "GET /api/v2/receivers HTTP/2.0" 401 68 "-" "-" 27382 "monitoring-alertmanager-alertmanager-foo-bar-example-ch@kubernetes" "-" 30ms
ERROR: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: search silter return empty result
ERROR: ldapAuth: 2022/10/07 14:20:12 restricted.go:51: Authentication failed
10.253.58.254 - - [07/Oct/2022:14:20:12 +0000] "GET /api/v2/alerts/groups?silenced=false&inhibited=false&active=true HTTP/2.0" 401 60 "-" "-" 27383 "monitoring-alertmanager-alertmanager-foo-bar-example-ch@kubernetes" "-" 31ms

These are our helm values (with some obfuscation applied):

---
metrics:
  prometheus:
    addRoutersLabels: true
service:
  spec:
    loadBalancerIP: 123.123.123.123
    externalTrafficPolicy: Local
env:
  - name: http_proxy
    value: http://proxy.example.com:3128
  - name: https_proxy
    value: http://proxy.example.com:3128
  - name: no_proxy
    value: localhost,127.0.0.1,10.206.0.0/16,10.205.0.0/16,.svc,.cluster.local,.local,.cilium,123.123.123.123,123.123.123.0/27,.foo.bar.example.com,ldaps*.example.com
hostNetwork: false
deployment:
  replicas: 2
autoscaling:
  enabled: true
  maxReplicas: 5
ingressClass:
  enabled: true
  isDefaultClass: true
ingressRoute:
  dashboard:
    enabled: false
logs:
  access:
    enabled: true
  general:
    level: INFO
experimental:
  plugins:
    enabled: true
globalArguments:
  - --global.checknewversion
  - --experimental.plugins.ldapAuth.modulename=github.com/wiltonsr/ldapAuth
  - --experimental.plugins.ldapAuth.version=v0.0.14
  - --providers.kubernetescrd.allowCrossNamespace=true

We don't see the same problem with grafana which has its own built-in LDAP authentication mechanism, which is configured more or less the same as this plugin.

Any hint/advice would be appreciated.

wiltonsr commented 2 years ago

Hello, @miminar

You are trying to bind to a TLS LDAP server.

Unfortunately, this isn't supported yet. See #2

The intermittence is very strange, it should fail in all attempts.

wiltonsr commented 2 years ago

I will try to work on it in the next few days. But, unfortunately, I don't have a TLS LDAP server, so I will try to provide a lab server to simulate the error.

miminar commented 2 years ago

The intermittence is very strange, it should fail in all attempts.

That's strange, wireshark shows just encrypted data being exchanged back and forth. They speak both TLSv1.2

I will try to work on it in the next few days. But, unfortunately, I don't have a TLS LDAP server, so I will try to provide a lab server to simulate the error.

That would be really cool. Highly appreciated. I'll be happy to test.

wiltonsr commented 2 years ago

The backbone of ldapAuth middleware is go-ldap/v3.

That's strange, wireshark shows just encrypted data being exchanged back and forth. They speak both TLSv1.2

The TLS connection is not fully supported yet. We use DialURL to connect: https://github.com/wiltonsr/ldapAuth/blob/dac711584f972655de2ed8a96e98908e5cbff401/ldapauth.go#L260

If you use production-ready certificates you will be fine, but if you have custom Root CA or self-signed certificates, you won't successfully connect.

But, for the last case, I was expecting to see an error like this in the logs:

LDAP Result Code 200 "Network Error": x509: certificate signed by unknown authority

However, the errors that appear in your log point to an issue that ocurrs on ARM https://github.com/go-ldap/ldap/issues/195 and don't should be affecting v3.

wiltonsr commented 2 years ago

Hello, @miminar

I released version v0.0.15 with latest version of go-ldap.

Let me know if the error persists.

miminar commented 2 years ago

Thank you @wiltonsr!

If you use production-ready certificates you will be fine, but if you have custom Root CA or self-signed certificates, you won't successfully connect.

Luckily, we do have a production-ready certificate, not self-signed.

I released version v0.0.15 with latest version of go-ldap. Let me know if the error persists.

Unfortunately, it does persist. Update: although it seems that much less frequently than before (circa once in 35 attempts).

wiltonsr commented 2 years ago

Could you try some attempts from the same server where the error occurs with ldapAuth?

Here, there are some examples. You can also add -d 1 to increase debug level if the same error happens with ldapsearch.

If there isn't any error with ldapsearch too, you can try to compile a simple go example using go-ldap and try to reproduce the problem. There is a complete example in theirs docs. This approach is very similar to what we do in the middleware.

The ldapAuth only use the response from go-ldap to determine if the request will proceed or not. So, let's isolate the problem to try to determine the best solution.

miminar commented 2 years ago

Hi @wiltonsr, I tried to reproduce both with ldapsearch and an ad-hoc go binary using the upstream go-ldap lib. No luck reproducing the issue. I tried the same from both inside and outside of k8s CNI, no luck. I haven't tried to interpret it with yaegi though. I will give it a shot.

miminar commented 2 years ago

I tried one more time to interpret the same code with yaegi 0.14.2 from inside of CNI network. Couldn't reproduce either :shrug: OTOH, intially I tried with yaegi 0.10.0 and that hanged on trying to Bind. Our traefik is 2.8.7 which is also using yaegi 0.14.2.

wiltonsr commented 2 years ago

Hi, @miminar

intially I tried with yaegi 0.10.0 and that hanged on trying to Bind.

This is expected, yaegi only supported go-ldap in v0.11.1, as described in requirements.

Could you post the error again with LogLevel: DEBUG?

If yaegi and go-ldap aren't the problem, then something is wrong with ldapAuth.

I never ran ldapAuth in k8s. So, if you can provide your k8s's architecture (CNI, Ingress Controller) I can try to reproduce it.

miminar commented 2 years ago

Hi @wiltonsr,

here is the debug log from one failed log-in attempt:

``` 10.253.58.151 - - [14/Oct/2022:05:44:52 +0000] "GET / HTTP/2.0" 401 88 "-" "-" 45751 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "-" 0ms DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET / HTTP/2.0" 200 1381 "-" "-" 45752 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.243.230:9093" 38ms DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET /script.js HTTP/2.0" 200 108434 "-" "-" 45753 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.245.27:9093" 63ms DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch DEBUG: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET /lib/font-awesome-4.7.0/css/font-awesome.min.css HTTP/2.0" 200 31000 "-" "-" 45755 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.246.95:9093" 34ms INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET /lib/bootstrap-4.0.0-alpha.6-dist/css/bootstrap.min.css HTTP/2.0" 200 150996 "-" "-" 45754 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.243.230:9093" 38 ms 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET /api/v2/receivers HTTP/2.0" 200 89 "-" "-" 45757 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.245.27:9093" 30ms INFO: ldapAuth: 2022/10/14 05:44:53 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:53 +0000] "GET /api/v2/alerts/groups?silenced=false&inhibited=false&active=true HTTP/2.0" 200 1194 "-" "-" 45758 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.246.95:9093" 34ms DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET / HTTP/2.0" 200 1381 "-" "-" 45759 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.243.230:9093" 42ms DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET / HTTP/2.0" 200 1381 "-" "-" 45759 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.243.230:9093" 42ms DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET /script.js HTTP/2.0" 200 108434 "-" "-" 45760 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.245.27:9093" 43ms DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Host: ldaps.example.ch DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Connect Address: ldaps.example.ch:636 10.253.58.151 - - [14/Oct/2022:05:44:58 +0000] "GET /lib/elm-datepicker/css/elm-datepicker.css HTTP/2.0" 401 60 "-" "-" 45763 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "-" 34ms 10.253.58.151 - - [14/Oct/2022:05:44:58 +0000] "GET /lib/bootstrap-4.0.0-alpha.6-dist/css/bootstrap.min.css HTTP/2.0" 401 68 "-" "-" 45761 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "-" 36ms ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: search filter return empty result ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication failed ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: search filter return multiple entries (2) ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication failed INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET /lib/font-awesome-4.7.0/css/font-awesome.min.css HTTP/2.0" 200 31000 "-" "-" 45762 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.246.95:9093" 40ms DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Running in Search Mode DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Performing User BindDN Search DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' DEBUG: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Search Filter: '(cn=mminar)' INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authenticating User: cn=mminar,ou=users,ou=nethz,ou=id,ou=auth,o=example,c=ch INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded INFO: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication succeeded 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET /api/v2/receivers HTTP/2.0" 200 89 "-" "-" 45764 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" "http://10.205.243.230:9093" 32ms 10.253.58.151 - mminar [14/Oct/2022:05:44:58 +0000] "GET /api/v2/alerts/groups?silenced=false&inhibited=false&active=true HTTP/2.0" 200 1194 "-" "-" 45765 "monitoring-alertmanager-alertmanager-eu-dev-hpc-example-ch@kubernetes" ```

What strikes me is that there seem to be two concurrent requests resulting in one thread receiving no results and the other receiving both. Could that be the case?

ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: search filter return empty result    
ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication failed 
ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: search filter return multiple entries (2)
ERROR: ldapAuth: 2022/10/14 05:44:58 restricted.go:51: Authentication failed
wiltonsr commented 2 years ago

Hello @miminar,

What strikes me is that there seem to be two concurrent requests resulting in one thread receiving no results and the other receiving both. Could that be the case?

Any file requested to traefik will be translated into a new connection to LDAP server, but each of them should be individual.

I created a new branch to solve #20, could you test this and report if a cache layer solves your problem?

miminar commented 2 years ago

Thanks a lot! With that I can't reproduce anymore. I'm closing this.