Sending delayed reject for request 182
Waking up in 0.5 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 227
++[files] returns ok
[sql]   expand: %{User-Name} -> 454861234567111
[sql] sql_set_user escaped user --> '454861234567111'
rlm_sql (sql): Reserving sql socket id: 12
[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 = '454861234567111'           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 = '454861234567111'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = '454861234567111'           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.trimbletl.com'           ORDER BY id
[sql] User found in group vodafone.trimbletl.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.trimbletl.com'           ORDER BY id
rlm_sql (sql): Released sql socket id: 12
++[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 "XXXXXXXXXXXXXXXXXXXXXXXXXX990900"
[pap] Using clear text password "XXXXXXXXXXXXXXXXXXXXXXXXXX990900"
[pap] User authenticated successfully
++[pap] returns ok
Login OK: [454861234567111] (from client proximus-nas-carli port 29449 cli 327700011041734)
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
rlm_sql (sql): Reserving sql socket id: 11
[sqlippool]     expand: %{User-Name} -> 454861234567111
[sqlippool] sql_set_user escaped user --> '454861234567111'
[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 = '327700011041734'
[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 = 'proximus-carli'   AND username = '454861234567111' LIMIT 1
[sqlippool] SQL query did not return any results
[sqlippool]     expand: COMMIT -> COMMIT
[sqlippool]     expand: SELECT id FROM radippool /* pool-check */  WHERE pool_name='%{control:Pool-Name}' LIMIT 1 -> SELECT id FROM radippool /* pool-check */  WHERE pool_name='proximus-carli' LIMIT 1
rlm_sql (sql): Released sql socket id: 11
[sqlippool] pool appears to be full
[sqlippool]     expand: IP Allocation FAILED from %{control:Pool-Name}   (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) -> IP Allocation FAILED from proximus-carli   (did proximus.trimbletl.com cli 327700011041734 port 29449 user 454861234567111)
IP Allocation FAILED from proximus-carli   (did proximus.trimbletl.com cli 327700011041734 port 29449 user 454861234567111)
++[sqlippool] returns notfound
[sql]   expand: %{User-Name} -> 454861234567111
[sql] sql_set_user escaped user --> '454861234567111'
[sql]   expand: %{User-Password} -> XXXXXXXXXXXXXXXXXXXXXXXXXX990900
[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 (                           '454861234567111',                           'XXXXXXXXXXXXXXXXXXXXXXXXXX990900',                           'Access-Accept', '2015-11-06 11:12:31')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           '454861234567111',                           'XXXXXXXXXXXXXXXXXXXXXXXXXX990900',                           'Access-Accept', '2015-11-06 11:12:31')
rlm_sql (sql): Reserving sql socket id: 10
rlm_sql (sql): Released sql socket id: 10
++[sql] returns ok
++[exec] returns noop
Finished request 184.
Going to the next request