Hint - (automatically created accounting 'stop')

13 Sep 2017


      Hello All,
       Someone can give me a hint?

       Sometimes I can see this info in my Logs:
       sql: Running Accounting section for automatically created
   accounting 'stop'
       After this I have this incomplete register in my database without
   naporttype and callingstationid. Why??


   radacctid acctsessionid acctuniqueid username groupname realm
   nasipaddress nasportid nasporttype acctstarttime acctupdatetime
   acctstoptime acctinterval acctsessiontime acctauthentic
   connectinfo_start connectinfo_stop acctinputoctets acctoutputoctets
   calledstationid callingstationid acctterminatecause servicetype
   framedprotocol framedipaddress acctstartdelay acctstopdelay
   xascendsessionsvrkey
   676589 81c00242 69bee70f31ad12b1d7df868bb5caf780 simonecarlos
   172.17.30.2 15729235
   2017-09-11 09:48:58 2017-09-11 09:48:58 2017-09-11 09:48:58 NULL 0
   0 0
   Framed-User PPP 187.120.205.22 NULL NULL NULL

       Here is the complete log:

   Ready to process requests
   (8023) Received Access-Request Id 212 from 172.17.60.2:34960 to
   187.120.197.140:1812 length 191
   (8023)   Service-Type = Framed-User
   (8023)   Framed-Protocol = PPP
   (8023)   NAS-Port = 15729185
   (8023)   NAS-Port-Type = Ethernet
   (8023)   User-Name = "flaviasilva"
   (8023)   Calling-Station-Id = "00:1A:3F:A0:B1:D2"
   (8023)   Called-Station-Id = "CE - POP ABTE"
   (8023)   NAS-Port-Id = "bridge1"
   (8023)   MS-CHAP-Challenge = 0xd0033cbd3739184c
   (8023)   MS-CHAP-Response =
   0x0101000000000000000000000000000000000000000000000000c1f75534b802f945e
   5ee4707ecd8b790709253be2ca90ce6
   (8023)   NAS-Identifier = "CE-ABAETE"
   (8023)   NAS-IP-Address = 172.17.60.2
   (8023) # Executing section authorize from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   authorize {
   (8023)     [preprocess] = ok
   (8023)     [chap] = noop
   (8023) mschap: Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
   (8023)     [mschap] = ok
   (8023) sql: EXPAND %{User-Name}
   (8023) sql:    --> flaviasilva
   (8023) sql: SQL-User-Name set to 'flaviasilva'
   rlm_sql (sql): Reserved connection (30)
   (8023) 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'
   (8023) 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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND N.nasname =
   '172.17.60.2'                                  AND N.gw_id = (SELECT
   gateway_id                                                       FROM
   mpc_lw.maclist
   WHERE usuario_login =  BINARY
   'flaviasilva'                                                       AND
   plano_id NOT IN
   (8,9,793)                                                       AND
   gateway_id = ( SELECT gw_id FROM
   mpc_freeradius.nas
                          WHERE nasname =
   '172.17.60.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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND
   M.grupocliente = 'ALL-POPS'
   (8023) 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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND N.nasname =
   '172.17.60.2'                                  AND N.gw_id = (SELECT
   gateway_id                                                       FROM
   mpc_lw.maclist
   WHERE usuario_login =  BINARY
   'flaviasilva'                                                       AND
   plano_id NOT IN
   (8,9,793)                                                       AND
   gateway_id = ( SELECT gw_id FROM
   mpc_freeradius.nas
                          WHERE nasname =
   '172.17.60.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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND
   M.grupocliente = 'ALL-POPS'
   (8023) sql: User found in radcheck table
   (8023) sql: Conditional check items matched, merging assignment check
   items
   (8023) sql:   Simultaneous-Use := 1
   (8023) sql:   Pool-Name := "main_pool"
   (8023) sql:   Cleartext-Password := "FS189"
   (8023) 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'
   (8023) 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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND N.nasname =
   '172.17.60.2'                                  AND N.gw_id = (SELECT
   gateway_id                                                       FROM
   mpc_lw.maclist
   WHERE usuario_login =  BINARY
   'flaviasilva'                                                       AND
   plano_id NOT IN
   (8,9,793)                                                       AND
   gateway_id = ( SELECT
   gw_id
             FROM
   mpc_freeradius.nas
                          WHERE nasname =
   '172.17.60.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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND
   M.grupocliente = 'ALL-POPS'
   (8023) 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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND N.nasname =
   '172.17.60.2'                                  AND N.gw_id = (SELECT
   gateway_id                                                       FROM
   mpc_lw.maclist
   WHERE usuario_login =  BINARY
   'flaviasilva'                                                       AND
   plano_id NOT IN
   (8,9,793)                                                       AND
   gateway_id = ( SELECT
   gw_id
             FROM
   mpc_freeradius.nas
                          WHERE nasname =
   '172.17.60.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
   'flaviasilva'                                  AND M.usuario_login =
   BINARY 'flaviasilva'                                  AND
   M.grupocliente = 'ALL-POPS'
   (8023) sql: User found in radreply table, merging reply items
   (8023) sql:   Simultaneous-Use := 1
   (8023) sql:   Pool-Name := "main_pool"
   (8023) sql:   Cleartext-Password := "FS189"
   (8023) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
   '%{SQL-User-Name}' ORDER BY priority
   (8023) sql:    --> SELECT groupname FROM radusergroup WHERE username =
   'flaviasilva' ORDER BY priority
   (8023) sql: Executing select query: SELECT groupname FROM radusergroup
   WHERE username = 'flaviasilva' ORDER BY priority
   (8023) sql: User found in the group table
   (8023) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM
   radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
   (8023) sql:    --> SELECT id, groupname, attribute, Value, op FROM
   radgroupcheck WHERE groupname = '715' ORDER BY id
   (8023) sql: Executing select query: SELECT id, groupname, attribute,
   Value, op FROM radgroupcheck WHERE groupname = '715' ORDER BY id
   (8023) sql: Group "715": Conditional check items matched
   (8023) sql: Group "715": Merging assignment check items
   (8023) sql: EXPAND SELECT id, groupname, attribute, value, op FROM
   radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
   (8023) sql:    --> SELECT id, groupname, attribute, value, op FROM
   radgroupreply WHERE groupname = '715' ORDER BY id
   (8023) sql: Executing select query: SELECT id, groupname, attribute,
   value, op FROM radgroupreply WHERE groupname = '715' ORDER BY id
   (8023) sql: Group "715": Merging reply items
   (8023) sql:   Framed-Compression := Van-Jacobson-TCP-IP
   (8023) sql:   Framed-Protocol := PPP
   (8023) sql:   Framed-Routing := Broadcast-Listen
   (8023) sql:   Framed-MTU := 1500
   (8023) sql:   Service-Type := Framed-User
   (8023) sql:   Mikrotik-Rate-Limit := "500k/2048k 563k/5632k 538k/4096k
   54/54"
   rlm_sql (sql): Released connection (30)
   (8023)     [sql] = ok
   (8023)     [expiration] = noop
   (8023)     [logintime] = noop
   (8023) pap: WARNING: Auth-Type already set.  Not setting to PAP
   (8023)     [pap] = noop
   (8023)   } # authorize = ok
   (8023) Found Auth-Type = MS-CHAP
   (8023) # Executing group from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   Auth-Type MS-CHAP {
   (8023) mschap: Found Cleartext-Password, hashing to create NT-Password
   (8023) mschap: Found Cleartext-Password, hashing to create LM-Password
   (8023) mschap: Client is using MS-CHAPv1 with NT-Password
   (8023) mschap: adding MS-CHAPv1 MPPE keys
   (8023)     [mschap] = ok
   (8023)     if (reject) {
   (8023)     if (reject)  -> FALSE
   (8023)   } # Auth-Type MS-CHAP = ok
   (8023) # Executing section session from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   session {
   (8023) sql: EXPAND %{User-Name}
   (8023) sql:    --> flaviasilva
   (8023) sql: SQL-User-Name set to 'flaviasilva'
   (8023) sql: EXPAND SELECT COUNT(*)                              FROM
   radacct                              WHERE username =
   '%{SQL-User-Name}'                              AND acctstoptime IS
   NULL                              AND framedipaddress NOT REGEXP
   '^10\.'
   (8023) sql:    --> SELECT COUNT(*)                              FROM
   radacct                              WHERE username =
   'flaviasilva'                              AND acctstoptime IS
   NULL                              AND framedipaddress NOT REGEXP
   '^10\.'
   rlm_sql (sql): Reserved connection (17)
   (8023) sql: Executing select query: SELECT
   COUNT(*)                              FROM
   radacct                              WHERE username =
   'flaviasilva'                              AND acctstoptime IS
   NULL                              AND framedipaddress NOT REGEXP
   '^10\.'
   (8023) 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\.'
   (8023) sql:    --> SELECT radacctid, acctsessionid,
   username,                                nasipaddress, nasportid,
   framedipaddress,                                callingstationid,
   framedprotocol                                FROM
   radacct                                WHERE username =
   'flaviasilva'                                AND acctstoptime IS
   NULL                                AND framedipaddress NOT REGEXP
   '^10\.'
   (8023) sql: Executing select query: SELECT radacctid, acctsessionid,
   username,                                nasipaddress, nasportid,
   framedipaddress,                                callingstationid,
   framedprotocol                                FROM
   radacct                                WHERE username =
   'flaviasilva'                                AND acctstoptime IS
   NULL                                AND framedipaddress NOT REGEXP
   '^10\.'
   (8023) sql: Running Accounting section for automatically created
   accounting 'stop'
   (8023) sql:   Service-Type = Framed-User
   (8023) sql:   Framed-Protocol = PPP
   (8023) sql:   NAS-Port = 15729185
   (8023) sql:   NAS-Port-Type = Ethernet
   (8023) sql:   User-Name = "flaviasilva"
   (8023) sql:   Calling-Station-Id = "00:1A:3F:A0:B1:D2"
   (8023) sql:   Called-Station-Id = "CE - POP ABTE"
   (8023) sql:   NAS-Port-Id = "bridge1"
   (8023) sql:   MS-CHAP-Challenge = 0xd0033cbd3739184c
   (8023) sql:   MS-CHAP-Response =
   0x0101000000000000000000000000000000000000000000000000c1f75534b802f945e
   5ee4707ecd8b790709253be2ca90ce6
   (8023) sql:   NAS-Identifier = "CE-ABAETE"
   (8023) sql:   NAS-IP-Address = 172.17.60.2
   (8023) sql:   Event-Timestamp = "Sep 11 2017 11:07:05 BRT"
   (8023) sql:   SQL-User-Name := "flaviasilva"
   (8023) # Executing section preacct from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   preacct {
   (8023)     [preprocess] = ok
   (8023)     policy acct_unique {
   (8023)       update request {
   (8023)         &Tmp-String-9 := "ai:"
   (8023)       } # update request = noop
   (8023)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
   ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
   (8023)       EXPAND %{hex:&Class}
   (8023)          -->
   (8023)       EXPAND ^%{hex:&Tmp-String-9}
   (8023)          --> ^61693a
   (8023)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
   ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i))  -> FALSE
   (8023)       else {
   (8023)         update request {
   (8023)           EXPAND
   %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-A
   ddress}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
   (8023)              --> a3978be96deadcc79c5b59c0df7462f6
   (8023)           &Acct-Unique-Session-Id :=
   a3978be96deadcc79c5b59c0df7462f6
   (8023)         } # update request = noop
   (8023)       } # else = noop
   (8023)     } # policy acct_unique = noop
   (8023)     [files] = noop
   (8023)   } # preacct = ok
   (8023) # Executing section accounting from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   accounting {
   (8023) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
   (8023) sql:    --> type.stop.query
   (8023) sql: Using query template 'query'
   rlm_sql (sql): Reserved connection (31)
   (8023) sql: EXPAND %{User-Name}
   (8023) sql:    --> flaviasilva
   (8023) sql: SQL-User-Name set to 'flaviasilva'
   (8023) 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}'
   (8023) sql:    --> UPDATE radacct SET acctstoptime    = NOW(),
   acctsessiontime = 0, acctinputoctets = '0' << 32 | '0',
   acctoutputoctets = '0' << 32 | '0', acctterminatecause = '',
   connectinfo_stop = '' WHERE AcctUniqueId =
   'a3978be96deadcc79c5b59c0df7462f6'
   (8023) sql: Executing query: UPDATE radacct SET acctstoptime    =
   NOW(), acctsessiontime = 0, acctinputoctets = '0' << 32 | '0',
   acctoutputoctets = '0' << 32 | '0', acctterminatecause = '',
   connectinfo_stop = '' WHERE AcctUniqueId =
   'a3978be96deadcc79c5b59c0df7462f6'
   rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
   (8023) sql: SQL query returned: success
   (8023) sql: 0 record(s) updated
   (8023) sql: Trying next query...
   (8023) 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}')
   (8023) 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
   ('81f001e1', 'a3978be96deadcc79c5b59c0df7462f6', 'flaviasilva', '',
   '172.17.60.2', '15729147', '', (NOW() - 0), NOW(), NOW(), 0, '', '',
   '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', 'Framed-User', 'PPP',
   '187.120.206.211')
   (8023) 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
   ('81f001e1', 'a3978be96deadcc79c5b59c0df7462f6', 'flaviasilva', '',
   '172.17.60.2', '15729147', '', (NOW() - 0), NOW(), NOW(), 0, '', '',
   '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', 'Framed-User', 'PPP',
   '187.120.206.211')
   (8023) sql: SQL query returned: success
   (8023) sql: 1 record(s) updated
   rlm_sql (sql): Released connection (31)
   Need 1 more connections to reach 35 spares
   rlm_sql (sql): Opening additional connection (36), 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
   (8023)     [sql] = ok
   (8023)     [exec] = noop
   (8023) attr_filter.accounting_response: EXPAND %{User-Name}
   (8023) attr_filter.accounting_response:    --> flaviasilva
   (8023) attr_filter.accounting_response: Matched entry DEFAULT at line
   12
   (8023)     [attr_filter.accounting_response] = updated
   (8023) log_accounting: EXPAND
   Accounting-Request.%{%{Acct-Status-Type}:-unknown}
   (8023) log_accounting:    --> Accounting-Request.Stop
   (8023) log_accounting: EXPAND %t : Info: Released IP
   %{Framed-IP-Address} (did %{Called-Station-Id} cli
   %{Calling-Station-Id} user %{User-Name})
   (8023) log_accounting:    --> Mon Sep 11 11:07:05 2017 : Info: Released
   IP 187.120.206.211 (did  cli  user flaviasilva)
   (8023) log_accounting: EXPAND /var/log/radius.log
   (8023) log_accounting:    --> /var/log/radius.log
   (8023)     [log_accounting] = ok
   (8023)   } # accounting = updated
   rlm_sql (sql): Released connection (17)
   (8023)     [sql] = ok
   (8023)   } # session = ok
   (8023) # Executing section post-auth from file
   /usr/local/etc/raddb/sites-enabled/default
   (8023)   post-auth {
   (8023)     update {
   (8023)       No attributes updated
   (8023)     } # update = noop
   rlm_sql (sql): Reserved connection (4)
   (8023) sqlippool: EXPAND %{User-Name}
   (8023) sqlippool:    --> flaviasilva
   (8023) sqlippool: SQL-User-Name set to 'flaviasilva'
   (8023) sqlippool: EXPAND START TRANSACTION
   (8023) sqlippool:    --> START TRANSACTION
   (8023) sqlippool: Executing query: START TRANSACTION
   (8023) 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}'
   (8023) 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 = '00:1A:3F:A0:B1:D2'
   (8023) 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 = '00:1A:3F:A0:B1:D2'
   rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0
   (8023) sqlippool: EXPAND COMMIT
   (8023) sqlippool:    --> COMMIT
   (8023) sqlippool: Executing query: COMMIT
   (8023) sqlippool: EXPAND START TRANSACTION
   (8023) sqlippool:    --> START TRANSACTION
   (8023) sqlippool: Executing query: START TRANSACTION
   (8023) 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
   (8023) sqlippool:    --> SELECT framedipaddress FROM radippool WHERE
   pool_name = 'main_pool' AND  expiry_time = '0000-00-00 00:00:00' ORDER
   BY (username <> 'flaviasilva'), (callingstationid <>
   '00:1A:3F:A0:B1:D2'), expiry_time LIMIT 1 FOR UPDATE
   (8023) 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 <> 'flaviasilva'), (callingstationid <>
   '00:1A:3F:A0:B1:D2'), expiry_time LIMIT 1 FOR UPDATE
   (8023) sqlippool: Allocated IP 187.120.203.66
   (8023) 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 3600 SECOND WHERE framedipaddress =
   '187.120.203.66' AND expiry_time = '0000-00-00 00:00:00'
   (8023) sqlippool:    --> UPDATE radippool SET nasipaddress =
   '172.17.60.2', pool_key = '00:1A:3F:A0:B1:D2', callingstationid =
   '00:1A:3F:A0:B1:D2', username = 'flaviasilva', expiry_time = NOW() +
   INTERVAL 3600 SECOND WHERE framedipaddress = '187.120.203.66' AND
   expiry_time = '0000-00-00 00:00:00'
   (8023) sqlippool: Executing query: UPDATE radippool SET nasipaddress =
   '172.17.60.2', pool_key = '00:1A:3F:A0:B1:D2', callingstationid =
   '00:1A:3F:A0:B1:D2', username = 'flaviasilva', expiry_time = NOW() +
   INTERVAL 3600 SECOND WHERE framedipaddress = '187.120.203.66' AND
   expiry_time = '0000-00-00 00:00:00'
   rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0
   (8023) sqlippool: EXPAND COMMIT
   (8023) sqlippool:    --> COMMIT
   (8023) sqlippool: Executing query: COMMIT
   rlm_sql (sql): Released connection (4)
   (8023) 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})
   (8023) sqlippool:    --> Allocated IP: 187.120.203.66 from main_pool
   (did CE - POP ABTE cli 00:1A:3F:A0:B1:D2 port 15729185 user
   flaviasilva)
   (8023)     [sqlippool] = ok
   (8023) sql: EXPAND .query
   (8023) sql:    --> .query
   (8023) sql: Using query template 'query'
   rlm_sql (sql): Reserved connection (0)
   (8023) sql: EXPAND %{User-Name}
   (8023) sql:    --> flaviasilva
   (8023) sql: SQL-User-Name set to 'flaviasilva'
   (8023) sql: EXPAND INSERT INTO radpostauth (username, pass, reply,
   authdate) VALUES ( '%{SQL-User-Name}',
   '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
   (8023) sql:    --> INSERT INTO radpostauth (username, pass, reply,
   authdate) VALUES ( 'flaviasilva', '', 'Access-Accept', '2017-09-11
   11:07:05')
   (8023) sql: Executing query: INSERT INTO radpostauth (username, pass,
   reply, authdate) VALUES ( 'flaviasilva', '', 'Access-Accept',
   '2017-09-11 11:07:05')
   (8023) sql: SQL query returned: success
   (8023) sql: 1 record(s) updated
   rlm_sql (sql): Released connection (0)
   (8023)     [sql] = ok
   (8023)     [exec] = noop
   (8023) linelog: EXPAND messages.%{%{reply:Packet-Type}:-default}
   (8023) linelog:    --> messages.Access-Accept
   (8023) linelog: EXPAND %t : Auth: Login OK: [%{User-Name}] (from client
   %{Called-Station-Id} port %{NAS-Port} cli %{Calling-Station-Id})
   (8023) linelog:    --> Mon Sep 11 11:07:05 2017 : Auth: Login OK:
   [flaviasilva] (from client CE - POP ABTE port 15729185 cli
   00:1A:3F:A0:B1:D2)
   (8023) linelog: EXPAND /var/log/radius.log
   (8023) linelog:    --> /var/log/radius.log
   (8023)     [linelog] = ok
   (8023)   } # post-auth = ok
   (8023) Login OK: [flaviasilva] (from client ce-popabte-rb port 15729185
   cli 00:1A:3F:A0:B1:D2)
   (8023) Sent Access-Accept Id 212 from 187.120.197.140:1812 to
   172.17.60.2:34960 length 0
   (8023)   Framed-Compression = Van-Jacobson-TCP-IP
   (8023)   Framed-Protocol = PPP
   (8023)   Framed-Routing = Broadcast-Listen
   (8023)   Framed-MTU = 1500
   (8023)   Service-Type = Framed-User
   (8023)   Mikrotik-Rate-Limit = "500k/2048k 563k/5632k 538k/4096k 54/54"
   (8023)   MS-CHAP-MPPE-Keys =
   0xad5bd30f071d877fa66cd825e53c163d6c9530b38f7c0ce6
   (8023)   MS-MPPE-Encryption-Policy = Encryption-Allowed
   (8023)   MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
   (8023)   Framed-IP-Address = 187.120.203.66
   (8023) Finished request

Hint - (automatically created accounting 'stop')

Aurélio de Souza Ribeiro Neto