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@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
--