FreeRADIUS 3.1.x not changing the status of a failed home server

Donald Sherker dsherker at gmail.com
Thu Mar 17 16:07:23 CET 2016


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 at 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 at 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


More information about the Freeradius-Users mailing list