radmin - problem with setting up username based filter as condition

Fekete Tamás fektom at gmail.com
Tue Jan 22 08:23:15 CET 2019


> Did you look at the *content* of the file?

Yes. I will attach it below. My assumption is, that only "bob" user should
go into bob.log with the mentioned condition.

(0) Mon Jan 21 15:50:31 2019: Debug: Received Access-Request Id 95 from
127.0.0.1:44499 to 127.0.0.1:1812 length 73
(0) Mon Jan 21 15:50:31 2019: Debug:   User-Name = "bob"
(0) Mon Jan 21 15:50:31 2019: Debug:   User-Password = "hello"
(0) Mon Jan 21 15:50:31 2019: Debug:   NAS-IP-Address = 127.0.0.1
(0) Mon Jan 21 15:50:31 2019: Debug:   NAS-Port = 0
(0) Mon Jan 21 15:50:31 2019: Debug:   Message-Authenticator =
0xd4f66ead47e4727879f6202ba7ed3fcc
(0) Mon Jan 21 15:50:31 2019: Debug: session-state: No State attribute
(0) Mon Jan 21 15:50:31 2019: Debug: # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
(0) Mon Jan 21 15:50:31 2019: Debug:   authorize {
(0) Mon Jan 21 15:50:31 2019: Debug:     policy filter_username {
(0) Mon Jan 21 15:50:31 2019: Debug:       if (&User-Name) {
(0) Mon Jan 21 15:50:31 2019: Debug:       if (&User-Name)  -> TRUE
(0) Mon Jan 21 15:50:31 2019: Debug:       if (&User-Name)  {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ / /) {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ / /)  ->
FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /@[^@]*@/ ) {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /@[^@]*@/ )
-> FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /\.\./ ) {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /\.\./ )  ->
FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))  {
(0) Mon Jan 21 15:50:31 2019: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /\.$/)  {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /\.$/)   ->
FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /@\./)  {
(0) Mon Jan 21 15:50:31 2019: Debug:         if (&User-Name =~ /@\./)   ->
FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:       } # if (&User-Name)  = notfound
(0) Mon Jan 21 15:50:31 2019: Debug:     } # policy filter_username =
notfound
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
preprocess (rlm_preprocess)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from preprocess (rlm_preprocess)
(0) Mon Jan 21 15:50:31 2019: Debug:     [preprocess] = ok
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
auth_log (rlm_detail)
(0) Mon Jan 21 15:50:31 2019: Debug: auth_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(0) Mon Jan 21 15:50:31 2019: Debug: auth_log:    -->
/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20190121
(0) Mon Jan 21 15:50:31 2019: Debug: auth_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20190121
(0) Mon Jan 21 15:50:31 2019: Debug: auth_log: EXPAND %t
(0) Mon Jan 21 15:50:31 2019: Debug: auth_log:    --> Mon Jan 21 15:50:31
2019
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from auth_log (rlm_detail)
(0) Mon Jan 21 15:50:31 2019: Debug:     [auth_log] = ok
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling chap
(rlm_chap)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from chap (rlm_chap)
(0) Mon Jan 21 15:50:31 2019: Debug:     [chap] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
mschap (rlm_mschap)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from mschap (rlm_mschap)
(0) Mon Jan 21 15:50:31 2019: Debug:     [mschap] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
digest (rlm_digest)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from digest (rlm_digest)
(0) Mon Jan 21 15:50:31 2019: Debug:     [digest] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
suffix (rlm_realm)
(0) Mon Jan 21 15:50:31 2019: Debug: suffix: Checking for suffix after "@"
(0) Mon Jan 21 15:50:31 2019: Debug: suffix: No '@' in User-Name = "bob",
looking up realm NULL
(0) Mon Jan 21 15:50:31 2019: Debug: suffix: No such realm "NULL"
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from suffix (rlm_realm)
(0) Mon Jan 21 15:50:31 2019: Debug:     [suffix] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling eap
(rlm_eap)
(0) Mon Jan 21 15:50:31 2019: Debug: eap: No EAP-Message, not doing EAP
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from eap (rlm_eap)
(0) Mon Jan 21 15:50:31 2019: Debug:     [eap] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
files (rlm_files)
(0) Mon Jan 21 15:50:31 2019: Debug: files: users: Matched entry bob at
line 87
(0) Mon Jan 21 15:50:31 2019: Debug: files: ::: FROM 1 TO 0 MAX 1
(0) Mon Jan 21 15:50:31 2019: Debug: files: ::: Examining Reply-Message
(0) Mon Jan 21 15:50:31 2019: Debug: files: EXPAND Hello, %{User-Name}
(0) Mon Jan 21 15:50:31 2019: Debug: files:    --> Hello, bob
(0) Mon Jan 21 15:50:31 2019: Debug: files: ::: APPENDING Reply-Message
FROM 0 TO 0
(0) Mon Jan 21 15:50:31 2019: Debug: files: ::: TO in 0 out 0
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from files (rlm_files)
(0) Mon Jan 21 15:50:31 2019: Debug:     [files] = ok
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
expiration (rlm_expiration)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from expiration (rlm_expiration)
(0) Mon Jan 21 15:50:31 2019: Debug:     [expiration] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling
logintime (rlm_logintime)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from logintime (rlm_logintime)
(0) Mon Jan 21 15:50:31 2019: Debug:     [logintime] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: calling pap
(rlm_pap)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authorize]: returned
from pap (rlm_pap)
(0) Mon Jan 21 15:50:31 2019: Debug:     [pap] = updated
(0) Mon Jan 21 15:50:31 2019: Debug:   } # authorize = updated
(0) Mon Jan 21 15:50:31 2019: Debug: Found Auth-Type = PAP
(0) Mon Jan 21 15:50:31 2019: Debug: # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
(0) Mon Jan 21 15:50:31 2019: Debug:   Auth-Type PAP {
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authenticate]: calling
pap (rlm_pap)
(0) Mon Jan 21 15:50:31 2019: Debug: pap: Login attempt with password
"hello" (5)
(0) Mon Jan 21 15:50:31 2019: Debug: pap: Comparing with "known good"
Cleartext-Password "hello" (5)
(0) Mon Jan 21 15:50:31 2019: Debug: pap: User authenticated successfully
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[authenticate]: returned
from pap (rlm_pap)
(0) Mon Jan 21 15:50:31 2019: Debug:     [pap] = ok
(0) Mon Jan 21 15:50:31 2019: Debug:   } # Auth-Type PAP = ok
(0) Mon Jan 21 15:50:31 2019: Debug: # Executing section post-auth from
file /usr/local/etc/raddb/sites-enabled/default
(0) Mon Jan 21 15:50:31 2019: Debug:   post-auth {
(0) Mon Jan 21 15:50:31 2019: Debug:     update {
(0) Mon Jan 21 15:50:31 2019: Debug:       No attributes updated
(0) Mon Jan 21 15:50:31 2019: Debug:     } # update = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[post-auth]: calling
reply_log (rlm_detail)
(0) Mon Jan 21 15:50:31 2019: Debug: reply_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
(0) Mon Jan 21 15:50:31 2019: Debug: reply_log:    -->
/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20190121
(0) Mon Jan 21 15:50:31 2019: Debug: reply_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20190121
(0) Mon Jan 21 15:50:31 2019: Debug: reply_log: EXPAND %t
(0) Mon Jan 21 15:50:31 2019: Debug: reply_log:    --> Mon Jan 21 15:50:31
2019
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[post-auth]: returned
from reply_log (rlm_detail)
(0) Mon Jan 21 15:50:31 2019: Debug:     [reply_log] = ok
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[post-auth]: calling exec
(rlm_exec)
(0) Mon Jan 21 15:50:31 2019: Debug:     modsingle[post-auth]: returned
from exec (rlm_exec)
(0) Mon Jan 21 15:50:31 2019: Debug:     [exec] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     policy remove_reply_message_if_eap
{
(0) Mon Jan 21 15:50:31 2019: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message) {
(0) Mon Jan 21 15:50:31 2019: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message)  -> FALSE
(0) Mon Jan 21 15:50:31 2019: Debug:       else {
(0) Mon Jan 21 15:50:31 2019: Debug:         modsingle[post-auth]: calling
noop (rlm_always)
(0) Mon Jan 21 15:50:31 2019: Debug:         modsingle[post-auth]: returned
from noop (rlm_always)
(0) Mon Jan 21 15:50:31 2019: Debug:         [noop] = noop
(0) Mon Jan 21 15:50:31 2019: Debug:       } # else = noop
(0) Mon Jan 21 15:50:31 2019: Debug:     } # policy
remove_reply_message_if_eap = noop
(0) Mon Jan 21 15:50:31 2019: Debug:   } # post-auth = ok
(0) Mon Jan 21 15:50:31 2019: Debug: Sent Access-Accept Id 95 from
127.0.0.1:1812 to 127.0.0.1:44499 length 0
(0) Mon Jan 21 15:50:31 2019: Debug:   Reply-Message = "Hello, bob"
(0) Mon Jan 21 15:50:31 2019: Debug: Finished request
(0) Mon Jan 21 15:50:36 2019: Debug: Cleaning up request packet ID 95 with
timestamp +133
(1) Mon Jan 21 15:50:41 2019: Debug: Received Access-Request Id 124 from
127.0.0.1:36274 to 127.0.0.1:1812 length 78
(1) Mon Jan 21 15:50:41 2019: Debug:   User-Name = "whatever"
(1) Mon Jan 21 15:50:41 2019: Debug:   User-Password = "hello"
(1) Mon Jan 21 15:50:41 2019: Debug:   NAS-IP-Address = 127.0.0.1
(1) Mon Jan 21 15:50:41 2019: Debug:   NAS-Port = 0
(1) Mon Jan 21 15:50:41 2019: Debug:   Message-Authenticator =
0x7bd78b27263510e61533a91bf14a7438
(1) Mon Jan 21 15:50:41 2019: Debug: session-state: No State attribute
(1) Mon Jan 21 15:50:41 2019: Debug: # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
(1) Mon Jan 21 15:50:41 2019: Debug:   authorize {
(1) Mon Jan 21 15:50:41 2019: Debug:     policy filter_username {
(1) Mon Jan 21 15:50:41 2019: Debug:       if (&User-Name) {
(1) Mon Jan 21 15:50:41 2019: Debug:       if (&User-Name)  -> TRUE
(1) Mon Jan 21 15:50:41 2019: Debug:       if (&User-Name)  {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ / /) {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ / /)  ->
FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /@[^@]*@/ ) {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /@[^@]*@/ )
-> FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /\.\./ ) {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /\.\./ )  ->
FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))  {
(1) Mon Jan 21 15:50:41 2019: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /\.$/)  {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /\.$/)   ->
FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /@\./)  {
(1) Mon Jan 21 15:50:41 2019: Debug:         if (&User-Name =~ /@\./)   ->
FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:       } # if (&User-Name)  = notfound
(1) Mon Jan 21 15:50:41 2019: Debug:     } # policy filter_username =
notfound
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
preprocess (rlm_preprocess)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from preprocess (rlm_preprocess)
(1) Mon Jan 21 15:50:41 2019: Debug:     [preprocess] = ok
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
auth_log (rlm_detail)
(1) Mon Jan 21 15:50:41 2019: Debug: auth_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(1) Mon Jan 21 15:50:41 2019: Debug: auth_log:    -->
/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20190121
(1) Mon Jan 21 15:50:41 2019: Debug: auth_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20190121
(1) Mon Jan 21 15:50:41 2019: Debug: auth_log: EXPAND %t
(1) Mon Jan 21 15:50:41 2019: Debug: auth_log:    --> Mon Jan 21 15:50:41
2019
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from auth_log (rlm_detail)
(1) Mon Jan 21 15:50:41 2019: Debug:     [auth_log] = ok
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling chap
(rlm_chap)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from chap (rlm_chap)
(1) Mon Jan 21 15:50:41 2019: Debug:     [chap] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
mschap (rlm_mschap)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from mschap (rlm_mschap)
(1) Mon Jan 21 15:50:41 2019: Debug:     [mschap] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
digest (rlm_digest)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from digest (rlm_digest)
(1) Mon Jan 21 15:50:41 2019: Debug:     [digest] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
suffix (rlm_realm)
(1) Mon Jan 21 15:50:41 2019: Debug: suffix: Checking for suffix after "@"
(1) Mon Jan 21 15:50:41 2019: Debug: suffix: No '@' in User-Name =
"whatever", looking up realm NULL
(1) Mon Jan 21 15:50:41 2019: Debug: suffix: No such realm "NULL"
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from suffix (rlm_realm)
(1) Mon Jan 21 15:50:41 2019: Debug:     [suffix] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling eap
(rlm_eap)
(1) Mon Jan 21 15:50:41 2019: Debug: eap: No EAP-Message, not doing EAP
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from eap (rlm_eap)
(1) Mon Jan 21 15:50:41 2019: Debug:     [eap] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
files (rlm_files)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from files (rlm_files)
(1) Mon Jan 21 15:50:41 2019: Debug:     [files] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
expiration (rlm_expiration)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from expiration (rlm_expiration)
(1) Mon Jan 21 15:50:41 2019: Debug:     [expiration] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling
logintime (rlm_logintime)
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from logintime (rlm_logintime)
(1) Mon Jan 21 15:50:41 2019: Debug:     [logintime] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: calling pap
(rlm_pap)
(1) Mon Jan 21 15:50:41 2019: WARNING: pap: No "known good" password found
for the user.  Not setting Auth-Type
(1) Mon Jan 21 15:50:41 2019: WARNING: pap: Authentication will fail unless
a "known good" password is available
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[authorize]: returned
from pap (rlm_pap)
(1) Mon Jan 21 15:50:41 2019: Debug:     [pap] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:   } # authorize = ok
(1) Mon Jan 21 15:50:41 2019: ERROR: No Auth-Type found: rejecting the user
via Post-Auth-Type = Reject
(1) Mon Jan 21 15:50:41 2019: Debug: Failed to authenticate the user
(1) Mon Jan 21 15:50:41 2019: Debug: Using Post-Auth-Type Reject
(1) Mon Jan 21 15:50:41 2019: Debug: # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
(1) Mon Jan 21 15:50:41 2019: Debug:   Post-Auth-Type REJECT {
(1) Mon Jan 21 15:50:41 2019: Debug:     update reply {
(1) Mon Jan 21 15:50:41 2019: Debug:       Module-Failure-Message :=
&request:Module-Failure-Message -> 'No Auth-Type found: rejecting the user
via Post-Auth-Type = Reject'
(1) Mon Jan 21 15:50:41 2019: Debug:     } # update reply = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: calling
reply_log (rlm_detail)
(1) Mon Jan 21 15:50:41 2019: Debug: reply_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
(1) Mon Jan 21 15:50:41 2019: Debug: reply_log:    -->
/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20190121
(1) Mon Jan 21 15:50:41 2019: Debug: reply_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20190121
(1) Mon Jan 21 15:50:41 2019: Debug: reply_log: EXPAND %t
(1) Mon Jan 21 15:50:41 2019: Debug: reply_log:    --> Mon Jan 21 15:50:41
2019
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: returned
from reply_log (rlm_detail)
(1) Mon Jan 21 15:50:41 2019: Debug:     [reply_log] = ok
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: calling
attr_filter.access_reject (rlm_attr_filter)
(1) Mon Jan 21 15:50:41 2019: Debug: attr_filter.access_reject: EXPAND
%{User-Name}
(1) Mon Jan 21 15:50:41 2019: Debug: attr_filter.access_reject:    -->
whatever
(1) Mon Jan 21 15:50:41 2019: Debug: attr_filter.access_reject: Matched
entry DEFAULT at line 11
(1) Mon Jan 21 15:50:41 2019: Debug: attr_filter.access_reject: Attribute
"Module-Failure-Message" allowed by 0 rules, disallowed by 0 rules
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: returned
from attr_filter.access_reject (rlm_attr_filter)
(1) Mon Jan 21 15:50:41 2019: Debug:     [attr_filter.access_reject] =
updated
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: calling eap
(rlm_eap)
(1) Mon Jan 21 15:50:41 2019: Debug: eap: Request didn't contain an
EAP-Message, not inserting EAP-Failure
(1) Mon Jan 21 15:50:41 2019: Debug:     modsingle[post-auth]: returned
from eap (rlm_eap)
(1) Mon Jan 21 15:50:41 2019: Debug:     [eap] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     policy remove_reply_message_if_eap
{
(1) Mon Jan 21 15:50:41 2019: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message) {
(1) Mon Jan 21 15:50:41 2019: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message)  -> FALSE
(1) Mon Jan 21 15:50:41 2019: Debug:       else {
(1) Mon Jan 21 15:50:41 2019: Debug:         modsingle[post-auth]: calling
noop (rlm_always)
(1) Mon Jan 21 15:50:41 2019: Debug:         modsingle[post-auth]: returned
from noop (rlm_always)
(1) Mon Jan 21 15:50:41 2019: Debug:         [noop] = noop
(1) Mon Jan 21 15:50:41 2019: Debug:       } # else = noop
(1) Mon Jan 21 15:50:41 2019: Debug:     } # policy
remove_reply_message_if_eap = noop
(1) Mon Jan 21 15:50:41 2019: Debug:   } # Post-Auth-Type REJECT = updated
(1) Mon Jan 21 15:50:41 2019: Debug: Delaying response for 1.000000 seconds
(1) Mon Jan 21 15:50:42 2019: Debug: Sending delayed response
(1) Mon Jan 21 15:50:42 2019: Debug: Sent Access-Reject Id 124 from
127.0.0.1:1812 to 127.0.0.1:36274 length 20
(1) Mon Jan 21 15:50:46 2019: Debug: Cleaning up request packet ID 124 with
timestamp +143

Alan Buxey <alan.buxey at gmail.com> ezt írta (időpont: 2019. jan. 21., H,
20:24):

> Hi
>
> You set the filename to bob.log so everything went there. Different users
> etc etc. All will go into the filename set. There's no magic link between
> the username in the log filename and the users passing through the server
>
> alan
>
> On Mon, 21 Jan 2019, 14:56 Fekete Tamás <fektom at gmail.com wrote:
>
> > > It does work.  Especially if you use a different use name.
> >
> > First I set up these:
> > [root at compiler radius]# radmin
> > radmin version 3.0.17, built on Jan 11 2019 at 08:31:34 - FreeRADIUS
> Server
> > administration tool.
> > Copyright (C) 2008-2017 The FreeRADIUS server project and contributors.
> > There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
> > PARTICULAR PURPOSE.
> > You may redistribute copies of FreeRADIUS under the terms of the
> > GNU General Public License v2.
> > radmin> debug level 4
> > radmin> debug condition '(User-Name == "bob")'
> > radmin> debug file bob.log
> > radmin> show debug level
> > 4
> > radmin> show debug condition
> > &User-Name == "bob"
> > radmin> show debug file
> > /usr/local/var/log/radius/bob.log
> > radmin>
> >
> > And I run two different test-case with two different user names and the
> > size of the output file (bob.log) enhanced (mind the ls -l output below):
> >
> > [root at compiler radius]# radtest bob hello localhost 0 testing123
> > Sent Access-Request Id 95 from 0.0.0.0:44499 to 127.0.0.1:1812 length 73
> > User-Name = "bob"
> > User-Password = "hello"
> > NAS-IP-Address = 127.0.0.1
> > NAS-Port = 0
> > Message-Authenticator = 0x00
> > Cleartext-Password = "hello"
> > Received Access-Accept Id 95 from 127.0.0.1:1812 to 127.0.0.1:44499
> length
> > 32
> > Reply-Message = "Hello, bob"
> > [root at compiler radius]# ls -l
> > total 332
> > -rw-r--r-- 1 root root   9601 Jan 21 15:50 bob.log
> > drwx------ 3 root root     23 Jan 11 10:55 radacct
> > -rw-r----- 1 root root 245801 Jan 21 15:50 radius.log
> > [root at compiler radius]# radtest whatever hello localhost 0 testing123
> > Sent Access-Request Id 124 from 0.0.0.0:36274 to 127.0.0.1:1812 length
> 78
> > User-Name = "whatever"
> > User-Password = "hello"
> > NAS-IP-Address = 127.0.0.1
> > NAS-Port = 0
> > Message-Authenticator = 0x00
> > Cleartext-Password = "hello"
> > Received Access-Reject Id 124 from 127.0.0.1:1812 to 127.0.0.1:36274
> > length
> > 20
> > (0) -: Expected Access-Accept got Access-Reject
> > [root at compiler radius]# ls -l
> > total 340
> > -rw-r--r-- 1 root root  19462 Jan 21 15:50 bob.log
> > drwx------ 3 root root     23 Jan 11 10:55 radacct
> > -rw-r----- 1 root root 271295 Jan 21 15:50 radius.log
> > [root at compiler radius]#
> >
> > Is something missing from my process?
> >
> > Alan DeKok <aland at deployingradius.com> ezt írta (időpont: 2019. jan.
> 21.,
> > H, 14:27):
> >
> > > On Jan 21, 2019, at 2:23 AM, Fekete Tamás <fektom at gmail.com> wrote:
> > > > I want to log debug information only about one user with using
> radmin,
> > > but
> > > > I experience two problems in the expected behaviour of this tool.
> > > > When I set up radmin with the following options:
> > > >
> > > > debug level 4
> > > > debug condition '(User-Name == "bob")'
> > > > debug file bob.log
> > > >
> > > > the /var/log/radius/bob.log is created and filled by Freeradius, but
> > > > /var/log/radius/radius.log gets the same debug logs, so the debug
> > > > information is duplicated.
> > >
> > >   That's unfortunately the way it works.  Changing that is hard at this
> > > point.
> > >
> > > > The second problem is that if I use another user name, for example
> > > > 'whatever', for connection trial, the debug information still goes to
> > > > /var/log/radius/bob.log, however, the debug condition was
> > >
> > >   You can change the debug file...
> > >
> > > > debug condition '(User-Name == "bob")'
> > > >
> > > > My question is, why the filtering condition doesn't work
> > >
> > >   It does work.  Especially if you use a different use name.
> > >
> > > > and the second is,
> > > > how can I stop the double logging (into /var/log/radius/radius.log
> > > > /var/log/radius/bob.log in the same time)?
> > >
> > >   Send a patch.
> > >
> > >   Alan DeKok.
> > >
> > >
> > > -
> > > List info/subscribe/unsubscribe? See
> > > http://www.freeradius.org/list/users.html
> > -
> > List info/subscribe/unsubscribe? See
> > http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html


More information about the Freeradius-Users mailing list