Problems with freeradius accounting proxy

[Phil Pierotti]

So I've run freeradius with -X -xx

Other than logging the details of the packets sent and received, the debug
logs do not have much more than "marking as zombie, seems to be dead".

No complaints, no explanation, no details, just jumps straight into "looks
like its dead".



This is the point at which freeradius decides the downstream has died.

Tue Feb 16 09:40:25 2010 : Info: ++[files] returns ok
Sending Accounting-Request of id 180 to 192.168.147.2 port 1813
        Acct-Session-Id = "00064089"
        Tunnel-Type:0 = L2TP
        Tunnel-Medium-Type:0 = IPv4
        Tunnel-Server-Endpoint:0 = "192.168.92.1"
        Tunnel-Client-Endpoint:0 = "192.168.189.5"
        Tunnel-Assignment-Id:0 = "-------------"
        Tunnel-Client-Auth-Id:0 = "-------------"
        Tunnel-Server-Auth-Id:0 = "-------------"
        Acct-Tunnel-Connection = "2997106923"
        Framed-Protocol = PPP
        Tunnel-Medium-Type:0 = IPv4
        Tunnel-Client-Endpoint:0 = "192.168.136.41"
        Tunnel-Server-Endpoint:0 = "192.168.136.44"
        Tunnel-Assignment-Id:0 = "-------------"
        Tunnel-Type:0 = L2TP
        Acct-Tunnel-Connection = "3093807349"
        Tunnel-Client-Auth-Id:0 = "-------------"
        Tunnel-Server-Auth-Id:0 = "-------------"
        User-Name := "------------- at -------------"
        Cisco-AVPair = "connect-progress=Call Up"
        Acct-Session-Time = 58738
        Acct-Input-Octets = 2042638912
        Acct-Output-Octets = 82147247
        Acct-Input-Packets = 2167463
        Acct-Output-Packets = 1162476
        Acct-Authentic = Local
        Acct-Status-Type = Interim-Update
        Calling-Station-Id = "GigabitEthernet
8/0.31100305:3110-305#587265364###pppoe 00:1e:2a:13:24:28#QTORQE17M atm
1/1/14/32:8.35#"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.144.10
        Acct-Delay-Time = 2
        Proxy-State = 0x3936
Tue Feb 16 09:40:25 2010 : Info: Proxying request 33 to home server
192.168.147.2 port 1813
Sending Accounting-Request of id 180 to 192.168.147.2 port 1813
        Acct-Session-Id = "00064089"
        Tunnel-Type:0 = L2TP
        Tunnel-Medium-Type:0 = IPv4
        Tunnel-Server-Endpoint:0 = "192.168.92.1"
        Tunnel-Client-Endpoint:0 = "192.168.189.5"
        Tunnel-Assignment-Id:0 = "-------------"
        Tunnel-Client-Auth-Id:0 = "-------------"
        Tunnel-Server-Auth-Id:0 = "-------------"
        Acct-Tunnel-Connection = "2997106923"
        Framed-Protocol = PPP
        Tunnel-Medium-Type:0 = IPv4
        Tunnel-Client-Endpoint:0 = "192.168.136.41"
        Tunnel-Server-Endpoint:0 = "192.168.136.44"
        Tunnel-Assignment-Id:0 = "-------------"
        Tunnel-Type:0 = L2TP
        Acct-Tunnel-Connection = "3093807349"
        Tunnel-Client-Auth-Id:0 = "-------------"
        Tunnel-Server-Auth-Id:0 = "-------------"
        User-Name := "------------- at -------------"
        Cisco-AVPair = "connect-progress=Call Up"
        Acct-Session-Time = 58738
        Acct-Input-Octets = 2042638912
        Acct-Output-Octets = 82147247
        Acct-Input-Packets = 2167463
        Acct-Output-Packets = 1162476
        Acct-Authentic = Local
        Acct-Status-Type = Interim-Update
        Calling-Station-Id = "GigabitEthernet
8/0.31100305:3110-305#587265364###pppoe 00:1e:2a:13:24:28#QTORQE17M atm
1/1/14/32:8.35#"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.144.10
        Acct-Delay-Time = 2
        Proxy-State = 0x3936
Tue Feb 16 09:40:25 2010 : Debug: Going to the next request
Tue Feb 16 09:40:25 2010 : Debug: Waking up in 0.1 seconds.
Tue Feb 16 09:40:25 2010 : Proxy: Marking home server 192.168.147.2 port
1813 as zombie (it looks like it is dead).
Sending Accounting-Request of id 228 to 192.168.147.2 port 1813
        User-Name := "------------- at -------------"
        Acct-Status-Type := Stop
        Acct-Session-Id := "00000000"
        Event-Timestamp := "Feb 16 2010 09:40:25 EST"
        NAS-Identifier := "Status Check. Are you alive?"
Tue Feb 16 09:40:25 2010 : Debug: Waking up in 0.7 seconds.
rad_recv: Accounting-Response packet from host 192.168.147.2 port 1813,
id=228, length=20
Tue Feb 16 09:40:25 2010 : Proxy: Received response to status check 34 (1 in
current sequence)
Tue Feb 16 09:40:25 2010 : Debug: Waking up in 0.7 seconds.


Thanks,
Phil P

On Tue, Feb 16, 2010 at 9:11 AM, Phil Pierotti <phil.pierotti at gmail.com>wrote:

> Hi Alan,
>
> Sorry, I didn't mean to imply I wasn't interested in looking further, my
> primary concern was to find out if it was something as simple and obvious as
> the downstream proxy not responding.
>
> Thanks for your feedback, I'll look at the debug logs and see what they
> tell me, given the fairly frequent packets, that'll be a decent bit of
> reading.
>
> Meanwhile - on what basis does Freeradius decide that a downstream proxy is
> dead?
>
> Thanks,
> PhilP
>
>
> On Tue, Feb 16, 2010 at 8:35 AM, Alan DeKok <aland at deployingradius.com>wrote:
>
>> Phil Pierotti wrote:
>> > The main reason my initial checking was with tcpdump was to identify
>> > what the packets were doing.
>>
>>   As opposed to looking at the debug logs from the server?
>>
>>  You can look at the high level "packet in / packet out" view.  Or, you
>> can look at the detailed log messages from the server saying what's
>> going wrong, and why.
>>
>>  You chose the high-level view.  I'm trying to convince you to look at
>> the informative view.  You don't seem to see this as useful.
>>
>> > So the problem is not due to the downstream RADIUS failing to respond at
>> > all. (ie genuinely/obviously dead)
>>
>>   There is a LOT more that can go on than just packet in / packet out.
>> Maybe you might want to look for more information.
>>
>>  Since you've ALREADY looked at the tcpdump logs and they didn't
>> help... maybe looking for MORE information would be a good idea.
>>
>> > Freeradius is deciding that my accounting proxy destination 'looks like
>> > it is dead'.
>> >
>> > Tue Feb 16 07:45:32 2010 : Proxy: Marking home server {{radius-ip}}
>> > port 1813 as zombie (it looks like it is dead).
>>
>>   If you had bothered to run the server in debugging mode, OR to use
>> "raddebug" as I suggested, you might find out WHY this is happening.
>>
>>  Can you explain why you're not doing that?
>>
>> > I'm not entirely sure why, though. TCPDUMP shows a stream of accounting
>> > requests being proxied to that server, and being received from that
>> > server, while at the same time freeradius continues to log 'looks like
>> > it is dead' messages.
>>
>>   You've said that.  It's simply one step out of many.  For some reason,
>> you can't get past "BUT PACKETS ARE GOING BACK AND FORTH".  You have
>> refused to follow the instructions which can help you solve the problem.
>>
>> > Also, status check (via request) succeeds, naturally,  given that its
>> > not the auth proxy that freeradius is complaining about.
>> > (single downstream RADIUS configured as auth+acct)
>>
>>   There is no "naturally" here.
>>
>>  Run in debugging mode.  Have I said that enough?  Is there anything
>> else I need to say to convince you to run in debugging mode?
>>
>>  Alan DeKok.
>> -
>> List info/subscribe/unsubscribe? See
>> http://www.freeradius.org/list/users.html
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100216/83370ea0/attachment.html>