FreeRADIUS 3.1.x not changing the status of a failed home server
I am testing 3.1.x and I have a proxy server that will forward access-requests to a realm containing two home servers. If one of the home servers fails to respond the proxy server is not marking it a zombie, and does not start sending status-server checks to see if the failed server recovers. The proxy server is configured to sent status-server checks. The pool the home servers are in is using keyed-balance. All of the servers in question are running 3.1.x. Please let me know if you need any more configuration information on the proxy, or home servers. Mar 17 10:39:26 (231) Received Access-Request Id 26 from X.X.X.X:50708 to Y.Y.Y.Y:1812 via eth0 length 199 Mar 17 10:39:26 (231) User-Name = "User-Name" Mar 17 10:39:26 (231) NAS-IP-Address = X.X.X.X Mar 17 10:39:26 (231) Called-Station-Id = "000d67218560:shore03PR020201" Mar 17 10:39:26 (231) NAS-Port-Type = Wireless-802.11 Mar 17 10:39:26 (231) NAS-Port = 0 Mar 17 10:39:26 (231) Calling-Station-Id = "10417f1906f1" Mar 17 10:39:26 (231) Connect-Info = "CONNECT 0Mbps 802.11b" Mar 17 10:39:26 (231) Acct-Session-Id = "56EABCC1-0000000D" Mar 17 10:39:26 (231) Framed-MTU = 1400 Mar 17 10:39:26 (231) EAP-Message = 0x02a3000d017161726573646f6e Mar 17 10:39:26 (231) Location-Capable = 3 Mar 17 10:39:26 (231) HS20-AP-Version = 1 Mar 17 10:39:26 (231) HS20-Mobile-Device-Version = 0x000000 Mar 17 10:39:26 (231) Message-Authenticator = 0x20ddbd35221f67aeb9f8c2fa0cdded10 Mar 17 10:39:26 (231) Running section authorize from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:26 (231) authorize { Mar 17 10:39:26 (231) if (&Calling-Station-Id =~ /([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})/i) { Mar 17 10:39:26 (231) update control { Mar 17 10:39:26 (231) EXPAND %{Calling-Station-Id} Mar 17 10:39:26 (231) --> 10417f1906f1 Mar 17 10:39:26 (231) &control:Load-Balance-Key := 10417f1906f1 Mar 17 10:39:26 (231) } # update control (noop) Mar 17 10:39:26 (231) } # if (&Calling-Station-Id =~ /([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})/i) (noop) Mar 17 10:39:26 (231) else { Mar 17 10:39:26 (231) ... skipping else for request 231: Preceding "if" was taken Mar 17 10:39:26 (231) } Mar 17 10:39:26 (231) if (&User-Name == 'anonymous@realm0') { Mar 17 10:39:26 (231) ... Mar 17 10:39:26 (231) } Mar 17 10:39:26 (231) else { Mar 17 10:39:26 (231) update request { Mar 17 10:39:26 (231) &Login-Method := 802.1x Mar 17 10:39:26 (231) } # update request (noop) Mar 17 10:39:26 (231) } # else (noop) Mar 17 10:39:26 (231) preprocess (ok) Mar 17 10:39:26 (231) cui.authorize { Mar 17 10:39:26 (231) if ("%{client:add_cui}" == 'yes') { Mar 17 10:39:26 (231) EXPAND %{client:add_cui} Mar 17 10:39:26 (231) --> yes Mar 17 10:39:26 (231) update request { Mar 17 10:39:26 (231) &Chargeable-User-Identity := 0x00 Mar 17 10:39:26 (231) } # update request (noop) Mar 17 10:39:26 (231) } # if ("%{client:add_cui}" == 'yes') (noop) Mar 17 10:39:26 (231) } # cui.authorize (noop) Mar 17 10:39:26 (231) if (&User-Name =~ /anonymous.*@provider1\.com/) { Mar 17 10:39:26 (231) ... Mar 17 10:39:26 (231) } Mar 17 10:39:26 (231) elsif (&User-Name != "healthcheck") { Mar 17 10:39:26 (231) update control { Mar 17 10:39:26 (231) &control:Proxy-To-Realm := proxyrealm0 Mar 17 10:39:26 (231) } # update control (noop) Mar 17 10:39:26 (231) } # elsif (&User-Name != "healthcheck") (noop) Mar 17 10:39:26 (231) files - Found match "DEFAULT" one line 243 of /usr/local/etc/raddb/mods-config/files/authorize Mar 17 10:39:26 (231) files (ok) Mar 17 10:39:26 (231) suffix - Checking for suffix after "@" Mar 17 10:39:26 (231) suffix - No '@' in User-Name = "User-Name", looking up realm NULL Mar 17 10:39:26 (231) suffix - No such realm "NULL" Mar 17 10:39:26 (231) suffix (noop) Mar 17 10:39:26 (231) expiration (noop) Mar 17 10:39:26 (231) logintime (noop) Mar 17 10:39:26 (231) pap (noop) Mar 17 10:39:26 (231) } # authorize (ok) Mar 17 10:39:26 (231) Running section pre-proxy from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:26 (231) pre-proxy { Mar 17 10:39:26 (231) cui.pre-proxy { Mar 17 10:39:26 (231) if (("%{request:Packet-Type}" == 'Access-Request') && ("%{client:add_cui}" == 'yes')) { Mar 17 10:39:26 (231) EXPAND %{request:Packet-Type} Mar 17 10:39:26 (231) --> Access-Request Mar 17 10:39:26 (231) EXPAND %{client:add_cui} Mar 17 10:39:26 (231) --> yes Mar 17 10:39:26 (231) update proxy-request { Mar 17 10:39:26 (231) &proxy-request:Chargeable-User-Identity = 0x00 Mar 17 10:39:26 (231) } # update proxy-request (noop) Mar 17 10:39:26 (231) } # if (("%{request:Packet-Type}" == 'Access-Request') && ("%{client:add_cui}" == 'yes')) (noop) Mar 17 10:39:26 (231) } # cui.pre-proxy (noop) Mar 17 10:39:26 (231) } # pre-proxy (noop) Mar 17 10:39:26 (231) Proxying request to home server Z.Z.Z.Z port 1812 timeout 20.000000 Mar 17 10:39:26 (231) Sent Access-Request Id 59 from 0.0.0.0:36831 to Z.Z.Z.Z:1812 length 212 Mar 17 10:39:26 (231) User-Name = "User-Name" Mar 17 10:39:26 (231) NAS-IP-Address = X.X.X.X Mar 17 10:39:26 (231) Called-Station-Id = "000d67218560:shore03PR020201" Mar 17 10:39:26 (231) NAS-Port-Type = Wireless-802.11 Mar 17 10:39:26 (231) NAS-Port = 0 Mar 17 10:39:26 (231) Calling-Station-Id = "10417f1906f1" Mar 17 10:39:26 (231) Connect-Info = "CONNECT 0Mbps 802.11b" Mar 17 10:39:26 (231) Acct-Session-Id = "56EABCC1-0000000D" Mar 17 10:39:26 (231) Framed-MTU = 1400 Mar 17 10:39:26 (231) EAP-Message = 0x02a3000d017161726573646f6e Mar 17 10:39:26 (231) Location-Capable = 3 Mar 17 10:39:26 (231) HS20-AP-Version = 1 Mar 17 10:39:26 (231) HS20-Mobile-Device-Version = 0x000000 Mar 17 10:39:26 (231) Message-Authenticator = 0x20ddbd35221f67aeb9f8c2fa0cdded10 Mar 17 10:39:26 (231) Event-Timestamp = "Mar 17 2016 10:39:26 EDT" Mar 17 10:39:26 (231) Chargeable-User-Identity := 0x00 Mar 17 10:39:26 (231) Proxy-State = 0x3236 Mar 17 10:39:26 Thread 5 waiting to be assigned a request Mar 17 10:39:27 (231) Expecting proxy response no later than 19.668615 seconds from now Mar 17 10:39:27 Waking up in 0.3 seconds. Mar 17 10:39:27 Thread 5 handling request 231, (251 handled so far) Mar 17 10:39:27 (231) Clearing existing &reply: attributes Mar 17 10:39:27 (231) Found Post-Proxy-Type Fail-Authentication Mar 17 10:39:27 (231) Post-Proxy-Type sub-section not found. Ignoring. Mar 17 10:39:27 (231) Login incorrect (Home Server failed to respond): [User-Name] (from client Client-A.A.A.A port 0 cli 10417f1906f1) Mar 17 10:39:27 (231) There was no response configured: rejecting request Mar 17 10:39:27 (231) Using Post-Auth-Type Reject Mar 17 10:39:27 (231) Running Post-Auth-Type Reject from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:27 (231) Post-Auth-Type REJECT { Mar 17 10:39:27 (231) attr_filter.access_reject - EXPAND %{User-Name} Mar 17 10:39:27 (231) attr_filter.access_reject - --> User-Name Mar 17 10:39:27 (231) attr_filter.access_reject - Matched entry DEFAULT at line 11 Mar 17 10:39:27 (231) attr_filter.access_reject (updated) Mar 17 10:39:27 (231) remove_reply_message_if_eap { Mar 17 10:39:27 (231) if (&reply:EAP-Message && &reply:Reply-Message) { Mar 17 10:39:27 (231) ... Mar 17 10:39:27 (231) } Mar 17 10:39:27 (231) else { Mar 17 10:39:27 (231) noop (noop) Mar 17 10:39:27 (231) } # else (noop) Mar 17 10:39:27 (231) } # remove_reply_message_if_eap (noop) Mar 17 10:39:27 (231) } # Post-Auth-Type REJECT (updated) Mar 17 10:39:27 (231) Sent Access-Reject Id 26 from Y.Y.Y.Y:1812 to X.X.X.X:50708 via eth0 length 0 Mar 17 10:39:27 (231) Finished request Mar 17 10:39:27 Thread 5 waiting to be assigned a request Mar 17 10:39:27 Waking up in 4.6 seconds. Mar 17 10:39:28 Waking up in 0.3 seconds. Mar 17 10:39:28 Thread 5 handling request 232, (252 handled so far) Mar 17 10:39:28 (232) Received Access-Request Id 27 from X.X.X.X:50708 to Y.Y.Y.Y:1812 via eth0 length 199 Mar 17 10:39:28 (232) User-Name = "User-Name" Mar 17 10:39:28 (232) NAS-IP-Address = X.X.X.X Mar 17 10:39:28 (232) Called-Station-Id = "000d67218560:shore03PR020201" Mar 17 10:39:28 (232) NAS-Port-Type = Wireless-802.11 Mar 17 10:39:28 (232) NAS-Port = 0 Mar 17 10:39:28 (232) Calling-Station-Id = "10417f1906f1" Mar 17 10:39:28 (232) Connect-Info = "CONNECT 0Mbps 802.11b" Mar 17 10:39:28 (232) Acct-Session-Id = "56EABCC1-0000000E" Mar 17 10:39:28 (232) Framed-MTU = 1400 Mar 17 10:39:28 (232) EAP-Message = 0x025d000d017161726573646f6e Mar 17 10:39:28 (232) Location-Capable = 3 Mar 17 10:39:28 (232) HS20-AP-Version = 1 Mar 17 10:39:28 (232) HS20-Mobile-Device-Version = 0x000000 Mar 17 10:39:28 (232) Message-Authenticator = 0xc390ccf8b070c383d30e99baf1025738 Mar 17 10:39:28 (232) Running section authorize from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:28 (232) authorize { Mar 17 10:39:28 (232) if (&Calling-Station-Id =~ /([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})/i) { Mar 17 10:39:28 (232) update control { Mar 17 10:39:28 (232) EXPAND %{Calling-Station-Id} Mar 17 10:39:28 (232) --> 10417f1906f1 Mar 17 10:39:28 (232) &control:Load-Balance-Key := 10417f1906f1 Mar 17 10:39:28 (232) } # update control (noop) Mar 17 10:39:28 (232) } # if (&Calling-Station-Id =~ /([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})/i) (noop) Mar 17 10:39:28 (232) else { Mar 17 10:39:28 (232) ... skipping else for request 232: Preceding "if" was taken Mar 17 10:39:28 (232) } Mar 17 10:39:28 (232) if (&User-Name == 'anonymous@realm0') { Mar 17 10:39:28 (232) ... Mar 17 10:39:28 (232) } Mar 17 10:39:28 (232) else { Mar 17 10:39:28 (232) update request { Mar 17 10:39:28 (232) &Login-Method := 802.1x Mar 17 10:39:28 (232) } # update request (noop) Mar 17 10:39:28 (232) } # else (noop) Mar 17 10:39:28 (232) preprocess (ok) Mar 17 10:39:28 (232) cui.authorize { Mar 17 10:39:28 (232) if ("%{client:add_cui}" == 'yes') { Mar 17 10:39:28 (232) EXPAND %{client:add_cui} Mar 17 10:39:28 (232) --> yes Mar 17 10:39:28 (232) update request { Mar 17 10:39:28 (232) &Chargeable-User-Identity := 0x00 Mar 17 10:39:28 (232) } # update request (noop) Mar 17 10:39:28 (232) } # if ("%{client:add_cui}" == 'yes') (noop) Mar 17 10:39:28 (232) } # cui.authorize (noop) Mar 17 10:39:28 (232) if (&User-Name =~ /anonymous.*@provider1\.com/) { Mar 17 10:39:28 (232) ... Mar 17 10:39:28 (232) } Mar 17 10:39:28 (232) elsif (&User-Name != "healthcheck") { Mar 17 10:39:28 (232) update control { Mar 17 10:39:28 (232) &control:Proxy-To-Realm := proxyrealm0 Mar 17 10:39:28 (232) } # update control (noop) Mar 17 10:39:28 (232) } # elsif (&User-Name != "healthcheck") (noop) Mar 17 10:39:28 (232) files - Found match "DEFAULT" one line 243 of /usr/local/etc/raddb/mods-config/files/authorize Mar 17 10:39:28 (232) files (ok) Mar 17 10:39:28 (232) suffix - Checking for suffix after "@" Mar 17 10:39:28 (232) suffix - No '@' in User-Name = "User-Name", looking up realm NULL Mar 17 10:39:28 (232) suffix - No such realm "NULL" Mar 17 10:39:28 (232) suffix (noop) Mar 17 10:39:28 (232) expiration (noop) Mar 17 10:39:28 (232) logintime (noop) Mar 17 10:39:28 (232) pap (noop) Mar 17 10:39:28 (232) } # authorize (ok) Mar 17 10:39:28 (232) Running section pre-proxy from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:28 (232) pre-proxy { Mar 17 10:39:28 (232) cui.pre-proxy { Mar 17 10:39:28 (232) if (("%{request:Packet-Type}" == 'Access-Request') && ("%{client:add_cui}" == 'yes')) { Mar 17 10:39:28 (232) EXPAND %{request:Packet-Type} Mar 17 10:39:28 (232) --> Access-Request Mar 17 10:39:28 (232) EXPAND %{client:add_cui} Mar 17 10:39:28 (232) --> yes Mar 17 10:39:28 (232) update proxy-request { Mar 17 10:39:28 (232) &proxy-request:Chargeable-User-Identity = 0x00 Mar 17 10:39:28 (232) } # update proxy-request (noop) Mar 17 10:39:28 (232) } # if (("%{request:Packet-Type}" == 'Access-Request') && ("%{client:add_cui}" == 'yes')) (noop) Mar 17 10:39:28 (232) } # cui.pre-proxy (noop) Mar 17 10:39:28 (232) } # pre-proxy (noop) Mar 17 10:39:28 (232) Proxying request to home server Z.Z.Z.Z port 1812 timeout 20.000000 Mar 17 10:39:28 (232) Sent Access-Request Id 194 from 0.0.0.0:36831 to Z.Z.Z.Z:1812 length 212 Mar 17 10:39:28 (232) User-Name = "User-Name" Mar 17 10:39:28 (232) NAS-IP-Address = X.X.X.X Mar 17 10:39:28 (232) Called-Station-Id = "000d67218560:shore03PR020201" Mar 17 10:39:28 (232) NAS-Port-Type = Wireless-802.11 Mar 17 10:39:28 (232) NAS-Port = 0 Mar 17 10:39:28 (232) Calling-Station-Id = "10417f1906f1" Mar 17 10:39:28 (232) Connect-Info = "CONNECT 0Mbps 802.11b" Mar 17 10:39:28 (232) Acct-Session-Id = "56EABCC1-0000000E" Mar 17 10:39:28 (232) Framed-MTU = 1400 Mar 17 10:39:28 (232) EAP-Message = 0x025d000d017161726573646f6e Mar 17 10:39:28 (232) Location-Capable = 3 Mar 17 10:39:28 (232) HS20-AP-Version = 1 Mar 17 10:39:28 (232) HS20-Mobile-Device-Version = 0x000000 Mar 17 10:39:28 (232) Message-Authenticator = 0xc390ccf8b070c383d30e99baf1025738 Mar 17 10:39:28 (232) Event-Timestamp = "Mar 17 2016 10:39:28 EDT" Mar 17 10:39:28 (232) Chargeable-User-Identity := 0x00 Mar 17 10:39:28 (232) Proxy-State = 0x3237 Mar 17 10:39:28 Thread 5 waiting to be assigned a request Mar 17 10:39:28 Waking up in 0.3 seconds. Mar 17 10:39:28 Waking up in 0.3 seconds. Mar 17 10:39:28 Thread 5 handling request 233, (253 handled so far) Mar 17 10:39:28 Thread 5 waiting to be assigned a request Mar 17 10:39:29 (232) Expecting proxy response no later than 19.668392 seconds from now Mar 17 10:39:29 Thread 5 handling request 232, (254 handled so far) Mar 17 10:39:29 (232) Clearing existing &reply: attributes Mar 17 10:39:29 (232) Found Post-Proxy-Type Fail-Authentication Mar 17 10:39:29 (232) Post-Proxy-Type sub-section not found. Ignoring. Mar 17 10:39:29 (232) Login incorrect (Home Server failed to respond): [User-Name] (from client Client-A.A.A.A port 0 cli 10417f1906f1) Mar 17 10:39:29 (232) There was no response configured: rejecting request Mar 17 10:39:29 (232) Using Post-Auth-Type Reject Mar 17 10:39:29 (232) Running Post-Auth-Type Reject from file /usr/local/etc/raddb/sites-enabled/default Mar 17 10:39:29 (232) Post-Auth-Type REJECT { Mar 17 10:39:29 (232) attr_filter.access_reject - EXPAND %{User-Name} Mar 17 10:39:29 (232) attr_filter.access_reject - --> User-Name Mar 17 10:39:29 (232) attr_filter.access_reject - Matched entry DEFAULT at line 11 Mar 17 10:39:29 (232) attr_filter.access_reject (updated) Mar 17 10:39:29 (232) remove_reply_message_if_eap { Mar 17 10:39:29 (232) if (&reply:EAP-Message && &reply:Reply-Message) { Mar 17 10:39:29 (232) ... Mar 17 10:39:29 (232) } Mar 17 10:39:29 (232) else { Mar 17 10:39:29 (232) noop (noop) Mar 17 10:39:29 (232) } # else (noop) Mar 17 10:39:29 (232) } # remove_reply_message_if_eap (noop) Mar 17 10:39:29 (232) } # Post-Auth-Type REJECT (updated) Mar 17 10:39:29 (232) Sent Access-Reject Id 27 from Y.Y.Y.Y:1812 to X.X.X.X:50708 via eth0 length 0 Mar 17 10:39:29 (232) Finished request Mar 17 10:39:29 Thread 5 waiting to be assigned a request Mar 17 10:39:29 Waking up in 0.3 seconds. Mar 17 10:39:29 Waking up in 2.4 seconds. Mar 17 10:39:30 Waking up in 0.3 seconds. Mar 17 10:39:30 Thread 5 handling request 234, (255 handled so far) Thanks, Don
On Mar 17, 2016, at 11:07 AM, Donald Sherker <dsherker@gmail.com> wrote:
I am testing 3.1.x and I have a proxy server that will forward access-requests to a realm containing two home servers. If one of the home servers fails to respond the proxy server is not marking it a zombie, and does not start sending status-server checks to see if the failed server recovers. The proxy server is configured to sent status-server checks. The pool the home servers are in is using keyed-balance. All of the servers in question are running 3.1.x. Please let me know if you need any more configuration information on the proxy, or home servers.
I've pushed a fix. Alan DeKok.
participants (2)
-
Alan DeKok -
Donald Sherker