Hi, I have two freeradius server. Both of them were working well until. But one the server stopped receiving auth request. I stopped the radius server and run in debug mode, radiusd -X then all I get is below: Request are coming but looks it is expanding the detail file then sends the Sending Accounting-Response of id 26 to 192.168.1.1 port 32770 and nothing else. How do I fix this so my second server start processing users request and authenticate them :? # Executing section preacct from file /etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok expand: %{Acct-Session-Time} -> 8 expand: %{Acct-Delay-Time} -> 0 expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1413805547 - 8 - 0 expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1413805539 ++[request] returns ok [acct_unique] Hashing 'NAS-Port = 1,Client-IP-Address = 192.168.1.1,NAS-IP-Address = 192.168.1.1,Acct-Session-Id = "5444f5e2/dc:86:d8:23:03:0d/290270",User-Name = "carpæ"' [acct_unique] Acct-Unique-Session-ID = "f1f7ece2e5e57147". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "carlol", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "carol" [suffix] Adding Realm = "NULL" [suffix] Accounting realm is LOCAL. ++[suffix] returns ok [files] acct_users: Matched entry DEFAULT at line 22 [files] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [files] expand: %{Framed-IP-Address:-%{NAS-IP-Address}} -> 192.168.5.2 ++[files] returns ok # Executing section accounting from file /etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> 192.168.1.1 [detail] expand: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radius/radacct/192.168.1.1/detail-20141020 [detail] /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.1/detail-20141020 [detail] expand: %t -> Mon Oct 20 11:45:47 2014 ++[detail] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> carol attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 26 to 192.168.1.1 port 32770 Finished request 62. Cleaning up request 62 ID 26 with timestamp +5 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 192.168.1.1 port 32770, id=27, length=264 User-Name = "jebish" NAS-Port = 1 NAS-IP-Address = 192.168.1.1 Framed-IP-Address = 192.168.5.9 NAS-Identifier = "hinet-wlc00-hbio" Airespace-Wlan-Id = 300 Acct-Session-Id = "5444f5ca/88:1f:a1:1b:f8:44/290236" NAS-Port-Type = Wireless-802.11 Cisco-AVPair = "audit-session-id=82d0a5f800051d5a5444f5c7" Acct-Authentic = RADIUS Event-Timestamp = "Oct 20 2014 11:45:47 GMT" Acct-Status-Type = Interim-Update Acct-Input-Octets = 41102 Acct-Input-Gigawords = 0 Acct-Output-Octets = 55255 Acct-Output-Gigawords = 0 Acct-Input-Packets = 213 Acct-Output-Packets = 191 Acct-Session-Time = 32 Acct-Delay-Time = 0 Calling-Station-Id = "192.168.2.71" Called-Station-Id = "192.168.1.1" # Executing section preacct from file /etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok expand: %{Acct-Session-Time} -> 32 expand: %{Acct-Delay-Time} -> 0 expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1413805547 - 32 - 0 expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1413805515 ++[request] returns ok [acct_unique] Hashing 'NAS-Port = 1,Client-IP-Address = 192.168.1.1,NAS-IP-Address = 192.168.1.1,Acct-Session-Id = "5444f5ca/88:1f:a1:1b:f8:44/290236",User-Name = "jebish"' [acct_unique] Acct-Unique-Session-ID = "ae16dee06152c99c". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "jebish", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "jebish" [suffix] Adding Realm = "NULL" [suffix] Accounting realm is LOCAL. ++[suffix] returns ok [files] acct_users: Matched entry DEFAULT at line 22 [files] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [files] expand: %{Framed-IP-Address:-%{NAS-IP-Address}} -> 192.168.3.74 ++[files] returns ok # Executing section accounting from file /etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> 192.168.1.1 [detail] expand: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radius/radacct/192.168.1.1/detail-20141020 [detail] /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.1/detail-20141020 [detail] expand: %t -> Mon Oct 20 11:45:47 2014 ++[detail] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> jenny attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 27 to 192.168.1.1 port 32770 Finished request 63. Cleaning up request 63 ID 27 with timestamp +5 Going to the next request Ready to process requests
Hi,
I have two freeradius server. Both of them were working well until. But one the server stopped receiving auth request.
..and it now gets the occasional accounting packet... check you rNAS to see what it thinks its doing with the AAA servers. some kit just do not load balance and are sticky on a working Auth server alan
Thanks Alan, It was working fine, then I saw a messgage in log as below: According to the log home server is dead but I checked the server 10.128.5.1 and it is working. There has been nothing change in the NAS ( at least net guys told me). Since the message below freeradius1 server stopped authenticating users. ntlm_auth, eap_pol test works okay as usual. I even tried stopping primary radius server for a while to see freeradius1 will start processing user authentication - but it doesn't ! This is the version I am using now .freeradius-2.1.12-6.el6.x86_64 Any hint or guide would help me. Oct 20 10:20:01 freeradius1 radiusd[1387]: Marking home server 10.128.5.1 port 1812 as zombie (it looks like it is dead). Oct 20 10:20:01 freeradius1 radiusd[1387]: Received response to status check 221055 (1 in current sequence) Oct 20 10:20:02 freeradius1 radiusd[1387]: Internal sanity check failed for child state Oct 20 10:20:02 freeradius1 radiusd[1387]: Reply from home server 10.128.5.1 port 1812 - ID: 119 arrived too late for request 220456. Try increasing 'retry_d elay' or 'max_request_time' Oct 20 10:20:21 freeradius1 radiusd[1387]: Marking home server 10.128.5.1 port 1812 as zombie (it looks like it is dead). Oct 20 10:20:22 freeradius1 radiusd[1387]: Internal sanity check failed for child state Oct 20 10:20:22 freeradius1 radiusd[1387]: Reply from home server 10.128.5.1 port 1812 - ID: 157 arrived too late for request 220836. Try increasing 'retry_d elay' or 'max_request_time' Oct 20 10:20:22 freeradius1 radiusd[1387]: Received response to status check 221132 (1 in current sequence) Oct 20 10:20:23 freeradius1 radiusd[1387]: ... adding new socket command file /var/run/radiusd/radiusd.sock Oct 20 10:20:23 freeradius1 radiusd[1387]: ... closing socket command file /var/run/radiusd/radiusd.sock Oct 20 10:20:27 freeradius1 radiusd[1387]: ... adding new socket command file /var/run/radiusd/radiusd.sock Oct 20 10:20:27 freeradius1 radiusd[1387]: ... closing socket command file /var/run/radiusd/radiusd.sock Oct 20 10:20:55 freeradius1 radiusd[1387]: Rejecting request 221141 (proxy Id 199) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:20:55 freeradius1 radiusd[1387]: Marking home server 10.128.5.1 port 1813 as zombie (it looks like it is dead). Oct 20 10:20:55 freeradius1 radiusd[1387]: Received response to status check 221267 (1 in current sequence) Oct 20 10:20:56 freeradius1 radiusd[1387]: Marking home server 10.128.5.1 port 1813 as dead. Oct 20 10:20:56 freeradius1 radiusd[1387]: Rejecting request 221145 (proxy Id 172) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:20:58 freeradius1 radiusd[1387]: Rejecting request 221155 (proxy Id 193) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:01 freeradius1 radiusd[1387]: Rejecting request 221163 (proxy Id 64) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:01 freeradius1 radiusd[1387]: Rejecting request 221166 (proxy Id 99) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:04 freeradius1 radiusd[1387]: Rejecting request 221180 (proxy Id 161) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:06 freeradius1 radiusd[1387]: Rejecting request 221191 (proxy Id 250) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:07 freeradius1 radiusd[1387]: Rejecting request 221193 (proxy Id 192) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:09 freeradius1 radiusd[1387]: Rejecting request 221207 (proxy Id 159) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:12 freeradius1 radiusd[1387]: Rejecting request 221221 (proxy Id 212) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:12 freeradius1 radiusd[1387]: Rejecting request 221224 (proxy Id 25) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:14 freeradius1 radiusd[1387]: Rejecting request 221233 (proxy Id 131) due to lack of any response from home server 10.128.5.1 port 1813 Oct 20 10:21:26 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 172 Oct 20 10:21:31 freeradius1 radiusd[1387]: Received response to status check 221382 (1 in current sequence) Oct 20 10:21:48 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 193 Oct 20 10:21:56 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 199 Oct 20 10:21:56 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 64 Oct 20 10:21:56 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 159 Oct 20 10:22:00 freeradius1 radiusd[1387]: Received response to status check 221484 (2 in current sequence) Oct 20 10:22:07 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 250 Oct 20 10:22:11 freeradius1 radiusd[1387]: No outstanding request was found for reply from host 10.128.5.1 port 1813 - ID 212 Oct 20 10:22:29 freeradius1 radiusd[1387]: Received response to status check 221591 (3 in current sequence) Oct 20 10:22:29 freeradius1 radiusd[1387]: Marking home server 10.128.5.1 port 1813 alive On Mon, Oct 20, 2014 at 12:25 PM, <A.L.M.Buxey@lboro.ac.uk> wrote:
Hi,
I have two freeradius server. Both of them were working well until. But one the server stopped receiving auth request.
..and it now gets the occasional accounting packet... check you rNAS to see what it thinks its doing with the AAA servers. some kit just do not load balance and are sticky on a working Auth server
alan - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (2)
-
A.L.M.Buxey@lboro.ac.uk -
Khapare Joshi