-Randall

On Mon, Mar 29, 2010 at 9:28 AM, Randall Degges <rdegges@gmail.com> wrote:

Hi Stefan,

Ah, I thought that it would have to show in the bottom portion of my netstat with the port numbers.

Also, when I run tcpdump (tcpdump port 1812) (tcpdump port 1813) I see no packets at all. I've submitted a ticket with rackspace, although I'm like 99% sure there is no firewall there. We have another freeradius server (really old running version 1.7) on another rackspace server instance in the cloud as well, and it seems to work just fine (and it has used the same as5400 as well).

So I think there may be another reason still, but once I hear back from rackspace I will make an update.

Thanks so much for your help so far! I can't wait to get to the bottom of this one :(

-Randall

On Mon, Mar 29, 2010 at 8:41 AM, Stefan Winter <stefan.winter@restena.lu> wrote:

Hi,

> *PROBLEM*

>
> The problem I'm having is that when I run Freeradius (in production or
> debug mode), my Cisco AS5400 is unable to connect to the freeradius
> server. When I do a netstat -a on my freeradius server, I see no
> connections listening on ports 1812 and 1813 (which freeradius should
> be listening on).

It listens just fine: your netstat shows

udp 0 0 *:radius *:*
udp 0 0 *:radius-acct *:*

You wouldn't believe it, but the IANA assigned port for "radius" is 1812

and "radius-acct" is 1813. It is BTW also what your FreeRADIUS debug says:

Listening on authentication address * port 1812
Listening on accounting address * port 1813
Ready to process requests.

So absolutely no problem here. If your server doesn't get any packets,
then either the AS5400 isn't sending any, or there is indeed a firewall
or other middlebox preventing the traffic from reaching your server.

> I believe that once this problem has been resolved, my setup will work
> correctly:
>
> 1. Call comes into my Cisco AS5400.
> 2. Cisco AS5400 sends accounting requests to my freeradius server.
> 3. Freeradius server performs a MySQL query to my MySQL database.
> 4. Caller hangs up.
> 5. Cisco AS5400 sends an accounting request to my freeradius server.
> 6. Freeradius server performs a MySQL update to my MySQL database,
> thus ending the transaction.

That's what many people do, including myself. It works fine, if the
accounting packets actually reach the server :-)

> And that my server is on a public IP (our radius server is hosted in
> the rackspace cloud, no firewall or anything as far as I know).

Maybe the "as far as I know" constitutes a problem here? Find out with
"tcpdump udp port 1813" if there is any accounting traffic reaching your
box.

Greetings,

Stefan Winter

> *CISCO SETUP*

>
> As I mentioned earlier, my freeradius *client* in this setup is my
> Cisco AS5400. When I have radius debugging turned on, on my cisco,
> here is some debugging output from a call. As you can see, it says
> that the server is not online. When I make calls, I see no activity in
> my freeradius debug window. So it seems that the packets aren't
> getting to freeradius from my cisco.
>
> *Jan 2 08:47:02.895: AAA/BIND(00000190): Bind i/f Serial7/0:15:23
> *Jan 2 08:47:02.899: AAA/BIND(00000191): Bind i/f
> *Jan 2 08:47:02.903: RADIUS/ENCODE(00000191):Orig. component type = VOICE
> *Jan 2 08:47:02.903: RADIUS(00000191): Config NAS IP: 0.0.0.0
> *Jan 2 08:47:02.903: RADIUS(00000191): sending
> *Jan 2 08:47:02.903: RADIUS/ENCODE: Best Local IP-Address 10.0.2.1
> for Radius-Server xx.xx.xx.xx
>
> *Jan 2 08:47:02.907: RADIUS(00000191): Send Accounting-Request
> to xx.xx.xx.xx:1813 id 1646/154, len 128
>
> *Jan 2 08:47:02.907: RADIUS: authenticator 5A 66 34 6D 47 00 B7 9E -
> BD 76 22 42 14 B6 A1 59
>
> *Jan 2 08:47:02.907: RADIUS: Acct-Session-Id [44] 18
> "0200000000000253"
> *Jan 2 08:47:02.907: RADIUS: Calling-Station-Id [31] 12
> "8182179228"
> *Jan 2 08:47:02.907: RADIUS: Called-Station-Id [30] 12
> "2172386245"
> *Jan 2 08:47:02.907: RADIUS: User-Name [1] 12
> "8182179228"
> *Jan 2 08:47:02.907: RADIUS: Acct-Status-Type [40] 6 Start
> [1]
> *Jan 2 08:47:02.907: RADIUS: NAS-Port-Type [61] 6 Async
> [0]
> *Jan 2 08:47:02.907: RADIUS: NAS-Port [5] 6 0
>
> *Jan 2 08:47:02.907: RADIUS: NAS-Port-Id [87] 18 "ISDN
> 7/7:15:D:24"
> *Jan 2 08:47:02.907: RADIUS: Service-Type [6] 6 Login
> [1]
> *Jan 2 08:47:02.907: RADIUS: NAS-IP-Address [4] 6 10.0.2.1
>
> *Jan 2 08:47:02.907: RADIUS: Acct-Delay-Time [41] 6 0
>
> *Jan 2 08:47:07.655: RADIUS: acct-timeout for 4012ECE4 now 5,
> acct-jitter 4294967295, acct-delay-time (at 4012ED5E) now 4
>
> *Jan 2 08:47:07.655: RADIUS: no sg in radius-timers: ctx 0x66F7FB78
> sg 0x0000
> *Jan 2 08:47:07.655: RADIUS: Retransmit to (xx.xx.xx.xx:1812,1813)
> for id 1646/155
> *Jan 2 08:47:12.687: RADIUS: acct-timeout for 4012ECE4 now 9,
> acct-jitter 0, acct-delay-time (at 4012ED5E) now 9
>
> *Jan 2 08:47:12.687: RADIUS: no sg in radius-timers: ctx 0x66F7FB78
> sg 0x0000
> *Jan 2 08:47:12.687: RADIUS: Retransmit to (xx.xx.xx.xx:1812,1813)
> for id 1646/156
> *Jan 2 08:47:14.947: RADIUS/ENCODE(00000191):Orig. component type =
> VOICE
> *Jan 2 08:47:14.947: RADIUS(00000191): Config NAS IP: 0.0.0.0
>
> *Jan 2 08:47:14.947: RADIUS(00000191): sending
>
> *Jan 2 08:47:14.951: RADIUS/ENCODE: Best Local
> IP-Address xx.xx.xx.xx for Radius-Server xx.xx.xx.xx
>
> *Jan 2 08:47:14.951: RADIUS(00000191): Send Accounting-Request
> to xx.xx.xx.xx:1813 id 1646/157, len 158
>
> *Jan 2 08:47:14.951: RADIUS: authenticator 6F 5D 1E 4E CC 63 E0 A1 -
> 64 3B 75 46 FF 42 65 55
>
> *Jan 2 08:47:14.951: RADIUS: Acct-Session-Id [44] 18
> "0200000000000253"
> *Jan 2 08:47:14.951: RADIUS: Calling-Station-Id [31] 12
> "8182179228"
> *Jan 2 08:47:14.951: RADIUS: Called-Station-Id [30] 12
> "2172386245"
> *Jan 2 08:47:14.951: RADIUS: Acct-Input-Octets [42] 6 94880
>
> *Jan 2 08:47:14.951: RADIUS: Acct-Output-Octets [43] 6 95520
>
> *Jan 2 08:47:14.951: RADIUS: Acct-Input-Packets [47] 6 593
>
> *Jan 2 08:47:14.951: RADIUS: Acct-Output-Packets [48] 6 597
>
> *Jan 2 08:47:14.951: RADIUS: Acct-Session-Time [46] 6 12
>
> *Jan 2 08:47:14.951: RADIUS: User-Name [1] 12 "8182179228"
> *Jan 2 08:47:14.951: RADIUS: Acct-Status-Type [40] 6 Stop
> [2]
> *Jan 2 08:47:14.951: RADIUS: NAS-Port-Type [61] 6 Async
> [0]
> *Jan 2 08:47:14.951: RADIUS: NAS-Port [5] 6 0
> *Jan 2 08:47:14.951: RADIUS: NAS-Port-Id [87] 18 "ISDN
> 7/7:15:D:24"
> *Jan 2 08:47:14.951: RADIUS: Service-Type [6] 6 Login
> [1]
> *Jan 2 08:47:14.951: RADIUS: NAS-IP-Address [4] 6 10.0.2.1
> *Jan 2 08:47:14.951: RADIUS: Acct-Delay-Time [41] 6 0
> *Jan 2 08:47:17.559: RADIUS: acct-timeout for 4012ECE4 now 14,
> acct-jitter 0, acct-delay-time (at 4012ED5E) now 14
> *Jan 2 08:47:17.559: RADIUS: no sg in radius-timers: ctx 0x66F7FB78
> sg 0x0000
> *Jan 2 08:47:17.559: RADIUS: Retransmit to (xx.xx.xx.xx:1812,1813)
> for id 1646/158
> *Jan 2 08:47:19.871: RADIUS: acct-timeout for 4013486C now 5,
> acct-jitter 4294967295, acct-delay-time (at 40134904) now 4
> *Jan 2 08:47:19.871: RADIUS: no sg in radius-timers: ctx 0x67045494
> sg 0x0000
> *Jan 2 08:47:19.871: %RADIUS-4-RADIUS_DEAD: RADIUS
> server xx.xx.xx.xx:1812,1813 is not responding.
> *Jan 2 08:47:19.871: %RADIUS-4-RADIUS_ALIVE: RADIUS
> server xx.xx.xx.xx:1812,1813 has returned.
> *Jan 2 08:47:19.871: RADIUS: Retransmit to (xx.xx.xx.xx:1812,1813)
> for id 1646/159
> *Jan 2 08:47:22.527: RADIUS: acct-timeout for 4012ECE4 now 19,
> acct-jitter 0, acct-delay-time (at 4012ED5E) now 19
> *Jan 2 08:47:22.527: RADIUS: no sg in radius-timers: ctx 0x66F7FB78
> sg 0x0000
> *Jan 2 08:47:22.527: RADIUS: No response from (xx.xx.xx.xx:1812,1813)
> for id 1646/158
> *Jan 2 08:47:22.527: RADIUS/DECODE: No response from radius-server;
> parse response; FAIL
> *Jan 2 08:47:22.527: RADIUS/DECODE: Case error(no response/ bad
> packet/ op decode);parse response; FAIL
> *Jan 2 08:47:24.903: RADIUS: acct-timeout for 4013486C now 9,
> acct-jitter 0, acct-delay-time (at 40134904) now 9
> *Jan 2 08:47:24.903: RADIUS: no sg in radius-timers: ctx 0x67045494
> sg 0x0000
> *Jan 2 08:47:24.903: RADIUS: Retransmit to (173.203.117.112:1812

> <http://173.203.117.112:1812>,1813) for id 1646/161

> *Jan 2 08:47:29.415: RADIUS: acct-timeout for 4013486C now 14,
> acct-jitter 0, acct-delay-time (at 40134904) now 14
> *Jan 2 08:47:29.415: RADIUS: no sg in radius-timers: ctx 0x67045494
> sg 0x0000
> *Jan 2 08:47:29.415: RADIUS: Retransmit to (xx.xx.xx.xx:1812,1813)
> for id 1646/162
> *Jan 2 08:47:34.415: RADIUS: acct-timeout for 4013486C now 19,
> acct-jitter 0, acct-delay-time (at 40134904) now 19
> *Jan 2 08:47:34.415: RADIUS: no sg in radius-timers: ctx 0x67045494
> sg 0x0000
> *Jan 2 08:47:34.415: RADIUS: No response from (xx.xx.xx.xx:1812,1813)
> for id 1646/162
> *Jan 2 08:47:34.415: RADIUS/DECODE: No response from radius-server;
> parse response; FAIL
> *Jan 2 08:47:34.415: RADIUS/DECODE: Case error(no response/ bad
> packet/ op decode);parse response; FAIL
>
> *HELP!*
>
> OK, so sorry for this terribly long email, but I hope that this has
> provided enough information for you guys to help me debug what the
> heck is going wrong here. I've spent tons of hours trying to resolve
> this to no avail. I'm out of ideas.
>
> Thanks so much for all of your help, this has been a really irritating
> and frustrating experience. I'm hoping that if anyone else has the
> same problem, this thread may help them later on.
>
> Thanks!
>
> -Randall
>
>

> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

--
Stefan WINTER
Ingenieur de Recherche
Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche
6, rue Richard Coudenhove-Kalergi
L-1359 Luxembourg

Tel: +352 424409 1
Fax: +352 422473

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html