Firstly, I'm new to this list, but I've searched for an answer to my problems for quite a while, and haven't been able to find a solution. Please excuse me if this has already been asked.
I'm using Freeradius to log call statistics from my Cisco AS5400 call gateway to a MySQL database. We use this for accounting ( to keep track of how many minutes callers use ).
FreeRADIUS Version 2.1.0, for host x86_64-pc-linux-gnu, built on Sep 17 2009 at 17:46:37
on ubuntu-server.
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).
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.
root@RAD01:~# freeradius -X
FreeRADIUS Version 2.1.0, for host x86_64-pc-linux-gnu, built on Sep 17 2009 at 17:46:37
Copyright (C) 1999-2008 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /etc/freeradius/radiusd.conf
including configuration file /etc/freeradius/clients.conf
including files in directory /etc/freeradius/modules/
including configuration file /etc/freeradius/modules/krb5
including configuration file /etc/freeradius/modules/pap
including configuration file /etc/freeradius/modules/unix
including configuration file /etc/freeradius/modules/linelog
including configuration file /etc/freeradius/modules/wimax
including configuration file /etc/freeradius/modules/realm
including configuration file /etc/freeradius/modules/sql_log
including configuration file /etc/freeradius/modules/exec
including configuration file /etc/freeradius/modules/mac2ip
including configuration file /etc/freeradius/modules/detail.log
including configuration file /etc/freeradius/modules/passwd
including configuration file /etc/freeradius/modules/attr_rewrite
including configuration file /etc/freeradius/modules/acct_unique
including configuration file /etc/freeradius/modules/always
including configuration file /etc/freeradius/modules/digest
including configuration file /etc/freeradius/modules/radutmp
including configuration file /etc/freeradius/modules/attr_filter
including configuration file /etc/freeradius/modules/smbpasswd
including configuration file /etc/freeradius/modules/checkval
including configuration file /etc/freeradius/modules/files
including configuration file /etc/freeradius/modules/counter
including configuration file /etc/freeradius/modules/expiration
including configuration file /etc/freeradius/modules/chap
including configuration file /etc/freeradius/modules/inner-eap
including configuration file /etc/freeradius/modules/pam
including configuration file /etc/freeradius/modules/policy
including configuration file /etc/freeradius/modules/sradutmp
including configuration file /etc/freeradius/modules/detail
including configuration file /etc/freeradius/modules/expr
including configuration file /etc/freeradius/modules/ippool
including configuration file /etc/freeradius/modules/logintime
including configuration file /etc/freeradius/modules/mschap
including configuration file /etc/freeradius/modules/ldap
including configuration file /etc/freeradius/modules/mac2vlan
including configuration file /etc/freeradius/modules/preprocess
including configuration file /etc/freeradius/modules/etc_group
including configuration file /etc/freeradius/modules/echo
including configuration file /etc/freeradius/sql.conf
including configuration file /etc/freeradius/sql/mysql/dialup.conf
including files in directory /etc/freeradius/sites-enabled/
including configuration file /etc/freeradius/sites-enabled/inner-tunnel
including configuration file /etc/freeradius/sites-enabled/default
including dictionary file /etc/freeradius/dictionary
main {
prefix = "/usr"
localstatedir = "/var"
logdir = "/var/log/freeradius"
libdir = "/usr/lib/freeradius"
radacctdir = "/var/log/freeradius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 9600
allow_core_dumps = no
pidfile = "/var/run/freeradius/freeradius.pid"
checkrad = "/usr/sbin/checkrad"
debug_level = 0
proxy_requests = no
log {
stripped_names = no
auth = yes
auth_badpass = yes
auth_goodpass = yes
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
client xx.xx.xx.xx {
ipaddr = xx.xx.xx.xx
require_message_authenticator = no
secret = "password"
shortname = "AA"
nastype = "cisco"
}
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Instantiating modules ####
instantiate {
}
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
modules {
Module: Checking session {...} for more modules to load
Module: Linked to module rlm_sql
Module: Instantiating sql
sql {
driver = "rlm_sql_mysql"
server = "xx.xx.xx.xx"
port = ""
login = "radius"
password = "password"
radius_db = "accounting"
read_groups = yes
sqltrace = yes
sqltracefile = "/var/log/freeradius/sqltrace.sql"
readclients = no
deletestalesessions = yes
num_sql_socks = 25
sql_user_name = "%{User-Name}"
default_user_profile = ""
nas_query = "SELECT id,nasname,shortname,type,secret FROM nas"
authorize_check_query = ""
authorize_group_check_query = ""
authorize_group_reply_query = ""
accounting_onoff_query = ""
accounting_update_query = ""
accounting_update_query_alt = ""
accounting_start_query = "INSERT INTO dids (sessionid, did, caller, start) VALUES ('%{NAS-Identifier}%{Acct-Session-Id}', '%{Called-Station-Id}', '%{Calling-Station-Id}', NOW())"
accounting_start_query_alt = ""
accounting_stop_query = "UPDATE dids SET stop=NOW(), duration=%{Acct-Session-Time}, termination_cause='%{Acct-Terminate-Cause}' WHERE sessionid='%{NAS-Identifier}%{Acct-Session-Id}' LIMIT 1"
accounting_stop_query_alt = ""
connect_failure_retry_delay = 60
simul_count_query = ""
simul_verify_query = ""
postauth_query = ""
safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
}
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius@xx.xx.xx.xx:/accounting
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): starting 5
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5
rlm_sql (sql): Connected new DB handle, #5
rlm_sql (sql): starting 6
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql (sql): Connected new DB handle, #6
rlm_sql (sql): starting 7
rlm_sql (sql): Attempting to connect rlm_sql_mysql #7
rlm_sql_mysql: Starting connect to MySQL server for #7
rlm_sql (sql): Connected new DB handle, #7
rlm_sql (sql): starting 8
rlm_sql (sql): Attempting to connect rlm_sql_mysql #8
rlm_sql_mysql: Starting connect to MySQL server for #8
rlm_sql (sql): Connected new DB handle, #8
rlm_sql (sql): starting 9
rlm_sql (sql): Attempting to connect rlm_sql_mysql #9
rlm_sql_mysql: Starting connect to MySQL server for #9
rlm_sql (sql): Connected new DB handle, #9
rlm_sql (sql): starting 10
rlm_sql (sql): Attempting to connect rlm_sql_mysql #10
rlm_sql_mysql: Starting connect to MySQL server for #10
rlm_sql (sql): Connected new DB handle, #10
rlm_sql (sql): starting 11
rlm_sql (sql): Attempting to connect rlm_sql_mysql #11
rlm_sql_mysql: Starting connect to MySQL server for #11
rlm_sql (sql): Connected new DB handle, #11
rlm_sql (sql): starting 12
rlm_sql (sql): Attempting to connect rlm_sql_mysql #12
rlm_sql_mysql: Starting connect to MySQL server for #12
rlm_sql (sql): Connected new DB handle, #12
rlm_sql (sql): starting 13
rlm_sql (sql): Attempting to connect rlm_sql_mysql #13
rlm_sql_mysql: Starting connect to MySQL server for #13
rlm_sql (sql): Connected new DB handle, #13
rlm_sql (sql): starting 14
rlm_sql (sql): Attempting to connect rlm_sql_mysql #14
rlm_sql_mysql: Starting connect to MySQL server for #14
rlm_sql (sql): Connected new DB handle, #14
rlm_sql (sql): starting 15
rlm_sql (sql): Attempting to connect rlm_sql_mysql #15
rlm_sql_mysql: Starting connect to MySQL server for #15
rlm_sql (sql): Connected new DB handle, #15
rlm_sql (sql): starting 16
rlm_sql (sql): Attempting to connect rlm_sql_mysql #16
rlm_sql_mysql: Starting connect to MySQL server for #16
rlm_sql (sql): Connected new DB handle, #16
rlm_sql (sql): starting 17
rlm_sql (sql): Attempting to connect rlm_sql_mysql #17
rlm_sql_mysql: Starting connect to MySQL server for #17
rlm_sql (sql): Connected new DB handle, #17
rlm_sql (sql): starting 18
rlm_sql (sql): Attempting to connect rlm_sql_mysql #18
rlm_sql_mysql: Starting connect to MySQL server for #18
rlm_sql (sql): Connected new DB handle, #18
rlm_sql (sql): starting 19
rlm_sql (sql): Attempting to connect rlm_sql_mysql #19
rlm_sql_mysql: Starting connect to MySQL server for #19
rlm_sql (sql): Connected new DB handle, #19
rlm_sql (sql): starting 20
rlm_sql (sql): Attempting to connect rlm_sql_mysql #20
rlm_sql_mysql: Starting connect to MySQL server for #20
rlm_sql (sql): Connected new DB handle, #20
rlm_sql (sql): starting 21
rlm_sql (sql): Attempting to connect rlm_sql_mysql #21
rlm_sql_mysql: Starting connect to MySQL server for #21
rlm_sql (sql): Connected new DB handle, #21
rlm_sql (sql): starting 22
rlm_sql (sql): Attempting to connect rlm_sql_mysql #22
rlm_sql_mysql: Starting connect to MySQL server for #22
rlm_sql (sql): Connected new DB handle, #22
rlm_sql (sql): starting 23
rlm_sql (sql): Attempting to connect rlm_sql_mysql #23
rlm_sql_mysql: Starting connect to MySQL server for #23
rlm_sql (sql): Connected new DB handle, #23
rlm_sql (sql): starting 24
rlm_sql (sql): Attempting to connect rlm_sql_mysql #24
rlm_sql_mysql: Starting connect to MySQL server for #24
rlm_sql (sql): Connected new DB handle, #24
}
}
modules {
Module: Checking accounting {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating detail
detail {
detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Checking session {...} for more modules to load
}
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
}
listen {
type = "acct"
ipaddr = *
port = 0
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Ready to process requests.
As you can see in the previous section, my freeradius debug seems to execute perfectly. Note how it says it is listening on 1812 and 1813. When I do a netstat -a command, I get:
Note how it appears that ports 1812 and 1813 do not have anything listening...
Now, after seeing this, I thought maybe I have a firewall active or something. But upon further investigation, I found that iptables has no rules:
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).
Here are my freeradius configuration files. I've put them on a pastebin because I didn't want to make this email immensely long. Please have a look at them if you have any questions.
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: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
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.