Freeradius Not working with Bits limit for Hotspots
Jahans Solutions
jahans.solutions at gmail.com
Mon Jul 5 17:49:37 CEST 2021
Hi
I have acquired a freeradius server which i currently manage. I am facing
some issues with it. All hotspot users are getting disconnected after using
2gb. As per debug what i have seen is that freeradius is receiving an
attribute Mikrotik-Total-Limit with 2147483648 I cannot find where this
attribute is coming from.. Also there is no Mikrotik-Total-Limit on
radgroupreply. It is driving me crazy. Can someone help me with this? I
have attached three debug reports. Thanks in advance. Regards
-------------- next part --------------
Mon Jul 5 17:56:17 2021 : Info: Ready to process requests
Mon Jul 5 17:58:42 2021 : Debug: (5) Received Access-Request Id 46 from 103.136 .204.45:49215 to 172.26.11.27:1812 length 216
Mon Jul 5 17:58:42 2021 : Debug: (5) NAS-Port-Type = Wireless-802.11
Mon Jul 5 17:58:42 2021 : Debug: (5) Calling-Station-Id = "00:0C:29:D6:B8:A6"
Mon Jul 5 17:58:42 2021 : Debug: (5) Called-Station-Id = "hotspot1"
Mon Jul 5 17:58:42 2021 : Debug: (5) NAS-Port-Id = "ether3-LAN"
Mon Jul 5 17:58:42 2021 : Debug: (5) User-Name = "06767"
Mon Jul 5 17:58:42 2021 : Debug: (5) NAS-Port = 2149580827
Mon Jul 5 17:58:42 2021 : Debug: (5) Acct-Session-Id = "8020001b"
Mon Jul 5 17:58:42 2021 : Debug: (5) Framed-IP-Address = 192.168.251.117
Mon Jul 5 17:58:42 2021 : Debug: (5) Mikrotik-Host-IP = 192.168.251.117
Mon Jul 5 17:58:42 2021 : Debug: (5) CHAP-Challenge = 0x0aef2a23b7227cc495ba3 4eef3a51d23
Mon Jul 5 17:58:42 2021 : Debug: (5) CHAP-Password = 0x8d3594bf6b78b066c3cef4 270b0505695a
Mon Jul 5 17:58:42 2021 : Debug: (5) Service-Type = Login-User
Mon Jul 5 17:58:42 2021 : Debug: (5) WISPr-Logoff-URL = "http://192.168.251.2 54/logout"
Mon Jul 5 17:58:42 2021 : Debug: (5) NAS-Identifier = "Nayeem-R1-CoreRouter"
Mon Jul 5 17:58:42 2021 : Debug: (5) NAS-IP-Address = 192.168.31.77
Mon Jul 5 17:58:42 2021 : Debug: (5) session-state: No State attribute
Mon Jul 5 17:58:42 2021 : Debug: (5) # Executing section authorize from file /e tc/freeradius/3.0/sites-enabled/default
Mon Jul 5 17:58:42 2021 : Debug: (5) authorize {
Mon Jul 5 17:58:42 2021 : Debug: (5) policy filter_username {
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name) {
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name) -> TRUE
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name) {
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ / /) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ / /) -> FALSE
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /\.\./ ) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /\.\./ ) -> FAL SE
Mon Jul 5 17:58:42 2021 : Debug: (5) if ((&User-Name =~ /@/) && (&User- Name !~ /@(.+)\.(.+)$/)) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if ((&User-Name =~ /@/) && (&User- Name !~ /@(.+)\.(.+)$/)) -> FALSE
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /\.$/) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /\.$/) -> FALS E
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /@\./) {
Mon Jul 5 17:58:42 2021 : Debug: No matches
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&User-Name =~ /@\./) -> FALS E
Mon Jul 5 17:58:42 2021 : Debug: (5) } # if (&User-Name) = notfound
Mon Jul 5 17:58:42 2021 : Debug: (5) } # policy filter_username = notfound
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling preproce ss (rlm_preprocess)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from pr eprocess (rlm_preprocess)
Mon Jul 5 17:58:42 2021 : Debug: (5) [preprocess] = ok
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling chap (rl m_chap)
Mon Jul 5 17:58:42 2021 : Debug: (5) chap: &control:Auth-Type := CHAP
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from ch ap (rlm_chap)
Mon Jul 5 17:58:42 2021 : Debug: (5) [chap] = ok
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling mschap ( rlm_mschap)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from ms chap (rlm_mschap)
Mon Jul 5 17:58:42 2021 : Debug: (5) [mschap] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling digest ( rlm_digest)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from di gest (rlm_digest)
Mon Jul 5 17:58:42 2021 : Debug: (5) [digest] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling suffix ( rlm_realm)
Mon Jul 5 17:58:42 2021 : Debug: (5) suffix: Checking for suffix after "@"
Mon Jul 5 17:58:42 2021 : Debug: (5) suffix: No '@' in User-Name = "06767", loo king up realm NULL
Mon Jul 5 17:58:42 2021 : Debug: (5) suffix: No such realm "NULL"
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from su ffix (rlm_realm)
Mon Jul 5 17:58:42 2021 : Debug: (5) [suffix] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling eap (rlm _eap)
Mon Jul 5 17:58:42 2021 : Debug: (5) eap: No EAP-Message, not doing EAP
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from ea p (rlm_eap)
Mon Jul 5 17:58:42 2021 : Debug: (5) [eap] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling files (r lm_files)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from fi les (rlm_files)
Mon Jul 5 17:58:42 2021 : Debug: (5) [files] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling sql (rlm _sql)
Mon Jul 5 17:58:42 2021 : Debug: %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> 06767
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:58:42 2021 : Info: rlm_sql (sql): Closing connection (11): Hit idl e_timeout, was idle for 145 seconds
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): You probably need to lower "min "
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Socket destructor called, closi ng socket
Mon Jul 5 17:58:42 2021 : Info: rlm_sql (sql): Closing connection (12): Hit idl e_timeout, was idle for 145 seconds
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): You probably need to lower "min "
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Socket destructor called, closi ng socket
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
Mon Jul 5 17:58:42 2021 : Info: rlm_sql (sql): Opening additional connection (1 3), 1 of 32 pending slots used
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Starting connect to MySQL serve r
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.34-0ubuntu0.18.04.1, protocol v ersion 10
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Reserved connection (13)
Mon Jul 5 17:58:42 2021 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT id, username, attribute, va lue, op FROM radcheck WHERE username = '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:58:42 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND SELECT id, username, attribute , value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> SELECT id, username, attribute , value, op FROM radcheck WHERE username = '06767' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing select query: SELECT id, us ername, attribute, value, op FROM radcheck WHERE username = '06767' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: User found in radcheck table
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Conditional check items matched, merg ing assignment check items
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Cleartext-Password := "12411"
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: FROM 1 TO 1 MAX 2
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Cleartext-Password
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Cleartext-Password FROM 0 TO 1
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: TO in 1 out 1
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: to[0] = Auth-Type
Mon Jul 5 17:58:42 2021 : Debug: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT id, username, attribute, va lue, op FROM radreply WHERE username = '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:58:42 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND SELECT id, username, attribute , value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> SELECT id, username, attribute , value, op FROM radreply WHERE username = '06767' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing select query: SELECT id, us ername, attribute, value, op FROM radreply WHERE username = '06767' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ... falling-through to group processi ng
Mon Jul 5 17:58:42 2021 : Debug: SELECT groupname FROM radusergroup WHERE usern ame = '%{SQL-User-Name}' ORDER BY priority
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:58:42 2021 : Debug: literal --> ' ORDER BY priority
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND SELECT groupname FROM raduserg roup WHERE username = '%{SQL-User-Name}' ORDER BY priority
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> SELECT groupname FROM raduserg roup WHERE username = '06767' ORDER BY priority
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing select query: SELECT groupn ame FROM radusergroup WHERE username = '06767' ORDER BY priority
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: User found in the group table
Mon Jul 5 17:58:42 2021 : Debug: SELECT id, groupname, attribute, Value, op FRO M radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT id, groupname, attribute, V alue, op FROM radgroupcheck WHERE groupname = '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-Group
Mon Jul 5 17:58:42 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND SELECT id, groupname, attribut e, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> SELECT id, groupname, attribut e, Value, op FROM radgroupcheck WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing select query: SELECT id, gr oupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Group "HSP6G-20day": Conditional chec k items matched
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Group "HSP6G-20day": Merging assignme nt check items
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Max-All-MB := 2147483648
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Max-All-Session := 1728000
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: FROM 2 TO 2 MAX 4
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Max-All-MB
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Max-All-MB FROM 0 TO 2
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Max-All-Session
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Max-All-Session FROM 1 TO 2
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: TO in 2 out 2
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: to[0] = Auth-Type
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: to[1] = Cleartext-Password
Mon Jul 5 17:58:42 2021 : Debug: SELECT id, groupname, attribute, value, op FRO M radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT id, groupname, attribute, v alue, op FROM radgroupreply WHERE groupname = '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-Group
Mon Jul 5 17:58:42 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND SELECT id, groupname, attribut e, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> SELECT id, groupname, attribut e, value, op FROM radgroupreply WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing select query: SELECT id, gr oupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Group "HSP6G-20day": Merging reply it ems
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: WISPr-Bandwidth-Max-Down := 5242880 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: WISPr-Bandwidth-Max-Up := 52428800
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Simultaneous-Use := 1
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Max-All-Session := 1728000
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Max-All-MB := 2147483648
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: FROM 5 TO 0 MAX 5
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining WISPr-Bandwidth-Max-Dow n
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING WISPr-Bandwidth-Max-Dow n FROM 0 TO 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining WISPr-Bandwidth-Max-Up
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING WISPr-Bandwidth-Max-Up FROM 1 TO 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Simultaneous-Use
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Simultaneous-Use FROM 2 TO 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Max-All-Session
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Max-All-Session FROM 3 TO 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: Examining Max-All-MB
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: APPENDING Max-All-MB FROM 4 TO 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ::: TO in 0 out 0
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: ... falling-through to profile proces sing
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Released connection (13)
Mon Jul 5 17:58:42 2021 : Info: Need 2 more connections to reach min connection s (3)
Mon Jul 5 17:58:42 2021 : Info: rlm_sql (sql): Opening additional connection (1 4), 1 of 31 pending slots used
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Starting connect to MySQL serve r
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.34-0ubuntu0.18.04.1, protocol v ersion 10
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from sq l (rlm_sql)
Mon Jul 5 17:58:42 2021 : Debug: (5) [sql] = ok
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: calling maximum_ mbs (rlm_sqlcounter)
Mon Jul 5 17:58:42 2021 : Debug: sqlcounter_expand: 'SELECT IFNULL((SUM(AcctInp utOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='%{User-Name}''
Mon Jul 5 17:58:42 2021 : Debug: %{sql:SELECT IFNULL((SUM(AcctInputOctets)+SUM( AcctOutputOctets)),0) FROM radacct WHERE UserName='%{User-Name}'}
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: xlat --> sql
Mon Jul 5 17:58:42 2021 : Debug: {
Mon Jul 5 17:58:42 2021 : Debug: literal --> SELECT IFNULL((SUM(AcctInput Octets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:58:42 2021 : Debug: literal --> '
Mon Jul 5 17:58:42 2021 : Debug: }
Mon Jul 5 17:58:42 2021 : Debug: %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: EXPAND %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: --> 06767
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: SQL-User-Name set to '06767'
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Reserved connection (13)
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: Executing select query: SELEC T IFNULL((SUM(AcctInputOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE User Name='06767'
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Released connection (13)
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: EXPAND %{sql:SELECT IFNULL((S UM(AcctInputOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='%{Use r-Name}'}
Mon Jul 5 17:58:42 2021 : Debug: (5) maximum_mbs: --> 2147485182
Mon Jul 5 17:58:42 2021 : ERROR: (5) maximum_mbs: Maximum never usage time reac hed
Mon Jul 5 17:58:42 2021 : ERROR: (5) maximum_mbs: Rejecting user, &control:Max- All-MB value (2147483648) is less than counter value (2147485182)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[authorize]: returned from ma ximum_mbs (rlm_sqlcounter)
Mon Jul 5 17:58:42 2021 : Debug: (5) [maximum_mbs] = reject
Mon Jul 5 17:58:42 2021 : Debug: (5) } # authorize = reject
Mon Jul 5 17:58:42 2021 : Debug: (5) Using Post-Auth-Type Reject
Mon Jul 5 17:58:42 2021 : Debug: (5) # Executing group from file /etc/freeradiu s/3.0/sites-enabled/default
Mon Jul 5 17:58:42 2021 : Debug: (5) Post-Auth-Type REJECT {
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: calling sql (rlm _sql)
Mon Jul 5 17:58:42 2021 : Debug: .query
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> .query
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND .query
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> .query
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Using query template 'query'
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Reserved connection (14)
Mon Jul 5 17:58:42 2021 : Debug: %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> 06767
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:58:42 2021 : Debug: INSERT INTO radpostauth (username, pass, reply , authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}' , '%{reply:Packet-Type}', '%S')
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:58:42 2021 : Debug: literal --> ', '
Mon Jul 5 17:58:42 2021 : Debug: XLAT-IF {
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Password
Mon Jul 5 17:58:42 2021 : Debug: }
Mon Jul 5 17:58:42 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:58:42 2021 : Debug: attribute --> CHAP-Password
Mon Jul 5 17:58:42 2021 : Debug: }
Mon Jul 5 17:58:42 2021 : Debug: literal --> ', '
Mon Jul 5 17:58:42 2021 : Debug: attribute --> Packet-Type
Mon Jul 5 17:58:42 2021 : Debug: literal --> ', '
Mon Jul 5 17:58:42 2021 : Debug: percent --> S
Mon Jul 5 17:58:42 2021 : Debug: literal --> ')
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: EXPAND INSERT INTO radpostauth (usern ame, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{ Chap-Password}}', '%{reply:Packet-Type}', '%S')
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: --> INSERT INTO radpostauth (usern ame, pass, reply, authdate) VALUES ( '06767', '0x8d3594bf6b78b066c3cef4270b05056 95a', 'Access-Reject', '2021-07-05 17:58:42')
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: Executing query: INSERT INTO radposta uth (username, pass, reply, authdate) VALUES ( '06767', '0x8d3594bf6b78b066c3cef 4270b0505695a', 'Access-Reject', '2021-07-05 17:58:42')
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: SQL query returned: success
Mon Jul 5 17:58:42 2021 : Debug: (5) sql: 1 record(s) updated
Mon Jul 5 17:58:42 2021 : Debug: rlm_sql (sql): Released connection (14)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: returned from sq l (rlm_sql)
Mon Jul 5 17:58:42 2021 : Debug: (5) [sql] = ok
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: calling attr_fil ter.access_reject (rlm_attr_filter)
Mon Jul 5 17:58:42 2021 : Debug: %{User-Name}
Mon Jul 5 17:58:42 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:58:42 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: EXPAND %{User-N ame}
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: --> 06767
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Matched entry D EFAULT at line 11
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "WISP r-Bandwidth-Max-Down" allowed by 0 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "WISP r-Bandwidth-Max-Up" allowed by 0 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "Simu ltaneous-Use" allowed by 0 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "Max- All-Session" allowed by 0 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "Max- All-MB" allowed by 0 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Reply-Message = "Your maximum never usage time has been reached" allowed by Reply-Message =* ""
Mon Jul 5 17:58:42 2021 : Debug: (5) attr_filter.access_reject: Attribute "Repl y-Message" allowed by 1 rules, disallowed by 0 rules
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: returned from at tr_filter.access_reject (rlm_attr_filter)
Mon Jul 5 17:58:42 2021 : Debug: (5) [attr_filter.access_reject] = updated
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: calling eap (rlm _eap)
Mon Jul 5 17:58:42 2021 : Debug: (5) eap: Request didn't contain an EAP-Message , not inserting EAP-Failure
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: returned from ea p (rlm_eap)
Mon Jul 5 17:58:42 2021 : Debug: (5) [eap] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) policy remove_reply_message_if_eap {
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&reply:EAP-Message && &reply:Rep ly-Message) {
Mon Jul 5 17:58:42 2021 : Debug: (5) if (&reply:EAP-Message && &reply:Rep ly-Message) -> FALSE
Mon Jul 5 17:58:42 2021 : Debug: (5) else {
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: calling noop (rlm_always)
Mon Jul 5 17:58:42 2021 : Debug: (5) modsingle[post-auth]: returned fro m noop (rlm_always)
Mon Jul 5 17:58:42 2021 : Debug: (5) [noop] = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) } # else = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) } # policy remove_reply_message_if_eap = noop
Mon Jul 5 17:58:42 2021 : Debug: (5) } # Post-Auth-Type REJECT = updated
Mon Jul 5 17:58:42 2021 : Debug: (5) Delaying response for 1.000000 seconds
Mon Jul 5 17:58:42 2021 : Debug: Waking up in 0.3 seconds.
Mon Jul 5 17:58:43 2021 : Debug: (5) (5) Discarding duplicate request from clie nt port 49215 - ID: 46 due to delayed response
Mon Jul 5 17:58:43 2021 : Debug: Waking up in 0.6 seconds.
Mon Jul 5 17:58:43 2021 : Debug: (5) (5) Discarding duplicate request from clie nt port 49215 - ID: 46 due to delayed response
Mon Jul 5 17:58:43 2021 : Debug: Waking up in 0.4 seconds.
Mon Jul 5 17:58:43 2021 : Debug: (5) Sending delayed response
Mon Jul 5 17:58:43 2021 : Debug: (5) Sent Access-Reject Id 46 from 172.26.11.27 :1812 to 103.136.204.45:49215 length 68
Mon Jul 5 17:58:43 2021 : Debug: (5) Reply-Message = "Your maximum never usag e time has been reached"
Mon Jul 5 17:58:43 2021 : Debug: Waking up in 3.9 seconds.
Mon Jul 5 17:58:47 2021 : Debug: (5) Cleaning up request packet ID 46 with timestamp +897
Mon Jul 5 17:58:47 2021 : Info: Ready to process requests
-------------- next part --------------
Mon Jul 5 17:54:43 2021 : Info: Ready to process requests
Mon Jul 5 17:56:17 2021 : Debug: (4) Received Accounting-Request Id 45 from 103.136. 204.45:43532 to 172.26.11.27:1813 length 202
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Status-Type = Stop
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Terminate-Cause = NAS-Request
Mon Jul 5 17:56:17 2021 : Debug: (4) NAS-Port-Type = Wireless-802.11
Mon Jul 5 17:56:17 2021 : Debug: (4) Calling-Station-Id = "00:0C:29:D6:B8:A6"
Mon Jul 5 17:56:17 2021 : Debug: (4) Called-Station-Id = "hotspot1"
Mon Jul 5 17:56:17 2021 : Debug: (4) NAS-Port-Id = "ether3-LAN"
Mon Jul 5 17:56:17 2021 : Debug: (4) User-Name = "06767"
Mon Jul 5 17:56:17 2021 : Debug: (4) NAS-Port = 2149580826
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Session-Id = "8020001a"
Mon Jul 5 17:56:17 2021 : Debug: (4) Framed-IP-Address = 192.168.251.117
Mon Jul 5 17:56:17 2021 : Debug: (4) Mikrotik-Host-IP = 192.168.251.117
Mon Jul 5 17:56:17 2021 : Debug: (4) Event-Timestamp = "Jul 5 2021 17:56:17 +04"
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Input-Octets = 21740756
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Output-Octets = 2125744426
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Input-Gigawords = 0
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Output-Gigawords = 0
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Input-Packets = 498913
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Output-Packets = 487557
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Session-Time = 694
Mon Jul 5 17:56:17 2021 : Debug: (4) NAS-Identifier = "Nayeem-R1-CoreRouter"
Mon Jul 5 17:56:17 2021 : Debug: (4) Acct-Delay-Time = 0
Mon Jul 5 17:56:17 2021 : Debug: (4) NAS-IP-Address = 192.168.31.77
Mon Jul 5 17:56:17 2021 : Debug: (4) # Executing section preacct from file /etc/free radius/3.0/sites-enabled/default
Mon Jul 5 17:56:17 2021 : Debug: (4) preacct {
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: calling preprocess (rlm _preprocess)
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: returned from preproces s (rlm_preprocess)
Mon Jul 5 17:56:17 2021 : Debug: (4) [preprocess] = ok
Mon Jul 5 17:56:17 2021 : Debug: (4) policy acct_unique {
Mon Jul 5 17:56:17 2021 : Debug: (4) update request {
Mon Jul 5 17:56:17 2021 : Debug: (4) &Tmp-String-9 := "ai:"
Mon Jul 5 17:56:17 2021 : Debug: (4) } # update request = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-Stri ng-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{hex:&Class}
Mon Jul 5 17:56:17 2021 : Debug: (4) -->
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND ^%{hex:&Tmp-String-9}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> ^61693a
Mon Jul 5 17:56:17 2021 : Debug: No matches
Mon Jul 5 17:56:17 2021 : Debug: (4) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-Stri ng-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
Mon Jul 5 17:56:17 2021 : Debug: (4) else {
Mon Jul 5 17:56:17 2021 : Debug: (4) update request {
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{md5:%{User-Name},%{Acct-Sess ion-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{ NAS-Port}}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 3f74fa78ccd63a57e895ef24572721 40
Mon Jul 5 17:56:17 2021 : Debug: (4) &Acct-Unique-Session-Id := 3f74fa78cc d63a57e895ef2457272140
Mon Jul 5 17:56:17 2021 : Debug: (4) } # update request = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) } # else = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) } # policy acct_unique = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: calling suffix (rlm_rea lm)
Mon Jul 5 17:56:17 2021 : Debug: (4) suffix: Checking for suffix after "@"
Mon Jul 5 17:56:17 2021 : Debug: (4) suffix: No '@' in User-Name = "06767", looking up realm NULL
Mon Jul 5 17:56:17 2021 : Debug: (4) suffix: No such realm "NULL"
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: returned from suffix (r lm_realm)
Mon Jul 5 17:56:17 2021 : Debug: (4) [suffix] = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: calling files (rlm_file s)
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[preacct]: returned from files (rl m_files)
Mon Jul 5 17:56:17 2021 : Debug: (4) [files] = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) } # preacct = ok
Mon Jul 5 17:56:17 2021 : Debug: (4) # Executing section accounting from file /etc/f reeradius/3.0/sites-enabled/default
Mon Jul 5 17:56:17 2021 : Debug: (4) accounting {
Mon Jul 5 17:56:17 2021 : Debug: (4) update control {
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) SQL-User-Name set to '06767'
Mon Jul 5 17:56:17 2021 : Info: rlm_sql (sql): Closing connection (9): Hit idle_time out, was idle for 94 seconds
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): You probably need to lower "min"
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Socket destructor called, closing so cket
Mon Jul 5 17:56:17 2021 : Info: rlm_sql (sql): Closing connection (10): Hit idle_tim eout, was idle for 94 seconds
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): You probably need to lower "min"
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Socket destructor called, closing so cket
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
Mon Jul 5 17:56:17 2021 : Info: rlm_sql (sql): Opening additional connection (11), 1 of 32 pending slots used
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Connected to database 'radius' on Lo calhost via UNIX socket, server version 5.7.34-0ubuntu0.18.04.1, protocol version 10
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Reserved connection (11)
Mon Jul 5 17:56:17 2021 : Debug: (4) Executing select query: SELECT (SUM(accti nputOctets)+SUM(acctoutputoctets)) AS Total FROM radacct WHERE radacct.username='0676 7'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Released connection (11)
Mon Jul 5 17:56:17 2021 : Info: Need 2 more connections to reach min connections (3)
Mon Jul 5 17:56:17 2021 : Info: rlm_sql (sql): Opening additional connection (12), 1 of 31 pending slots used
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Connected to database 'radius' on Lo calhost via UNIX socket, server version 5.7.34-0ubuntu0.18.04.1, protocol version 10
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{sql:SELECT (SUM(acctinputOctets) +SUM(acctoutputoctets)) AS Total FROM radacct WHERE radacct.username='%{User-Name}'}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 1802278260
Mon Jul 5 17:56:17 2021 : Debug: (4) Tmp-Integer-0 := 1802278260
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) SQL-User-Name set to '06767'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Reserved connection (11)
Mon Jul 5 17:56:17 2021 : Debug: (4) Executing select query: SELECT value FRO M radcheck WHERE attribute='Max-All-MB’ AND username='06767'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: No additional diagnostic info on ser ver
Mon Jul 5 17:56:17 2021 : ERROR: (4) rlm_sql_mysql: ERROR 1064 (You have an er ror in your SQL syntax; check the manual that corresponds to your MySQL server versio n for the right syntax to use near '06767'' at line 1): 42000
Mon Jul 5 17:56:17 2021 : ERROR: (4) SQL query failed: server error
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Released connection (11)
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{sql: SELECT value FROM radcheck WHERE attribute='Max-All-MB’ AND username='%{User-Name}'}
Mon Jul 5 17:56:17 2021 : Debug: (4) -->
Mon Jul 5 17:56:17 2021 : Debug: (4) Tmp-String-1 :=
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) SQL-User-Name set to '06767'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Reserved connection (12)
Mon Jul 5 17:56:17 2021 : Debug: (4) Executing select query: SELECT value FRO M radgroupcheck WHERE attribute='Max-All-MB'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Released connection (12)
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{sql: SELECT value FROM radgroupc heck WHERE attribute='Max-All-MB'}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 10737418240
Mon Jul 5 17:56:17 2021 : Debug: (4) Tmp-String-1 := 10737418240
Mon Jul 5 17:56:17 2021 : Debug: (4) Overwriting value "" with "10737418240"
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) SQL-User-Name set to '06767'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Reserved connection (11)
Mon Jul 5 17:56:17 2021 : Debug: (4) Executing select query: select calledstat ionid from radacct where acctsessionid='8020001a'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Released connection (11)
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{sql:select calledstationid from radacct where acctsessionid='%{Acct-Session-Id}'}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> hotspot1
Mon Jul 5 17:56:17 2021 : Debug: (4) Tmp-String-3 := hotspot1
Mon Jul 5 17:56:17 2021 : Debug: (4) } # update control = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) if ("%{control:Tmp-Integer-0}" > "%{control :Tmp-String-1}"){
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{control:Tmp-Integer-0}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 1802278260
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:56:17 2021 : Debug: (4) EXPAND %{control:Tmp-String-1}
Mon Jul 5 17:56:17 2021 : Debug: (4) --> 10737418240
Mon Jul 5 17:56:17 2021 : Debug: (4) if ("%{control:Tmp-Integer-0}" > "%{control :Tmp-String-1}") -> FALSE
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: calling detail (rlm_ detail)
Mon Jul 5 17:56:17 2021 : Debug: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Addre ss}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: literal --> /var/log/freeradius/radacct/
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Packet-Src-IP-Address
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Packet-Src-IPv6-Address
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> /detail-
Mon Jul 5 17:56:17 2021 : Debug: percent --> Y
Mon Jul 5 17:56:17 2021 : Debug: percent --> m
Mon Jul 5 17:56:17 2021 : Debug: percent --> d
Mon Jul 5 17:56:17 2021 : Debug: (4) detail: EXPAND /var/log/freeradius/radacct/%{%{ Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
Mon Jul 5 17:56:17 2021 : Debug: (4) detail: --> /var/log/freeradius/radacct/103. 136.204.45/detail-20210705
Mon Jul 5 17:56:17 2021 : Debug: (4) detail: /var/log/freeradius/radacct/%{%{Packet- Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freera dius/radacct/103.136.204.45/detail-20210705
Mon Jul 5 17:56:17 2021 : Debug: %t
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: percent --> t
Mon Jul 5 17:56:17 2021 : Debug: (4) detail: EXPAND %t
Mon Jul 5 17:56:17 2021 : Debug: (4) detail: --> Mon Jul 5 17:56:17 2021
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: returned from detail (rlm_detail)
Mon Jul 5 17:56:17 2021 : Debug: (4) [detail] = ok
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: calling unix (rlm_un ix)
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: returned from unix ( rlm_unix)
Mon Jul 5 17:56:17 2021 : Debug: (4) [unix] = ok
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: calling sql (rlm_sql )
Mon Jul 5 17:56:17 2021 : Debug: %{tolower:type.%{Acct-Status-Type}.query}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: xlat --> tolower
Mon Jul 5 17:56:17 2021 : Debug: {
Mon Jul 5 17:56:17 2021 : Debug: literal --> type.
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Status-Type
Mon Jul 5 17:56:17 2021 : Debug: literal --> .query
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: EXPAND %{tolower:type.%{Acct-Status-Type}. query}
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: --> type.stop.query
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: Using query template 'query'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Reserved connection (12)
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: EXPAND %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:56:17 2021 : Debug: UPDATE radacct SET acctstoptime = FROM_UNIXTI ME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acct inputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0} ', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octet s}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connec t-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: literal --> UPDATE radacct SET acctstoptime = FRO M_UNIXTIME(
Mon Jul 5 17:56:17 2021 : Debug: xlat --> integer
Mon Jul 5 17:56:17 2021 : Debug: {
Mon Jul 5 17:56:17 2021 : Debug: literal --> Event-Timestamp
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> ), acctsessiontime =
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Session-Time
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: literal --> NULL
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> , acctinputoctets = '
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Input-Gigawords
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: literal --> 0
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> ' << 32 | '
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Input-Octets
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: literal --> 0
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> ', acctoutputoctets = '
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Output-Gigawords
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: literal --> 0
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> ' << 32 | '
Mon Jul 5 17:56:17 2021 : Debug: XLAT-IF {
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Output-Octets
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:56:17 2021 : Debug: literal --> 0
Mon Jul 5 17:56:17 2021 : Debug: }
Mon Jul 5 17:56:17 2021 : Debug: literal --> ', acctterminatecause = '
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Terminate-Cause
Mon Jul 5 17:56:17 2021 : Debug: literal --> ', connectinfo_stop = '
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Connect-Info
Mon Jul 5 17:56:17 2021 : Debug: literal --> ' WHERE AcctUniqueId = '
Mon Jul 5 17:56:17 2021 : Debug: attribute --> Acct-Unique-Session-Id
Mon Jul 5 17:56:17 2021 : Debug: literal --> '
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Ti me}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-I nput-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{A cct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_ stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1625493377), acctsessiontime = 694, acctinputoctets = '0' << 32 | '21740756', acctoutputoctets = '0' << 32 | '2125744426', acctterminatecause = 'NAS-R equest', connectinfo_stop = '' WHERE AcctUniqueId = '3f74fa78ccd63a57e895ef2457272140 '
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: Executing query: UPDATE radacct SET acctst optime = FROM_UNIXTIME(1625493377), acctsessiontime = 694, acctinputoctets = '0' << 32 | '21740756', acctoutputoctets = '0' << 32 | '2125744426', acctterminatecause = 'NAS-Request', connectinfo_stop = '' WHERE AcctUniqueId = '3f74fa78ccd63a57e895ef24 57272140'
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql_mysql: Rows matched: 1 Changed: 1 Warning s: 0
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: SQL query returned: success
Mon Jul 5 17:56:17 2021 : Debug: (4) sql: 1 record(s) updated
Mon Jul 5 17:56:17 2021 : Debug: rlm_sql (sql): Released connection (12)
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: returned from sql (r lm_sql)
Mon Jul 5 17:56:17 2021 : Debug: (4) [sql] = ok
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: calling exec (rlm_ex ec)
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: returned from exec ( rlm_exec)
Mon Jul 5 17:56:17 2021 : Debug: (4) [exec] = noop
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: calling attr_filter. accounting_response (rlm_attr_filter)
Mon Jul 5 17:56:17 2021 : Debug: %{User-Name}
Mon Jul 5 17:56:17 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:56:17 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:56:17 2021 : Debug: (4) attr_filter.accounting_response: EXPAND %{User- Name}
Mon Jul 5 17:56:17 2021 : Debug: (4) attr_filter.accounting_response: --> 06767
Mon Jul 5 17:56:17 2021 : Debug: (4) attr_filter.accounting_response: Matched entry DEFAULT at line 12
Mon Jul 5 17:56:17 2021 : Debug: (4) modsingle[accounting]: returned from attr_f ilter.accounting_response (rlm_attr_filter)
Mon Jul 5 17:56:17 2021 : Debug: (4) [attr_filter.accounting_response] = updated
Mon Jul 5 17:56:17 2021 : Debug: (4) } # accounting = updated
Mon Jul 5 17:56:17 2021 : Debug: (4) Sent Accounting-Response Id 45 from 172.26.11.2 7:1813 to 103.136.204.45:43532 length 0
Mon Jul 5 17:56:17 2021 : Debug: (4) Finished request
Mon Jul 5 17:56:17 2021 : Debug: (4) Cleaning up request packet ID 45 with timestamp +752
Mon Jul 5 17:56:17 2021 : Info: Ready to process requests
-------------- next part --------------
Mon Jul 5 17:43:45 2021 : Info: Ready to process requests
Mon Jul 5 17:44:43 2021 : Debug: (0) Received Access-Request Id 41 from 103.136 .204.45:47019 to 172.26.11.27:1812 length 216
Mon Jul 5 17:44:43 2021 : Debug: (0) NAS-Port-Type = Wireless-802.11
Mon Jul 5 17:44:43 2021 : Debug: (0) Calling-Station-Id = "00:0C:29:D6:B8:A6"
Mon Jul 5 17:44:43 2021 : Debug: (0) Called-Station-Id = "hotspot1"
Mon Jul 5 17:44:43 2021 : Debug: (0) NAS-Port-Id = "ether3-LAN"
Mon Jul 5 17:44:43 2021 : Debug: (0) User-Name = "06767"
Mon Jul 5 17:44:43 2021 : Debug: (0) NAS-Port = 2149580826
Mon Jul 5 17:44:43 2021 : Debug: (0) Acct-Session-Id = "8020001a"
Mon Jul 5 17:44:43 2021 : Debug: (0) Framed-IP-Address = 192.168.251.117
Mon Jul 5 17:44:43 2021 : Debug: (0) Mikrotik-Host-IP = 192.168.251.117
Mon Jul 5 17:44:43 2021 : Debug: (0) CHAP-Challenge = 0xca3c9573001464eb300f0 d8c3ebe7a79
Mon Jul 5 17:44:43 2021 : Debug: (0) CHAP-Password = 0x53366b5b1a6f407af389df 013e65f0b10a
Mon Jul 5 17:44:43 2021 : Debug: (0) Service-Type = Login-User
Mon Jul 5 17:44:43 2021 : Debug: (0) WISPr-Logoff-URL = "http://192.168.251.2 54/logout"
Mon Jul 5 17:44:43 2021 : Debug: (0) NAS-Identifier = "Nayeem-R1-CoreRouter"
Mon Jul 5 17:44:43 2021 : Debug: (0) NAS-IP-Address = 192.168.31.77
Mon Jul 5 17:44:43 2021 : Debug: (0) session-state: No State attribute
Mon Jul 5 17:44:43 2021 : Debug: (0) # Executing section authorize from file /e tc/freeradius/3.0/sites-enabled/default
Mon Jul 5 17:44:43 2021 : Debug: (0) authorize {
Mon Jul 5 17:44:43 2021 : Debug: (0) policy filter_username {
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name) {
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name) -> TRUE
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name) {
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ / /) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ / /) -> FALSE
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /\.\./ ) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FAL SE
Mon Jul 5 17:44:43 2021 : Debug: (0) if ((&User-Name =~ /@/) && (&User- Name !~ /@(.+)\.(.+)$/)) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if ((&User-Name =~ /@/) && (&User- Name !~ /@(.+)\.(.+)$/)) -> FALSE
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /\.$/) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /\.$/) -> FALS E
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /@\./) {
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&User-Name =~ /@\./) -> FALS E
Mon Jul 5 17:44:43 2021 : Debug: (0) } # if (&User-Name) = notfound
Mon Jul 5 17:44:43 2021 : Debug: (0) } # policy filter_username = notfound
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling preproce ss (rlm_preprocess)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from pr eprocess (rlm_preprocess)
Mon Jul 5 17:44:43 2021 : Debug: (0) [preprocess] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling chap (rl m_chap)
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: &control:Auth-Type := CHAP
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ch ap (rlm_chap)
Mon Jul 5 17:44:43 2021 : Debug: (0) [chap] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling mschap ( rlm_mschap)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ms chap (rlm_mschap)
Mon Jul 5 17:44:43 2021 : Debug: (0) [mschap] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling digest ( rlm_digest)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from di gest (rlm_digest)
Mon Jul 5 17:44:43 2021 : Debug: (0) [digest] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling suffix ( rlm_realm)
Mon Jul 5 17:44:43 2021 : Debug: (0) suffix: Checking for suffix after "@"
Mon Jul 5 17:44:43 2021 : Debug: (0) suffix: No '@' in User-Name = "06767", loo king up realm NULL
Mon Jul 5 17:44:43 2021 : Debug: (0) suffix: No such realm "NULL"
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from su ffix (rlm_realm)
Mon Jul 5 17:44:43 2021 : Debug: (0) [suffix] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling eap (rlm _eap)
Mon Jul 5 17:44:43 2021 : Debug: (0) eap: No EAP-Message, not doing EAP
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ea p (rlm_eap)
Mon Jul 5 17:44:43 2021 : Debug: (0) [eap] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling files (r lm_files)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from fi les (rlm_files)
Mon Jul 5 17:44:43 2021 : Debug: (0) [files] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling sql (rlm _sql)
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (1)
Mon Jul 5 17:44:43 2021 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT id, username, attribute, va lue, op FROM radcheck WHERE username = '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND SELECT id, username, attribute , value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> SELECT id, username, attribute , value, op FROM radcheck WHERE username = '06767' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing select query: SELECT id, us ername, attribute, value, op FROM radcheck WHERE username = '06767' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: User found in radcheck table
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Conditional check items matched, merg ing assignment check items
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Cleartext-Password := "12411"
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: FROM 1 TO 1 MAX 2
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Cleartext-Password
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Cleartext-Password FROM 0 TO 1
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: TO in 1 out 1
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: to[0] = Auth-Type
Mon Jul 5 17:44:43 2021 : Debug: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT id, username, attribute, va lue, op FROM radreply WHERE username = '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND SELECT id, username, attribute , value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> SELECT id, username, attribute , value, op FROM radreply WHERE username = '06767' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing select query: SELECT id, us ername, attribute, value, op FROM radreply WHERE username = '06767' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ... falling-through to group processi ng
Mon Jul 5 17:44:43 2021 : Debug: SELECT groupname FROM radusergroup WHERE usern ame = '%{SQL-User-Name}' ORDER BY priority
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> ' ORDER BY priority
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND SELECT groupname FROM raduserg roup WHERE username = '%{SQL-User-Name}' ORDER BY priority
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> SELECT groupname FROM raduserg roup WHERE username = '06767' ORDER BY priority
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing select query: SELECT groupn ame FROM radusergroup WHERE username = '06767' ORDER BY priority
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: User found in the group table
Mon Jul 5 17:44:43 2021 : Debug: SELECT id, groupname, attribute, Value, op FRO M radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT id, groupname, attribute, V alue, op FROM radgroupcheck WHERE groupname = '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-Group
Mon Jul 5 17:44:43 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND SELECT id, groupname, attribut e, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> SELECT id, groupname, attribut e, Value, op FROM radgroupcheck WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing select query: SELECT id, gr oupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Group "HSP6G-20day": Conditional chec k items matched
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Group "HSP6G-20day": Merging assignme nt check items
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Max-All-MB := 2147483648
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Max-All-Session := 1728000
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: FROM 2 TO 2 MAX 4
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Max-All-MB
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Max-All-MB FROM 0 TO 2
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Max-All-Session
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Max-All-Session FROM 1 TO 2
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: TO in 2 out 2
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: to[0] = Auth-Type
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: to[1] = Cleartext-Password
Mon Jul 5 17:44:43 2021 : Debug: SELECT id, groupname, attribute, value, op FRO M radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT id, groupname, attribute, v alue, op FROM radgroupreply WHERE groupname = '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-Group
Mon Jul 5 17:44:43 2021 : Debug: literal --> ' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND SELECT id, groupname, attribut e, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> SELECT id, groupname, attribut e, value, op FROM radgroupreply WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing select query: SELECT id, gr oupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HSP6G-20day' ORDER BY id
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Group "HSP6G-20day": Merging reply it ems
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: WISPr-Bandwidth-Max-Down := 5242880 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: WISPr-Bandwidth-Max-Up := 52428800
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Simultaneous-Use := 1
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Max-All-Session := 1728000
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Max-All-MB := 2147483648
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: FROM 5 TO 0 MAX 5
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining WISPr-Bandwidth-Max-Dow n
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING WISPr-Bandwidth-Max-Dow n FROM 0 TO 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining WISPr-Bandwidth-Max-Up
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING WISPr-Bandwidth-Max-Up FROM 1 TO 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Simultaneous-Use
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Simultaneous-Use FROM 2 TO 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Max-All-Session
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Max-All-Session FROM 3 TO 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: Examining Max-All-MB
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: APPENDING Max-All-MB FROM 4 TO 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ::: TO in 0 out 0
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: ... falling-through to profile proces sing
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (1)
Mon Jul 5 17:44:43 2021 : Info: Need 4 more connections to reach 10 spares
Mon Jul 5 17:44:43 2021 : Info: rlm_sql (sql): Opening additional connection (6 ), 1 of 26 pending slots used
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql_mysql: Starting connect to MySQL serve r
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.34-0ubuntu0.18.04.1, protocol v ersion 10
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from sq l (rlm_sql)
Mon Jul 5 17:44:43 2021 : Debug: (0) [sql] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling maximum_ mbs (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: sqlcounter_expand: 'SELECT IFNULL((SUM(AcctInp utOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='%{User-Name}''
Mon Jul 5 17:44:43 2021 : Debug: %{sql:SELECT IFNULL((SUM(AcctInputOctets)+SUM( AcctOutputOctets)),0) FROM radacct WHERE UserName='%{User-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: xlat --> sql
Mon Jul 5 17:44:43 2021 : Debug: {
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT IFNULL((SUM(AcctInput Octets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> '
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (2)
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: Executing select query: SELEC T IFNULL((SUM(AcctInputOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE User Name='06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (2)
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: EXPAND %{sql:SELECT IFNULL((S UM(AcctInputOctets)+SUM(AcctOutputOctets)),0) FROM radacct WHERE UserName='%{Use r-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: --> 0
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: Allowing user, &control:Max-A ll-MB value (2147483648) is greater than counter value (0)
Mon Jul 5 17:44:43 2021 : Debug: (0) maximum_mbs: Setting &reply:Mikrotik-Total -Limit value to 2147483648
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ma ximum_mbs (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: (0) [maximum_mbs] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling expire_o n_login (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : WARNING: (0) expire_on_login: Couldn't find check att ribute, control:Expire-After, doing nothing...
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ex pire_on_login (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: (0) [expire_on_login] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling accesspe riod (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : WARNING: (0) accessperiod: Couldn't find check attrib ute, control:Access-Period, doing nothing...
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ac cessperiod (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: (0) [accessperiod] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling noresetc ounter (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: sqlcounter_expand: 'SELECT IFNULL(SUM(AcctSess ionTime),0) FROM radacct WHERE UserName='%{User-Name}''
Mon Jul 5 17:44:43 2021 : Debug: %{sql:SELECT IFNULL(SUM(AcctSessionTime),0) FR OM radacct WHERE UserName='%{User-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: xlat --> sql
Mon Jul 5 17:44:43 2021 : Debug: {
Mon Jul 5 17:44:43 2021 : Debug: literal --> SELECT IFNULL(SUM(AcctSessio nTime),0) FROM radacct WHERE UserName='
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> '
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: SQL-User-Name set to '0676 7'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (3)
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: Executing select query: SE LECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (3)
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: EXPAND %{sql:SELECT IFNULL (SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{User-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: --> 0
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: Allowing user, &control:Ma x-All-Session value (1728000) is greater than counter value (0)
Mon Jul 5 17:44:43 2021 : Debug: (0) noresetcounter: Setting &reply:Session-Tim eout value to 1728000
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from no resetcounter (rlm_sqlcounter)
Mon Jul 5 17:44:43 2021 : Debug: (0) [noresetcounter] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling expirati on (rlm_expiration)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from ex piration (rlm_expiration)
Mon Jul 5 17:44:43 2021 : Debug: (0) [expiration] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling logintim e (rlm_logintime)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from lo gintime (rlm_logintime)
Mon Jul 5 17:44:43 2021 : Debug: (0) [logintime] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: calling pap (rlm _pap)
Mon Jul 5 17:44:43 2021 : WARNING: (0) pap: Auth-Type already set. Not setting to PAP
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authorize]: returned from pa p (rlm_pap)
Mon Jul 5 17:44:43 2021 : Debug: (0) [pap] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) } # authorize = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) Found Auth-Type = CHAP
Mon Jul 5 17:44:43 2021 : Debug: (0) # Executing group from file /etc/freeradiu s/3.0/sites-enabled/default
Mon Jul 5 17:44:43 2021 : Debug: (0) Auth-Type CHAP {
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authenticate]: calling chap (rlm_chap)
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: Comparing with "known good" &control :Cleartext-Password value "12411"
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: Using challenge from &request:CHAP-C hallenge
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: CHAP challenge : ca3c9573001464eb3 00f0d8c3ebe7a79
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: Client sent : 366b5b1a6f407af38 9df013e65f0b10a
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: We calculated : 366b5b1a6f407af38 9df013e65f0b10a
Mon Jul 5 17:44:43 2021 : Debug: (0) chap: CHAP user "06767" authenticated succ essfully
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[authenticate]: returned from chap (rlm_chap)
Mon Jul 5 17:44:43 2021 : Debug: (0) [chap] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) } # Auth-Type CHAP = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) # Executing section post-auth from file /e tc/freeradius/3.0/sites-enabled/default
Mon Jul 5 17:44:43 2021 : Debug: (0) post-auth {
Mon Jul 5 17:44:43 2021 : Debug: (0) update {
Mon Jul 5 17:44:43 2021 : Debug: (0) No attributes updated
Mon Jul 5 17:44:43 2021 : Debug: (0) } # update = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: calling sql (rlm _sql)
Mon Jul 5 17:44:43 2021 : Debug: .query
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> .query
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND .query
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> .query
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Using query template 'query'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (4)
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: INSERT INTO radpostauth (username, pass, reply , authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}' , '%{reply:Packet-Type}', '%S')
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: XLAT-IF {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Password
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> CHAP-Password
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Packet-Type
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: percent --> S
Mon Jul 5 17:44:43 2021 : Debug: literal --> ')
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: EXPAND INSERT INTO radpostauth (usern ame, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{ Chap-Password}}', '%{reply:Packet-Type}', '%S')
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: --> INSERT INTO radpostauth (usern ame, pass, reply, authdate) VALUES ( '06767', '0x53366b5b1a6f407af389df013e65f0b 10a', 'Access-Accept', '2021-07-05 17:44:43')
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: Executing query: INSERT INTO radposta uth (username, pass, reply, authdate) VALUES ( '06767', '0x53366b5b1a6f407af389d f013e65f0b10a', 'Access-Accept', '2021-07-05 17:44:43')
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: SQL query returned: success
Mon Jul 5 17:44:43 2021 : Debug: (0) sql: 1 record(s) updated
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (4)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: returned from sq l (rlm_sql)
Mon Jul 5 17:44:43 2021 : Debug: (0) [sql] = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: calling exec (rl m_exec)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: returned from ex ec (rlm_exec)
Mon Jul 5 17:44:43 2021 : Debug: (0) [exec] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) policy remove_reply_message_if_eap {
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&reply:EAP-Message && &reply:Rep ly-Message) {
Mon Jul 5 17:44:43 2021 : Debug: (0) if (&reply:EAP-Message && &reply:Rep ly-Message) -> FALSE
Mon Jul 5 17:44:43 2021 : Debug: (0) else {
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: calling noop (rlm_always)
Mon Jul 5 17:44:43 2021 : Debug: (0) modsingle[post-auth]: returned fro m noop (rlm_always)
Mon Jul 5 17:44:43 2021 : Debug: (0) [noop] = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) } # else = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) } # policy remove_reply_message_if_eap = noop
Mon Jul 5 17:44:43 2021 : Debug: (0) } # post-auth = ok
Mon Jul 5 17:44:43 2021 : Debug: (0) Sent Access-Accept Id 41 from 172.26.11.27 :1812 to 103.136.204.45:47019 length 0
Mon Jul 5 17:44:43 2021 : Debug: (0) WISPr-Bandwidth-Max-Down = 52428800
Mon Jul 5 17:44:43 2021 : Debug: (0) WISPr-Bandwidth-Max-Up = 52428800
Mon Jul 5 17:44:43 2021 : Debug: (0) Mikrotik-Total-Limit = 2147483648
Mon Jul 5 17:44:43 2021 : Debug: (0) Session-Timeout = 1728000
Mon Jul 5 17:44:43 2021 : Debug: (0) Finished request
Mon Jul 5 17:44:43 2021 : Debug: Waking up in 4.9 seconds.
Mon Jul 5 17:44:43 2021 : Debug: (1) Received Accounting-Request Id 42 from 103 .136.204.45:60317 to 172.26.11.27:1813 length 154
Mon Jul 5 17:44:43 2021 : Debug: (1) Acct-Status-Type = Start
Mon Jul 5 17:44:43 2021 : Debug: (1) NAS-Port-Type = Wireless-802.11
Mon Jul 5 17:44:43 2021 : Debug: (1) Calling-Station-Id = "00:0C:29:D6:B8:A6"
Mon Jul 5 17:44:43 2021 : Debug: (1) Called-Station-Id = "hotspot1"
Mon Jul 5 17:44:43 2021 : Debug: (1) NAS-Port-Id = "ether3-LAN"
Mon Jul 5 17:44:43 2021 : Debug: (1) User-Name = "06767"
Mon Jul 5 17:44:43 2021 : Debug: (1) NAS-Port = 2149580826
Mon Jul 5 17:44:43 2021 : Debug: (1) Acct-Session-Id = "8020001a"
Mon Jul 5 17:44:43 2021 : Debug: (1) Framed-IP-Address = 192.168.251.117
Mon Jul 5 17:44:43 2021 : Debug: (1) Mikrotik-Host-IP = 192.168.251.117
Mon Jul 5 17:44:43 2021 : Debug: (1) Event-Timestamp = "Jul 5 2021 17:44:42 +04"
Mon Jul 5 17:44:43 2021 : Debug: (1) NAS-Identifier = "Nayeem-R1-CoreRouter"
Mon Jul 5 17:44:43 2021 : Debug: (1) Acct-Delay-Time = 0
Mon Jul 5 17:44:43 2021 : Debug: (1) NAS-IP-Address = 192.168.31.77
Mon Jul 5 17:44:43 2021 : Debug: (1) # Executing section preacct from file /etc /freeradius/3.0/sites-enabled/default
Mon Jul 5 17:44:43 2021 : Debug: (1) preacct {
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: calling preprocess (rlm_preprocess)
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: returned from prep rocess (rlm_preprocess)
Mon Jul 5 17:44:43 2021 : Debug: (1) [preprocess] = ok
Mon Jul 5 17:44:43 2021 : Debug: (1) policy acct_unique {
Mon Jul 5 17:44:43 2021 : Debug: (1) update request {
Mon Jul 5 17:44:43 2021 : Debug: (1) &Tmp-String-9 := "ai:"
Mon Jul 5 17:44:43 2021 : Debug: (1) } # update request = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp -String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{hex:&Class}
Mon Jul 5 17:44:43 2021 : Debug: (1) -->
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND ^%{hex:&Tmp-String-9}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> ^61693a
Mon Jul 5 17:44:43 2021 : Debug: No matches
Mon Jul 5 17:44:43 2021 : Debug: (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp -String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> F ALSE
Mon Jul 5 17:44:43 2021 : Debug: (1) else {
Mon Jul 5 17:44:43 2021 : Debug: (1) update request {
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{md5:%{User-Name},%{Acct -Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-P ort-ID},%{NAS-Port}}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 3f74fa78ccd63a57e895ef245 7272140
Mon Jul 5 17:44:43 2021 : Debug: (1) &Acct-Unique-Session-Id := 3f74f a78ccd63a57e895ef2457272140
Mon Jul 5 17:44:43 2021 : Debug: (1) } # update request = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) } # else = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) } # policy acct_unique = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: calling suffix (rl m_realm)
Mon Jul 5 17:44:43 2021 : Debug: (1) suffix: Checking for suffix after "@"
Mon Jul 5 17:44:43 2021 : Debug: (1) suffix: No '@' in User-Name = "06767", loo king up realm NULL
Mon Jul 5 17:44:43 2021 : Debug: (1) suffix: No such realm "NULL"
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: returned from suff ix (rlm_realm)
Mon Jul 5 17:44:43 2021 : Debug: (1) [suffix] = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: calling files (rlm _files)
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[preacct]: returned from file s (rlm_files)
Mon Jul 5 17:44:43 2021 : Debug: (1) [files] = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) } # preacct = ok
Mon Jul 5 17:44:43 2021 : Debug: (1) # Executing section accounting from file / etc/freeradius/3.0/sites-enabled/default
Mon Jul 5 17:44:43 2021 : Debug: (1) accounting {
Mon Jul 5 17:44:43 2021 : Debug: (1) update control {
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (1) SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (0)
Mon Jul 5 17:44:43 2021 : Debug: (1) Executing select query: SELECT (SUM( acctinputOctets)+SUM(acctoutputoctets)) AS Total FROM radacct WHERE radacct.user name='06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (0)
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{sql:SELECT (SUM(acctinputOc tets)+SUM(acctoutputoctets)) AS Total FROM radacct WHERE radacct.username='%{Use r-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: (1) -->
Mon Jul 5 17:44:43 2021 : Debug: (1) Tmp-Integer-0 := 0
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (1) SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (5)
Mon Jul 5 17:44:43 2021 : Debug: (1) Executing select query: SELECT valu e FROM radcheck WHERE attribute='Max-All-MB’ AND username='06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql_mysql: No additional diagnostic info o n server
Mon Jul 5 17:44:43 2021 : ERROR: (1) rlm_sql_mysql: ERROR 1064 (You have an error in your SQL syntax; check the manual that corresponds to your MySQL ser ver version for the right syntax to use near '06767'' at line 1): 42000
Mon Jul 5 17:44:43 2021 : ERROR: (1) SQL query failed: server error
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (5)
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{sql: SELECT value FROM radc heck WHERE attribute='Max-All-MB’ AND username='%{User-Name}'}
Mon Jul 5 17:44:43 2021 : Debug: (1) -->
Mon Jul 5 17:44:43 2021 : Debug: (1) Tmp-String-1 :=
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (1) SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (1)
Mon Jul 5 17:44:43 2021 : Debug: (1) Executing select query: SELECT valu e FROM radgroupcheck WHERE attribute='Max-All-MB'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (1)
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{sql: SELECT value FROM radg roupcheck WHERE attribute='Max-All-MB'}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 10737418240
Mon Jul 5 17:44:43 2021 : Debug: (1) Tmp-String-1 := 10737418240
Mon Jul 5 17:44:43 2021 : Debug: (1) Overwriting value "" with "107374182 40"
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (1) SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (6)
Mon Jul 5 17:44:43 2021 : Debug: (1) Executing select query: select calle dstationid from radacct where acctsessionid='8020001a'
Mon Jul 5 17:44:43 2021 : Debug: (1) SQL query returned no results
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (6)
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{sql:select calledstationid from radacct where acctsessionid='%{Acct-Session-Id}'}
Mon Jul 5 17:44:43 2021 : Debug: (1) -->
Mon Jul 5 17:44:43 2021 : Debug: (1) Tmp-String-3 :=
Mon Jul 5 17:44:43 2021 : Debug: (1) } # update control = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) if ("%{control:Tmp-Integer-0}" > "%{co ntrol:Tmp-String-1}"){
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{control:Tmp-Integer-0}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 0
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND TMPL XLAT STRUCT
Mon Jul 5 17:44:43 2021 : Debug: (1) EXPAND %{control:Tmp-String-1}
Mon Jul 5 17:44:43 2021 : Debug: (1) --> 10737418240
Mon Jul 5 17:44:43 2021 : Debug: (1) if ("%{control:Tmp-Integer-0}" > "%{co ntrol:Tmp-String-1}") -> FALSE
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: calling detail (rlm_detail)
Mon Jul 5 17:44:43 2021 : Debug: /var/log/freeradius/radacct/%{%{Packet-Src-IP- Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> /var/log/freeradius/radacct/
Mon Jul 5 17:44:43 2021 : Debug: XLAT-IF {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Packet-Src-IP-Address
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Packet-Src-IPv6-Address
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: literal --> /detail-
Mon Jul 5 17:44:43 2021 : Debug: percent --> Y
Mon Jul 5 17:44:43 2021 : Debug: percent --> m
Mon Jul 5 17:44:43 2021 : Debug: percent --> d
Mon Jul 5 17:44:43 2021 : Debug: (1) detail: EXPAND /var/log/freeradius/radacct /%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
Mon Jul 5 17:44:43 2021 : Debug: (1) detail: --> /var/log/freeradius/radacct /103.136.204.45/detail-20210705
Mon Jul 5 17:44:43 2021 : Debug: (1) detail: /var/log/freeradius/radacct/%{%{Pa cket-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/ log/freeradius/radacct/103.136.204.45/detail-20210705
Mon Jul 5 17:44:43 2021 : Debug: %t
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: percent --> t
Mon Jul 5 17:44:43 2021 : Debug: (1) detail: EXPAND %t
Mon Jul 5 17:44:43 2021 : Debug: (1) detail: --> Mon Jul 5 17:44:43 2021
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: returned from d etail (rlm_detail)
Mon Jul 5 17:44:43 2021 : Debug: (1) [detail] = ok
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: calling unix (r lm_unix)
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: returned from u nix (rlm_unix)
Mon Jul 5 17:44:43 2021 : Debug: (1) [unix] = ok
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: calling sql (rl m_sql)
Mon Jul 5 17:44:43 2021 : Debug: %{tolower:type.%{Acct-Status-Type}.query}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: xlat --> tolower
Mon Jul 5 17:44:43 2021 : Debug: {
Mon Jul 5 17:44:43 2021 : Debug: literal --> type.
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Acct-Status-Type
Mon Jul 5 17:44:43 2021 : Debug: literal --> .query
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: EXPAND %{tolower:type.%{Acct-Status-T ype}.query}
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: --> type.start.query
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: Using query template 'query'
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Reserved connection (2)
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: EXPAND %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: --> 06767
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: SQL-User-Name set to '06767'
Mon Jul 5 17:44:43 2021 : Debug: INSERT INTO radacct (acctsessionid, a cctuniqueid, username, realm, nasipaddress, n asportid, nasporttype, acctstarttime, acctupdatetime, acctstop time, acctsessiontime, acctauthentic, connectinfo_start, c onnectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedpr otocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id }', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NA S-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_U NIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect- Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Se rvice-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: literal --> INSERT INTO radacct (acctsessionid , acctuniqueid, username, realm, n asipaddress, nasportid, nasporttype, acctstarttime, a cctupdatetime, acctstoptime, acctsessiontime, acctauthentic, c onnectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctet s, calledstationid, callingstationid, acctterminatecause, servicet ype, framedprotocol, framedipaddress) VALUES ('
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Acct-Session-Id
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Acct-Unique-Session-Id
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> SQL-User-Name
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Realm
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> NAS-IP-Address
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: XLAT-IF {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> NAS-Port-Id
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: XLAT-ELSE {
Mon Jul 5 17:44:43 2021 : Debug: attribute --> NAS-Port
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> NAS-Port-Type
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', FROM_UNIXTIME(
Mon Jul 5 17:44:43 2021 : Debug: xlat --> integer
Mon Jul 5 17:44:43 2021 : Debug: {
Mon Jul 5 17:44:43 2021 : Debug: literal --> Event-Timestamp
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: literal --> ), FROM_UNIXTIME(
Mon Jul 5 17:44:43 2021 : Debug: xlat --> integer
Mon Jul 5 17:44:43 2021 : Debug: {
Mon Jul 5 17:44:43 2021 : Debug: literal --> Event-Timestamp
Mon Jul 5 17:44:43 2021 : Debug: }
Mon Jul 5 17:44:43 2021 : Debug: literal --> ), NULL, '0', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Acct-Authentic
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Connect-Info
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '', '0', '0', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Called-Station-Id
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Calling-Station-Id
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Service-Type
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Framed-Protocol
Mon Jul 5 17:44:43 2021 : Debug: literal --> ', '
Mon Jul 5 17:44:43 2021 : Debug: attribute --> Framed-IP-Address
Mon Jul 5 17:44:43 2021 : Debug: literal --> ')
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: EXPAND INSERT INTO radacct (acctsessi onid, acctuniqueid, username, realm, n asipaddress, nasportid, nasporttype, acctstarttime, a cctupdatetime, acctstoptime, acctsessiontime, acctauthentic, c onnectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctet s, calledstationid, callingstationid, acctterminatecause, servicet ype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', ' %{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:E vent-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct- Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling -Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address }')
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: --> INSERT INTO radacct (acctsessi onid, acctuniqueid, username, realm, n asipaddress, nasportid, nasporttype, acctstarttime, a cctupdatetime, acctstoptime, acctsessiontime, acctauthentic, c onnectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctet s, calledstationid, callingstationid, acctterminatecause, servicet ype, framedprotocol, framedipaddress) VALUES ('8020001a', '3f74fa78cc d63a57e895ef2457272140', '06767', '', '192.168.31.77', 'ether3-LAN', 'Wireless-8 02.11', FROM_UNIXTIME(1625492682), FROM_UNIXTIME(1625492682), NULL, '0', '', '', '', '0', '0', 'hotspot1', '00:0C:29:D6:B8:A6', '', '', '', '192.168.251.117')
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: Executing query: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, n asipaddress, nasportid, nasporttype, acctstarttime, a cctupdatetime, acctstoptime, acctsessiontime, acctauthentic, c onnectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctet s, calledstationid, callingstationid, acctterminatecause, servicet ype, framedprotocol, framedipaddress) VALUES ('8020001a', '3f74fa78cc d63a57e895ef2457272140', '06767', '', '192.168.31.77', 'ether3-LAN', 'Wireless-8 02.11', FROM_UNIXTIME(1625492682), FROM_UNIXTIME(1625492682), NULL, '0', '', '', '', '0', '0', 'hotspot1', '00:0C:29:D6:B8:A6', '', '', '', '192.168.251.117')
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: SQL query returned: success
Mon Jul 5 17:44:43 2021 : Debug: (1) sql: 1 record(s) updated
Mon Jul 5 17:44:43 2021 : Debug: rlm_sql (sql): Released connection (2)
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: returned from s ql (rlm_sql)
Mon Jul 5 17:44:43 2021 : Debug: (1) [sql] = ok
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: calling exec (r lm_exec)
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: returned from e xec (rlm_exec)
Mon Jul 5 17:44:43 2021 : Debug: (1) [exec] = noop
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: calling attr_fi lter.accounting_response (rlm_attr_filter)
Mon Jul 5 17:44:43 2021 : Debug: %{User-Name}
Mon Jul 5 17:44:43 2021 : Debug: Parsed xlat tree:
Mon Jul 5 17:44:43 2021 : Debug: attribute --> User-Name
Mon Jul 5 17:44:43 2021 : Debug: (1) attr_filter.accounting_response: EXPAND %{ User-Name}
Mon Jul 5 17:44:43 2021 : Debug: (1) attr_filter.accounting_response: --> 06 767
Mon Jul 5 17:44:43 2021 : Debug: (1) attr_filter.accounting_response: Matched e ntry DEFAULT at line 12
Mon Jul 5 17:44:43 2021 : Debug: (1) modsingle[accounting]: returned from a ttr_filter.accounting_response (rlm_attr_filter)
Mon Jul 5 17:44:43 2021 : Debug: (1) [attr_filter.accounting_response] = up dated
Mon Jul 5 17:44:43 2021 : Debug: (1) } # accounting = updated
Mon Jul 5 17:44:43 2021 : Debug: (1) Sent Accounting-Response Id 42 from 172.26 .11.27:1813 to 103.136.204.45:60317 length 0
Mon Jul 5 17:44:43 2021 : Debug: (1) Finished request
Mon Jul 5 17:44:43 2021 : Debug: (1) Cleaning up request packet ID 42 with time stamp +58
Mon Jul 5 17:44:43 2021 : Debug: Waking up in 4.8 seconds.
Mon Jul 5 17:44:48 2021 : Debug: (0) Cleaning up request packet ID 41 with time stamp +58
Mon Jul 5 17:44:48 2021 : Info: Ready to process requests
More information about the Freeradius-Users
mailing list