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