Unused Authorize Queries
Ammad Ali
ammad.ali at rapidcompute.com
Mon Nov 30 11:22:04 CET 2020
Hi,
I have checked a user in debugging of user via raddebug, if the user is
not being found in radcheck table, the freeradius is still executing
groupcheck and groupreply tables. It look like its causing extra load on
mysql database. Is there a way to minimize them ? or is there a way that
if the user is not found in radcheck, then freeradius should not execute
other queries.
Below is the debug result.
(257372773) Mon Nov 30 15:11:24 2020 : Debug: Received Access-Request
packet from host 192.168.247.70 port 53214, id=108, length=26
(257372773) Mon Nov 30 15:11:24 2020 : Debug: User-Name = 'test'
(257372773) Mon Nov 30 15:11:24 2020 : Debug: # Executing section
authorize from file /etc/raddb/sites-enabled/default
(257372773) Mon Nov 30 15:11:24 2020 : Debug: authorize {
(257372773) Mon Nov 30 15:11:24 2020 : Debug: filter_username
filter_username {
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (!&User-Name)
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (!&User-Name) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~ / /)
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~ /
/) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/@.*@/ )
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/@.*@/ ) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/\\.\\./ )
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/\\.\\./ ) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~ /\\.$/)
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/\\.$/) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~ /@\\./)
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&User-Name =~
/@\\./) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: } # filter_username
filter_username = notfound
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [preprocess] = ok
(257372773) Mon Nov 30 EXPAND
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail
(257372773) Mon Nov 30 -->
/var/log/radius/radacct/192.168.247.70/auth-detail
(257372773) Mon Nov 30
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail
expands to /var/log/radius/radacct/192.168.247.70/auth-detail
(257372773) Mon Nov 30 EXPAND %t
(257372773) Mon Nov 30 --> Mon Nov 30 15:11:24 2020
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [auth_log] = ok
(257372773) Mon Nov 3Checking for suffix after "@"
(257372773) Mon Nov 3No '@' in User-Name = "test", looking up realm NULL
(257372773) Mon Nov 3No such realm "NULL"
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [suffix] = noop
(257372773) Mon NoEXPAND %{User-Name}
(257372773) Mon No --> test
(257372773) Mon NoSQL-User-Name set to 'test'
(257372773) Mon NoEXPAND SELECT id, username, attribute, value, op FROM
radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id
(257372773) Mon No --> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = BINARY 'test' ORDER BY id
(257372773) Mon NoUser found in radcheck table
(257372773) Mon NoEXPAND SELECT groupname FROM radusergroup WHERE
username = BINARY '%{SQL-User-Name}' ORDER BY priority
(257372773) Mon No --> SELECT groupname FROM radusergroup WHERE
username = BINARY 'test' ORDER BY priority
(257372773) Mon NoUser found in the group table
(257372773) Mon NoEXPAND SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id
(257372773) Mon No --> SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = 'Alpine-9-KHI' ORDER BY id
(257372773) Mon NoGroup "Alpine-9-KHI" check items matched
(257372773) Mon NoEXPAND SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = '%{Sql-Group}' and nas_ip_addr =
'%{NAS-IP-Address}' ORDER BY id
(257372773) Mon No --> SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = 'Alpine-9-KHI' and nas_ip_addr =
'192.168.247.70' ORDER BY id
(257372773) Mon NoGroup "Alpine-9-KHI" reply items processed
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [sql] = ok
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [expiration] = noop
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [logintime] = noop
(257372773) WARNING: Mon NoNo "known good" password found for the user.
Not setting Auth-Type
(257372773) WARNING: Mon NoAuthentication will fail unless a "known
good" password is available
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [pap] = noop
(257372773) Mon Nov 30 15:11:24 2020 : Debug: } # authorize = ok
(257372773) ERROR: Mon Nov 30 15:11:24 2020 : ERROR: No Auth-Type found:
rejecting the user via Post-Auth-Type = Reject
(257372773) Mon Nov 30 15:11:24 2020 : Debug: Failed to authenticate the
user
(257372773) Mon Nov 30 15:11:24 2020 : Debug: EXPAND Error: Invalid
Username/Password...!
(257372773) Mon Nov 30 15:11:24 2020 : Debug: --> Error: Invalid
Username/Password...!
(257372773) Mon Nov 30 15:11:24 2020 : Debug: Using Post-Auth-Type Reject
(257372773) Mon Nov 30 15:11:24 2020 : Debug: # Executing group from
file /etc/raddb/sites-enabled/default
(257372773) Mon Nov 30 15:11:24 2020 : Debug: Post-Auth-Type REJECT {
(257372773) Mon NoEXPAND .query
(257372773) Mon No --> .query
(257372773) Mon NoUsing query template 'query'
(257372773) Mon NoEXPAND %{User-Name}
(257372773) Mon No --> test
(257372773) Mon NoSQL-User-Name set to 'test'
(257372773) Mon NoEXPAND INSERT INTO radpostauth (username, pass, reply,
authdate, CallingStationId, NASPortId, nasipaddress) VALUES (
'%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S', '%{Calling-Station-Id}', '%{NAS-Port-Id}',
'%{NAS-IP-Address}')
(257372773) Mon No --> INSERT INTO radpostauth (username, pass, reply,
authdate, CallingStationId, NASPortId, nasipaddress) VALUES ( 'test',
'', 'Access-Reject', '2020-11-30 15:11:24', '', '', '192.168.247.70')
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [sql] = ok
(257372773) Mon Nov 30 15:11:24 2020 : DEXPAND %{User-Name}
(257372773) Mon Nov 30 15:11:24 2020 : D --> test
(257372773) Mon Nov 30 15:11:24 2020 : DMatched entry DEFAULT at line 11
(257372773) Mon Nov 30 15:11:24 2020 : Debug:
[attr_filter.access_reject] = updated
(257372773) Mon Nov 30 15:11:24 2020 : Debug:
remove_reply_message_if_eap remove_reply_message_if_eap {
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&reply:EAP-Message
&& &reply:Reply-Message)
(257372773) Mon Nov 30 15:11:24 2020 : Debug: if (&reply:EAP-Message
&& &reply:Reply-Message) -> FALSE
(257372773) Mon Nov 30 15:11:24 2020 : Debug: else else {
(257372773) Mon Nov 30 15:11:24 2020 : Debug: [noop] = noop
(257372773) Mon Nov 30 15:11:24 2020 : Debug: } # else else = noop
(257372773) Mon Nov 30 15:11:24 2020 : Debug: } #
remove_reply_message_if_eap remove_reply_message_if_eap = noop
(257372773) Mon Nov 30 15:11:24 2020 : Debug: } # Post-Auth-Type REJECT
= updated
(257372773) Mon Nov 30 15:11:24 2020 : Debug: Delaying response for 1
seconds
(257372773) Mon Nov 30 15:11:25 2020 : Debug: Sending delayed response
(257372773) Mon Nov 30 15:11:25 2020 : Debug: Sending Access-Reject
packet to host 192.168.247.70 port 53214, id=108, length=0
(257372773) Mon Nov 30 15:11:34 2020 : Debug: Cleaning up request packet
ID 108 with timestamp +3880200
--
More information about the Freeradius-Users
mailing list