LDAP not working

[jens-234]

Hi everybody,

I'm trying to use LDAP as authentication backend. Unfortunately it's not working for me.

I have already configured many different applications to authenticate against my LDAP servers. So I should be able to supply the right values. But I'm unable to find the reason for it not working here.

This is an excerpt from my .env file:

LDAP_AUTH=1
AUTH_LDAP_SERVER_URI=ldap://dc1.subdomain.domain.tld:389/
AUTH_LDAP_BIND_DN=CN=SOMEUSER,CN=Users,DC=subdomain,DC=domain,DC=tld
AUTH_LDAP_BIND_PASSWORD=SOMEPASSWORD
AUTH_LDAP_USER_SEARCH_BASE_DN=CN=Users,DC=subdomain,DC=domain,DC=tld

SOMEUSER, SOMEPASSWORD and the domain names are of cause just placeholders here.

Judging by the documentation and this page: https://github.com/TandoorRecipes/recipes/blob/develop/.env.template
....my file looks ok.

Until I manage to get LDAP connections to work in cleartext, I always leave encryption disabled for the config phase. It would just be another source of problems.

I've had a look at these posts already:
#1225
But the log file stays empty for me unfortunately.

Doesn't help either: #1299

@lostlont By any chance might you be able to help here?

[smilerz]

can you please enable DEBUG and supply the log from tandoor?

[jens-234]

I already enabled that earlier, but it doesn't seem to be very verbose.

someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/css/app.min.css HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/js/jquery-3.5.1.min.js HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/js/bootstrap.min.js HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/js/popper.min.js HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/css/select2.min.css HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/js/select2.min.js HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/css/select2-bootstrap.css HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/themes/select2-bootstrap-theme.css HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/fontawesome/fontawesome_all.min.css HTTP/1.0" 304 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/themes/tandoor.min.css HTTP/1.0" 200 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/assets/brand_logo.png HTTP/1.0" 200 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"
someIP - - [09/Feb/2022:23:06:32 +0100] "GET /static/assets/favicon.svg HTTP/1.0" 200 0 "http://linux14/accounts/login/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0"

Or is this an indicator that the env file isn't really used?

[smilerz]

ugh - logging isn't enabled for LDAP. I pushed a PR, but it won't hit the release version for a week or so

[jens-234]

I guess I can wait another week. Just installed everything, but didn't want to start using it with local accounts.

[smilerz]

someone else might be able to help - i've just never set it up

[lostlont]

The settings you have should be fine. Is this a Docker setup? If so, are you sure your container can reach the LDAP server at this URI?

[jens-234]

Yes, it's in docker.

Good point, I had only tested that connectivity from the docker host. But in the end it turns out fine as far as I can tell:

root@linux14:~# ping dc1.mydomainname.org
PING dc1.mydomainname.org (mySubNet.2) 56(84) bytes of data.
64 bytes from dc1.mydomainname.org (mySubNet.2): icmp_seq=1 ttl=128 ti                                                                             me=1.07 ms
64 bytes from dc1.mydomainname.org (mySubNet.2): icmp_seq=2 ttl=128 ti                                                                             me=0.384 ms
^C
--- dc1.mydomainname.org ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1002ms
rtt min/avg/max/mdev = 0.384/0.725/1.067/0.341 ms

root@linux14:~# su - tandoor
tandoor@linux14:~$ docker ps
CONTAINER ID   IMAGE                   COMMAND                  CREATED        STATUS        PORTS                NAMES
2fa2b602ba25   nginx:mainline-alpine   "/docker-entrypoint.…"   10 hours ago   Up 10 hours   0.0.0.0:80->80/tcp   docker_config_nginx_recipes_1
68583642b6bb   vabene1111/recipes      "/opt/recipes/boot.sh"   10 hours ago   Up 10 hours   8080/tcp             docker_config_web_recipes_1
1f98fda8b865   postgres:11-alpine      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   5432/tcp             docker_config_db_recipes_1

tandoor@linux14:~$ docker exec -it 68583642b6bb echo "test"
test
tandoor@linux14:~$ docker exec -it 68583642b6bb ping dc1.mydomainname.org
PING dc1.mydomainname.org (mySubNet.2): 56 data bytes
64 bytes from mySubNet.2: seq=0 ttl=127 time=0.936 ms
64 bytes from mySubNet.2: seq=1 ttl=127 time=0.604 ms
64 bytes from mySubNet.2: seq=2 ttl=127 time=0.486 ms
^C
--- dc1.mydomainname.org ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.486/0.675/0.936 ms
tandoor@linux14:~$

As always, domain and subnets disguised.

If that's of any relevance, this is the docker-compose file I used to create the setup:

version: "3"
services:
  db_recipes:
    restart: always
    image: postgres:11-alpine
    volumes:
      - ./postgresql:/var/lib/postgresql/data
    env_file:
      - ./.env

  web_recipes:
    image: vabene1111/recipes
    restart: always
    env_file:
      - ./.env
    volumes:
      - staticfiles:/opt/recipes/staticfiles
      - nginx_config:/opt/recipes/nginx/conf.d
      - ./mediafiles:/opt/recipes/mediafiles
    depends_on:
      - db_recipes

  nginx_recipes:
    image: nginx:mainline-alpine
    restart: always
    ports:
      - 80:80
    env_file:
      - ./.env
    depends_on:
      - web_recipes
    volumes:
      - nginx_config:/etc/nginx/conf.d:ro
      - staticfiles:/static
      - ./mediafiles:/media

volumes:
  nginx_config:
  staticfiles:

But I wouldn't see any problem here. With the initially created admin account I am able to use Tandoor as expected.

[departet]

Any update on this? Having the same issue

[smilerz]

DEBUG logging for LDAP is in the next release which should be out this week. Maybe next.

[jens-234]

I see a new version has been released. I just upgraded to it. But the behavior hasn't changed nor has the content of the log file.

Do you have any idea how to activate LDAP debug logging?

[smilerz]

if DEBUG=1 the LDAP component is supposed to log additional details. But I just copied the code from their documentation and didn't test it.

[vabene1111]

the build of the new version was not ready yesterday evening as it failed due to a borken cryptography build on arm/v7. Builds are rolling out now but without arm/v7 so if you are running raspi you might need to wait a bit longer until i have that build working again as well (hopefully in a few hours)

[jens-234]

I just upgraded. I'm on x86, but I get this output for the main container:

[2022-03-02 12:39:02 +0000] [1] [INFO] Starting gunicorn 20.1.0
[2022-03-02 12:39:02 +0000] [1] [INFO] Listening at: http://0.0.0.0:8080 (1)
[2022-03-02 12:39:02 +0000] [1] [INFO] Using worker: sync
[2022-03-02 12:39:02 +0000] [12] [INFO] Booting worker with pid: 12
[2022-03-02 12:39:02 +0000] [12] [ERROR] Exception in worker process
Traceback (most recent call last):
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/arbiter.py", line 589, in spawn_worker
    worker.init_process()
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/workers/base.py", line 134, in init_process
    self.load_wsgi()
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/workers/base.py", line 146, in load_wsgi
    self.wsgi = self.app.wsgi()
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/app/base.py", line 67, in wsgi
    self.callable = self.load()
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 58, in load
    return self.load_wsgiapp()
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 48, in load_wsgiapp
    return util.import_app(self.app_uri)
  File "/opt/recipes/venv/lib/python3.10/site-packages/gunicorn/util.py", line 359, in import_app
    mod = importlib.import_module(module)
  File "/usr/local/lib/python3.10/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1006, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 688, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 883, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/opt/recipes/recipes/wsgi.py", line 15, in <module>
    _application = get_wsgi_application()
  File "/opt/recipes/venv/lib/python3.10/site-packages/django/core/wsgi.py", line 12, in get_wsgi_application
    django.setup(set_prefix=False)
  File "/opt/recipes/venv/lib/python3.10/site-packages/django/__init__.py", line 19, in setup
    configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
  File "/opt/recipes/venv/lib/python3.10/site-packages/django/conf/__init__.py", line 82, in __getattr__
    self._setup(name)
  File "/opt/recipes/venv/lib/python3.10/site-packages/django/conf/__init__.py", line 69, in _setup
    self._wrapped = Settings(settings_module)
  File "/opt/recipes/venv/lib/python3.10/site-packages/django/conf/__init__.py", line 170, in __init__
    mod = importlib.import_module(self.SETTINGS_MODULE)
  File "/usr/local/lib/python3.10/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1006, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 688, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 883, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/opt/recipes/recipes/settings.py", line 173, in <module>
    import ldap
  File "/opt/recipes/venv/lib/python3.10/site-packages/ldap/__init__.py", line 34, in <module>
    import _ldap
ImportError: Error loading shared library libldap.so.2: No such file or directory (needed by /opt/recipes/venv/lib/python3.10/site-packages/_ldap.cpython-310-x86_64-linux-gnu.so)
[2022-03-02 12:39:02 +0000] [12] [INFO] Worker exiting (pid: 12)
[2022-03-02 12:39:03 +0000] [1] [INFO] Shutting down: Master
[2022-03-02 12:39:03 +0000] [1] [INFO] Reason: Worker failed to boot.

Are you referring to this error?

[vabene1111]

interesting, it appears that the linking of the ldap lip that we introduced with the update does not work as expected. Honestly not sure why this is happening need to properly review this.

[SuperMasterPhoenix]

I have the same problem and already created an issue: #1619
Sorry, didn't check the discussions beforehand.

[jens-234]

Would be cool, if you could post a reply here once you've learned anything about it.

[MaxJa4]

That's what I thought... well, luckily such tests are mostly necessary when changing something about the infrastructure only (like the alpine image change).

[vabene1111]

i think there will be a point into this application development where tests relying on external resources become a thing but at its current stage its probably to much work. But good idea anyway

[MaxJa4]

I have experience in test automation and test management from work so that's why it occurred to me.
But I agree, that it's quite a bit of work and would slow down the development speed quite a bit during introduction of more extensive tests.
For now, bugs are still within margin I'd say so we should be fine for a while :)

[vabene1111]

if you want we can work together at some point in building those tests if some stuff is prepared and someone knows how to theoretically do it we i can shell out some time to make the project specific changes needed.

[MaxJa4]

Sure, happy to help.
Setting up a plan and getting an overview of features and what should tested in what circumstances would be a good start and probably doesn't require any changes in code yet.
Implementation can be done iteratively at any point after that in as many steps as necessary.

Knowing what you/we/Tandoor need(s) and want(s) is probably a good starting point :)

[jens-234]

Hi everyone,

thanks for the fix. LDAP debugging is working now.

Now it shows some more details. I have experimented with a couple of variations of the AUTH_LDAP_USER_SEARCH_FILTER_STR. It turns out they were all correct, but still I got something like this:

search_s('CN=Users,DC=my,DC=domain,DC=name', 2, '(uid=%(user)s)') returned 0 objects:
Authentication failed for myUsername: failed to map the username to a DN.

Even Active Directory style filters bring the same result:

AUTH_LDAP_USER_SEARCH_FILTER_STR=(&(objectClass=user)(memberOf=CN=Rezeptsammlung,CN=Users,DC=my,DC=domain,DC=name)(sAMAccountName=%(user)s))

I had trouble believing that, but the fact that the result was 0 and not an actual error made me check the group again. It turns out the user was really not directly in the group, but in a nested group. After adding the user directly to the group I could finally login!!

[smilerz]

glad you got it working!

[vabene1111]

awesome, good that the debug logging helped :)

[AgentScrubbles]

Hello! It's 2 years later and I wanted to say THANK YOU for writing this up, you saved the day!