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