Authenticated device does not receive and IP, so continuously requests IP allocation
Sophie Loewenthal
sophie.loewenthal at trimbletl.com
Mon Nov 2 11:36:57 CET 2015
Good morning,
Below output was produced by running with '-sfxx -l myradius.log'
I did see Access-Accept below
The device did not receive an IP address.
Thanks, S.
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 177598
Cleaning up request 177597 ID 219 with timestamp +131514
Waking up in 4.9 seconds.
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[digest] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[files] users: Matched entry DEFAULT at line 207
++[files] returns ok
[sql] expand: %{User-Name} -> 010101010
[sql] sql_set_user escaped user --> '010101010'
rlm_sql (sql): Reserving sql socket id: 23
[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 = '010101010' 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 = '010101010' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'010101010' 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 = 'vodafone.example.com' ORDER BY id
[sql] User found in group vodafone.example.com
[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 = 'vodafone.example.com' ORDER BY id
rlm_sql (sql): Released sql socket id: 23
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
Found Auth-Type = PAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group PAP {...}
[pap] login attempt with password "XXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
[pap] Using clear text password "XXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
[pap] User authenticated successfully
++[pap] returns ok
Login OK: [010101010] (from client vodafone-nas port 556657 cli 31655425447)
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
rlm_sql (sql): Reserving sql socket id: 22
[sqlippool] expand: %{User-Name} -> 010101010
[sqlippool] sql_set_user escaped user --> '010101010'
[sqlippool] expand: START TRANSACTION -> START TRANSACTION
[sqlippool] expand: UPDATE radippool /* allocate-clear */ SET
nasipaddress = '', pool_key = 0, callingstationid = '', calledstationid
= '', expiry_time = NULL, 3GPP_Imsi = '' WHERE pool_key =
'%{Calling-Station-Id}' -> UPDATE radippool /* allocate-clear */ SET
nasipaddress = '', pool_key = 0, callingstationid = '', calledstationid
= '', expiry_time = NULL, 3GPP_Imsi = '' WHERE pool_key = '31655425447'
[sqlippool] expand: SELECT framedipaddress FROM radippool WHERE
pool_name = '%{control:Pool-Name}' AND username = '%{User-Name}' LIMIT
1 -> SELECT framedipaddress FROM radippool WHERE pool_name =
'vodafone' AND username = '010101010' LIMIT 1
[sqlippool] expand: UPDATE radippool /* allocate-update */ SET
nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}',
callingstationid = '%{Calling-Station-Id}', expiry_time = NOW() +
INTERVAL 3600 SECOND, 3GPP_Imsi = '%{3GPP-IMSI}', calledstationid =
'%{Called-Station-Id}' WHERE framedipaddress = '10.26.0.16' AND
username = '%{User-Name}' -> UPDATE radippool /* allocate-update */ SET
nasipaddress = '172.200.100.1', pool_key = '31655425447',
callingstationid = '31655425447', expiry_time = NOW() + INTERVAL 3600
SECOND, 3GPP_Imsi = '204045650449471', calledstationid =
'vodafone.example.com' WHERE framedipaddress = '10.26.0.16' AND
username = '010101010'
[sqlippool] Allocated IP 10.26.0.16 [10001a0a]
[sqlippool] expand: COMMIT -> COMMIT
rlm_sql (sql): Released sql socket id: 22
[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: 10.26.0.16 from vodafone (did vodafone.example.com cli 31655425447
port 556657 user 010101010)
Allocated IP: 10.26.0.16 from vodafone (did vodafone.example.com cli
31655425447 port 556657 user 010101010)
++[sqlippool] returns ok
[sql] expand: %{User-Name} -> 010101010
[sql] sql_set_user escaped user --> '010101010'
[sql] expand: %{User-Password} -> XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
[sql] expand: INSERT INTO radpostauth (username, pass, reply,
authdate) VALUES ( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
-> INSERT INTO radpostauth (username, pass,
reply, authdate) VALUES
( '010101010',
'XXXXXXXXXXXXXXXXXXXXXXXXXXXXX', 'Access-Accept', '2015-11-01 03:23:00')
rlm_sql (sql) in sql_postauth: query is INSERT INTO
radpostauth (username, pass, reply,
authdate) VALUES (
'010101010', 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXX', 'Access-Accept',
'2015-11-01 03:23:00')
rlm_sql (sql): Reserving sql socket id: 21
rlm_sql (sql): Released sql socket id: 21
++[sql] returns ok
++[exec] returns noop
Finished request 177599.
Going to the next request
On 30-Oct-15 1:49 PM, Alan DeKok wrote:
> On Oct 30, 2015, at 8:41 AM, Sophie Loewenthal <sophie.loewenthal at example.com> wrote:
>> For a few weeks some devices have had their IP allocation "lost" en route. They authenticate, and IP is allocated but not received by the device.
> There are a few steps between authentication and the device receiving the IP.
>
> Is FreeRADIUS *sending* the correct IP? If so, the problem is the NAS. Nothing you do to FreeRADIUS will help.
>
> If not, then you can fix FreeRADIUS.
>
>> Afterwards a device continuously asking for an IP address, being allocated, and then asking again.
>>
>> This has happened intermittently with some devices on Vodafone APN. I did not see devices on other APNs affected.
> Then it's probably the vodafone APN which is dropping the IP.
>
>> Please see the three Radius requests in debug mode at the end of this email in attachments. They are small files of approx 10Kb and were collected with options to radiusd -xxx
> And not "radiusd -X", which is suggested in the FAQ, "man" page, web pages, and daily on this list.
>
> Which means you can't see what's in the Access-Request, or what's in the Access-Accept. That information is *critical* to solving the problem.
>
> PLEASE follow the documentation.
>
> Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list