https://github.com/lldap/lldap logo
Powered by
Mushroom - Hi, I am trying to setup tomsquest/...
# troubleshooting
m
Hi, I am trying to setup tomsquest/docker-radicale which is the ghcr.io/nagimov/agendav-docker backend. I'd like to authenticate users with LLDAP (lldap works fine with authelia) I used to make radicale work with openLDAP but i can't with lldap... I get
Copy code
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-7 (process_request_thread)] [INFO] Access to '/' denied for anonymous user
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-7 (process_request_thread)] [INFO] PROPFIND response status for '/' in 0.003 seconds: 401 Unauthorized
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-8 (process_request_thread)] [INFO] PROPFIND request for '/' received from 172.18.0.9 (forwarded for '172.18.0.1') using 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36 OPR/106.0.0.0'
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-8 (process_request_thread)] [INFO] LDAP user ['rrctim'] (uid=rrctim,ou=people,dc=local,dc=intoxx,dc=fr) found
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-8 (process_request_thread)] [ERROR] LDAP bind failed
radicale  | [2024-01-17 06:55:42 +0100] [6/Thread-8 (process_request_thread)] [WARNING] Failed login attempt from 172.18.0.9 (forwarded for '172.18.0.1'): 'rrctim'
radicale  | [2024-01-17 06:55:43 +0100] [6/Thread-8 (process_request_thread)] [INFO] PROPFIND response status for '/' in 1.513 seconds: 401 Unauthorized
radicale config :
Copy code
[auth]
type = radicale_auth_ldap
ldap_url = ldap://172.16.10.3:3890
ldap_base = dc=local,dc=intoxx,dc=fr
ldap_attribute = uid
ldap_filter = (objectClass=person)
ldap_binddn = uid=admin,ou=people,dc=local,dc=intoxx,dc=fr
ldap_password = *REDACTED*
ldap_scope = LEVEL
ldap_support_extended = yes
n
I'd be curious to see the LLDAP verbose logs for this. I see an LDAP bind failed, but I also see some http propfind unauthorized and that confuses me.
m
it gives really nothing interesting 😦
n
Still, I'd like to see the bind request and so on
(did you put on verbose mode?)
m
for now
Copy code
lldap  | 2024-01-17T07:25:47.238315601+00:00  INFO     LDAP session [ 241µs | 60.29% / 100.00% ]
lldap  | 2024-01-17T07:25:47.238532058+00:00  INFO     ┕━ LDAP request [ 95.6µs | 39.71% ]
i'm investigating why werbose=true doesnt help imma get back to you in a few minutes
n
You can also try with LLDAP_VERBOSE=true in the env
m
thats what i'm testing 😄
Copy code
lldap  | 2024-01-17T07:30:11.212442757+00:00  INFO     LDAP session [ 164ms | 0.26% / 100.00% ]
lldap  | 2024-01-17T07:30:11.213287309+00:00  INFO     ┝━ LDAP request [ 161ms | 97.80% ]
lldap  | 2024-01-17T07:30:11.375912761+00:00  INFO     ┝━ LDAP request [ 293µs | 0.18% ]
lldap  | 2024-01-17T07:30:11.421164066+00:00  INFO     ┝━ LDAP request [ 227µs | 0.14% ]
lldap  | 2024-01-17T07:30:11.423140166+00:00  INFO     ┝━ LDAP request [ 2.67ms | 1.62% ]
lldap  | 2024-01-17T07:30:11.469232909+00:00  INFO     ┕━ LDAP request [ 4.60µs | 0.00% ]
lldap  | 2024-01-17T07:30:11.534867673+00:00  INFO     LDAP session [ 95.9ms | 0.29% / 100.00% ]
lldap  | 2024-01-17T07:30:11.534905516+00:00  INFO     ┝━ LDAP request [ 95.3ms | 99.31% ]
lldap  | 2024-01-17T07:30:11.631797146+00:00  INFO     ┝━ LDAP request [ 191µs | 0.20% ]
lldap  | 2024-01-17T07:30:11.677093021+00:00  INFO     ┝━ LDAP request [ 195µs | 0.20% ]
lldap  | 2024-01-17T07:30:11.678156702+00:00  INFO     ┕━ LDAP request [ 2.68µs | 0.00% ]
n
Still not verbose
m
my bad bad copy / paste
n
(for any other config trouble, setting verbose mode helps because it dumps the config 😄 )
m
n
Root cause of the problem is likely this unsupported whoami operation: 1.3.6.1.4.1.4203.1.11.3
Can you disable the extended mode in your client config?
In radicale
m
i do
i'm trying without
n
Hmm actually it seems to proceed even after the failure
It gets the test user, then binds as the test user, and checks again the properties of the server
And you get the same logs as at the top, just with the user "test" instead?
Because both binds succeed, so I'm a bit surprised
m
radicale log :
Copy code
[2024-01-17 08:40:35 +0100] [6/Thread-15 (process_request_thread)] [INFO] PROPFIND request for '/' received from 172.18.0.9 (forwarded for '172.18.0.1') using 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36 OPR/106.0.0.0'
[2024-01-17 08:40:35 +0100] [6/Thread-15 (process_request_thread)] [INFO] Access to '/' denied for anonymous user
[2024-01-17 08:40:35 +0100] [6/Thread-15 (process_request_thread)] [INFO] PROPFIND response status for '/' in 0.003 seconds: 401 Unauthorized
[2024-01-17 08:40:35 +0100] [6/Thread-16 (process_request_thread)] [INFO] PROPFIND request for '/' received from 172.18.0.9 (forwarded for '172.18.0.1') using 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36 OPR/106.0.0.0'
[2024-01-17 08:40:35 +0100] [6/Thread-16 (process_request_thread)] [INFO] LDAP user ['test'] (uid=test,ou=people,dc=local,dc=intoxx,dc=fr) found
[2024-01-17 08:40:35 +0100] [6/Thread-16 (process_request_thread)] [ERROR] LDAP bind failed
[2024-01-17 08:40:35 +0100] [6/Thread-16 (process_request_thread)] [WARNING] Failed login attempt from 172.18.0.9 (forwarded for '172.18.0.1'): 'test'
[2024-01-17 08:40:36 +0100] [6/Thread-16 (process_request_thread)] [INFO] PROPFIND response status for '/' in 1.151 seconds: 401 Unauthorized
[2024-01-17 08:40:39 +0100] [6/Thread-17 (process_request_thread)] [INFO] GET request for '/' received from 127.0.0.1 using 'curl/8.1.2'
[2024-01-17 08:40:39 +0100] [6/Thread-17 (process_request_thread)] [INFO] GET response status for '/' in 0.001 seconds: 302 Found
so yeah, the same. I will set radicale log to debug
n
Yeah, check with them because I don't see why they say the bind failed
Unless it's the whoami request
(but then the error message is not great)
m
n
Yeah, it seems to be the whoami
m
mmmh mmh
n
It looks like you should be able to skip whoami
By setting the extended support to no
m
i deleted the "ldap_support_extended = yes" then set it up to "ldap_support_extended = no" but same result, it does'nt work
n
If push comes to shove, whoami is a simple extension to support
But it shouldn't be needed here
I don't have your setup, but maybe you can add some debug logs in the plugin?
m
there's no urgency here but still, i would like to use lldap only, not openldap+ lldap ^^
i'll take a look
n
Actually when it starts up it prints the config
(the plugin)
Check that support extended is false
m
Copy code
gendav   | [Wed Jan 17 07:57:44.126246 2024] [core:notice] [pid 43] AH00094: Command line: '/usr/sbin/apache2 -D FOREGROUND'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Loaded default config
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Loaded config file '/config/config'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Starting Radicale
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] auth type is 'radicale_auth_ldap'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] LDAP auth configuration:
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_url' is 'ldap://172.16.10.3:3890'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_base' is 'dc=local,dc=intoxx,dc=fr'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_filter' is '(objectClass=person)'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_attribute' is 'uid'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_binddn' is 'uid=admin,ou=people,dc=local,dc=intoxx,dc=fr'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_password' is '*REDACTED*'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_scope' is 'LEVEL'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO]   'ldap_support_extended' is 'no'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] storage type is 'radicale.storage.multifilesystem'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] rights type is 'radicale.rights.owner_only'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] web type is 'radicale.web.internal'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Listening on '[0.0.0.0]:5232'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Listening on '[::]:5232'
radicale  | [2024-01-17 08:57:44 +0100] [7] [INFO] Radicale server ready
it IS set to no ...
n
Can you set it to false without quotes?
I don't know the config format
But I think the string 'no' is truthy in python
m
with ``radicale | [2024-01-17 08:59:21 +0100] [7] [INFO] 'ldap_support_extended' is 'false'`` i still got
Copy code
2024-01-17T08:00:02.123972647+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | response: ExtendedResponse(LdapExtendedResponse { result: LdapResult { code: UnwillingToPerform, matcheddn: "", message: "Unsupported extended operation: 1.3.6.1.4.1.4203.1.11.3", referral: [] }, name: None, value: "vec![...]" })
n
There's 2 of them, one is expected and doesn't matter
It's the second one, after the bind for "test" that matters
m
n
Any non-empty string is truthy in python, even "false"
How does your config file look?
m
the radicale config ?
n
Yeah
m
Copy code
[auth]
#type = htpasswd
#htpasswd_filename = /etc/radicale/users/radicale-users
#htpasswd_encryption = md5
type = radicale_auth_ldap
ldap_url = ldap://172.16.10.3:3890
ldap_base = dc=local,dc=intoxx,dc=fr
ldap_attribute = uid
#ldap_filter = (&(ou=people)(objectClass=person))
ldap_filter = (objectClass=person)
ldap_binddn = uid=admin,ou=people,dc=local,dc=intoxx,dc=fr
ldap_password = *REDACTED*
ldap_scope = LEVEL
ldap_support_extended = no

[server]
hosts = 0.0.0.0:5232, [::]:5232

[storage]
filesystem_folder = /data/.var/lib/radicale/collections

[logging]
#level = debug, info, warning, error, critical
level = debug
mask_passwords = false

#[rights]
#type = authenticated
#type = from_file
#file = /etc/radicale/rights/rights
n
And with a capital F?
m
i dont think it would change anything
n
Yeah, it's toml
Still, that's the crux of the issue
m
^^
i'll give it a try
n
Gotta go, I'll let you dig into that
m
thanks for your help
a lot
n
Another thing you can try is to set the extended support to an empty string
""
m
`` RuntimeError: Invalid bool value for option 'ldap_support_extended' in section 'auth' in config file '/config/config': '""' `` not supported 😄
i guess it should be a boolean then ?
Copy code
"ldap_support_extended": {
            "value": True,
            "help": "",
            "type": bool
        }
from https://github.com/ricjcosme/radicale-auth-ldap/blob/master/radicale_auth_ldap/__init__.py
n
You can try to add a print in the script to check if the config value is true
(not print the config value, but check if it's true)
m
i don't know what to do 😮‍💨 i set up a new instance with LLDAP + radicale+agendav
n
Did you add a print in the script above?
m
i don't know how to do that cat Dockerfile.extended
Copy code
FROM tomsquest/docker-radicale

RUN python3 -m pip install git+https://github.com/ricjcosme/radicale-auth-ldap
but when i docker exec -it, i don't know how to find the script radicale-auth-ldap
n
Like, line 139:
Copy code
python
if self.ldap_support_extended:
  print("Support!")
You can do 
pip show radicale-auth-ldap
to see where it's installed
m
thanks
Copy code
/usr/lib/python3.11/site-packages/radicale_auth_ldap/__init__.py
i guess it is only used at setup i will fork the repo to add the line permanently
so i don't get the Support! at startup
Copy code
=> [radicale internal] load build definition from Dockerfile.extended                                                                                 0.3s
...
 => [radicale 2/2] RUN python3 -m pip install git+https://github.com/shroomify-it/radicale-auth-ldap                                                  12.3s
 => [radicale] exporting to image                                                                                                                      2.0s
 => => exporting layers                                                                                                                                1.9s
 => => writing image sha256:29bb292824039dd9ad84b9908b13d2c826b43adee06fe604bdfe6aa5e3c73e00                                                           0.1s
 => => naming to docker.io/library/agenda-radicale                                                                                                     0.1s
[+] Running 2/2
 ✔ Container radicale  Started                                                                                                                         1.2s
 ✔ Container agendav   Started                                                                                                                         1.2s
Copy code
agendav   | Start webserver
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Loaded default config
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Loaded config file '/config/config'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Starting Radicale
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] auth type is 'radicale_auth_ldap'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] LDAP auth configuration:
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_url' is 'ldap://lldap:3890'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_base' is 'dc=local,dc=intoxx,dc=fr'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_filter' is '(objectClass=person)'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_attribute' is 'uid'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_binddn' is 'uid=admin,ou=people,dc=local,dc=intoxx,dc=fr'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_password' is '*REDACTED*'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_scope' is 'LEVEL'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO]   'ldap_support_extended' is 'no'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] storage type is 'radicale.storage.multifilesystem'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] rights type is 'radicale.rights.from_file'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] web type is 'radicale.web.internal'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Listening on '[0.0.0.0]:5232'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Listening on '[::]:5232'
radicale  | [2024-01-18 12:09:37 +0100] [8] [INFO] Radicale server ready
n
Can you add 
print(conn.result)
line 186?
and maybe another print in the other branch of the if, just above, to see whether we go to send a whoami
(switching to paranoid mode 👀 )
m
before that, i expected to see Support! is i set up 'ldap_support_extended' to 'yes' but i still get no print :
Copy code
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO]   'ldap_scope' is 'LEVEL'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO]   'ldap_support_extended' is 'yes'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] storage type is 'radicale.storage.multifilesystem'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] rights type is 'radicale.rights.from_file'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] web type is 'radicale.web.internal'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] Listening on '[0.0.0.0]:5232'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] Listening on '[::]:5232'
radicale  | [2024-01-18 12:12:35 +0100] [6] [INFO] Radicale server ready
i will try different values
n
ah, that might be because your change didn't get applied
m
am i wrong here ? ( i'm quite new to these tests)
mmmmh
should I delete the docker images again ?
i don't get why, i'm trying to wrap my head around it but as far as i added your little print lines in the __init__ i shouldn't, right
n
The easiest should be to go into the container and edit the file (with sudo)
m
yes but i need to recreate the containers to make it print those logs
so changes won't persist
n
you just need to restart, no? Not recreate
m
docker compose down && docker compose up -d isn't the same as restarting then ? ^^
n
nope
m
my bad
n
docker restart my_container
much faster as well!
m
oh !
Copy code
[2024-01-18 12:19:10 +0100] [6] [INFO] Stopping Radicale
Support!

...

[2024-01-18 12:19:13 +0100] [6] [INFO]   'ldap_support_extended' is 'True'
it works as expected
ok, i'll try
Copy code
print(conn.result) line 186
n
what about when you set the config to false?
or no
m
still got the Support!
🫠
n
a-ha! That's what I thought!
m
i'll try with capital F, with yes, no etc
no matter what i set for ``ldap_support_extended`` is prints Support!
yes / no / false / False
n
Seems like a bug in `radicale`'s config utility
but I don't have time to dig into that
m
yeah right, it isn't your priority. I learn a few things here, thanks again
i guess i need to open a issue
352 current issues. I'm not sure mine will ever get resolved...
crap
n
The core of the issue, I think, is that they're using the Python "bool" function to convert from string to bool
Which only returns false for empty strings
Note that the plugin author can also change that himself by providing a function in the config declaration, as I understand it
Maybe it's easier to file an issue there
m
https://github.com/ricjcosme/radicale-auth-ldap -> can't open an issue here 😭
n
If you fork it, send me the link and I'll make you a PR
m
imma try to resolve this issue. It could be great for the community
n
Alright, I sent you an (untested) PR, that could become the beginning of a PR to upstream if you want it to
although for an upstream PR, you probably want to detect if the user used "bool" as the type, and special-case dispatch to that parsing function
m
at first i had to build with --no-cache because of : => CACHED [radicale 2/2] RUN python3 -m pip install git+https://github.com/shroomify-it/radicale-auth-ldap 0.0s once done, The radicale+agendav stack goes up (with the latest version of my __init__.py) but i got the same error when trying to connect
Copy code
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] Base prefix (from SCRIPT_NAME): ''
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] Sanitized path: '/'
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] LDAP whoami: None
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] LDAP bind for uid=test in base dc=local,dc=intoxx,dc=fr
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] LDAP filter: (&(uid=test)(objectClass=person))
[2024-01-18 15:55:56 +0100] [7/Thread-14 (process_request_thread)] [INFO] LDAP user ['test'] (uid=test,ou=people,dc=local,dc=intoxx,dc=fr) found
[2024-01-18 15:55:57 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] {'result': 0, 'description': 'success', 'dn': '', 'message': '', 'referrals': None, 'saslCreds': None, 'type': 'bindResponse'}
[2024-01-18 15:55:57 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] LDAP whoami: None
[2024-01-18 15:55:57 +0100] [7/Thread-14 (process_request_thread)] [ERROR] LDAP bind failed
[2024-01-18 15:55:57 +0100] [7/Thread-14 (process_request_thread)] [WARNING] Failed login attempt from 172.18.0.1: 'test'
[2024-01-18 15:55:57 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] Sleeping 1.426 seconds
[2024-01-18 15:55:58 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] Asking client for authentication
[2024-01-18 15:55:58 +0100] [7/Thread-14 (process_request_thread)] [DEBUG] Response content:
Access to the requested resource forbidden.
[2024-01-18 15:55:58 +0100] [7/Thread-14 (process_request_thread)] [INFO] PROPFIND response status for '/' in 1.814 seconds: 401 Unauthorized
n
You can try to add a print in the bool conversion function
To check that it's called with the value you expect
m
ok 🙂
oh crap i got it
i need to use "v" not "ldap_support_extended"
🤭
n
You should print the value in the top print
You'll never reach the bottom one
m
oh ok thanks
yeah, return makes me exit the function
Copy code
value of ldap_support_extended:  True type of the variable:  <class 'str'>
value of ldap_support_extended:  no type of the variable:  <class 'str'>
Support!
it's a string
n
erf, that's an interface bug. I don't know how it ever works for them
Well, what you can do instead is to use the conversion function when you check the value
so line 191, instead of 
if self.ldap_support_extended
you'd write 
if parse_bool(self.ldap_support_extended):
Did you manage to make it work?
m
hey thanks for reaching out i've been busy but i'll find more time in the weeks coming
n
Ah, no rush! I was just curious
m
it's working 🥺
maybe thanks to this last modification
n
Ah nice! Yeah, that would do it
m
i'm really surprised but in a good way ^^
n
Maybe you can write a config guide, pointing to your fork of the plugin?
m
i'll take a look
https://github.com/lldap/lldap/tree/main/example_configs -> should i PR a config guide in here ? 🙂
n
Yep!
And add a link in the readme as well, with the list of integrations
m
I submited a PR
I'll try everything before you confirm it 🙂
seems OK to me
n
Hmm, I don't see the PR
Did you send it yet?
m
i may need to click on that green button ? ^^
n
Yep!
m
done
i'll review this tomorrow 😉
I guess you can close the issue. Thanks again chief ! 🙂
n
I don't think there was an issue? But I'm glad we got it sorted!
m
yeah, more a troubleshooting topic if you prefer ! 😉
PreviousNext
Powered by