random 3.0.22 issues with hostapd
HI! I'm running a Wifi access point with hostapd 2.9 and FreeRADIUS 3.0.22 [1] running on raspberry pi armv6 (32-bit) with openSUSE Tumbleweed (kernel 5.12.3). OpenLDAP (Æ-DIR) is used as user management backend. Client is also a Laptop with openSUSE Tumbleweed x86_64 and the usual Network Manager setup with WPA2 with EAP-TTLS/PAP. In general the configuration seems to work and I had no issues with 3.0.21. But with 3.0.22 every now and then it does not work anymore. Restarting radiusd "fixes" it for some time. Unfortunately I did not find a way to easily reproduce it. In syslog I see these messages (first line is the last good case before failure): 2021-05-21T17:24:13.571211+00:00 ap1 radiusd[1728]: (13) Login OK: [miwi] (from client localhost port 1 cli 84-EF-18-F7-9E-6E) 2021-05-21T18:18:31.765761+00:00 ap1 radiusd[1728]: (20) Invalid user (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.772668+00:00 ap1 radiusd[1728]: (20) Login incorrect (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.775870+00:00 ap1 radiusd[1728]: (20) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed): [miwi] (from client localhost port 1 cli 84-
From the above I suspect radiusd does not properly properly reconnect as configured with SASL/EXTERNAL bind (using its EAP-TLS server cert as client cert) probably after reaching idle connection timeout. Instead it seems to use an anonymous bind.
Any clue what's going on here? Ciao, Michael. [1] https://build.opensuse.org/package/show/home:stroeder:iam/freeradius-server
On May 21, 2021, at 6:58 PM, Michael Ströder via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
But with 3.0.22 every now and then it does not work anymore. Restarting radiusd "fixes" it for some time. Unfortunately I did not find a way to easily reproduce it.
In syslog I see these messages (first line is the last good case before failure):
2021-05-21T17:24:13.571211+00:00 ap1 radiusd[1728]: (13) Login OK: [miwi] (from client localhost port 1 cli 84-EF-18-F7-9E-6E) 2021-05-21T18:18:31.765761+00:00 ap1 radiusd[1728]: (20) Invalid user (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.772668+00:00 ap1 radiusd[1728]: (20) Login incorrect (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.775870+00:00 ap1 radiusd[1728]: (20) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed): [miwi] (from client localhost port 1 cli 84-
From the above I suspect radiusd does not properly properly reconnect as configured with SASL/EXTERNAL bind (using its EAP-TLS server cert as client cert) probably after reaching idle connection timeout. Instead it seems to use an anonymous bind.
Weird.
Any clue what's going on here?
Not sure. The only changes to rlm_ldap between 3.0.21 and 3.0.22 are to add configuration items which set tls_min_version. Everything else is unchanged. Alan DeKok.
On 5/23/21 3:19 PM, Alan DeKok wrote:
On May 21, 2021, at 6:58 PM, Michael Ströder via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
But with 3.0.22 every now and then it does not work anymore. Restarting radiusd "fixes" it for some time. Unfortunately I did not find a way to easily reproduce it.
In syslog I see these messages (first line is the last good case before failure):
2021-05-21T17:24:13.571211+00:00 ap1 radiusd[1728]: (13) Login OK: [miwi] (from client localhost port 1 cli 84-EF-18-F7-9E-6E) 2021-05-21T18:18:31.765761+00:00 ap1 radiusd[1728]: (20) Invalid user (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.772668+00:00 ap1 radiusd[1728]: (20) Login incorrect (ldap: Bind with (anonymous) to ldaps://ae-dir.hv.local:636 failed: Local error): [miwi] (from client localhost port 0 via TLS tunnel) 2021-05-21T18:18:31.775870+00:00 ap1 radiusd[1728]: (20) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed): [miwi] (from client localhost port 1 cli 84-
From the above I suspect radiusd does not properly properly reconnect as configured with SASL/EXTERNAL bind (using its EAP-TLS server cert as client cert) probably after reaching idle connection timeout. Instead it seems to use an anonymous bind.
Weird.
Any clue what's going on here?
Not sure. The only changes to rlm_ldap between 3.0.21 and 3.0.22 are to add configuration items which set tls_min_version. Everything else is unchanged.
The config is here: https://gitlab.com/ae-dir/client-examples/-/blob/master/freeradius/radiusd.c... I've created this radiusd.conf as a learning experience and to have all site-specific settings of this very simple setup in one place in a shorter form. But let's look at slapd log for a good case (stripped a bit of syslog output to keep lines shorter): 2021-05-23T15:53:04 conn=1735 fd=36 ACCEPT from IP=10.1.1.4:38150 (IP=0.0.0.0:636) 2021-05-23T15:53:04 conn=1735 fd=36 TLS established tls_ssf=256 ssf=256 2021-05-23T15:53:04 conn=1735 op=0 BIND dn="" method=163 2021-05-23T15:53:04 conn=1735 op=0 BIND authcid="cn=wifirad1.stroeder.local,ou=its,o=stroeder.com" authzid="cn=wifirad1.stroeder.local,ou=its,o=stroeder.com" 2021-05-23T15:53:04 conn=1735 op=0 BIND dn="uid=system_radiusd_ap1,cn=kl11-wifi-radius,cn=kl11,ou=ae-dir" mech=EXTERNAL sasl_ssf=0 ssf=256 2021-05-23T15:53:04 conn=1735 op=0 RESULT tag=97 err=0 text= 2021-05-23T15:53:04 conn=1735 op=1 SRCH base="ou=ae-dir" scope=2 deref=0 filter="(&(uid=miwi)(pwdChangedTime=*))" 2021-05-23T15:53:04 conn=1735 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 2021-05-23T15:53:04 conn=1735 op=2 BIND anonymous mech=implicit ssf=0 2021-05-23T15:53:04 conn=1735 op=2 BIND dn="uid=miwi,cn=wifi,ou=ae-dir" method=128 2021-05-23T15:53:04 conn=1735 op=2 BIND dn="uid=miwi,cn=wifi,ou=ae-dir" mech=SIMPLE ssf=0 2021-05-23T15:53:04 conn=1735 op=2 RESULT tag=97 err=0 text= 2021-05-23T16:09:48 conn=1735 fd=36 closed (idletimeout) As you can see the SASL/EXTERNAL bind for searching the user entry and the simple bind operation for checking user's password is done within a single pooled LDAP connection (conn=1735). This leads to this LDAP session being bound to the end user's entity. But this end user is not authorized to do the searches for users! Is that really how it is supposed to work? In my own implementations I always have persistent pooled connections for searching the LDAP directory, typically to map input username to the bind-DN, but strictly open new temporary LDAP connection for each simple bind operation checking a user's password. For better performance the latter can also be a second pooled anonymous connection exclusively used to send bind operations for user password validation and nothing else. BTW: For such a situation OpenLDAP 2.5 now has a new overlay which implements the so-called Verify Credentials extended operation with which you can check the user's password including password policy checks done by slapd without re-binding. This would also save round-trips. But it will probably take some time before 2.5 gets widely available. Ciao, Michael.
On 5/23/21 5:28 PM, Michael Ströder via Freeradius-Users wrote:
As you can see the SASL/EXTERNAL bind for searching the user entry and the simple bind operation for checking user's password is done within a single pooled LDAP connection (conn=1735). This leads to this LDAP session being bound to the end user's entity. But this end user is not authorized to do the searches for users!
As work-around I've now set: pool { uses = 1 } Let's see whether that works. Have to accept more round-trips though. Ciao, Michael.
On May 23, 2021, at 11:28 AM, Michael Ströder via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
But let's look at slapd log for a good case (stripped a bit of syslog output to keep lines shorter): ... As you can see the SASL/EXTERNAL bind for searching the user entry and the simple bind operation for checking user's password is done within a single pooled LDAP connection (conn=1735). This leads to this LDAP session being bound to the end user's entity. But this end user is not authorized to do the searches for users!
Is that really how it is supposed to work?
Nope. That code hasn't changed in 3.0.22, so I'm not sure what's going on. Look for "rebound" in src/modules/rlm_ldap. If it binds a connection as a particular user, then it sets "rebound=true". And before using that connection again, it re-binds as the admin / read-only user.
In my own implementations I always have persistent pooled connections for searching the LDAP directory, typically to map input username to the bind-DN, but strictly open new temporary LDAP connection for each simple bind operation checking a user's password. For better performance the latter can also be a second pooled anonymous connection exclusively used to send bind operations for user password validation and nothing else.
It doesn't do exactly that, but pretty close.
BTW: For such a situation OpenLDAP 2.5 now has a new overlay which implements the so-called Verify Credentials extended operation with which you can check the user's password including password policy checks done by slapd without re-binding. This would also save round-trips. But it will probably take some time before 2.5 gets widely available.
Yes. Alan DeKok.
participants (2)
-
Alan DeKok -
Michael Ströder