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