Hello, I'm using freeradius 2.1.8 with wpa_supplicant 0.7.1, both on 32bit-linux with openssl 1.0.0 or openssl 0.9.8. AP is a Linksys WAP610N. In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled. The initial login works fine. But there seems to be a problem to fill the cache during initial login: rad_recv: Access-Request packet from host 192.168.1.9 port 2048, id=50, length=178 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-....:mywlan" Calling-Station-Id = "00-13-..." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020800060d00 State = 0x89d58d3e8edd800104fb11e3a0338e57 Message-Authenticator = 0xe8f5eca1715e4bd2ecfa23c444efe859 Wed Jun 2 20:29:14 2010 : Info: +- entering group authorize {...} Wed Jun 2 20:29:14 2010 : Info: ++[preprocess] returns ok Wed Jun 2 20:29:14 2010 : Info: ++[chap] returns noop Wed Jun 2 20:29:14 2010 : Info: ++[mschap] returns noop Wed Jun 2 20:29:14 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Wed Jun 2 20:29:14 2010 : Info: [suffix] No such realm "mydom" Wed Jun 2 20:29:14 2010 : Info: ++[suffix] returns noop Wed Jun 2 20:29:14 2010 : Info: [eap] EAP packet type response id 8 length 6 Wed Jun 2 20:29:14 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Jun 2 20:29:14 2010 : Info: ++[eap] returns updated Wed Jun 2 20:29:14 2010 : Info: ++[unix] returns notfound Wed Jun 2 20:29:14 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Wed Jun 2 20:29:14 2010 : Info: ++[files] returns ok Wed Jun 2 20:29:14 2010 : Info: ++[expiration] returns noop Wed Jun 2 20:29:14 2010 : Info: ++[logintime] returns noop Wed Jun 2 20:29:14 2010 : Info: ++[pap] returns noop Wed Jun 2 20:29:14 2010 : Info: Found Auth-Type = EAP Wed Jun 2 20:29:14 2010 : Info: +- entering group authenticate {...} Wed Jun 2 20:29:14 2010 : Info: [eap] Request found, released from the list Wed Jun 2 20:29:14 2010 : Info: [eap] EAP/tls Wed Jun 2 20:29:14 2010 : Info: [eap] processing type tls Wed Jun 2 20:29:14 2010 : Info: [tls] Authenticate Wed Jun 2 20:29:14 2010 : Info: [tls] processing EAP-TLS Wed Jun 2 20:29:14 2010 : Info: [tls] Received TLS ACK Wed Jun 2 20:29:14 2010 : Info: [tls] ACK handshake is finished Wed Jun 2 20:29:14 2010 : Info: [tls] eaptls_verify returned 3 Wed Jun 2 20:29:14 2010 : Info: [tls] eaptls_process returned 3 Wed Jun 2 20:29:14 2010 : Info: [tls] Adding user data to cached session Wed Jun 2 20:29:14 2010 : Info: [tls] Saving response in the cache Wed Jun 2 20:29:14 2010 : Info: [tls] WARNING: No information to cache: session caching will be disabled for this session. If the reconnect takes place, the missing cache-data seems to be the problem -> the user cannot be authenticated: rad_recv: Access-Request packet from host 192.168.1.9 port 2048, id=55, length=237 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mywlan" Calling-Station-Id = "00-13-..." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = ...df1e94bea7671e5b6cf4571cf262db282b055d78ab191a3 State = 0x01880c0103840161cd60973c24894f7d Message-Authenticator = 0xf8b7771a372c0768720c9bf05de8708b Wed Jun 2 20:39:18 2010 : Info: +- entering group authorize {...} Wed Jun 2 20:39:18 2010 : Info: ++[preprocess] returns ok Wed Jun 2 20:39:18 2010 : Info: ++[chap] returns noop Wed Jun 2 20:39:18 2010 : Info: ++[mschap] returns noop Wed Jun 2 20:39:18 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Wed Jun 2 20:39:18 2010 : Info: [suffix] No such realm "mydom" Wed Jun 2 20:39:18 2010 : Info: ++[suffix] returns noop Wed Jun 2 20:39:18 2010 : Info: [eap] EAP packet type response id 12 length 65 Wed Jun 2 20:39:18 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Jun 2 20:39:18 2010 : Info: ++[eap] returns updated Wed Jun 2 20:39:18 2010 : Info: ++[unix] returns notfound Wed Jun 2 20:39:18 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Wed Jun 2 20:39:18 2010 : Info: ++[files] returns ok Wed Jun 2 20:39:18 2010 : Info: ++[expiration] returns noop Wed Jun 2 20:39:18 2010 : Info: ++[logintime] returns noop Wed Jun 2 20:39:18 2010 : Info: ++[pap] returns noop Wed Jun 2 20:39:18 2010 : Info: Found Auth-Type = EAP Wed Jun 2 20:39:18 2010 : Info: +- entering group authenticate {...} Wed Jun 2 20:39:18 2010 : Info: [eap] Request found, released from the list Wed Jun 2 20:39:18 2010 : Info: [eap] EAP/tls Wed Jun 2 20:39:18 2010 : Info: [eap] processing type tls Wed Jun 2 20:39:18 2010 : Info: [tls] Authenticate Wed Jun 2 20:39:18 2010 : Info: [tls] processing EAP-TLS Wed Jun 2 20:39:18 2010 : Info: [tls] eaptls_verify returned 7 Wed Jun 2 20:39:18 2010 : Info: [tls] Done initial handshake Wed Jun 2 20:39:18 2010 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Wed Jun 2 20:39:18 2010 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished Wed Jun 2 20:39:18 2010 : Info: [tls] TLS_accept: SSLv3 read finished A Wed Jun 2 20:39:18 2010 : Info: [tls] (other): SSL negotiation finished successfully Wed Jun 2 20:39:18 2010 : Debug: SSL Connection Established Wed Jun 2 20:39:18 2010 : Debug: SSL Application Data Wed Jun 2 20:39:18 2010 : Info: [tls] eaptls_process returned 3 Wed Jun 2 20:39:18 2010 : Info: [tls] Retrieved session data from cached session Wed Jun 2 20:39:18 2010 : Info: [tls] WARNING: No information in cached session! Wed Jun 2 20:39:18 2010 : Info: [eap] Freeing handler Wed Jun 2 20:39:18 2010 : Info: ++[eap] returns reject Wed Jun 2 20:39:18 2010 : Info: Failed to authenticate the user. Wed Jun 2 20:39:18 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-...) Wed Jun 2 20:39:18 2010 : Info: Using Post-Auth-Type Reject Wed Jun 2 20:39:18 2010 : Info: +- entering group REJECT {...} Wed Jun 2 20:39:18 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Wed Jun 2 20:39:18 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Jun 2 20:39:18 2010 : Info: ++[attr_filter.access_reject] returns updated Wed Jun 2 20:39:18 2010 : Info: Delaying reject of request 13 for 1 seconds Wed Jun 2 20:39:18 2010 : Debug: Going to the next request Wed Jun 2 20:39:18 2010 : Debug: Waking up in 0.9 seconds. Wed Jun 2 20:39:19 2010 : Info: Sending delayed reject for request 13 Sending Access-Reject of id 55 to 192.168.1.9 port 2048 EAP-Message = 0x040c0004 Message-Authenticator = 0x00000000000000000000000000000000 Independently of this incorrect login. the connection between the supplicant and the AP isn't disconnected or interrupted(!!), but the reauthentication is done every minute now. If the cache in eap.conf is disabled, the user can't be authenticated too, but the error during reauthentication is another (SSL_GET_PREV_SESSION:session id context uninitialized): rad_recv: Access-Request packet from host 192.168.1.9 port 2048, id=77, length=1484 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mywlan" Calling-Station-Id = "00-13-...." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = ...0170018001900230420447af7318cf8a9 EAP-Message = ...a3900200a0967a31318e54f7028eb6869963739a506ba EAP-Message = ...a35e57c17bbc86639826ba135d40271a953ec8fc6b1748 EAP-Message = ...ffe48b048b34ca5e97417950e1963592be7aa223ef906e8 EAP-Message = ...5647e8913e37299de4c889576a3cc2ac565285a27750f EAP-Message = ...5cccfedd1b96f38c9897681d78bbf75296a5e559e31c59b State = 0xaeafb685afa4bb3f1df61345a8211214 Message-Authenticator = 0xef86f802b12b474972c47fcd3692ae4f Wed Jun 2 21:04:16 2010 : Info: +- entering group authorize {...} Wed Jun 2 21:04:16 2010 : Info: ++[preprocess] returns ok Wed Jun 2 21:04:16 2010 : Info: ++[chap] returns noop Wed Jun 2 21:04:16 2010 : Info: ++[mschap] returns noop Wed Jun 2 21:04:16 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Wed Jun 2 21:04:16 2010 : Info: [suffix] No such realm "mydom" Wed Jun 2 21:04:16 2010 : Info: ++[suffix] returns noop Wed Jun 2 21:04:16 2010 : Info: [eap] EAP packet type response id 11 length 253 Wed Jun 2 21:04:16 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Jun 2 21:04:16 2010 : Info: ++[eap] returns updated Wed Jun 2 21:04:16 2010 : Info: ++[unix] returns notfound Wed Jun 2 21:04:16 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Wed Jun 2 21:04:16 2010 : Info: ++[files] returns ok Wed Jun 2 21:04:16 2010 : Info: ++[expiration] returns noop Wed Jun 2 21:04:16 2010 : Info: ++[logintime] returns noop Wed Jun 2 21:04:16 2010 : Info: ++[pap] returns noop Wed Jun 2 21:04:16 2010 : Info: Found Auth-Type = EAP Wed Jun 2 21:04:16 2010 : Info: +- entering group authenticate {...} Wed Jun 2 21:04:16 2010 : Info: [eap] Request found, released from the list Wed Jun 2 21:04:16 2010 : Info: [eap] EAP/tls Wed Jun 2 21:04:16 2010 : Info: [eap] processing type tls Wed Jun 2 21:04:16 2010 : Info: [tls] Authenticate Wed Jun 2 21:04:16 2010 : Info: [tls] processing EAP-TLS Wed Jun 2 21:04:16 2010 : Info: [tls] eaptls_verify returned 7 Wed Jun 2 21:04:16 2010 : Info: [tls] Done initial handshake Wed Jun 2 21:04:16 2010 : Info: [tls] (other): before/accept initialization Wed Jun 2 21:04:16 2010 : Info: [tls] TLS_accept: before/accept initialization Wed Jun 2 21:04:16 2010 : Info: [tls] <<< TLS 1.0 Handshake [length 050b], ClientHello Wed Jun 2 21:04:16 2010 : Error: TLS_accept:error in SSLv3 read client hello C Wed Jun 2 21:04:16 2010 : Error: rlm_eap: SSL error error:140D9115:SSL routines:SSL_GET_PREV_SESSION:session id context uninitialized Wed Jun 2 21:04:16 2010 : Error: SSL: SSL_read failed in a system call (-1), TLS session fails. Wed Jun 2 21:04:16 2010 : Debug: TLS receive handshake failed during operation If fast_reauth in wpa_supplicant is disabled, the reauthentication works fine, but the connection between the AP and the supplicant ist interrupted for about 20 seconds - much to long :-). Do you have any idea how to solve this problem? Thanks for you help, Andreas
Andreas Hartmann wrote:
In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled.
Uh... that makes no sense. You've disabled caching (i.e fast re-auth) on the server, and enabled it on the client. Why are you surprised that fast re-auth isn't working?
If the reconnect takes place, the missing cache-data seems to be the problem -> the user cannot be authenticated:
<shrug> That's what you told the server to do.
If fast_reauth in wpa_supplicant is disabled, the reauthentication works fine, but the connection between the AP and the supplicant ist interrupted for about 20 seconds - much to long :-).
Do you have any idea how to solve this problem?
Find out why the supplicant is taking 20s for authentication. Alan DeKok.
Alan DeKok wrote:
Andreas Hartmann wrote:
In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled.
Uh... that makes no sense.
You've disabled caching (i.e fast re-auth) on the server, and enabled it on the client. Why are you surprised that fast re-auth isn't working?
I've seen similar problems between FreeRadius and wpa_supplicant both with and without the cache enabled. Getting wpa_supplicant to restart seems to clear it temporarily. My reading of Andreas's message was that he has tried it both ways. I haven't yet dug into it enough to try and pin down where the problem is. It does seem that problems with the cache should just result in a slow authentication taking place, not a total failure of authentication. -David Mitchell
If the reconnect takes place, the missing cache-data seems to be the problem -> the user cannot be authenticated:
<shrug> That's what you told the server to do.
If fast_reauth in wpa_supplicant is disabled, the reauthentication works fine, but the connection between the AP and the supplicant ist interrupted for about 20 seconds - much to long :-).
Do you have any idea how to solve this problem?
Find out why the supplicant is taking 20s for authentication.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- ----------------------------------------------------------------- | David Mitchell (mitchell@ucar.edu) Network Engineer IV | | Tel: (303) 497-1845 National Center for | | FAX: (303) 497-1818 Atmospheric Research | -----------------------------------------------------------------
David Mitchell schrieb:
Alan DeKok wrote:
Andreas Hartmann wrote:
In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled.
Uh... that makes no sense.
You've disabled caching (i.e fast re-auth) on the server, and enabled it on the client. Why are you surprised that fast re-auth isn't working?
I've seen similar problems between FreeRadius and wpa_supplicant both with and without the cache enabled. Getting wpa_supplicant to restart seems to clear it temporarily.
Well, I took your realization to implement the following workaround: Caching is enabled in freeradius, fast_reauth is switched on in wpa_supplicant. I set the reauth-timeout of the AP to 2 hours. On the supplicant, I started a cronjob, which HUP's the supplicant each 59 minutes. That's the way how the supplicant is prevented to do a fast reauth (which doesn't really work). A full reauth isn't necessary too, because of the sig hup all 59 minutes, which is done like this: rad_recv: Accounting-Request packet from host 192.168.1.9 port 2049, id=112, length=177 Acct-Session-Id = "0000001B-00000007" Acct-Status-Type = Stop Acct-Authentic = RADIUS User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mylan" Calling-Station-Id = "00-13-..." NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Acct-Session-Time = 358 Event-Timestamp = "Jan 1 1970 02:26:18 CET" Acct-Terminate-Cause = User-Request Thu Jun 3 05:41:43 2010 : Info: +- entering group preacct {...} Thu Jun 3 05:41:43 2010 : Info: ++[preprocess] returns ok Thu Jun 3 05:41:43 2010 : Info: [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.1.9,NAS-IP-Address = 192.168.1.9,Acct-Session-Id = "0000001B-00000007",User-Name = "myuser@mydom"' Thu Jun 3 05:41:43 2010 : Info: [acct_unique] Acct-Unique-Session-ID = "aba6339d45d8fab1". Thu Jun 3 05:41:43 2010 : Info: ++[acct_unique] returns ok Thu Jun 3 05:41:43 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Thu Jun 3 05:41:43 2010 : Info: [suffix] No such realm "mydom" Thu Jun 3 05:41:43 2010 : Info: ++[suffix] returns noop Thu Jun 3 05:41:43 2010 : Info: ++[files] returns noop Thu Jun 3 05:41:43 2010 : Info: +- entering group accounting {...} Thu Jun 3 05:41:43 2010 : Info: [detail] expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/radius/radacct/192.168.1.9/detail-20100603 Thu Jun 3 05:41:43 2010 : Info: [detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.9/detail-20100603 Thu Jun 3 05:41:43 2010 : Info: [detail] expand: %t -> Thu Jun 3 05:41:43 2010 Thu Jun 3 05:41:43 2010 : Info: ++[detail] returns ok Thu Jun 3 05:41:43 2010 : Info: ++[unix] returns ok Thu Jun 3 05:41:43 2010 : Info: [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp Thu Jun 3 05:41:43 2010 : Info: [radutmp] expand: %{User-Name} -> myuser@mydom Thu Jun 3 05:41:43 2010 : Info: ++[radutmp] returns ok Thu Jun 3 05:41:43 2010 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> myuser@mydom Thu Jun 3 05:41:43 2010 : Debug: attr_filter: Matched entry DEFAULT at line 12 Thu Jun 3 05:41:43 2010 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 112 to 192.168.1.9 port 2049 Thu Jun 3 05:41:43 2010 : Info: Finished request 111. Thu Jun 3 05:41:43 2010 : Info: Cleaning up request 111 ID 112 with timestamp +5054 Thu Jun 3 05:41:43 2010 : Debug: Going to the next request Thu Jun 3 05:41:43 2010 : Info: Ready to process requests. rad_recv: Accounting-Request packet from host 192.168.1.9 port 2049, id=113, length=159 Acct-Session-Id = "0000001B-00000008" Acct-Status-Type = Start Acct-Authentic = RADIUS User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mylan" Calling-Station-Id = "00-13-..." NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Thu Jun 3 05:41:44 2010 : Info: +- entering group preacct {...} Thu Jun 3 05:41:44 2010 : Info: ++[preprocess] returns ok Thu Jun 3 05:41:44 2010 : Info: [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.1.9,NAS-IP-Address = 192.168.1.9,Acct-Session-Id = "0000001B-00000008",User-Name = "myuser@mydom"' Thu Jun 3 05:41:44 2010 : Info: [acct_unique] Acct-Unique-Session-ID = "efac47a366ac188f". Thu Jun 3 05:41:44 2010 : Info: ++[acct_unique] returns ok Thu Jun 3 05:41:44 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Thu Jun 3 05:41:44 2010 : Info: [suffix] No such realm "mydom" Thu Jun 3 05:41:44 2010 : Info: ++[suffix] returns noop Thu Jun 3 05:41:44 2010 : Info: ++[files] returns noop Thu Jun 3 05:41:44 2010 : Info: +- entering group accounting {...} Thu Jun 3 05:41:44 2010 : Info: [detail] expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/radius/radacct/192.168.1.9/detail-20100603 Thu Jun 3 05:41:44 2010 : Info: [detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.9/detail-20100603 Thu Jun 3 05:41:44 2010 : Info: [detail] expand: %t -> Thu Jun 3 05:41:44 2010 Thu Jun 3 05:41:44 2010 : Info: ++[detail] returns ok Thu Jun 3 05:41:44 2010 : Info: ++[unix] returns ok Thu Jun 3 05:41:44 2010 : Info: [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp Thu Jun 3 05:41:44 2010 : Info: [radutmp] expand: %{User-Name} -> myuser@mydom Thu Jun 3 05:41:44 2010 : Info: ++[radutmp] returns ok Thu Jun 3 05:41:44 2010 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> myuser@mydom Thu Jun 3 05:41:44 2010 : Debug: attr_filter: Matched entry DEFAULT at line 12 Thu Jun 3 05:41:44 2010 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 113 to 192.168.1.9 port 2049 Thu Jun 3 05:41:44 2010 : Info: Finished request 112. Thu Jun 3 05:41:44 2010 : Info: Cleaning up request 112 ID 113 with timestamp +5055 Thu Jun 3 05:41:44 2010 : Debug: Going to the next request Thu Jun 3 05:41:44 2010 : Info: Ready to process requests.
My reading of Andreas's message was that he has tried it both ways.
Yes :-)
I haven't yet dug into it enough to try and pin down where the problem is. It does seem that problems with the cache should just result in a slow authentication taking place, not a total failure of authentication.
Kind regards, Andreas
Andreas Hartmann schrieb:
David Mitchell schrieb:
Alan DeKok wrote:
Andreas Hartmann wrote:
In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled.
Uh... that makes no sense.
You've disabled caching (i.e fast re-auth) on the server, and enabled it on the client. Why are you surprised that fast re-auth isn't working?
I've seen similar problems between FreeRadius and wpa_supplicant both with and without the cache enabled. Getting wpa_supplicant to restart seems to clear it temporarily.
Well, I took your realization to implement the following workaround:
Caching is enabled in freeradius, fast_reauth is switched on in wpa_supplicant.
I set the reauth-timeout of the AP to 2 hours. On the supplicant, I started a cronjob, which HUP's the supplicant each 59 minutes. That's the way how the supplicant is prevented to do a fast reauth (which doesn't really work). A full reauth isn't necessary too, because of the sig hup all 59 minutes, which is done like this:
rad_recv: Accounting-Request packet from host 192.168.1.9 port 2049, id=112, length=177 Acct-Session-Id = "0000001B-00000007" Acct-Status-Type = Stop Acct-Authentic = RADIUS User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mylan" Calling-Station-Id = "00-13-..." NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Acct-Session-Time = 358 Event-Timestamp = "Jan 1 1970 02:26:18 CET" ^^^^^^^^^^^^^^^^^^^^^^^^
Hmmm, where does this funny Event-Timestamp comes from? All my times of client and server are ok. Otherwise, I can't find any way to set the time at the AP (linksys WAP610N)? Is there any way? clueless ... Kind regards, Andreas
Alan DeKok schrieb:
Andreas Hartmann wrote:
In eap.conf, the option eap -> tls -> cache -> enable is switched off and fast_reauth in wpa_supplicant is enabled.
Uh... that makes no sense.
Yes, you're right - I meant option eap -> tls -> cache -> enable is switched _on_ and fast_reauth is on too on the supplicant. My wrong :-(. You can see it at this log entry at the initial login: Wed Jun 2 20:29:14 2010 : Info: [tls] Adding user data to cached session Wed Jun 2 20:29:14 2010 : Info: [tls] Saving response in the cache Wed Jun 2 20:29:14 2010 : Info: [tls] WARNING: No information to cache: session caching will be disabled for this session. And then the reauth: Wed Jun 2 20:39:18 2010 : Info: [tls] Retrieved session data from cached session Wed Jun 2 20:39:18 2010 : Info: [tls] WARNING: No information in cached session! Wed Jun 2 20:39:18 2010 : Info: [eap] Freeing handler Wed Jun 2 20:39:18 2010 : Info: ++[eap] returns reject Wed Jun 2 20:39:18 2010 : Info: Failed to authenticate the user. Wed Jun 2 20:39:18 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-...) Wed Jun 2 20:39:18 2010 : Info: Using Post-Auth-Type Reject Wed Jun 2 20:39:18 2010 : Info: +- entering group REJECT {...} Wed Jun 2 20:39:18 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Wed Jun 2 20:39:18 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Jun 2 20:39:18 2010 : Info: ++[attr_filter.access_reject] returns updated Wed Jun 2 20:39:18 2010 : Info: Delaying reject of request 13 for 1 seconds Wed Jun 2 20:39:18 2010 : Debug: Going to the next request Wed Jun 2 20:39:18 2010 : Debug: Waking up in 0.9 seconds. Wed Jun 2 20:39:19 2010 : Info: Sending delayed reject for request 13 Sending Access-Reject of id 55 to 192.168.1.9 port 2048 EAP-Message = 0x040c0004 Message-Authenticator = 0x00000000000000000000000000000000 It's strangely, that the supplicant couldn't be authorized but the AP doesn't lock the connection anyway :-). I would have resoected, that the connection would have been locked afterwards. Instead of, the supplicant reauths from now on every minute, using this broken fast reauth. If I do a full reauthentication, the authentication succeeds, but I'm getting locked anywhere - that makes no sense to me.
If fast_reauth in wpa_supplicant is disabled, the reauthentication >> works fine, but the connection between the AP and the supplicant ist interrupted for about 20 seconds - much to long :-).
Do you have any idea how to solve this problem?
Find out why the supplicant is taking 20s for authentication.
How much time should be ok for the full reauthentication? I traced the authentication and could see, that the part with the radiusserver takes less than a second. Most of the time is needed until the AP sends the new keys for the encryption of the session. Ok, sometimes it's a little bit faster (9 seconds). Thanks for your help, Andreas
Andreas Hartmann <andihartmann@01019freenet.de> wrote:
If fast_reauth in wpa_supplicant is disabled, the reauthentication
works fine, but the connection between the AP and the supplicant ist interrupted for about 20 seconds - much to long :-).
Do you have any idea how to solve this problem?
Find out why the supplicant is taking 20s for authentication.
How much time should be ok for the full reauthentication?
As far as I know, we *all* get sub-second re-auths, however our actual full authentications (seven LDAP queries included) also take a similar amount of time. Fast re-auth results in fewer packets needing to be passed back and forth. For a full authentication for us about 10 EAP packets need to be exchanged between the client and RADIUS server, re-auth means for us only about three or so need to be passed.
I traced the authentication and could see, that the part with the radiusserver takes less than a second. Most of the time is needed until the AP sends the new keys for the encryption of the session. Ok, sometimes it's a little bit faster (9 seconds).
I could have this wrong, but it is the RADIUS server that sends the encryption keys, not the AP. It might be worth running tcpdump/wireshark on the client workstation and compare that to what you are seeing at the RADIUS server end. Cheers -- Alexander Clouter .sigmonster says: BOFH excuse #35: working as designed
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Yes, you're right - I meant option eap -> tls -> cache -> enable is switched _on_ and fast_reauth is on too on the supplicant. My wrong :-(.
You can see it at this log entry at the initial login: Wed Jun 2 20:29:14 2010 : Info: [tls] Adding user data to cached session Wed Jun 2 20:29:14 2010 : Info: [tls] Saving response in the cache Wed Jun 2 20:29:14 2010 : Info: [tls] WARNING: No information to cache: session caching will be disabled for this session.
And then the reauth:
Wed Jun 2 20:39:18 2010 : Info: [tls] Retrieved session data from cached session Wed Jun 2 20:39:18 2010 : Info: [tls] WARNING: No information in cached session!
FWIW I've seen exactly the same with FR 2.1.8. Ended up disabling caching. But I would like to know the cause of this "No information to cache" warning. The resulting failure to retrieve cached data is of course to be expected, but the warning itself doesn't make any sense to me. There must be information to cache since the authentication is sucessful. See also the thread that https://lists.freeradius.org/pipermail/freeradius-users/2010-January/msg0018... is part of. Don't think there was any solution presented although there are claims that session caching is working. Bjørn
Bjørn Mork <bjorn@mork.no> wrote:
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Yes, you're right - I meant option eap -> tls -> cache -> enable is switched _on_ and fast_reauth is on too on the supplicant. My wrong :-(.
You can see it at this log entry at the initial login: Wed Jun 2 20:29:14 2010 : Info: [tls] Adding user data to cached session Wed Jun 2 20:29:14 2010 : Info: [tls] Saving response in the cache Wed Jun 2 20:29:14 2010 : Info: [tls] WARNING: No information to cache: session caching will be disabled for this session.
And then the reauth:
Wed Jun 2 20:39:18 2010 : Info: [tls] Retrieved session data from cached session Wed Jun 2 20:39:18 2010 : Info: [tls] WARNING: No information in cached session!
FWIW I've seen exactly the same with FR 2.1.8. Ended up disabling caching. But I would like to know the cause of this "No information to cache" warning. The resulting failure to retrieve cached data is of course to be expected, but the warning itself doesn't make any sense to me. There must be information to cache since the authentication is sucessful.
The 'No information to cache' means you do not have anything useful (for example 'User-Name') in the reply packet. In the post-auth of my inner-eap virtual server I have added: ---- post-auth { ... # needed for TTLS cache update reply { User-Name := "%{request:User-Name}" } ... } ---- That should fix your problem. Cheers -- Alexander Clouter .sigmonster says: Money is the root of all evil, and man needs roots.
Alexander Clouter <alex@digriz.org.uk> writes:
The 'No information to cache' means you do not have anything useful (for example 'User-Name') in the reply packet.
Makes sense.
In the post-auth of my inner-eap virtual server I have added: ---- post-auth { ... # needed for TTLS cache update reply { User-Name := "%{request:User-Name}" } ... } ----
That should fix your problem.
Thanks. Looks like something for the default config/documentation with that comment included. Bjørn
Bjørn Mork <bjorn@mork.no> wrote:
The 'No information to cache' means you do not have anything useful (for example 'User-Name') in the reply packet.
Makes sense.
In the post-auth of my inner-eap virtual server I have added: ---- post-auth { ... # needed for TTLS cache update reply { User-Name := "%{request:User-Name}" } ... } ----
That should fix your problem.
Thanks. Looks like something for the default config/documentation with that comment included.
To make things more interesting, depending on you situation[1] you might want to then strip the User-Name attribute from your reply traffic on the outer layer. We do this as in the 'eduroam' world when our lusers are roaming away from their home institution we want to protect the guilty and give them some degree of anonymity. This means the remote organisation the user is visiting only sees the username in the initial request packet...which for TTLS *should* be '@example.com' and *not* 'luser@example.com'. Of course when our users are onsite we pass on the User-Name in the Access-Accept so that the accounting packets from the NAS have the inner username present making grepping/SELECTing your accounting logs that much easier. Cheers -- Alexander Clouter .sigmonster says: You are so boring that when I see you my feet go to sleep.
Bjørn Mork <bjorn@mork.no> writes:
Alexander Clouter <alex@digriz.org.uk> writes:
The 'No information to cache' means you do not have anything useful (for example 'User-Name') in the reply packet.
Makes sense.
In the post-auth of my inner-eap virtual server I have added: ---- post-auth { ... # needed for TTLS cache update reply { User-Name := "%{request:User-Name}" } ... } ----
That should fix your problem.
Thanks. Looks like something for the default config/documentation with that comment included.
Hmm, well I found that this needed to be update outer.reply { User-Name := "%{request:User-Name}" } like the example that's already there... Not that I pretend to understand any of this. But the first version left me with still having Thu Jun 3 16:53:30 2010 : Info: [ttls] Got tunneled Access-Accept Thu Jun 3 16:53:30 2010 : Info: [ttls] Saving response in the cache Thu Jun 3 16:53:30 2010 : Info: [ttls] WARNING: No information to cache: session caching will be disabled for this session. while updating the outer.reply list gave: Thu Jun 3 17:00:07 2010 : Info: [ttls] Got tunneled Access-Accept Thu Jun 3 17:00:07 2010 : Info: [ttls] Saving response in the cache Bjørn
Bjørn Mork <bjorn@mork.no> writes:
while updating the outer.reply list gave:
Thu Jun 3 17:00:07 2010 : Info: [ttls] Got tunneled Access-Accept Thu Jun 3 17:00:07 2010 : Info: [ttls] Saving response in the cache
But it still doesn't seem to work: Fri Jun 4 07:09:03 2010 : Info: [ttls] eaptls_process returned 3 Fri Jun 4 07:09:03 2010 : Info: [ttls] Skipping Phase2 due to session resumption Fri Jun 4 07:09:03 2010 : Info: [ttls] WARNING: No information in cached session! Fri Jun 4 07:09:03 2010 : Info: [eap] Freeing handler Fri Jun 4 07:09:03 2010 : Info: ++[eap] returns reject Fri Jun 4 07:09:03 2010 : Info: Failed to authenticate the user. Fri Jun 4 07:09:03 2010 : Auth: Login incorrect: [luser@realm/<via Auth-Type = EAP>] (from client ap1.example.com port 60 cli 0016deadbeef) Maybe I should tune the reauth time down a bit while debugging this. Or maybe just let it be... It doesn't really matter much to me. Bjørn
Alexander Clouter schrieb:
Bjørn Mork <bjorn@mork.no> wrote:
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Yes, you're right - I meant option eap -> tls -> cache -> enable is switched _on_ and fast_reauth is on too on the supplicant. My wrong :-(.
You can see it at this log entry at the initial login: Wed Jun 2 20:29:14 2010 : Info: [tls] Adding user data to cached session Wed Jun 2 20:29:14 2010 : Info: [tls] Saving response in the cache Wed Jun 2 20:29:14 2010 : Info: [tls] WARNING: No information to cache: session caching will be disabled for this session.
And then the reauth:
Wed Jun 2 20:39:18 2010 : Info: [tls] Retrieved session data from cached session Wed Jun 2 20:39:18 2010 : Info: [tls] WARNING: No information in cached session!
FWIW I've seen exactly the same with FR 2.1.8. Ended up disabling caching. But I would like to know the cause of this "No information to cache" warning. The resulting failure to retrieve cached data is of course to be expected, but the warning itself doesn't make any sense to me. There must be information to cache since the authentication is sucessful.
The 'No information to cache' means you do not have anything useful (for example 'User-Name') in the reply packet.
In the post-auth of my inner-eap virtual server I have added: ---- post-auth { ... # needed for TTLS cache update reply { User-Name := "%{request:User-Name}" } ... } ----
Ok, I'm using exclusivly certificates for authorization. Therefore, I dont't have any inner-eap, if I got it right. I have one basic question: There are now two different caches: one in eap (based on ssl) and the extern cache, rlm_caching. If I want to use fast_reauth, is it necessary to enable both caches or must the ssl-cache in eap.conf be disabled to run fast_reauth successfully with rlm_caching? Meanwhile, I have a configuration, which does a User-Name-based rlm_caching at the end of the last fragment of the initial authentication with an originaly empty database. The entry is the following in /etc/raddb/modules/caching caching { filename = ${db_dir}/db.cache cache-ttl = 1d hit-ratio = 1000 key = "%{User-Name}" # post-auth = "%{User-Name}" cache-size = 200000 # cache-rejects = yes } I'm not sure, if User-Name is the best key for this purpose. In /etc/raddb/sites-enabled/defaults, caching has the following entries: authorize { caching { ok = return } .... } post-auth { .... caching if (updated) { update reply { User-Name := "%{User-Name}" } } } With this config, the key is written to the caching database at the end of the inital login. But the problem is: If the user reconnects or wants to connect initial again, the process is stopped (with success returned) at the moment, the client sends the User-Name. This is wrong. The process can't be interrupted before the key exchange has been done successfully. How can this be written in the config-file (authorize-section)? Kind regards, Andreas
Andreas Hartmann wrote:
I have one basic question: There are now two different caches: one in eap (based on ssl) and the extern cache, rlm_caching.
rlm_caching has nothing to do with EAP.
If I want to use fast_reauth, is it necessary to enable both caches or must the ssl-cache in eap.conf be disabled to run fast_reauth successfully with rlm_caching?
The EAP configuration explains what you need to do for fast re-auth.
Meanwhile, I have a configuration, which does a User-Name-based rlm_caching at the end of the last fragment of the initial authentication with an originaly empty database.
What is it supposed to do?
But the problem is:
If the user reconnects or wants to connect initial again, the process is stopped (with success returned) at the moment, the client sends the User-Name. This is wrong. The process can't be interrupted before the key exchange has been done successfully. How can this be written in the config-file (authorize-section)?
What do you want to do? I have no idea why you configured the caching module, and you haven't explained why you configured it. Alan DeKok.
Alan DeKok schrieb:
Andreas Hartmann wrote:
I have one basic question: There are now two different caches: one in eap (based on ssl) and the extern cache, rlm_caching.
rlm_caching has nothing to do with EAP.
If I want to use fast_reauth, is it necessary to enable both caches or must the ssl-cache in eap.conf be disabled to run fast_reauth successfully with rlm_caching?
The EAP configuration explains what you need to do for fast re-auth.
Meanwhile, I have a configuration, which does a User-Name-based rlm_caching at the end of the last fragment of the initial authentication with an originaly empty database.
What is it supposed to do?
But the problem is:
If the user reconnects or wants to connect initial again, the process is stopped (with success returned) at the moment, the client sends the User-Name. This is wrong. The process can't be interrupted before the key exchange has been done successfully. How can this be written in the config-file (authorize-section)?
What do you want to do?
I have no idea why you configured the caching module, and you haven't explained why you configured it.
Thanks for your reply, I configured it, because fast-reauth doesn't work for me. - In the wpa_supplicant, fast_reauth is switched to 1. - In eap.conf, the cache under tls is enabled. Now, wpa_supplicant is started and the client got authenticated. But there is a warning nearly at the end of the successfull authentication: Fri Jun 4 09:42:11 2010 : Info: [tls] eaptls_verify returned 3 Fri Jun 4 09:42:11 2010 : Info: [tls] eaptls_process returned 3 Fri Jun 4 09:42:11 2010 : Info: [tls] Adding user data to cached session Fri Jun 4 09:42:11 2010 : Info: [tls] Saving response in the cache Fri Jun 4 09:42:11 2010 : Info: [tls] WARNING: No information to ^^^^^^^^^^^^^^^^^^^^^^^^^^ cache: session caching will be disabled for this session. ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Fri Jun 4 09:42:11 2010 : Info: [eap] Freeing handler Fri Jun 4 09:42:11 2010 : Info: ++[eap] returns ok Fri Jun 4 09:42:11 2010 : Auth: Login OK: [myuser@mydom] (from client WAP610N port 0 cli 00-13-.....) Fri Jun 4 09:42:11 2010 : Info: +- entering group post-auth {...} Fri Jun 4 09:42:11 2010 : Info: ++[exec] returns noop Sending Access-Accept of id 238 to 192.168.... port 2048 .... Some time later, the fast_reauth follows, which breaks, because of missing datas in the cache. My question is: How must the client or the server be configured, that there are cached datas in order to get a working fast_reauth? rad_recv: Access-Request packet from host 192.168.1.9 port 2048, id=240, length=177 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-...:mywlan" Calling-Station-Id = "00-13-...." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x02000017016e6f7465626f6f6b31406d6179612e6f7267 Message-Authenticator = 0xc7d7831bf74eb29cc2862fbf9c1164f8 Fri Jun 4 10:05:37 2010 : Info: +- entering group authorize {...} Fri Jun 4 10:05:37 2010 : Info: ++[preprocess] returns ok Fri Jun 4 10:05:37 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Fri Jun 4 10:05:37 2010 : Info: [suffix] No such realm "mydom" Fri Jun 4 10:05:37 2010 : Info: ++[suffix] returns noop Fri Jun 4 10:05:37 2010 : Info: [eap] EAP packet type response id 0 length 23 Fri Jun 4 10:05:37 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns updated Fri Jun 4 10:05:37 2010 : Info: ++[unix] returns notfound Fri Jun 4 10:05:37 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Fri Jun 4 10:05:37 2010 : Info: ++[files] returns ok Fri Jun 4 10:05:37 2010 : Info: ++[expiration] returns noop Fri Jun 4 10:05:37 2010 : Info: ++[logintime] returns noop Fri Jun 4 10:05:37 2010 : Info: Found Auth-Type = EAP Fri Jun 4 10:05:37 2010 : Info: +- entering group authenticate {...} Fri Jun 4 10:05:37 2010 : Info: [eap] EAP Identity Fri Jun 4 10:05:37 2010 : Info: [eap] processing type tls Fri Jun 4 10:05:37 2010 : Info: [tls] Requiring client certificate Fri Jun 4 10:05:37 2010 : Info: [tls] Initiate Fri Jun 4 10:05:37 2010 : Info: [tls] Start returned 1 Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 240 to 192.168.... port 2048 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbc40ebedbc41e6950bd358ee7ea3ba57 Fri Jun 4 10:05:37 2010 : Info: Finished request 9. Fri Jun 4 10:05:37 2010 : Debug: Going to the next request Fri Jun 4 10:05:37 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168..... port 2048, id=241, length=1516 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-....:mywlan" Calling-Station-Id = "00-13-...." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020105360d00160301052b.... EAP-Message = 0xc19621437c240ee8........ EAP-Message = d1b03b4d9ba1a79b324d237c3b8c8ef1806597ec8 ... EAP-Message = 0x77f505a88ea15af0e517.... EAP-Message = 0x39e23c539c6250cf89bc10dbbfb48c3bb5f2fecf... EAP-Message = 0xae584e899f3de05f54edcc..... State = 0xbc40ebedbc41e6950bd358ee7ea3ba57 Message-Authenticator = 0x99433479c1d2750ac02738bcb5e629a9 Fri Jun 4 10:05:37 2010 : Info: +- entering group authorize {...} Fri Jun 4 10:05:37 2010 : Info: ++[preprocess] returns ok Fri Jun 4 10:05:37 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Fri Jun 4 10:05:37 2010 : Info: [suffix] No such realm "mydom" Fri Jun 4 10:05:37 2010 : Info: ++[suffix] returns noop Fri Jun 4 10:05:37 2010 : Info: [eap] EAP packet type response id 1 length 253 Fri Jun 4 10:05:37 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns updated Fri Jun 4 10:05:37 2010 : Info: ++[unix] returns notfound Fri Jun 4 10:05:37 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Fri Jun 4 10:05:37 2010 : Info: ++[files] returns ok Fri Jun 4 10:05:37 2010 : Info: ++[expiration] returns noop Fri Jun 4 10:05:37 2010 : Info: ++[logintime] returns noop Fri Jun 4 10:05:37 2010 : Info: Found Auth-Type = EAP Fri Jun 4 10:05:37 2010 : Info: +- entering group authenticate {...} Fri Jun 4 10:05:37 2010 : Info: [eap] Request found, released from the list Fri Jun 4 10:05:37 2010 : Info: [eap] EAP/tls Fri Jun 4 10:05:37 2010 : Info: [eap] processing type tls Fri Jun 4 10:05:37 2010 : Info: [tls] Authenticate Fri Jun 4 10:05:37 2010 : Info: [tls] processing EAP-TLS Fri Jun 4 10:05:37 2010 : Info: [tls] eaptls_verify returned 7 Fri Jun 4 10:05:37 2010 : Info: [tls] Done initial handshake Fri Jun 4 10:05:37 2010 : Info: [tls] (other): before/accept initialization Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: before/accept initialization Fri Jun 4 10:05:37 2010 : Info: [tls] <<< TLS 1.0 Handshake [length 052b], ClientHello Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 read client hello A Fri Jun 4 10:05:37 2010 : Info: [tls] >>> TLS 1.0 Handshake [length 0051], ServerHello Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 write server hello A Fri Jun 4 10:05:37 2010 : Info: [tls] >>> TLS 1.0 ChangeCipherSpec [length 0001] Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 write change cipher spec A Fri Jun 4 10:05:37 2010 : Info: [tls] >>> TLS 1.0 Handshake [length 0010], Finished Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 write finished A Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 flush data Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read finished A Fri Jun 4 10:05:37 2010 : Debug: In SSL Handshake Phase Fri Jun 4 10:05:37 2010 : Debug: In SSL Accept mode Fri Jun 4 10:05:37 2010 : Info: [tls] eaptls_process returned 13 Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 241 to 192.168.... port 2048 EAP-Message = 0x0102009b0d8000000091160301005...... Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbc40ebedbd42e6950bd358ee7ea3ba57 Fri Jun 4 10:05:37 2010 : Info: Finished request 10. Fri Jun 4 10:05:37 2010 : Debug: Going to the next request Fri Jun 4 10:05:37 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.1.9 port 2048, id=242, length=237 User-Name = "myuser@mydom" NAS-Port = 0 Called-Station-Id = "00-25-....:mywlan" Calling-Station-Id = "00-13-...." Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020200410d001403010001011603010.... State = 0xbc40ebedbd42e6950bd358ee7ea3ba57 Message-Authenticator = 0x21f2e35898da2e8b85b5d916baab5237 Fri Jun 4 10:05:37 2010 : Info: +- entering group authorize {...} Fri Jun 4 10:05:37 2010 : Info: ++[preprocess] returns ok Fri Jun 4 10:05:37 2010 : Info: [suffix] Looking up realm "mydom" for User-Name = "myuser@mydom" Fri Jun 4 10:05:37 2010 : Info: [suffix] No such realm "mydom" Fri Jun 4 10:05:37 2010 : Info: ++[suffix] returns noop Fri Jun 4 10:05:37 2010 : Info: [eap] EAP packet type response id 2 length 65 Fri Jun 4 10:05:37 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns updated Fri Jun 4 10:05:37 2010 : Info: ++[unix] returns notfound Fri Jun 4 10:05:37 2010 : Info: [files] users: Matched entry myuser@mydom at line 203 Fri Jun 4 10:05:37 2010 : Info: ++[files] returns ok Fri Jun 4 10:05:37 2010 : Info: ++[expiration] returns noop Fri Jun 4 10:05:37 2010 : Info: ++[logintime] returns noop Fri Jun 4 10:05:37 2010 : Info: Found Auth-Type = EAP Fri Jun 4 10:05:37 2010 : Info: +- entering group authenticate {...} Fri Jun 4 10:05:37 2010 : Info: [eap] Request found, released from the list Fri Jun 4 10:05:37 2010 : Info: [eap] EAP/tls Fri Jun 4 10:05:37 2010 : Info: [eap] processing type tls Fri Jun 4 10:05:37 2010 : Info: [tls] Authenticate Fri Jun 4 10:05:37 2010 : Info: [tls] processing EAP-TLS Fri Jun 4 10:05:37 2010 : Info: [tls] eaptls_verify returned 7 Fri Jun 4 10:05:37 2010 : Info: [tls] Done initial handshake Fri Jun 4 10:05:37 2010 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Fri Jun 4 10:05:37 2010 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished Fri Jun 4 10:05:37 2010 : Info: [tls] TLS_accept: SSLv3 read finished A Fri Jun 4 10:05:37 2010 : Info: [tls] (other): SSL negotiation finished successfully Fri Jun 4 10:05:37 2010 : Debug: SSL Connection Established Fri Jun 4 10:05:37 2010 : Debug: SSL Application Data Fri Jun 4 10:05:37 2010 : Info: [tls] eaptls_process returned 3 Fri Jun 4 10:05:37 2010 : Info: [tls] Retrieved session data from cached session Fri Jun 4 10:05:37 2010 : Info: [tls] WARNING: No information in ^^^^^^^^^^^^^^^^^^^^^^^^^^ cached session! ^^^^^^^^^^^^^^^ Fri Jun 4 10:05:37 2010 : Info: [eap] Freeing handler Fri Jun 4 10:05:37 2010 : Info: ++[eap] returns reject Fri Jun 4 10:05:37 2010 : Info: Failed to authenticate the user. ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Fri Jun 4 10:05:37 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) Fri Jun 4 10:05:37 2010 : Info: Using Post-Auth-Type Reject Fri Jun 4 10:05:37 2010 : Info: +- entering group REJECT {...} Fri Jun 4 10:05:37 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Fri Jun 4 10:05:37 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri Jun 4 10:05:37 2010 : Info: ++[attr_filter.access_reject] returns updated Fri Jun 4 10:05:37 2010 : Info: Delaying reject of request 11 for 1 seconds Fri Jun 4 10:05:37 2010 : Debug: Going to the next request Fri Jun 4 10:05:37 2010 : Debug: Waking up in 0.9 seconds. Fri Jun 4 10:05:38 2010 : Info: Sending delayed reject for request 11 Sending Access-Reject of id 242 to 192.168.... port 2048 EAP-Message = 0x04020004 Message-Authenticator = 0x00000000000000000000000000000000 Fri Jun 4 10:05:38 2010 : Debug: Waking up in 3.9 seconds. Fri Jun 4 10:05:42 2010 : Info: Cleaning up request 9 ID 240 with timestamp +1415 Fri Jun 4 10:05:42 2010 : Info: Cleaning up request 10 ID 241 with timestamp +1415 Fri Jun 4 10:05:42 2010 : Debug: Waking up in 1.0 seconds. Fri Jun 4 10:05:43 2010 : Info: Cleaning up request 11 ID 242 with timestamp +1415 Fri Jun 4 10:05:43 2010 : Info: Ready to process requests. Thank you very much for your help, kind regards, Andreas
Andreas Hartmann schrieb:
Alan DeKok schrieb:
Andreas Hartmann wrote:
I have one basic question: There are now two different caches: one in eap (based on ssl) and the extern cache, rlm_caching.
rlm_caching has nothing to do with EAP.
If I want to use fast_reauth, is it necessary to enable both caches or must the ssl-cache in eap.conf be disabled to run fast_reauth successfully with rlm_caching?
The EAP configuration explains what you need to do for fast re-auth.
Meanwhile, I have a configuration, which does a User-Name-based rlm_caching at the end of the last fragment of the initial authentication with an originaly empty database.
What is it supposed to do?
But the problem is:
If the user reconnects or wants to connect initial again, the process is stopped (with success returned) at the moment, the client sends the User-Name. This is wrong. The process can't be interrupted before the key exchange has been done successfully. How can this be written in the config-file (authorize-section)?
What do you want to do?
I have no idea why you configured the caching module, and you haven't explained why you configured it.
Thanks for your reply,
I configured it, because fast-reauth doesn't work for me.
- In the wpa_supplicant, fast_reauth is switched to 1. - In eap.conf, the cache under tls is enabled.
Now, wpa_supplicant is started and the client got authenticated. But there is a warning nearly at the end of the successfull authentication:
Fri Jun 4 09:42:11 2010 : Info: [tls] eaptls_verify returned 3 Fri Jun 4 09:42:11 2010 : Info: [tls] eaptls_process returned 3 Fri Jun 4 09:42:11 2010 : Info: [tls] Adding user data to cached session Fri Jun 4 09:42:11 2010 : Info: [tls] Saving response in the cache Fri Jun 4 09:42:11 2010 : Info: [tls] WARNING: No information to ^^^^^^^^^^^^^^^^^^^^^^^^^^ cache: session caching will be disabled for this session. ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Meanwhile, I defined a realm (I didn't had any until now). This seems to make the initial session caching working! Jun 4 11:12:43 2010 : Info: [tls] ACK handshake is finished Fri Jun 4 11:12:43 2010 : Info: [tls] eaptls_verify returned 3 Fri Jun 4 11:12:43 2010 : Info: [tls] eaptls_process returned 3 Fri Jun 4 11:12:43 2010 : Info: [tls] Adding user data to cached ^^^^^^^^^^^^^^^^^^^^^^^^^^ session ^^^^^^^ Fri Jun 4 11:12:43 2010 : Info: [tls] Saving response in the cache Fri Jun 4 11:12:43 2010 : Info: [eap] Freeing handler Fri Jun 4 11:12:43 2010 : Info: ++[eap] returns ok Fri Jun 4 11:12:43 2010 : Auth: Login OK: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) But the following fast-reauth doesn't work nevertheless: Fri Jun 4 11:22:48 2010 : Info: [tls] Done initial handshake Fri Jun 4 11:22:48 2010 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Fri Jun 4 11:22:48 2010 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished Fri Jun 4 11:22:48 2010 : Info: [tls] TLS_accept: SSLv3 read finished A Fri Jun 4 11:22:48 2010 : Info: [tls] (other): SSL negotiation finished successfully Fri Jun 4 11:22:48 2010 : Debug: SSL Connection Established Fri Jun 4 11:22:48 2010 : Debug: SSL Application Data Fri Jun 4 11:22:48 2010 : Info: [tls] eaptls_process returned 3 Fri Jun 4 11:22:48 2010 : Info: [tls] Retrieved session data from cached session Fri Jun 4 11:22:48 2010 : Info: [tls] WARNING: No information in ^^^^^^^^^^^^^^^^^^^^^^^^^ cached session! ^^^^^^^^^^^^^^^ Fri Jun 4 11:22:48 2010 : Info: [eap] Freeing handler Fri Jun 4 11:22:48 2010 : Info: ++[eap] returns reject Fri Jun 4 11:22:48 2010 : Info: Failed to authenticate the user. Fri Jun 4 11:22:48 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) Fri Jun 4 11:22:48 2010 : Info: Using Post-Auth-Type Reject Fri Jun 4 11:22:48 2010 : Info: +- entering group REJECT {...} Fri Jun 4 11:22:48 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Fri Jun 4 11:22:48 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri Jun 4 11:22:48 2010 : Info: ++[attr_filter.access_reject] returns updated Fri Jun 4 11:22:48 2010 : Info: Delaying reject of request 11 for 1 seconds What does it mean: No information in cached session? Couldn't the key be found (what's the key? The username "myuser" or "myuser@mydom" or soemthing else - do I have the chance to debug it?) or was the key found, but there was no data associated? Kind regards, Andreas
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Fri Jun 4 11:22:48 2010 : Info: [tls] WARNING: No information in ^^^^^^^^^^^^^^^^^^^^^^^^^ cached session! ^^^^^^^^^^^^^^^
Fri Jun 4 11:22:48 2010 : Info: [eap] Freeing handler Fri Jun 4 11:22:48 2010 : Info: ++[eap] returns reject Fri Jun 4 11:22:48 2010 : Info: Failed to authenticate the user. Fri Jun 4 11:22:48 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) Fri Jun 4 11:22:48 2010 : Info: Using Post-Auth-Type Reject Fri Jun 4 11:22:48 2010 : Info: +- entering group REJECT {...} Fri Jun 4 11:22:48 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Fri Jun 4 11:22:48 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri Jun 4 11:22:48 2010 : Info: ++[attr_filter.access_reject] returns updated Fri Jun 4 11:22:48 2010 : Info: Delaying reject of request 11 for 1 seconds
What does it mean: No information in cached session? Couldn't the key be found (what's the key? The username "myuser" or "myuser@mydom" or soemthing else - do I have the chance to debug it?) or was the key found, but there was no data associated?
I wondered about the same... You can find the session store and retrieve code in src/modules/rlm_eap/libeap/eap_tls.c : } else if (!SSL_session_reused(tls_session->ssl)) { RDEBUG2("Saving response in the cache"); vp = paircopy2(request->reply->vps, PW_USER_NAME); pairadd(&vps, vp); vp = paircopy2(request->packet->vps, PW_STRIPPED_USER_NAME); pairadd(&vps, vp); if (vps) { SSL_SESSION_set_ex_data(tls_session->ssl->session, eaptls_session_idx, vps); } else { RDEBUG2("WARNING: No information to cache: session caching will be disabled for this session."); SSL_CTX_remove_session(tls_session->ctx, tls_session->ssl->session); } /* * Else the session WAS allowed. Copy the cached * reply. */ } else { vp = SSL_SESSION_get_ex_data(tls_session->ssl->session, eaptls_session_idx); if (!vp) { RDEBUG("WARNING: No information in cached session!"); return eaptls_fail(handler, peap_flag); } else { RDEBUG("Adding cached attributes to the reply:"); debug_pair_list(vp); pairadd(&request->reply->vps, paircopy(vp)); /* * Mark the request as resumed. */ vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) pairadd(&request->packet->vps, vp); } } So I guess the warning means that either SSL_SESSION_set_ex_data() or SSL_SESSION_get_ex_data() failed. A useful change would be testing the return value of SSL_SESSION_set_ex_data() and print a warning if it fails, possibly using ERR_get_error() and ERR_error_string() or similar to get the actual error. The latter would also be useful in the SSL_SESSION_get_ex_data() failure case Bjørn
Bjørn Mork schrieb:
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Fri Jun 4 11:22:48 2010 : Info: [tls] WARNING: No information in ^^^^^^^^^^^^^^^^^^^^^^^^^ cached session! ^^^^^^^^^^^^^^^
Fri Jun 4 11:22:48 2010 : Info: [eap] Freeing handler Fri Jun 4 11:22:48 2010 : Info: ++[eap] returns reject Fri Jun 4 11:22:48 2010 : Info: Failed to authenticate the user. Fri Jun 4 11:22:48 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) Fri Jun 4 11:22:48 2010 : Info: Using Post-Auth-Type Reject Fri Jun 4 11:22:48 2010 : Info: +- entering group REJECT {...} Fri Jun 4 11:22:48 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Fri Jun 4 11:22:48 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri Jun 4 11:22:48 2010 : Info: ++[attr_filter.access_reject] returns updated Fri Jun 4 11:22:48 2010 : Info: Delaying reject of request 11 for 1 seconds
What does it mean: No information in cached session? Couldn't the key be found (what's the key? The username "myuser" or "myuser@mydom" or soemthing else - do I have the chance to debug it?) or was the key found, but there was no data associated?
I wondered about the same... You can find the session store and retrieve code in src/modules/rlm_eap/libeap/eap_tls.c :
} else if (!SSL_session_reused(tls_session->ssl)) { RDEBUG2("Saving response in the cache");
vp = paircopy2(request->reply->vps, PW_USER_NAME); pairadd(&vps, vp);
vp = paircopy2(request->packet->vps, PW_STRIPPED_USER_NAME); pairadd(&vps, vp);
if (vps) { SSL_SESSION_set_ex_data(tls_session->ssl->session, eaptls_session_idx, vps); } else { RDEBUG2("WARNING: No information to cache: session caching will be disabled for this session."); SSL_CTX_remove_session(tls_session->ctx, tls_session->ssl->session); }
/* * Else the session WAS allowed. Copy the cached * reply. */
} else {
vp = SSL_SESSION_get_ex_data(tls_session->ssl->session, eaptls_session_idx); if (!vp) { RDEBUG("WARNING: No information in cached session!"); return eaptls_fail(handler, peap_flag); } else { RDEBUG("Adding cached attributes to the reply:"); debug_pair_list(vp); pairadd(&request->reply->vps, paircopy(vp));
/* * Mark the request as resumed. */ vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) pairadd(&request->packet->vps, vp); } }
So I guess the warning means that either SSL_SESSION_set_ex_data() or SSL_SESSION_get_ex_data() failed. A useful change would be testing the return value of SSL_SESSION_set_ex_data() and print a warning if it fails, possibly using ERR_get_error() and ERR_error_string() or similar to get the actual error. The latter would also be useful in the SSL_SESSION_get_ex_data() failure case
Debugging of SSL_SESSION_set_ex_data() The returncode of the function is 1 (don't know, if it should be 0 - but it could be correct too, if it means, that one pair has been stored). vps, which SSL_SESSION_set_ex_data() is given as argument, consists of one NULL element. request->packet->vps->name gives User-Name, request->reply-vps is null (should be PW_USER_NAME). But there cant be any password, because there exists no password, because the authentication is done exclusively with keys. Could this problem be solved by a configuration entry or must it be hacked? Is it possible to give wpa_supplicant a dummy password? Debugging of SSL_SESSION_get_ex_data() At resuming, Index is 2 (eaptls_session_idx). This would be ok. Seems, that the returncode 1 from SSL_SESSION_set_ex_data() means, that nothing has been saved. I would be happy to get some more hints :-). Kind regards, Andreas
Andreas Hartmann <andihartmann@01019freenet.de> wrote:
So I guess the warning means that either SSL_SESSION_set_ex_data() or SSL_SESSION_get_ex_data() failed. A useful change would be testing the return value of SSL_SESSION_set_ex_data() and print a warning if it fails, possibly using ERR_get_error() and ERR_error_string() or similar to get the actual error. The latter would also be useful in the SSL_SESSION_get_ex_data() failure case
Debugging of SSL_SESSION_set_ex_data()
The returncode of the function is 1 (don't know, if it should be 0 - but it could be correct too, if it means, that one pair has been stored).
vps, which SSL_SESSION_set_ex_data() is given as argument, consists of one NULL element.
request->packet->vps->name gives User-Name, request->reply-vps is null (should be PW_USER_NAME). But there cant be any password, because there exists no password, because the authentication is done exclusively with keys. Could this problem be solved by a configuration entry or must it be hacked? Is it possible to give wpa_supplicant a dummy password?
Debugging of SSL_SESSION_get_ex_data()
At resuming, Index is 2 (eaptls_session_idx). This would be ok. Seems, that the returncode 1 from SSL_SESSION_set_ex_data() means, that nothing has been saved.
I would be happy to get some more hints :-).
This all sounds horribly familiar and related to: git log -n1 -p 2377012692e22532ed1c1e1e852d843861ce5367 https://bugs.freeradius.org/bugzilla/show_bug.cgi?id=15 http://rt.openssl.org/Ticket/Display.html?id=2036 I prodded Alan as I noticed that openssl would occasionally claim that the session was a resumed one when in fact it was not. FreeRADIUS interpreted this as a successful login regardless and so you could run into the situation where you would get an Access-Accept with no user credentials being sent or used at all! The solution was, as it seems to be an OpenSSL bug the maintainers refuse to acknowledge, to reject the 'resumption' if no cached data is returned at all[1] and force the client to go the whole hog and do a full authentication run. Cheers [1] as if there is data, it's obviously from somewhere Cheers -- Alexander Clouter .sigmonster says: Don't get to bragging.
Andreas Hartmann schrieb:
Bjørn Mork schrieb:
Andreas Hartmann <andihartmann@01019freenet.de> writes:
Fri Jun 4 11:22:48 2010 : Info: [tls] WARNING: No information in ^^^^^^^^^^^^^^^^^^^^^^^^^ cached session! ^^^^^^^^^^^^^^^
Fri Jun 4 11:22:48 2010 : Info: [eap] Freeing handler Fri Jun 4 11:22:48 2010 : Info: ++[eap] returns reject Fri Jun 4 11:22:48 2010 : Info: Failed to authenticate the user. Fri Jun 4 11:22:48 2010 : Auth: Login incorrect: [myuser@mydom] (from client WAP610N port 0 cli 00-13-....) Fri Jun 4 11:22:48 2010 : Info: Using Post-Auth-Type Reject Fri Jun 4 11:22:48 2010 : Info: +- entering group REJECT {...} Fri Jun 4 11:22:48 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> myuser@mydom Fri Jun 4 11:22:48 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri Jun 4 11:22:48 2010 : Info: ++[attr_filter.access_reject] returns updated Fri Jun 4 11:22:48 2010 : Info: Delaying reject of request 11 for 1 seconds
What does it mean: No information in cached session? Couldn't the key be found (what's the key? The username "myuser" or "myuser@mydom" or soemthing else - do I have the chance to debug it?) or was the key found, but there was no data associated?
I wondered about the same... You can find the session store and retrieve code in src/modules/rlm_eap/libeap/eap_tls.c :
} else if (!SSL_session_reused(tls_session->ssl)) { RDEBUG2("Saving response in the cache");
vp = paircopy2(request->reply->vps, PW_USER_NAME); pairadd(&vps, vp);
vp = paircopy2(request->packet->vps, PW_STRIPPED_USER_NAME); pairadd(&vps, vp);
if (vps) { SSL_SESSION_set_ex_data(tls_session->ssl->session, eaptls_session_idx, vps); } else { RDEBUG2("WARNING: No information to cache: session caching will be disabled for this session."); SSL_CTX_remove_session(tls_session->ctx, tls_session->ssl->session); }
/* * Else the session WAS allowed. Copy the cached * reply. */
} else {
vp = SSL_SESSION_get_ex_data(tls_session->ssl->session, eaptls_session_idx); if (!vp) { RDEBUG("WARNING: No information in cached session!"); return eaptls_fail(handler, peap_flag); } else { RDEBUG("Adding cached attributes to the reply:"); debug_pair_list(vp); pairadd(&request->reply->vps, paircopy(vp));
/* * Mark the request as resumed. */ vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) pairadd(&request->packet->vps, vp); } }
So I guess the warning means that either SSL_SESSION_set_ex_data() or SSL_SESSION_get_ex_data() failed. A useful change would be testing the return value of SSL_SESSION_set_ex_data() and print a warning if it fails, possibly using ERR_get_error() and ERR_error_string() or similar to get the actual error. The latter would also be useful in the SSL_SESSION_get_ex_data() failure case
Debugging of SSL_SESSION_set_ex_data()
The returncode of the function is 1 (don't know, if it should be 0 - but it could be correct too, if it means, that one pair has been stored).
vps, which SSL_SESSION_set_ex_data() is given as argument, consists of one NULL element.
request->packet->vps->name gives User-Name, request->reply-vps is null (should be PW_USER_NAME). But there cant be any password, because there exists no password, because the authentication is done exclusively with keys. Could this problem be solved by a configuration entry or must it be hacked? Is it possible to give wpa_supplicant a dummy password?
Well, SSL_SESSION_set_ex_data-Error: error:00000000:lib(0):func(0):reason(0) - SSL couldn't find an error.
Debugging of SSL_SESSION_get_ex_data()
At resuming, Index is 2 (eaptls_session_idx). This would be ok. Seems, that the returncode 1 from SSL_SESSION_set_ex_data() means, that nothing has been saved.
But: no error has been detected: SSL_SESSION_get_ex_data-Error: error:00000000:lib(0):func(0):reason(0) Now, I looked at the SSL-session_id. tls_session->ssl->session->session_id is empty when the data is saved to the session. At the time the data is fetched from the session during reauth, the session_id is not empty (means: there is another id). I tested to unload the datas after they have been saved - there was no problem! The data could be retrieved again. Could there be a problem with the session-handling? There seem to be different sessions? This would be an explanation why there are no errors while storing or restoring the data. Kind regards, Andreas
Hello, well, I thought about the problem with reauth: Why must there be passwords in the session? EAP/TLS doesn't need any passwords to be exchanged. The passphrase stays local. That's why it shouldn't be necessary to have these Keys in the Session or in the response (the client didn't send any password, too). At the moment of adding the Password to the session, the handshake has been done already. from src/modules/rlm_eap/libeap/eap_tls.c (original): ------------------------------------------------------------------------------------------------------------------------- } else if (!SSL_session_reused(tls_session->ssl)) { RDEBUG2("Saving response in the cache"); vp = paircopy2(request->reply->vps, PW_USER_NAME); pairadd(&vps, vp); vp = paircopy2(request->packet->vps, PW_STRIPPED_USER_NAME); pairadd(&vps, vp); if (vps) { SSL_SESSION_set_ex_data(tls_session->ssl->session, eaptls_session_idx, vps); } else { RDEBUG2("WARNING: No information to cache: session caching will be disabled for this session."); SSL_CTX_remove_session(tls_session->ctx, tls_session->ssl->session); } /* * Else the session WAS allowed. Copy the cached * reply. */ } else { vp = SSL_SESSION_get_ex_data(tls_session->ssl->session, eaptls_session_idx); if (!vp) { RDEBUG("WARNING: No information in cached session!"); return eaptls_fail(handler, peap_flag); } else { RDEBUG("Adding cached attributes to the reply:"); debug_pair_list(vp); pairadd(&request->reply->vps, paircopy(vp)); /* * Mark the request as resumed. */ vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) pairadd(&request->packet->vps, vp); } } ----------------------------------------------------------------------------------------------------------------------------------- Therefore, I did the following change (-> for testing only!!!! This should be used only with EAP/tls for testing - no warranty!): ----------------------------------------------------------------------------------------------------------------------------------- } else if (!SSL_session_reused(tls_session->ssl)) { RDEBUG2("Saving response in the cache"); vp = paircopy2(request->reply->vps, PW_USER_NAME); pairadd(&vps, vp); vp = paircopy2(request->packet->vps, PW_STRIPPED_USER_NAME); pairadd(&vps, vp); if (vps) { SSL_SESSION_set_ex_data(tls_session->ssl->session, eaptls_session_idx, vps); } else { RDEBUG2("WARNING: No information to cache: session caching will be disabled for this session."); SSL_CTX_remove_session(tls_session->ctx, tls_session->ssl->session); } /* * Else the session WAS allowed. Copy the cached * reply. */ } else { vp = SSL_SESSION_get_ex_data(tls_session->ssl->session, eaptls_session_idx); if (!vp) { // here should be a check for the authentication type EAP/tls, // because I'm not sure, if this code is used exclusively for eap/tls RDEBUG("WARNING: No information in cached session!"); vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) { pairadd(&request->packet->vps, vp); RDEBUG("WARNING: Missing session-data ignored!"); } else { RDEBUG("WARNING: Couldn't set EAP-Session-Resumed data!"); return eaptls_fail(handler, peap_flag); } } else { RDEBUG("Adding cached attributes to the reply:"); debug_pair_list(vp); pairadd(&request->reply->vps, paircopy(vp)); /* * Mark the request as resumed. */ vp = pairmake("EAP-Session-Resumed", "1", T_OP_SET); if (vp) pairadd(&request->packet->vps, vp); } } ----------------------------------------------------------------------------------------------------------------------------------- That's what is sent to the client after this process: Sending Access-Accept of id 52 to 192.168.1.9 port 2048 MS-MPPE-Recv-Key = 0xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx MS-MPPE-Send-Key = 0xyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy EAP-Message = 0x03020004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "myuser@mydom.it" Kind regards, Andreas Hartmann
Andreas Hartmann wrote:
well, I thought about the problem with reauth: Why must there be passwords in the session?
There shouldn't be passwords in the session. There should be a *name* in the session.
That's why it shouldn't be necessary to have these Keys in the Session or in the response (the client didn't send any password, too).
At the moment of adding the Password to the session, the handshake has been done already.
I have no idea why you think it's adding passwords to the session. It's not.
Therefore, I did the following change (-> for testing only!!!! This should be used only with EAP/tls for testing - no warranty!):
That change removes the fix added in 2.1.8. It *will* break your system. Alan DeKok.
Alan DeKok schrieb:
Andreas Hartmann wrote:
well, I thought about the problem with reauth: Why must there be passwords in the session?
There shouldn't be passwords in the session. There should be a *name* in the session.
That's why it shouldn't be necessary to have these Keys in the Session or in the response (the client didn't send any password, too).
At the moment of adding the Password to the session, the handshake has been done already.
I have no idea why you think it's adding passwords to the session. It's not.
I derived it from the PW_ prefix of the variable name, which is wrong. I know it meanwhile.
Therefore, I did the following change (-> for testing only!!!! This should be used only with EAP/tls for testing - no warranty!):
That change removes the fix added in 2.1.8. It *will* break your system.
I know that it was added because of another reported bug. And I know, that my test-change can't be a solution (as I wrote myself). The problem seems to be much deeper. Kind regards, Andreas
Andreas Hartmann wrote:
Now, I looked at the SSL-session_id.
tls_session->ssl->session->session_id is empty when the data is saved to the session.
At the time the data is fetched from the session during reauth, the session_id is not empty (means: there is another id).
<shrug> OpenSSL is weird. The fast re-auth worked when I tested it with TTLS && PEAP. Others have tested it to work. Alan DeKok.
Alan DeKok schrieb:
Andreas Hartmann wrote:
Now, I looked at the SSL-session_id.
tls_session->ssl->session->session_id is empty when the data is saved to the session.
At the time the data is fetched from the session during reauth, the session_id is not empty (means: there is another id).
<shrug> OpenSSL is weird.
The fast re-auth worked when I tested it with TTLS && PEAP. Others have tested it to work.
See http://bugs.freeradius.org/bugzilla/show_bug.cgi?id=81 It does not work for me. There seem to be problems with the session-handling, which should be checked, explained and, if necessary, fixed. Until I don't have a comprehensibly explanation for the reported session-ID behavior, the current version (and 2.1.8) of freeradius is highly insecure. Kind regards, Andreas
Andreas Hartmann wrote:
Where you file a bug against FreeRADIUS for an OpenSSL issue. I understand that FreeRADIUS is affected. But...
It does not work for me. There seem to be problems with the session-handling, which should be checked, explained and, if necessary, fixed.
FreeRADIUS does not create, update, or maintain the "session_id" variable. It's created by OpenSSL. If has different values for the "same" session, then file a bug against OpenSSL.
Until I don't have a comprehensibly explanation for the reported session-ID behavior, the current version (and 2.1.8) of freeradius is highly insecure.
I have no idea why you think that's true. Failing to find a previous session means that the new request will be rejected. There are no security issues with rejecting users. The patch you suggested in the bug report *bypasses* this session checking, and *CREATES A SECURITY PROBLEM*. You should not use it in any production system. Alan DeKok.
Alan DeKok schrieb:
Andreas Hartmann wrote:
Where you file a bug against FreeRADIUS for an OpenSSL issue.
I understand that FreeRADIUS is affected. But...
It does not work for me. There seem to be problems with the session-handling, which should be checked, explained and, if necessary, fixed.
FreeRADIUS does not create, update, or maintain the "session_id" variable. It's created by OpenSSL. If has different values for the "same" session, then file a bug against OpenSSL.
Until I don't have a comprehensibly explanation for the reported session-ID behavior, the current version (and 2.1.8) of freeradius is highly insecure.
I have no idea why you think that's true. Failing to find a previous session means that the new request will be rejected. There are no security issues with rejecting users.
That's right. But: 1. There could be a security issue with parallel handled users during initial login, because they probably have all the same empty session id's at the same time. 2. Session handling does definitely not work at this point (I tried to find the reason today but couldn't get it yet). Why should I believe that it works error free at the other places in freeradius? 3. You are right, that there are probably no security issues with rejected users. But why are you sure, that every session-id you get, does belong to the user you think that it belongs to? It could be the data from another user too. 4. I can't say, if it's an exploitable scenario. May be - may be not. The session-handling in freeradius does not allways work as expected and until now the cause for the not allways working session-handling is unknown. Or in other words: The session-handling works not predictable (sometimes it works as expected - sometimes not - but you can't define "sometimes" - or I didn't found it yet). Unpredictable behavior and security is a contradiction. It's your application that suffers - it's not openssls one. Therefore I can't understand why you don't set everything to get a real solution? And no, I don't want to bash you. I'm willing to help, but I need your support to try to understand what's going on. I am willing to help you to find and fix the problem - even if it is not a bug in freeradius. It is all the same to me, if it's a bug in openssl or in freeradius. I do have just one goal: freeradius should work predictable in that case. That's all and this goal can't be bad for you! I can't file a bug for openssl. What should I wrote? The session handling in openssl does not work with freeradius? They will say: ok, openssl has been patched for EAP or they will ask detailed things about the handling of SSL in freeradius. I think that you are the best person to answer these questions! BTW: During my investigations today, I detected, that the defined callback cbtls_new_session never gets called during an initial session. That corresponds to the thing, that I can't see any session-ID during initial login. I would like to know, why the client suddenly has a session-ID at resumption time? Where do they come from? Kind regards, Andreas
Andreas Hartmann wrote:
That's right. But:
1. There could be a security issue with parallel handled users during initial login, because they probably have all the same empty session id's at the same time.
Well... that's an OpenSSL bug. We can check for it and try to avoid the issue. But as I said, the session_id is managed by OpenSSL.
2. Session handling does definitely not work at this point (I tried to find the reason today but couldn't get it yet).
Uh... for *you*. It works for me, and others.
Why should I believe that it works error free at the other places in freeradius?
I have no idea what you mean by that. It really sounds like a veiled accusation that the server is somehow broken in unknown ways.
3. You are right, that there are probably no security issues with rejected users. But why are you sure, that every session-id you get, does belong to the user you think that it belongs to? It could be the data from another user too.
Blame OpenSSL. I really can't be any clearer than that. When *I* use OpenSSL, the session key isn't empty.
4. I can't say, if it's an exploitable scenario. May be - may be not.
FUD.
The session-handling in freeradius does not allways work as expected and until now the cause for the not allways working session-handling is unknown.
Nonsense. It's an OpenSSL bug, and you have been told repeatedly it's an OpenSSL bug. Calling it "unknown" is being stupid.
Or in other words: The session-handling works not predictable (sometimes it works as expected - sometimes not - but you can't define "sometimes" - or I didn't found it yet). Unpredictable behavior and security is a contradiction.
You're repeating your fears to the point of being ridiculous.
It's your application that suffers - it's not openssls one. Therefore I can't understand why you don't set everything to get a real solution?
Because no one else has reported this, and I don't want to track down bugs in OpenSSL. It's really not my problem.
And no, I don't want to bash you. I'm willing to help, but I need your support to try to understand what's going on.
What part of my message is unclear? It's an OpenSSL bug.
I am willing to help you to find and fix the problem - even if it is not a bug in freeradius. It is all the same to me, if it's a bug in openssl or in freeradius. I do have just one goal: freeradius should work predictable in that case. That's all and this goal can't be bad for you!
Thanks for thinking of our goals.
I can't file a bug for openssl. What should I wrote? The session handling in openssl does not work with freeradius?
And I can file a bug with more information? I can't reproduce the problem, so I have *less information than you. Stop being lazy, and go file an OpenSSL bug. If you care to fix the problem, this is the *only* way to solve it.
They will say: ok, openssl has been patched for EAP
Nonsense.
or they will ask detailed things about the handling of SSL in freeradius. I think that you are the best person to answer these questions!
Nonsense. I can't reproduce the problem, and the code is publicly available. *You* are the best person to reproduce the problem.
BTW: During my investigations today, I detected, that the defined callback cbtls_new_session never gets called during an initial session. That corresponds to the thing, that I can't see any session-ID during initial login.
Well... the callback is controlled by oh... let me guess.. *OPENSSL*.
I would like to know, why the client suddenly has a session-ID at resumption time? Where do they come from?
Perhaps you should try asking *THE OPENSSL PEOPLE* ? If you have a patch for FreeRADIUS, supply it. But it is inappropriate to ask *us* to track down and fix an *OpenSSL* issue that only *you* can see. Alan DeKok.
Hello! Problem is fixed! Your missing a ssl-option when setting up SSL. Since SSL version 0.9.8j, openssl supports stateless session resumption. This means, no session_id is created in the server, if both, client and server, support it. I'm using on both sides openssl 0.9.8k, the server generates no session-key (which you need for saving resume-data). See: http://www.mail-archive.com/openssl-users@openssl.org/msg56976.html. Setting ctx_options |= SSL_OP_NO_TICKET ; in rlm_eap_tls.c is needed, to get a working sessionhandling in freeradius with openssl > 0.9.8i. It was good to have a lot of comments in the code and to have a lot of debug messages. So I could follow what's going on in detail. Kind regards, Andreas
Andreas Hartmann wrote:
Problem is fixed! Your missing a ssl-option when setting up SSL. Since SSL version 0.9.8j, openssl supports stateless session resumption. This means, no session_id is created in the server, if both, client and server, support it.
I'm using on both sides openssl 0.9.8k, the server generates no session-key (which you need for saving resume-data).
See: http://www.mail-archive.com/openssl-users@openssl.org/msg56976.html.
All I can say is that is one of the *worst* poorly documented changes in behavior I have ever seen. They could have made the default to be no change in behavior, but no...
Setting
ctx_options |= SSL_OP_NO_TICKET ;
in rlm_eap_tls.c
I've added the fix, thanks.
is needed, to get a working sessionhandling in freeradius with openssl > 0.9.8i.
It was good to have a lot of comments in the code and to have a lot of debug messages. So I could follow what's going on in detail.
That's good to hear. Alan DeKok.
participants (5)
-
Alan DeKok -
Alexander Clouter -
Andreas Hartmann -
Bjørn Mork -
David Mitchell