rlm_proxy problems

15 Aug 2006

      I'm running FreeRadius 1.1.0 on Red Hat Linux, and appear to be running into 
an issue where heavy load causes rlm_proxy to stop responding.  If I restart 
radiusd, authentication will be properly proxied for 15-30 seconds, at which 
point I see incoming Access-Request messages logged, but I don't see any 
Access-Request messages being send to the backend server, and I don't see any 
Access-Accept or Access-Reject messages (or I see a few Access-Reject messages 
which appear to come from my proxy server, as there is no Reply-Message 
attribute set in them).

One of the most difficult problems I'm seeing is that while this is happening 
in production, it's NOT happening when I run radclient a half dozen times in 
parallel against radiusd, so it's *very* difficult to re-create outside of 
production.  Restarting radiusd solves the problem for 15-30 seconds. 
Pointing lightly-loaded NASes at radiusd works fine - it's only the NASes 
which have hundreds of simultaneous logins that auth frequently enough to 
cause this issue.

My proxy.conf looks like:

proxy server {
         synchronous = no
         retry_delay = 5
         retry_count = 1
         dead_time = 300
         default_fallback = yes
         post_proxy_authorize = yes
}
realm BackendAuth {
         type            = radius
         authhost        = radius.vip.domain.com:1812
         secret          = ThisIsNotMyRealSecret
}

I've attached some logs for review.  What I see is a valid auth at 
14:39:59-14:40:01, but then a failing one at 14:40:08.  Note that the 
SI_radius_keepalive packets are from our VIPs which are doing health checks, 
so they are expected to fail, but any other usernames should work.

Aug 15 14:39:59 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "junyi2000", User-Password = (hidden), NAS-Port = 
26300, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.209.87", Calling-Station-Id = "66.218.46.114", 
Tunnel-Client-Endpoint:0 = "66.218.46.114", NAS-IP-Address = 10.180.203.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.180.203.7, Hint = "HasSlash", 
Huntgroup-Name = "Office",

Aug 15 14:40:01 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "junyi2000", User-Password = (hidden), NAS-Port = 
26300, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.209.87", Calling-Station-Id = "66.218.46.114", 
Tunnel-Client-Endpoint:0 = "66.218.46.114", NAS-IP-Address = 10.180.203.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.180.203.7, Hint = "HasSlash", 
Huntgroup-Name = "Office", Realm = "UAS", Client-IP-Address = 10.180.203.7,

Aug 15 14:40:01 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Accept, User-Name = "junyi2000", Class = 
0x6c49755a5754477631786d45474d736c4d376b78475068396b43673d, Account-Flags = 
553680896, Connect-Info = "AOLOFFICE", User-Name = junyi2000, 
Client-IP-Address = 10.180.203.7, NAS-IP-Address = 10.180.203.7, NAS-Port = 26300,

Aug 15 14:40:07 205.188.188.212 radiusd-auth[6509]: Packet-Type = 
Access-Request, User-Name = "SI_radius_keepalive", User-Password = (hidden), 
Service-Type = Dialout-Framed-User, NAS-IP-Address = 205.188.188.250, 
Client-IP-Address = 205.188.188.250, Hint = "Port-1812",

Aug 15 14:40:07 205.188.188.212 radiusd-auth[6509]: Packet-Type = 
Access-Reject, User-Name = SI_radius_keepalive, Client-IP-Address = 
205.188.188.250, NAS-IP-Address = 205.188.188.250, NAS-Port = ,

Aug 15 14:40:08 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "nsitton", User-Password = (hidden), NAS-Port = 
26302, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.209.87", Calling-Station-Id = "69.228.216.95", 
Tunnel-Client-Endpoint:0 = "69.228.216.95", NAS-IP-Address = 10.180.203.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.180.203.7, Hint = "Port-1645", 
Huntgroup-Name = "Office",

Aug 15 14:40:08 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Reject, User-Name = nsitton, Client-IP-Address = 10.180.203.7, 
NAS-IP-Address = 10.180.203.7, NAS-Port = 26302,

Aug 15 14:40:08 152.163.209.142 radiusd-auth[23725]: Packet-Type = 
Access-Request, User-Name = "SI_radius_keepalive", User-Password = (hidden), 
NAS-IP-Address = 152.163.209.154, Client-IP-Address = 152.163.209.154, Hint = 
"Port-1812",

Aug 15 14:40:08 152.163.209.142 radiusd-auth[23725]: Packet-Type = 
Access-Reject, User-Name = SI_radius_keepalive, Client-IP-Address = 
152.163.209.154, NAS-IP-Address = 152.163.209.154, NAS-Port = ,

Aug 15 14:40:09 64.12.153.209 radiusd-auth[4826]: Packet-Type = 
Access-Request, User-Name = "SI_radius_keepalive", User-Password = (hidden), 
NAS-IP-Address = 64.12.153.218, Client-IP-Address = 64.12.153.218, Hint = 
"Port-1812",

Aug 15 14:40:09 64.12.153.209 radiusd-auth[4826]: Packet-Type = Access-Reject, 
User-Name = SI_radius_keepalive, Client-IP-Address = 64.12.153.218, 
NAS-IP-Address = 64.12.153.218, NAS-Port = ,

Aug 15 14:40:16 64.12.186.46 radiusd-auth[26637]: Packet-Type = 
Access-Request, User-Name = "SI_radius_keepalive", User-Password = (hidden), 
NAS-IP-Address = 64.12.186.58, Client-IP-Address = 64.12.186.58, Hint = 
"Port-1812",

Aug 15 14:40:16 64.12.186.46 radiusd-auth[26637]: Packet-Type = Access-Reject, 
User-Name = SI_radius_keepalive, Client-IP-Address = 64.12.186.58, 
NAS-IP-Address = 64.12.186.58, NAS-Port = ,

Aug 15 14:40:18 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "karenc876", User-Password = (hidden), NAS-Port = 
26303, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.209.87", Calling-Station-Id = "65.120.79.33", Tunnel-Client-Endpoint:0 
= "65.120.79.33", NAS-IP-Address = 10.180.203.7, NAS-Port-Type = Virtual, 
Client-IP-Address = 10.180.203.7, Hint = "HasSlash", Huntgroup-Name = "Office",

Aug 15 14:40:19 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "donaldknight11", User-Password = (hidden), 
NAS-Port = 26305, Service-Type = Framed-User, Framed-Protocol = PPP, 
Called-Station-Id = "64.236.209.87", Calling-Station-Id = "66.208.64.157", 
Tunnel-Client-Endpoint:0 = "66.208.64.157", NAS-IP-Address = 10.180.203.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.180.203.7, Hint = "HasSlash", 
Huntgroup-Name = "Office",

Aug 15 14:40:22 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "alemoyamx", User-Password = (hidden), NAS-Port = 
8537, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.128.7", Calling-Station-Id = "207.248.229.111", 
Tunnel-Client-Endpoint:0 = "207.248.229.111", NAS-IP-Address = 10.178.197.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.178.197.7, Hint = "HasSlash", 
Huntgroup-Name = "Office",

Aug 15 14:40:23 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Request, User-Name = "swxdan", User-Password = (hidden), NAS-Port = 
26306, Service-Type = Framed-User, Framed-Protocol = PPP, Called-Station-Id = 
"64.236.209.87", Calling-Station-Id = "208.255.178.130", 
Tunnel-Client-Endpoint:0 = "208.255.178.130", NAS-IP-Address = 10.180.203.7, 
NAS-Port-Type = Virtual, Client-IP-Address = 10.180.203.7, Hint = "Port-1645", 
Huntgroup-Name = "Office",

Aug 15 14:40:23 205.188.136.151 radiusd-auth[30371]: Packet-Type = 
Access-Reject, User-Name = swxdan, Client-IP-Address = 10.180.203.7, 
NAS-IP-Address = 10.180.203.7, NAS-Port = 26306,

rlm_proxy problems

Geoff Silver