FreeRadius 3.0.15 - Help with accounting

7 Aug 2017


      Hello,

     I have problems with some accounting packets.

     Certainly it's my problem, but I need help (or hint).

     Sometimes I receive a complete Start request, but in my database 
(MySQL)  the data are inserted incomplete, without nasporttype and 
callingstationid.

     When this occours I receive an automatic stop  and a new start 
packet and then all is ok.

     Where's my problem?

     Look radiusd -X output.

(1427) Received Access-Request Id 52 from 172.17.5.2:36040 to 
187.120.197.140:1812 length 150
(1427)   Service-Type = Framed-User
(1427)   Framed-Protocol = PPP
(1427)   NAS-Port = 15728725
(1427)   NAS-Port-Type = Ethernet
(1427)   User-Name = "joaocontri"
(1427)   Calling-Station-Id = "00:40:A7:0A:8D:AC"
(1427)   Called-Station-Id = "CE - POP IFA"
(1427)   NAS-Port-Id = "vlan2000"
(1427)   CHAP-Challenge = 0xa08487414d87ab655704429ef9d934b9
(1427)   CHAP-Password = 0x010755db14028f7afa2ac1d9d59affdd3c
(1427)   NAS-Identifier = "CE-IFA"
(1427)   NAS-IP-Address = 172.17.5.2
(1427) # Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   authorize {
(1427)     [preprocess] = ok
(1427) chap:   &control:Auth-Type := CHAP
(1427)     [chap] = ok
(1427)     [mschap] = noop
(1427) sql: EXPAND %{User-Name}
(1427) sql:    --> joaocontri
(1427) sql: SQL-User-Name set to 'joaocontri'
rlm_sql (sql): Reserved connection (10)
(1427) sql: EXPAND SELECT DISTINCT (R.id), R.username, R.attribute, 
R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'%{SQL-User-Name}'                                  AND M.usuario_login 
=  BINARY '%{SQL-User-Name}'                                  AND 
N.nasname = '%{Nas-IP-Address}'                                  AND 
N.gw_id = (SELECT gateway_id FROM mpc_lw.maclist WHERE usuario_login =  
BINARY '%{SQL-User-Name}' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'%{Nas-IP-Address}' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'%{SQL-User-Name}'                                  AND M.usuario_login 
=  BINARY '%{SQL-User-Name}'                                  AND 
M.grupocliente = 'ALL-POPS'
(1427) sql:    --> SELECT DISTINCT (R.id), R.username, R.attribute, 
R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND N.nasname =  
'172.17.5.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'joaocontri' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'172.17.5.2' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND M.grupocliente 
= 'ALL-POPS'
(1427) sql: Executing select query: SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND N.nasname =  
'172.17.5.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'joaocontri' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'172.17.5.2' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND M.grupocliente 
= 'ALL-POPS'
(1427) sql: User found in radcheck table
(1427) sql: Conditional check items matched, merging assignment check items
(1427) sql:   Simultaneous-Use := 1
(1427) sql:   Pool-Name := "main_pool"
(1427) sql:   Cleartext-Password := "2189jc"
(1427) sql: EXPAND SELECT DISTINCT (R.id), R.username, R.attribute, 
R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'%{SQL-User-Name}'                                  AND M.usuario_login 
=  BINARY '%{SQL-User-Name}'                                  AND 
N.nasname = '%{Nas-IP-Address}'                                  AND 
N.gw_id = (SELECT gateway_id FROM mpc_lw.maclist WHERE usuario_login =  
BINARY '%{SQL-User-Name}' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'%{Nas-IP-Address}' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'%{SQL-User-Name}'                                  AND M.usuario_login 
=  BINARY '%{SQL-User-Name}'                                  AND 
M.grupocliente = 'ALL-POPS'
(1427) sql:    --> SELECT DISTINCT (R.id), R.username, R.attribute, 
R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND N.nasname =  
'172.17.5.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'joaocontri' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'172.17.5.2' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND M.grupocliente 
= 'ALL-POPS'
(1427) sql: Executing select query: SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND N.nasname =  
'172.17.5.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'joaocontri' AND plano_id NOT IN 
(8,9,793)                                                       AND 
gateway_id = ( SELECT gw_id FROM mpc_freeradius.nas WHERE nasname = 
'172.17.5.2' )                                  ORDER BY 
ID)                                  UNION 
ALL                                  SELECT DISTINCT (R.id), R.username, 
R.attribute, R.value, R.op                                  FROM 
mpc_freeradius.radcheck R, mpc_freeradius.nas N, mpc_lw.maclist 
M                                  WHERE R.username =  BINARY 
'joaocontri'                                  AND M.usuario_login = 
BINARY 'joaocontri'                                  AND M.grupocliente 
= 'ALL-POPS'
(1427) sql: User found in radreply table, merging reply items
(1427) sql:   Simultaneous-Use := 1
(1427) sql:   Pool-Name := "main_pool"
(1427) sql:   Cleartext-Password := "2189jc"
(1427) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority
(1427) sql:    --> SELECT groupname FROM radusergroup WHERE username = 
'joaocontri' ORDER BY priority
(1427) sql: Executing select query: SELECT groupname FROM radusergroup 
WHERE username = 'joaocontri' ORDER BY priority
(1427) sql: User found in the group table
(1427) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM 
radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
(1427) sql:    --> SELECT id, groupname, attribute, Value, op FROM 
radgroupcheck WHERE groupname = '714' ORDER BY id
(1427) sql: Executing select query: SELECT id, groupname, attribute, 
Value, op FROM radgroupcheck WHERE groupname = '714' ORDER BY id
(1427) sql: Group "714": Conditional check items matched
(1427) sql: Group "714": Merging assignment check items
(1427) sql: EXPAND SELECT id, groupname, attribute, value, op FROM 
radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
(1427) sql:    --> SELECT id, groupname, attribute, value, op FROM 
radgroupreply WHERE groupname = '714' ORDER BY id
(1427) sql: Executing select query: SELECT id, groupname, attribute, 
value, op FROM radgroupreply WHERE groupname = '714' ORDER BY id
(1427) sql: Group "714": Merging reply items
(1427) sql:   Framed-Compression := Van-Jacobson-TCP-IP
(1427) sql:   Framed-Protocol := PPP
(1427) sql:   Framed-Routing := Broadcast-Listen
(1427) sql:   Framed-MTU := 1500
(1427) sql:   Service-Type := Framed-User
(1427) sql:   Mikrotik-Rate-Limit := "300K/820k 330k/2227k 315k/1638k 54/54"
rlm_sql (sql): Released connection (10)
(1427)     [sql] = ok
(1427)     [expiration] = noop
(1427)     [logintime] = noop
(1427) pap: WARNING: Auth-Type already set.  Not setting to PAP
(1427)     [pap] = noop
(1427)   } # authorize = ok
(1427) Found Auth-Type = CHAP
(1427) # Executing group from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   Auth-Type CHAP {
(1427) chap: Comparing with "known good" Cleartext-Password
(1427) chap: CHAP user "joaocontri" authenticated successfully
(1427)     [chap] = ok
(1427)     if (fail) {
(1427)     if (fail)  -> FALSE
(1427)   } # Auth-Type CHAP = ok
(1427) # Executing section session from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   session {
(1427) sql: EXPAND %{User-Name}
(1427) sql:    --> joaocontri
(1427) sql: SQL-User-Name set to 'joaocontri'
(1427) sql: EXPAND SELECT COUNT(*)                              FROM 
radacct                              WHERE username = 
'%{SQL-User-Name}'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
(1427) sql:    --> SELECT COUNT(*) FROM 
radacct                              WHERE username = 
'joaocontri'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
rlm_sql (sql): Reserved connection (4)
(1427) sql: Executing select query: SELECT 
COUNT(*)                              FROM 
radacct                              WHERE username = 
'joaocontri'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
(1427) sql: EXPAND SELECT radacctid, acctsessionid, 
username,                                nasipaddress, nasportid, 
framedipaddress,                                callingstationid, 
framedprotocol                                FROM 
radacct                                WHERE username = 
'%{SQL-User-Name}'                                AND acctstoptime IS 
NULL                                AND framedipaddress NOT REGEXP '^10\.'
(1427) sql:    --> SELECT radacctid, acctsessionid, 
username,                                nasipaddress, nasportid, 
framedipaddress,                                callingstationid, 
framedprotocol                                FROM 
radacct                                WHERE username = 
'joaocontri'                                AND acctstoptime IS 
NULL                                AND framedipaddress NOT REGEXP '^10\.'
(1427) sql: Executing select query: SELECT radacctid, acctsessionid, 
username,                                nasipaddress, nasportid, 
framedipaddress,                                callingstationid, 
framedprotocol                                FROM 
radacct                                WHERE username = 
'joaocontri'                                AND acctstoptime IS 
NULL                                AND framedipaddress NOT REGEXP '^10\.'
(1427) sql: Running Accounting section for automatically created 
accounting 'stop'
(1427) sql:   Service-Type = Framed-User
(1427) sql:   Framed-Protocol = PPP
(1427) sql:   NAS-Port = 15728725
(1427) sql:   NAS-Port-Type = Ethernet
(1427) sql:   User-Name = "joaocontri"
(1427) sql:   Calling-Station-Id = "00:40:A7:0A:8D:AC"
(1427) sql:   Called-Station-Id = "CE - POP IFA"
(1427) sql:   NAS-Port-Id = "vlan2000"
(1427) sql:   CHAP-Challenge = 0xa08487414d87ab655704429ef9d934b9
(1427) sql:   CHAP-Password = 0x010755db14028f7afa2ac1d9d59affdd3c
(1427) sql:   NAS-Identifier = "CE-IFA"
(1427) sql:   NAS-IP-Address = 172.17.5.2
(1427) sql:   Event-Timestamp = "Aug  3 2017 11:23:39 BRT"
(1427) sql:   SQL-User-Name := "joaocontri"
(1427) # Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   preacct {
(1427)     [preprocess] = ok
(1427)     policy acct_unique {
(1427)       update request {
(1427)         &Tmp-String-9 := "ai:"
(1427)       } # update request = noop
(1427)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&     
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(1427)       EXPAND %{hex:&Class}
(1427)          -->
(1427)       EXPAND ^%{hex:&Tmp-String-9}
(1427)          --> ^61693a
(1427)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&     
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i))  -> FALSE
(1427)       else {
(1427)         update request {
(1427)           EXPAND 
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1427)              --> 344e3c54b376827e6b2bc3e06d3dea1d
(1427)           &Acct-Unique-Session-Id := 344e3c54b376827e6b2bc3e06d3dea1d
(1427)         } # update request = noop
(1427)       } # else = noop
(1427)     } # policy acct_unique = noop
(1427)     [files] = noop
(1427)   } # preacct = ok
(1427) # Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   accounting {
rlm_sql (sql): Reserved connection (28)
(1427) sqlippool: EXPAND %{User-Name}
(1427) sqlippool:    --> joaocontri
(1427) sqlippool: SQL-User-Name set to 'joaocontri'
(1427) sqlippool: EXPAND START TRANSACTION
(1427) sqlippool:    --> START TRANSACTION
(1427) sqlippool: Executing query: START TRANSACTION
(1427) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', 
pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE nasipaddress = '%{Nas-IP-Address}' AND 
pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND 
callingstationid = '%{Calling-Station-Id}' AND framedipaddress = 
'%{Framed-IP-Address}'
(1427) sqlippool:    --> UPDATE radippool SET nasipaddress = '', 
pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE nasipaddress = '172.17.5.2' AND pool_key = 
'' AND username = 'joaocontri' AND callingstationid = '' AND 
framedipaddress = '187.120.206.180'
(1427) sqlippool: Executing query: UPDATE radippool SET nasipaddress = 
'', pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE nasipaddress = '172.17.5.2' AND pool_key = 
'' AND username = 'joaocontri' AND callingstationid = '' AND 
framedipaddress = '187.120.206.180'
rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
(1427) sqlippool: EXPAND COMMIT
(1427) sqlippool:    --> COMMIT
(1427) sqlippool: Executing query: COMMIT
(1427) sqlippool: EXPAND Released IP %{Framed-IP-Address} (did 
%{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})
(1427) sqlippool:    --> Released IP 187.120.206.180 (did  cli user 
joaocontri)
rlm_sql (sql): Released connection (28)
(1427)     [sqlippool] = ok
(1427) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(1427) sql:    --> type.stop.query
(1427) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (16)
(1427) sql: EXPAND %{User-Name}
(1427) sql:    --> joaocontri
(1427) sql: SQL-User-Name set to 'joaocontri'
(1427) sql: EXPAND UPDATE radacct SET acctstoptime    = NOW(), 
acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = 
'%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', 
acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | 
'%{%{Acct-Output-Octets}:-0}', acctterminatecause = 
'%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE 
AcctUniqueId = '%{Acct-Unique-Session-Id}'
(1427) sql:    --> UPDATE radacct SET acctstoptime    = NOW(), 
acctsessiontime = 0, acctinputoctets = '0' << 32 | '0', acctoutputoctets 
= '0' << 32 | '0', acctterminatecause = '', connectinfo_stop = '' WHERE 
AcctUniqueId = '344e3c54b376827e6b2bc3e06d3dea1d'
(1427) sql: Executing query: UPDATE radacct SET acctstoptime    = NOW(), 
acctsessiontime = 0, acctinputoctets = '0' << 32 | '0', acctoutputoctets 
= '0' << 32 | '0', acctterminatecause = '', connectinfo_stop = '' WHERE 
AcctUniqueId = '344e3c54b376827e6b2bc3e06d3dea1d'
rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0
(1427) sql: SQL query returned: success
(1427) sql: 1 record(s) updated
rlm_sql (sql): Released connection (16)
(1427)     [sql] = ok
(1427)     [exec] = noop
(1427) attr_filter.accounting_response: EXPAND %{User-Name}
(1427) attr_filter.accounting_response:    --> joaocontri
(1427) attr_filter.accounting_response: Matched entry DEFAULT at line 12
(1427)     [attr_filter.accounting_response] = updated
(1427) log_accounting: EXPAND 
Accounting-Request.%{%{Acct-Status-Type}:-unknown}
(1427) log_accounting:    --> Accounting-Request.Stop
(1427) log_accounting: EXPAND %t : Info: Released IP 
%{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} 
user %{User-Name})
(1427) log_accounting:    --> Thu Aug  3 11:23:39 2017 : Info: Released 
IP 187.120.206.180 (did  cli  user joaocontri)
(1427) log_accounting: EXPAND /var/log/radius.log
(1427) log_accounting:    --> /var/log/radius.log
(1427)     [log_accounting] = ok
(1427)   } # accounting = updated
rlm_sql (sql): Released connection (4)
(1427)     [sql] = ok
(1427)   } # session = ok
(1427) # Executing section post-auth from file 
/usr/local/etc/raddb/sites-enabled/default
(1427)   post-auth {
(1427)     update {
(1427)       No attributes updated
(1427)     } # update = noop
rlm_sql (sql): Reserved connection (0)
(1427) sqlippool: EXPAND %{User-Name}
(1427) sqlippool:    --> joaocontri
(1427) sqlippool: SQL-User-Name set to 'joaocontri'
(1427) sqlippool: EXPAND START TRANSACTION
(1427) sqlippool:    --> START TRANSACTION
(1427) sqlippool: Executing query: START TRANSACTION
(1427) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE 
pool_name = '%{control:Pool-Name}' AND  expiry_time = '0000-00-00 
00:00:00' ORDER BY (username <> '%{User-Name}'), (callingstationid <> 
'%{Calling-Station-Id}'), expiry_time LIMIT 1 FOR UPDATE
(1427) sqlippool:    --> SELECT framedipaddress FROM radippool WHERE 
pool_name = 'main_pool' AND  expiry_time = '0000-00-00 00:00:00' ORDER 
BY (username <> 'joaocontri'), (callingstationid <> 
'00:40:A7:0A:8D:AC'), expiry_time LIMIT 1 FOR UPDATE
(1427) sqlippool: Executing select query: SELECT framedipaddress FROM 
radippool WHERE pool_name = 'main_pool' AND  expiry_time = '0000-00-00 
00:00:00' ORDER BY (username <> 'joaocontri'), (callingstationid <> 
'00:40:A7:0A:8D:AC'), expiry_time LIMIT 1 FOR UPDATE
(1427) sqlippool: Allocated IP 187.120.205.15
(1427) sqlippool: EXPAND UPDATE radippool SET nasipaddress = 
'%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', 
callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', 
expiry_time = NOW() + INTERVAL 330 SECOND WHERE framedipaddress = 
'187.120.205.15' AND expiry_time = '0000-00-00 00:00:00'
(1427) sqlippool:    --> UPDATE radippool SET nasipaddress = 
'172.17.5.2', pool_key = '00:40:A7:0A:8D:AC', callingstationid = 
'00:40:A7:0A:8D:AC', username = 'joaocontri', expiry_time = NOW() + 
INTERVAL 330 SECOND WHERE framedipaddress = '187.120.205.15' AND 
expiry_time = '0000-00-00 00:00:00'
(1427) sqlippool: Executing query: UPDATE radippool SET nasipaddress = 
'172.17.5.2', pool_key = '00:40:A7:0A:8D:AC', callingstationid = 
'00:40:A7:0A:8D:AC', username = 'joaocontri', expiry_time = NOW() + 
INTERVAL 330 SECOND WHERE framedipaddress = '187.120.205.15' AND 
expiry_time = '0000-00-00 00:00:00'
rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0
(1427) sqlippool: EXPAND COMMIT
(1427) sqlippool:    --> COMMIT
(1427) sqlippool: Executing query: COMMIT
rlm_sql (sql): Released connection (0)
(1427) 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})
(1427) sqlippool:    --> Allocated IP: 187.120.205.15 from main_pool 
(did CE - POP IFA cli 00:40:A7:0A:8D:AC port 15728725 user joaocontri)
(1427)     [sqlippool] = ok
(1427)     [exec] = noop
(1427) linelog: EXPAND messages.%{%{reply:Packet-Type}:-default}
(1427) linelog:    --> messages.Access-Accept
(1427) linelog: EXPAND %t : Auth: Login OK: [%{User-Name}] (from client 
%{Called-Station-Id} port %{NAS-Port} cli %{Calling-Station-Id})
(1427) linelog:    --> Thu Aug  3 11:23:39 2017 : Auth: Login OK: 
[joaocontri] (from client CE - POP IFA port 15728725 cli 00:40:A7:0A:8D:AC)
(1427) linelog: EXPAND /var/log/radius.log
(1427) linelog:    --> /var/log/radius.log
(1427)     [linelog] = ok
(1427)   } # post-auth = ok
(1427) Login OK: [joaocontri] (from client ce-popifa-rb port 15728725 
cli 00:40:A7:0A:8D:AC)
(1427) Sent Access-Accept Id 52 from 187.120.197.140:1812 to 
172.17.5.2:36040 length 0
(1427)   Framed-Compression = Van-Jacobson-TCP-IP
(1427)   Framed-Protocol = PPP
(1427)   Framed-Routing = Broadcast-Listen
(1427)   Framed-MTU = 1500
(1427)   Service-Type = Framed-User
(1427)   Mikrotik-Rate-Limit = "300K/820k 330k/2227k 315k/1638k 54/54"
(1427)   Framed-IP-Address = 187.120.205.15
(1427) Finished request

     Thanks

Aurélio

FreeRadius 3.0.15 - Help with accounting

Aurélio de Souza Ribeiro Neto