IP allocation problem
Tevfik Ceydeliler
tevfik.ceydeliler at astron.yasar.com.tr
Thu Mar 5 13:41:15 CET 2015
here is debug log.
There is a warning about two type atuhentication. But I think this is
not cause of problem.
I check that same calling station ID .
But cant find why happen this:
rad_recv: Access-Request packet from host 172.30.80.1 port 24288,
id=190, length=396
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0xa326bfbfa326bfbfa326bfbfa326bfbf
CHAP-Password = 0x004de14711758f194ae8bbc0b2cd18899e
NAS-Port = 98076
3GPP-Charging-Gateway-Address = 10.200.211.27
# Executing section authorize from file
/etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "biryudumgida3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql] expand: %{User-Name} -> biryudumgida3
[sql] sql_set_user escaped user --> 'biryudumgida3'
rlm_sql (sql): Reserving sql socket id: 0
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'biryudumgida3' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'biryudumgida3' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority ->
SELECT groupname FROM radusergroup WHERE username =
'biryudumgida3' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
[sql] User found in group UGR_TcellOtonomYBB-Secovid
[sql] expand: SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
WARNING: Empty pre-proxy section. Using default return values.
Sending Access-Request of id 234 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0xa326bfbfa326bfbfa326bfbfa326bfbf
CHAP-Password = 0x004de14711758f194ae8bbc0b2cd18899e
NAS-Port = 98076
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x313930
Proxying request 4 to home server 10.1.1.51 port 1812
Sending Access-Request of id 234 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0xa326bfbfa326bfbfa326bfbfa326bfbf
CHAP-Password = 0x004de14711758f194ae8bbc0b2cd18899e
NAS-Port = 98076
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x313930
Going to the next request
Waking up in 0.9 seconds.
rad_recv: Access-Accept packet from host 10.1.1.51 port 1812, id=234,
length=25
Proxy-State = 0x313930
# Executing section post-proxy from file
/etc/freeradius/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Found Auth-Type = CHAP
Found Auth-Type = Accept
###THERE IS A WARNING HERE!! ####
Warning: Found 2 auth-types on request for user 'biryudumgida3'
Auth-Type = Accept, accepting the user
# Executing section post-auth from file
/etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
rlm_sql (sql): Reserving sql socket id: 4
[sqlippool] expand: %{User-Name} -> biryudumgida3
[sqlippool] sql_set_user escaped user --> 'biryudumgida3'
[sqlippool] expand: START TRANSACTION -> START TRANSACTION
[sqlippool] expand: UPDATE radippool SET nasipaddress = '',
pool_key = 0, callingstationid = '', username = '', expiry_time =
NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress
= '%{Nas-IP-Address}' -> UPDATE radippool SET nasipaddress = '',
pool_key = 0, callingstationid = '', username = '', expiry_time =
NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress
= '172.30.80.1'
[sqlippool] expand: SELECT framedipaddress FROM radippool WHERE
pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR
expiry_time IS NULL) ORDER BY (username <> '%{User-Name}'),
(callingstationid <> '%{Calling-Station-Id}'), expiry_time LIMIT 1
FOR UPDATE -> SELECT framedipaddress FROM radippool WHERE pool_name =
'IP_TcellOtonomYBB' AND (expiry_time < NOW() OR expiry_time IS NULL)
ORDER BY (username <> 'biryudumgida3'), (callingstationid <>
'905303643912'), expiry_time LIMIT 1 FOR UPDATE
[sqlippool] expand: UPDATE radippool SET nasipaddress =
'%{NAS-IP-Address}', pool_key = '%{NAS-Port}', callingstationid =
'%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW()
+ INTERVAL 7200 SECOND WHERE framedipaddress = '172.30.64.191' AND
expiry_time IS NULL -> UPDATE radippool SET nasipaddress =
'172.30.80.1', pool_key = '98076', callingstationid = '905303643912',
username = 'biryudumgida3', expiry_time = NOW() + INTERVAL 7200 SECOND
WHERE framedipaddress = '172.30.64.191' AND expiry_time IS NULL
[sqlippool] Allocated IP 172.30.64.191 [bf401eac]
[sqlippool] expand: COMMIT -> COMMIT
rlm_sql (sql): Released sql socket id: 4
[sqlippool] expand: Allocated IP: %{reply:Framed-IP-Address} from
%{control:Pool-Name} (did %{Called-Station-Id} cli
%{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) -> Allocated
IP: 172.30.64.191 from IP_TcellOtonomYBB (did yasarapn cli
905303643912 port 98076 user biryudumgida3)
#####IP ALLOCATED AS 172.30.64.191 #######
Allocated IP: 172.30.64.191 from IP_TcellOtonomYBB (did yasarapn cli
905303643912 port 98076 user biryudumgida3)
++[sqlippool] returns ok
++[exec] returns noop
Sending Access-Accept of id 190 to 172.30.80.1 port 24288
Framed-IP-Address = 172.30.64.191
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 4 ID 190 with timestamp +875
Ready to process requests.
#####REQ. COMES AGAIN ######
rad_recv: Access-Request packet from host 172.30.80.1 port 24480, id=83,
length=396
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x2d9abfbf2d9abfbf2d9abfbf2d9abfbf
CHAP-Password = 0x00ec83996af9236f1afe60dacc246bc3c4
NAS-Port = 128247
3GPP-Charging-Gateway-Address = 10.200.211.27
# Executing section authorize from file
/etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "biryudumgida3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql] expand: %{User-Name} -> biryudumgida3
[sql] sql_set_user escaped user --> 'biryudumgida3'
rlm_sql (sql): Reserving sql socket id: 3
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'biryudumgida3' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'biryudumgida3' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority ->
SELECT groupname FROM radusergroup WHERE username =
'biryudumgida3' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
[sql] User found in group UGR_TcellOtonomYBB-Secovid
[sql] expand: SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
WARNING: Empty pre-proxy section. Using default return values.
Sending Access-Request of id 132 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x2d9abfbf2d9abfbf2d9abfbf2d9abfbf
CHAP-Password = 0x00ec83996af9236f1afe60dacc246bc3c4
NAS-Port = 128247
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x3833
Proxying request 5 to home server 10.1.1.51 port 1812
Sending Access-Request of id 132 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x2d9abfbf2d9abfbf2d9abfbf2d9abfbf
CHAP-Password = 0x00ec83996af9236f1afe60dacc246bc3c4
NAS-Port = 128247
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x3833
Going to the next request
Waking up in 0.9 seconds.
rad_recv: Access-Reject packet from host 10.1.1.51 port 1812, id=132,
length=24
Proxy-State = 0x3833
# Executing section post-proxy from file
/etc/freeradius/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> biryudumgida3
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 5 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 5
#####ACCESS_REJECT SEND#######
Sending Access-Reject of id 83 to 172.30.80.1 port 24480
Waking up in 4.9 seconds.
Cleaning up request 5 ID 83 with timestamp +905
Ready to process requests.
######## REQ. COMES AGAIN ######
rad_recv: Access-Request packet from host 172.30.80.1 port 24304,
id=169, length=396
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x3f10c0c03f10c0c03f10c0c03f10c0c0
CHAP-Password = 0x00b66d4ff74c3480f2c1542a25e80a2339
NAS-Port = 85715
3GPP-Charging-Gateway-Address = 10.200.211.27
# Executing section authorize from file
/etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "biryudumgida3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql] expand: %{User-Name} -> biryudumgida3
[sql] sql_set_user escaped user --> 'biryudumgida3'
rlm_sql (sql): Reserving sql socket id: 2
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'biryudumgida3' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'biryudumgida3' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority ->
SELECT groupname FROM radusergroup WHERE username =
'biryudumgida3' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
[sql] User found in group UGR_TcellOtonomYBB-Secovid
[sql] expand: SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'UGR_TcellOtonomYBB-Secovid' ORDER BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
WARNING: Empty pre-proxy section. Using default return values.
Sending Access-Request of id 115 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x3f10c0c03f10c0c03f10c0c03f10c0c0
CHAP-Password = 0x00b66d4ff74c3480f2c1542a25e80a2339
NAS-Port = 85715
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x313639
Proxying request 6 to home server 10.1.1.51 port 1812
Sending Access-Request of id 115 to 10.1.1.51 port 1812
Calling-Station-Id = "905303643912"
User-Name = "biryudumgida3"
NAS-IP-Address = 172.30.80.1
NAS-Identifier = "MTCGGSNK3"
Service-Type = Framed-User
Framed-Protocol = GPRS-PDP-Context
NAS-Port-Type = Wireless-Other
---3GPP things--
Called-Station-Id = "yasarapn"
---3GPP things--
CHAP-Challenge = 0x3f10c0c03f10c0c03f10c0c03f10c0c0
CHAP-Password = 0x00b66d4ff74c3480f2c1542a25e80a2339
NAS-Port = 85715
3GPP-Charging-Gateway-Address = 10.200.211.27
Proxy-State = 0x313639
Going to the next request
Waking up in 0.9 seconds.
rad_recv: Access-Accept packet from host 10.1.1.51 port 1812, id=115,
length=25
Proxy-State = 0x313639
# Executing section post-proxy from file
/etc/freeradius/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Found Auth-Type = CHAP
Found Auth-Type = Accept
######## THERE IS A WARNING HERE ##############
Warning: Found 2 auth-types on request for user 'biryudumgida3'
Auth-Type = Accept, accepting the user
# Executing section post-auth from file
/etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
rlm_sql (sql): Reserving sql socket id: 1
[sqlippool] expand: %{User-Name} -> biryudumgida3
[sqlippool] sql_set_user escaped user --> 'biryudumgida3'
[sqlippool] expand: START TRANSACTION -> START TRANSACTION
[sqlippool] expand: UPDATE radippool SET nasipaddress = '',
pool_key = 0, callingstationid = '', username = '', expiry_time =
NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress
= '%{Nas-IP-Address}' -> UPDATE radippool SET nasipaddress = '',
pool_key = 0, callingstationid = '', username = '', expiry_time =
NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress
= '172.30.80.1'
[sqlippool] expand: SELECT framedipaddress FROM radippool WHERE
pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR
expiry_time IS NULL) ORDER BY (username <> '%{User-Name}'),
(callingstationid <> '%{Calling-Station-Id}'), expiry_time LIMIT 1
FOR UPDATE -> SELECT framedipaddress FROM radippool WHERE pool_name =
'IP_TcellOtonomYBB' AND (expiry_time < NOW() OR expiry_time IS NULL)
ORDER BY (username <> 'biryudumgida3'), (callingstationid <>
'905303643912'), expiry_time LIMIT 1 FOR UPDATE
[sqlippool] expand: UPDATE radippool SET nasipaddress =
'%{NAS-IP-Address}', pool_key = '%{NAS-Port}', callingstationid =
'%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW()
+ INTERVAL 7200 SECOND WHERE framedipaddress = '172.30.64.190' AND
expiry_time IS NULL -> UPDATE radippool SET nasipaddress =
'172.30.80.1', pool_key = '85715', callingstationid = '905303643912',
username = 'biryudumgida3', expiry_time = NOW() + INTERVAL 7200 SECOND
WHERE framedipaddress = '172.30.64.190' AND expiry_time IS NULL
[sqlippool] Allocated IP 172.30.64.190 [be401eac]
[sqlippool] expand: COMMIT -> COMMIT
rlm_sql (sql): Released sql socket id: 1
[sqlippool] expand: Allocated IP: %{reply:Framed-IP-Address} from
%{control:Pool-Name} (did %{Called-Station-Id} cli
%{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) -> Allocated
IP: 172.30.64.190 from IP_TcellOtonomYBB (did yasarapn cli
905303643912 port 85715 user biryudumgida3)
########## NOW ALLOCATE DIFFERENT IP TO SAME USER EVEN RELEASE TIME 7200
SEC #######
Allocated IP: 172.30.64.190 from IP_TcellOtonomYBB (did yasarapn cli
905303643912 port 85715 user biryudumgida3)
++[sqlippool] returns ok
++[exec] returns noop
Sending Access-Accept of id 169 to 172.30.80.1 port 24304
Framed-IP-Address = 172.30.64.190
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 6 ID 169 with timestamp +935
Ready to process requests.
On 03/03/2015 02:43 PM, Alan DeKok wrote:
> On Mar 3, 2015, at 3:47 AM, Tevfik Ceydeliler <tevfik.ceydeliler at astron.yasar.com.tr> wrote:
>> Altough I use sqlippool adn lease time 6 hours, why one user get more than one IP?
> No idea.
>
>> Any idea? or suggestion where I look?
> How about the debug output? Which tells you when / why the user was assigned an IP address?
>
> I’ll note that the default configuration hands out IP addresses based on Calling-Station-Id. And re-uses the same IP if the user logs in again with the same Calling-Station-Id. So… the problem doesn’t seem to be the default configuration.
>
> Alan DeKok.
>
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
--
More information about the Freeradius-Users
mailing list