Possible FreeBSD Jail problem, or other bug in/with FreeRADIUS 2.0.0-pre2

[Scott Lambert]

I have an issue with getting my new FreeRADIUS 2.0.0-pre2 server to
proxy requests to my old production RADIUS servers.  I would appreciate
any assistance you might have the time to provide.

I am recieving the replies from the old server, but freeradius is
throwing them out for some reason.  I didn't notice anything more
detailed in the radiusd -X output, so here are the log entries.

Mon Sep  3 01:52:21 2007 : Proxy: No outstanding request was found for proxy reply from home server old.old.old.old port 1645 - ID 15
Mon Sep  3 01:52:24 2007 : Proxy: No outstanding request was found for proxy reply from home server old.old.old.old port 1645 - ID 15
Mon Sep  3 01:52:27 2007 : Proxy: No outstanding request was found for proxy reply from home server old.old.old.old port 1645 - ID 15
Mon Sep  3 01:52:30 2007 : Proxy: No outstanding request was found for proxy reply from home server old.old.old.old port 1645 - ID 15
Mon Sep  3 01:52:33 2007 : Proxy: No outstanding request was found for proxy reply from home server old.old.old.old port 1645 - ID 15
Mon Sep  3 01:52:41 2007 : Error: Rejecting request 0 due to lack of any response from home server old.old.old.old port 1645

If you want the radiusd -X logs, let me know.

I decided to simplify and try just using radclient from the new server
and leaving the FreeRADIUS daemon out of it.  That also gets replies but
radclient throws them out because it doesn't think it sent the request.

In the archive, the only prolems I have found with the "radclient:
received response to request we did not send." error are due to the
reply coming from a different IP or port than that to which the request
was sent.  That doesn't seem to be the case here.  As far as I've been
able to tell, all the information appears to be the same between the
request and the reply.  

The new FreeRADIUS server is running under a FreeBSD 6.2 jail
configuration, halfway between a chroot and a virtual machine.  I don't
suspect the system's firewall, but ... There is a stateful firewall on
the jail host system, without NAT or redirection.  Each jail has it's
own routable IP address.

I suspect that the jail has a lot to do with the problem.  If it can't
be worked around, I'm in trouble.  In that case I'll try to take it
up with the FreeBSD developers to see if they have any ideas, while I
scrounge up some seperate hardware to run FreeRADIUS on.

newserver$ radclient -f ~/testuser.radclient -r 2 -s -x old.old.old.old:1645 auth pqr7s4z3
Sending Access-Request of id 9 to old.old.old.old port 1645
        User-Name = "tstuser"
        User-Password = "secretpassword"
        NAS-IP-Address = 255.255.255.255
        NAS-Port = 2
        Framed-Protocol = PPP
rad_recv: Access-Accept packet from host old.old.old.old port 1645, id=9, length=336
radclient: received response to request we did not send. (id=9 socket 3)
Sending Access-Request of id 9 to old.old.old.old port 1645
        User-Name = "tstuser"
        User-Password = "secretpassword"
        NAS-IP-Address = 255.255.255.255
        NAS-Port = 2
        Framed-Protocol = PPP
rad_recv: Access-Accept packet from host old.old.old.old port 1645, id=9, length=336
radclient: received response to request we did not send. (id=9 socket 3)
radclient: no response from server for ID 9 socket 3

           Total approved auths:  0
             Total denied auths:  0
               Total lost auths:  1

tcpdump of the request:

oldserver# tcpdump -i fxp0 -s 1500 -l host new.new.new.new
tcpdump: listening on fxp0
02:29:42.098188 new.new.new.62513 > old.old.old.radius:  rad-access-req 65 [id 9] Attr[  User{tstuser} Pass NAS_ipaddr{255.255.255.255} NAS_port{2} Framed_proto{PPP} ]

02:29:42.132898 old.old.old.radius > new.new.new.62513:  rad-access-accept 336 [id 9] Attr[  Service_type{Framed} Framed_proto{PPP} Framed_ipnet{255.255.255.255} Vendor_specific{....."................................} Vendor_specific{.....".........=... ..................} Vendor_specific{....."........E.p.. ..................} Vendor_specific{....."........E.p.. ..................} Vendor_specific{....."........AD... ..................} Vendor_specific{....."................................} Vendor_specific{....."................................} Session_timeout{09:00:00 hours} Port_limit{1} Framed_mtu{1500} ]

02:29:45.970121 new.new.new.62513 > old.old.old.radius:  rad-access-req 65 [id 9] Attr[  User{tstuser} Pass NAS_ipaddr{255.255.255.255} NAS_port{2} Framed_proto{PPP} ]

02:29:46.024013 old.old.old.radius > new.new.new.62513:  rad-access-accept 336 [id 9] Attr[  Service_type{Framed} Framed_proto{PPP} Framed_ipnet{255.255.255.255} Vendor_specific{....."................................} Vendor_specific{.....".........=... ..................} Vendor_specific{....."........E.p.. ..................} Vendor_specific{....."........E.p.. ..................} Vendor_specific{....."........AD... ..................} Vendor_specific{....."................................} Vendor_specific{....."................................} Session_timeout{09:00:00 hours} Port_limit{1} Framed_mtu{1500} ]

-- 
Scott Lambert                    KC5MLE                       Unix SysAdmin
lambert at lambertfam.org