Problems with IP address allocation, help needed debugging...
Ramm-Ericson, Johannes
Johannes.Ramm-Ericson at sonyericsson.com
Thu May 14 09:25:49 CEST 2009
Hi Freeradius-users!
I've run into a problem with my Freeradius 2.1.3 installation (on Suse Linux 10 - I'll be upgrading freeradius & migrating to Ubuntu Linux server during the weekend) that I'm hoping maybe someone on this list can help me with.
There are several NASes from various vendors / service providers connecting to my Freeradius server. I have instances of IP address allocation managed by the vendors equipment and in some cases IP address allocation is managed by my server. IP address management by Freeradius works fine except for in one instance and I have been hitting my head against the wall trying to figure out where the problem is. Here is the radiusd.conf post-auth / ippool configuration for a working instance (GLANA) and for the instance that does not work (CBJN)
ippool GLANA {
range-start = 192.168.10.2
range-stop = 192.168.10.254
netmask = 255.255.255.0
cache-size = 252
session-db = ${db_dir}/db.GLANA.pool
ip-index = ${db_dir}/db.GLANA.ipindex
#override = yes
maximum-timeout = 600
}
ippool CBJN {
range-start = 192.168.6.2
range-stop = 192.168.6.254
netmask = 255.255.255.0
cache-size = 252
session-db = ${db_dir}/db.CBJN.pool
ip-index = ${db_dir}/db.CBJN.ipindex
#override = yes
maximum-timeout = 600
}
Following are extracts from the debug log that exemplify a working instance with GLANA and a failing instance with CBJN:
************** Working instance with GLANA ***************
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.11.249 port 3886, id=80, length=126
NAS-IP-Address = 192.168.11.249
NAS-Identifier = "sh_ggsn_3"
Called-Station-Id = "GLANA"
Framed-Protocol = GPRS-PDP-Context
Service-Type = Framed-User
NAS-Port-Type = Virtual
NAS-Port = 64749880
User-Name = "048103"
User-Password = "*****"
Calling-Station-Id = "3333"
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[files] users: Matched entry DEFAULT at line 250
[files] users: Matched entry DEFAULT at line 278
++[files] returns ok
Found Auth-Type = System
+- entering group System {...}
pam_pass: using pamauth string <radiusd> for pam.conf lookup
pam_pass: authentication succeeded for <sel048103>
++[pam] returns ok
Login OK: [048103] (from client GLANA port 64749880 cli 3333)
+- entering group post-auth {...}
[GLANA] expand: %{NAS-IP-Address} %{NAS-Port} -> 192.168.11.249 64749880
[GLANA] MD5 on 'key' directive maps to: 525f9fa7f7e5045b96ec4ad53f324087
[GLANA] Searching for an entry for key: '525f9fa7f7e5045b96ec4ad53f324087'
rlm_ippool: Allocating ip to key: '525f9fa7f7e5045b96ec4ad53f324087'
[GLANA] num: 1
[GLANA] Allocated ip 192.168.10.55 to client key: 525f9fa7f7e5045b96ec4ad53f324087
++[GLANA] returns ok
[reply_log] expand: /opt/freeradius/current/var/log/radius/radacct/%{Client-IP-Address}/reply
-detail-%Y%m%d -> /opt/freeradius/current/var/log/radius/radacct/192.168.11.249/reply-detail-2009
0513
[reply_log] /opt/freeradius/current/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m
%d expands to /opt/freeradius/current/var/log/radius/radacct/192.168.11.249/reply-detail-20090513
[reply_log] expand: %t -> Wed May 13 11:10:21 2009
++[reply_log] returns ok
[sql] expand: %{User-Name} -> 048103
[sql] sql_set_user escaped user --> '048103'
[sql] expand: %{User-Password} -> *****
[sql] expand: INSERT INTO radpostauth (username, pass, reply, authdat
e) VALUES ( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}
', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( '048103',
'****', 'Access-Accept', '2009-05-13 11:10:21')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (userna
me, pass, reply, authdate) VALUES ( '048103',
'*****', 'Access-Accept', '2009-05-13
11:10:21')
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
Sending Access-Accept of id 80 to 192.168.11.249 port 3886
MS-Primary-DNS-Server = 192.168.212.10
Framed-IP-Address = 192.168.10.55
Framed-IP-Netmask = 255.255.255.0
Finished request 90.
*****************************************************
**************** Failing instance with CBJN ****************
Ready to process requests.
rad_recv: Access-Request packet from host 10.100.100.1 port 4415, id=170, length=136
NAS-IP-Address = 10.100.100.1
NAS-Identifier = "****"
Called-Station-Id = "CBJN"
Framed-Protocol = GPRS-PDP-Context
Service-Type = Framed-User
NAS-Port-Type = Virtual
NAS-Port = 9682712
User-Name = "100583"
User-Password = "****"
3GPP-IMSI = "111111111111"
Calling-Station-Id = "2222"
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[files] users: Matched entry DEFAULT at line 236
[files] users: Matched entry DEFAULT at line 278
++[files] returns ok
Found Auth-Type = System
+- entering group System {...}
pam_pass: using pamauth string <radiusd> for pam.conf lookup
pam_pass: authentication succeeded for <100583>
++[pam] returns ok
Login OK: [100583] (from client CBJN port 9682712 cli 2222)
+- entering group post-auth {...}
++[GLANA] returns noop
[reply_log] expand: /opt/freeradius/current/var/log/radius/radacct/%{Client-IP-Address}/reply
-detail-%Y%m%d -> /opt/freeradius/current/var/log/radius/radacct/10.100.100.1/reply-detail-200905
14
[reply_log] /opt/freeradius/current/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m
%d expands to /opt/freeradius/current/var/log/radius/radacct/10.100.100.1/reply-detail-20090514
[reply_log] expand: %t -> Thu May 14 07:52:51 2009
++[reply_log] returns ok
[sql] expand: %{User-Name} -> 100583
[sql] sql_set_user escaped user --> '100583'
[sql] expand: %{User-Password} -> ******
[sql] expand: INSERT INTO radpostauth (username, pass, reply, authdat
e) VALUES ( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}
', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( '100583',
'*****', 'Access-Accept', '2009-05-14 07:52:51')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (userna
me, pass, reply, authdate) VALUES ( '100583',
'****', 'Access-Accept', '2009-05-
14 07:52:51')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
Sending Access-Accept of id 170 to 10.100.100.1 port 4415
MS-Primary-DNS-Server = 192.168.212.10
Finished request 54.
**************************************************
I'm hoping someone can provide some guidance as to why IP address allocation via Freeradius fails in the second (CBJN) instance.... Also; naturally I'll provide any further logs necessary to clarify anything I may have missed mentioning now (for obvious reasons I also had to clean the logs before posting them here, so I may have missed a relevant entry).
Thanks and Regards,
Johannes
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20090514/67646ed2/attachment.html>
More information about the Freeradius-Users
mailing list