FreeRadius 3.0.15 - Help with accounting

Aurélio de Souza Ribeiro Neto netolistas at mpc.com.br
Wed Aug 9 22:41:09 CEST 2017


Hi Alan,

     Problem Output:

(28461) Received Access-Request Id 185 from 172.17.43.2:54246 to 
187.120.197.140:1812 length 188
(28461)   Service-Type = Framed-User
(28461)   Framed-Protocol = PPP
(28461)   NAS-Port = 15791968
(28461)   NAS-Port-Type = Ethernet
(28461)   User-Name = "waldemarjunior"
(28461)   Calling-Station-Id = "C4:6E:1F:F3:A1:E7"
(28461)   Called-Station-Id = "CE - POP SM9"
(28461)   NAS-Port-Id = "ether9"
(28461)   MS-CHAP-Challenge = 0x2e08483252d28f89
(28461)   MS-CHAP-Response = 
0x0101000000000000000000000000000000000000000000000000d1129355aac1e4cf1c152517f5251a854ea7e18c06bb71a4
(28461)   NAS-Identifier = "CE-SM"
(28461)   NAS-IP-Address = 172.17.43.2
(28461) # Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   authorize {
(28461)     [preprocess] = ok
(28461)     [chap] = noop
(28461) mschap: Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
(28461)     [mschap] = ok
(28461) sql: EXPAND %{User-Name}
(28461) sql:    --> waldemarjunior
(28461) sql: SQL-User-Name set to 'waldemarjunior'
rlm_sql (sql): Reserved connection (0)
(28461) 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'
(28461) 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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND N.nasname = 
'172.17.43.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'waldemarjunior' AND plano_id NOT IN (8,9,793) AND gateway_id = ( SELECT 
gw_id FROM mpc_freeradius.nas WHERE nasname = '172.17.43.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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND 
M.grupocliente = 'ALL-POPS'
(28461) 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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND N.nasname = 
'172.17.43.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'waldemarjunior' AND plano_id NOT IN (8,9,793) AND gateway_id = ( SELECT 
gw_id FROM mpc_freeradius.nas WHERE nasname = '172.17.43.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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND 
M.grupocliente = 'ALL-POPS'
(28461) sql: User found in radcheck table
(28461) sql: Conditional check items matched, merging assignment check items
(28461) sql:   Simultaneous-Use := 1
(28461) sql:   Pool-Name := "main_pool"
(28461) sql:   Cleartext-Password := "32000"
(28461) 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'
(28461) 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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND N.nasname = 
'172.17.43.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'waldemarjunior' AND plano_id NOT IN (8,9,793) AND gateway_id = ( SELECT 
gw_id FROM mpc_freeradius.nas WHERE nasname = '172.17.43.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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND 
M.grupocliente = 'ALL-POPS'
(28461) 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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND N.nasname = 
'172.17.43.2'                                  AND N.gw_id = (SELECT 
gateway_id FROM mpc_lw.maclist WHERE usuario_login =  BINARY 
'waldemarjunior' AND plano_id NOT IN (8,9,793) AND gateway_id = ( SELECT 
gw_id FROM mpc_freeradius.nas WHERE nasname = '172.17.43.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 
'waldemarjunior'                                  AND M.usuario_login =  
BINARY 'waldemarjunior'                                  AND 
M.grupocliente = 'ALL-POPS'
(28461) sql: User found in radreply table, merging reply items
(28461) sql:   Simultaneous-Use := 1
(28461) sql:   Pool-Name := "main_pool"
(28461) sql:   Cleartext-Password := "32000"
(28461) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority
(28461) sql:    --> SELECT groupname FROM radusergroup WHERE username = 
'waldemarjunior' ORDER BY priority
(28461) sql: Executing select query: SELECT groupname FROM radusergroup 
WHERE username = 'waldemarjunior' ORDER BY priority
(28461) sql: User found in the group table
(28461) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM 
radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
(28461) sql:    --> SELECT id, groupname, attribute, Value, op FROM 
radgroupcheck WHERE groupname = '716' ORDER BY id
(28461) sql: Executing select query: SELECT id, groupname, attribute, 
Value, op FROM radgroupcheck WHERE groupname = '716' ORDER BY id
(28461) sql: Group "716": Conditional check items matched
(28461) sql: Group "716": Merging assignment check items
(28461) sql: EXPAND SELECT id, groupname, attribute, value, op FROM 
radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
(28461) sql:    --> SELECT id, groupname, attribute, value, op FROM 
radgroupreply WHERE groupname = '716' ORDER BY id
(28461) sql: Executing select query: SELECT id, groupname, attribute, 
value, op FROM radgroupreply WHERE groupname = '716' ORDER BY id
(28461) sql: Group "716": Merging reply items
(28461) sql:   Framed-Compression := Van-Jacobson-TCP-IP
(28461) sql:   Framed-Protocol := PPP
(28461) sql:   Framed-Routing := Broadcast-Listen
(28461) sql:   Framed-MTU := 1500
(28461) sql:   Service-Type := Framed-User
(28461) sql:   Mikrotik-Rate-Limit := "1024k/4096k 1126k/11264k 
1075k/8192k 108/108"
rlm_sql (sql): Released connection (0)
(28461)     [sql] = ok
(28461)     [expiration] = noop
(28461)     [logintime] = noop
(28461) pap: WARNING: Auth-Type already set.  Not setting to PAP
(28461)     [pap] = noop
(28461)   } # authorize = ok
(28461) Found Auth-Type = MS-CHAP
(28461) # Executing group from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   Auth-Type MS-CHAP {
(28461) mschap: Found Cleartext-Password, hashing to create NT-Password
(28461) mschap: Found Cleartext-Password, hashing to create LM-Password
(28461) mschap: Client is using MS-CHAPv1 with NT-Password
(28461) mschap: adding MS-CHAPv1 MPPE keys
(28461)     [mschap] = ok
(28461)     if (reject) {
(28461)     if (reject)  -> FALSE
(28461)   } # Auth-Type MS-CHAP = ok
(28461) # Executing section session from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   session {
(28461) sql: EXPAND %{User-Name}
(28461) sql:    --> waldemarjunior
(28461) sql: SQL-User-Name set to 'waldemarjunior'
(28461) sql: EXPAND SELECT COUNT(*) FROM 
radacct                              WHERE username = 
'%{SQL-User-Name}'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
(28461) sql:    --> SELECT COUNT(*)                              FROM 
radacct                              WHERE username = 
'waldemarjunior'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
rlm_sql (sql): Reserved connection (17)
(28461) sql: Executing select query: SELECT 
COUNT(*)                              FROM 
radacct                              WHERE username = 
'waldemarjunior'                              AND acctstoptime IS 
NULL                              AND framedipaddress NOT REGEXP '^10\.'
(28461) 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\.'
(28461) sql:    --> SELECT radacctid, acctsessionid, 
username,                                nasipaddress, nasportid, 
framedipaddress,                                callingstationid, 
framedprotocol                                FROM 
radacct                                WHERE username = 
'waldemarjunior'                                AND acctstoptime IS 
NULL                                AND framedipaddress NOT REGEXP '^10\.'
(28461) sql: Executing select query: SELECT radacctid, acctsessionid, 
username, nasipaddress, nasportid, 
framedipaddress,                                callingstationid, 
framedprotocol                                FROM 
radacct                                WHERE username = 
'waldemarjunior'                                AND acctstoptime IS 
NULL                                AND framedipaddress NOT REGEXP '^10\.'
Timeout: No Response from 172.17.43.2
(28461) sql: Running Accounting section for automatically created 
accounting 'stop'
(28461) sql:   Service-Type = Framed-User
(28461) sql:   Framed-Protocol = PPP
(28461) sql:   NAS-Port = 15791968
(28461) sql:   NAS-Port-Type = Ethernet
(28461) sql:   User-Name = "waldemarjunior"
(28461) sql:   Calling-Station-Id = "C4:6E:1F:F3:A1:E7"
(28461) sql:   Called-Station-Id = "CE - POP SM9"
(28461) sql:   NAS-Port-Id = "ether9"
(28461) sql:   MS-CHAP-Challenge = 0x2e08483252d28f89
(28461) sql:   MS-CHAP-Response = 
0x0101000000000000000000000000000000000000000000000000d1129355aac1e4cf1c152517f5251a854ea7e18c06bb71a4
(28461) sql:   NAS-Identifier = "CE-SM"
(28461) sql:   NAS-IP-Address = 172.17.43.2
(28461) sql:   Event-Timestamp = "Aug  9 2017 13:41:58 BRT"
(28461) sql:   SQL-User-Name := "waldemarjunior"
(28461) # Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   preacct {
(28461)     [preprocess] = ok
(28461)     policy acct_unique {
(28461)       update request {
(28461)         &Tmp-String-9 := "ai:"
(28461)       } # update request = noop
(28461)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && 
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(28461)       EXPAND %{hex:&Class}
(28461)          -->
(28461)       EXPAND ^%{hex:&Tmp-String-9}
(28461)          --> ^61693a
(28461)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && 
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i))  -> FALSE
(28461)       else {
(28461)         update request {
(28461)           EXPAND 
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(28461)              --> 6d3eb9c3ffe04efb05453582256f179a
(28461)           &Acct-Unique-Session-Id := 
6d3eb9c3ffe04efb05453582256f179a
(28461)         } # update request = noop
(28461)       } # else = noop
(28461)     } # policy acct_unique = noop
(28461)     [files] = noop
(28461)   } # preacct = ok
(28461) # Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   accounting {
rlm_sql (sql): Reserved connection (28)
(28461) sqlippool: EXPAND %{User-Name}
(28461) sqlippool:    --> waldemarjunior
(28461) sqlippool: SQL-User-Name set to 'waldemarjunior'
(28461) sqlippool: EXPAND START TRANSACTION
(28461) sqlippool:    --> START TRANSACTION
(28461) sqlippool: Executing query: START TRANSACTION
(28461) 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}'
(28461) sqlippool:    --> UPDATE radippool SET nasipaddress = '', 
pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE nasipaddress = '172.17.43.2' AND pool_key = 
'' AND username = 'waldemarjunior' AND callingstationid = '' AND 
framedipaddress = '187.120.206.111'
(28461) sqlippool: Executing query: UPDATE radippool SET nasipaddress = 
'', pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE nasipaddress = '172.17.43.2' AND pool_key = 
'' AND username = 'waldemarjunior' AND callingstationid = '' AND 
framedipaddress = '187.120.206.111'
rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
(28461) sqlippool: EXPAND COMMIT
(28461) sqlippool:    --> COMMIT
(28461) sqlippool: Executing query: COMMIT
(28461) sqlippool: EXPAND Released IP %{Framed-IP-Address} (did 
%{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})
(28461) sqlippool:    --> Released IP 187.120.206.111 (did cli  user 
waldemarjunior)
rlm_sql (sql): Released connection (28)
Need 1 more connections to reach 35 spares
rlm_sql (sql): Opening additional connection (38), 1 of 29 pending slots 
used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'mpc_freeradius' on 
mysql.mpc.com.br via TCP/IP, server version 5.5.57-0ubuntu0.14.04.1-log, 
protocol version 10
(28461)     [sqlippool] = ok
(28461) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(28461) sql:    --> type.stop.query
(28461) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (22)
(28461) sql: EXPAND %{User-Name}
(28461) sql:    --> waldemarjunior
(28461) sql: SQL-User-Name set to 'waldemarjunior'
(28461) 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}'
(28461) sql:    --> UPDATE radacct SET acctstoptime    = NOW(), 
acctsessiontime = 0, acctinputoctets = '0' << 32 | '0', acctoutputoctets 
= '0' << 32 | '0', acctterminatecause = '', connectinfo_stop = '' WHERE 
AcctUniqueId = '6d3eb9c3ffe04efb05453582256f179a'
(28461) sql: Executing query: UPDATE radacct SET acctstoptime    = 
NOW(), acctsessiontime = 0, acctinputoctets = '0' << 32 | '0', 
acctoutputoctets = '0' << 32 | '0', acctterminatecause = '', 
connectinfo_stop = '' WHERE AcctUniqueId = 
'6d3eb9c3ffe04efb05453582256f179a'
rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
(28461) sql: SQL query returned: success
(28461) sql: 0 record(s) updated
(28461) sql: Trying next query...
(28461) sql: EXPAND INSERT INTO radacct 
(acctsessionid,acctuniqueid,username, realm,nasipaddress,nasportid, 
nasporttype,acctstarttime,acctupdatetime, acctstoptime,acctsessiontime, 
acctauthentic, connectinfo_start,connectinfo_stop, acctinputoctets, 
acctoutputoctets,calledstationid, callingstationid, 
acctterminatecause,servicetype,framedprotocol, framedipaddress) VALUES 
('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', 
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', 
(NOW() - %{%{Acct-Session-Time}:-0}), NOW(), NOW(), 
%{%{Acct-Session-Time}:-NULL}, '%{Acct-Authentic}', '', 
'%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | 
'%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | 
'%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', 
'%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', 
'%{Framed-Protocol}', '%{Framed-IP-Address}')
(28461) sql:    --> INSERT INTO radacct 
(acctsessionid,acctuniqueid,username, realm,nasipaddress,nasportid, 
nasporttype,acctstarttime,acctupdatetime, acctstoptime,acctsessiontime, 
acctauthentic, connectinfo_start,connectinfo_stop, acctinputoctets, 
acctoutputoctets,calledstationid, callingstationid, 
acctterminatecause,servicetype,framedprotocol, framedipaddress) VALUES 
('81b0eef6', '6d3eb9c3ffe04efb05453582256f179a', 'waldemarjunior', '', 
'172.17.43.2', '15791967', '', (NOW() - 0), NOW(), NOW(), 0, '', '', '', 
'0' << 32 | '0', '0' << 32 | '0', '', '', '', 'Framed-User', 'PPP', 
'187.120.206.111')
(28461) sql: Executing query: INSERT INTO radacct 
(acctsessionid,acctuniqueid,username, realm,nasipaddress,nasportid, 
nasporttype,acctstarttime,acctupdatetime, acctstoptime,acctsessiontime, 
acctauthentic, connectinfo_start,connectinfo_stop, acctinputoctets, 
acctoutputoctets,calledstationid, callingstationid, 
acctterminatecause,servicetype,framedprotocol, framedipaddress) VALUES 
('81b0eef6', '6d3eb9c3ffe04efb05453582256f179a', 'waldemarjunior', '', 
'172.17.43.2', '15791967', '', (NOW() - 0), NOW(), NOW(), 0, '', '', '', 
'0' << 32 | '0', '0' << 32 | '0', '', '', '', 'Framed-User', 'PPP', 
'187.120.206.111')
(28461) sql: SQL query returned: success
(28461) sql: 1 record(s) updated
rlm_sql (sql): Released connection (22)
(28461)     [sql] = ok
(28461)     [exec] = noop
(28461) attr_filter.accounting_response: EXPAND %{User-Name}
(28461) attr_filter.accounting_response:    --> waldemarjunior
(28461) attr_filter.accounting_response: Matched entry DEFAULT at line 12
(28461)     [attr_filter.accounting_response] = updated
(28461) log_accounting: EXPAND 
Accounting-Request.%{%{Acct-Status-Type}:-unknown}
(28461) log_accounting:    --> Accounting-Request.Stop
(28461) log_accounting: EXPAND %t : Info: Released IP 
%{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} 
user %{User-Name})
(28461) log_accounting:    --> Wed Aug  9 13:41:58 2017 : Info: Released 
IP 187.120.206.111 (did  cli  user waldemarjunior)
(28461) log_accounting: EXPAND /var/log/radius.log
(28461) log_accounting:    --> /var/log/radius.log
(28461)     [log_accounting] = ok
(28461)   } # accounting = updated
rlm_sql (sql): Released connection (17)
(28461)     [sql] = ok
(28461)   } # session = ok
(28461) # Executing section post-auth from file 
/usr/local/etc/raddb/sites-enabled/default
(28461)   post-auth {
(28461)     update {
(28461)       No attributes updated
(28461)     } # update = noop
rlm_sql (sql): Reserved connection (7)
(28461) sqlippool: EXPAND %{User-Name}
(28461) sqlippool:    --> waldemarjunior
(28461) sqlippool: SQL-User-Name set to 'waldemarjunior'
(28461) sqlippool: EXPAND START TRANSACTION
(28461) sqlippool:    --> START TRANSACTION
(28461) sqlippool: Executing query: START TRANSACTION
(28461) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', 
pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND 
pool_key = '%{Calling-Station-Id}'
(28461) sqlippool:    --> UPDATE radippool SET nasipaddress = '', 
pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND 
pool_key = 'C4:6E:1F:F3:A1:E7'
(28461) sqlippool: Executing query: UPDATE radippool SET nasipaddress = 
'', pool_key = 0, callingstationid = '', username = '', expiry_time = 
'0000-00-00 00:00:00' WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND 
pool_key = 'C4:6E:1F:F3:A1:E7'
rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
(28461) sqlippool: EXPAND COMMIT
(28461) sqlippool:    --> COMMIT
(28461) sqlippool: Executing query: COMMIT
(28461) sqlippool: EXPAND START TRANSACTION
(28461) sqlippool:    --> START TRANSACTION
(28461) sqlippool: Executing query: START TRANSACTION
(28461) 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
(28461) sqlippool:    --> SELECT framedipaddress FROM radippool WHERE 
pool_name = 'main_pool' AND  expiry_time = '0000-00-00 00:00:00' ORDER 
BY (username <> 'waldemarjunior'), (callingstationid <> 
'C4:6E:1F:F3:A1:E7'), expiry_time LIMIT 1 FOR UPDATE
(28461) 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 <> 'waldemarjunior'), (callingstationid <> 
'C4:6E:1F:F3:A1:E7'), expiry_time LIMIT 1 FOR UPDATE
(28461) sqlippool: Allocated IP 187.120.205.26
(28461) 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.26' AND expiry_time = '0000-00-00 00:00:00'
(28461) sqlippool:    --> UPDATE radippool SET nasipaddress = 
'172.17.43.2', pool_key = 'C4:6E:1F:F3:A1:E7', callingstationid = 
'C4:6E:1F:F3:A1:E7', username = 'waldemarjunior', expiry_time = NOW() + 
INTERVAL 330 SECOND WHERE framedipaddress = '187.120.205.26' AND 
expiry_time = '0000-00-00 00:00:00'
(28461) sqlippool: Executing query: UPDATE radippool SET nasipaddress = 
'172.17.43.2', pool_key = 'C4:6E:1F:F3:A1:E7', callingstationid = 
'C4:6E:1F:F3:A1:E7', username = 'waldemarjunior', expiry_time = NOW() + 
INTERVAL 330 SECOND WHERE framedipaddress = '187.120.205.26' AND 
expiry_time = '0000-00-00 00:00:00'
rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0
(28461) sqlippool: EXPAND COMMIT
(28461) sqlippool:    --> COMMIT
(28461) sqlippool: Executing query: COMMIT
rlm_sql (sql): Released connection (7)
(28461) 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})
(28461) sqlippool:    --> Allocated IP: 187.120.205.26 from main_pool 
(did CE - POP SM9 cli C4:6E:1F:F3:A1:E7 port 15791968 user waldemarjunior)
(28461)     [sqlippool] = ok
(28461)     [exec] = noop
(28461) linelog: EXPAND messages.%{%{reply:Packet-Type}:-default}
(28461) linelog:    --> messages.Access-Accept
(28461) linelog: EXPAND %t : Auth: Login OK: [%{User-Name}] (from client 
%{Called-Station-Id} port %{NAS-Port} cli %{Calling-Station-Id})
(28461) linelog:    --> Wed Aug  9 13:41:58 2017 : Auth: Login OK: 
[waldemarjunior] (from client CE - POP SM9 port 15791968 cli 
C4:6E:1F:F3:A1:E7)
(28461) linelog: EXPAND /var/log/radius.log
(28461) linelog:    --> /var/log/radius.log
(28461)     [linelog] = ok
(28461)   } # post-auth = ok
(28461) Login OK: [waldemarjunior] (from client ce-popsm-rb port 
15791968 cli C4:6E:1F:F3:A1:E7)
(28461) Sent Access-Accept Id 185 from 187.120.197.140:1812 to 
172.17.43.2:54246 length 0
(28461)   Framed-Compression = Van-Jacobson-TCP-IP
(28461)   Framed-Protocol = PPP
(28461)   Framed-Routing = Broadcast-Listen
(28461)   Framed-MTU = 1500
(28461)   Service-Type = Framed-User
(28461)   Mikrotik-Rate-Limit = "1024k/4096k 1126k/11264k 1075k/8192k 
108/108"
(28461)   MS-CHAP-MPPE-Keys = 
0x4147ceeab03cfcd0aa376984106901b2657866f8bd83948f
(28461)   MS-MPPE-Encryption-Policy = Encryption-Allowed
(28461)   MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
(28461)   Framed-IP-Address = 187.120.205.26
(28461) Finished request



     Thanks

Aurelio






Em 08/08/2017 17:32, Alan Buxey escreveu:
> Provide the output, that's why we ask you to run out that way. We can't
> just work on guesswork and if you've read, seen and understood the output
> then you don't need our help ;)
>
> alan
>
> On 8 Aug 2017 9:21 pm, "Aurélio de Souza Ribeiro Neto" <
> netolistas at mpc.com.br> wrote:
>
> Fajar,
>
>      I use  -X mode and my NAS send a complete information.
>
>      In the same request I got an "invalid" insert and the I receive a valid
> insert.
>
>      In the same NAS I have about 400 users and one or other have a "wrong"
> insert!!
>
>      In FreeRadius 2.2.9 I don't have this problem.
>
>      I know.... this is not a FreeRadius problem, but I want a hint  to
> solve this!
>
>      Thanks
>
>
>
> Em 08/08/2017 12:11, Fajar A. Nugraha escreveu:
>
>> On Tue, Aug 8, 2017 at 8:04 PM, Aurélio de Souza Ribeiro Neto
>> <netolistas at mpc.com.br> wrote:
>>
>>> Fajar,
>>>
>>>       I did and not appear to be a Query problem.
>>>
>>>       Look the first and the second insert:
>>>
>>> INSERT INTO radacct (acctsessionid, acctuniqueid,           username,
>>> realm,
>>> nasipaddress,           nasportid, nasporttype,
>>>                   acctstarttime,          acctupdatetime, acctstoptime,
>>> acctsessiontime,        acctauthentic, connectinfo_start,
>>> connectinfo_stop,
>>>           acctinputoctets, acctoutputoctets, calledstationid,
>>> callingstationid, acctterminatecause, servicetype,
>>> framedprotocol, framedipaddress)
>>> VALUES ('81b0ec6b', '1e485bcb3cfbe8526b33e4d1fb50fecd', 'katiasantos',
>>> '',
>>> '172.17.43.2', '15791310', '', (NOW() - 0), NOW(), NOW(), 0, '', '', '',
>>> '0'
>>> << 32 | '0', '0'
>>> 'Framed-User', 'PPP', '187.120.203.169');
>>>
>>>
>>> INSERT INTO radacct (acctsessionid, acctuniqueid,           username,
>>> realm,
>>> nasipaddress,           nasportid, nasporttype,
>>>                   acctstarttime,          acctupdatetime, acctstoptime,
>>> acctsessiontime,        acctauthentic, connectinfo_start,
>>> connectinfo_stop,
>>>           acctinputoctets, acctoutputoctets, calledstationid,
>>> callingstationid, acctterminatecause, servicetype,
>>> framedprotocol, framedipaddress)
>>>    VALUES ('81b0ecc1', '5b68881f4438da10588f26dbe616c917', 'katiasantos',
>>> '',
>>> '172.17.43.2', '15791396', 'Ethernet', NOW(), NOW(), NULL, '0', 'RADIUS',
>>> '', '', '0', '0',
>>>    'CE - POP SM8', '1C:7E:E5:C4:2E:73', '', 'Framed-User', 'PPP',
>>> '187.120.203.169');
>>>
>>>       What I can do?
>>>
>> Then you need to capture what the NAS send when this happens. On the
>> first insert, FR believes that the NAS is not sending nasporttype and
>> callingstationid. 'freeradius -X' can show you what FR receives (I did
>> not see accounting request on your original dump, only
>> Access-Request).
>>
>> Again, my GUESS is the NAS sends it that way. In which case you need
>> to ask whoever configured the NAS (or its creators) why it sends that.
>>
>>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list
> /users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html






More information about the Freeradius-Users mailing list