Duplicate "Auth: Login OK:"
Fajar A. Nugraha
list at fajar.net
Fri Mar 25 12:28:46 CET 2011
On Fri, Mar 25, 2011 at 4:01 PM, Alan DeKok <aland at deployingradius.com> wrote:
> Fajar A. Nugraha wrote:
>> I believe there's also another (possibly related) bug:
>> I disabled eap completely (comment-out the line "$INCLUDE eap.conf" on
>> radiusd.conf, removed sites-enabled/inner-tunnel, and removed all
>> reference to "eap" on sites-available/default and my virtual server),
>> yet with a simple "radtest" radius.log shows this:
>>
>> Fri Mar 25 10:42:08 2011 : Auth: Login OK: [xxxx at myrealm] (from client
>> localhost port 0 via TLS tunnel)
>
> Two issues:
>
> 1) Why aren't you runnin in debugging mode, as suggested in the FAQ,
> README, INSTALL, and daily on this list? Honestly, it's not that hard.
Sorry about that.
The server was configured for production environment so the debug log
will contaion sensitive information. This issue was low on my priority
list until I saw John's post who also got two "Auth: Login OK:" log.
I've created a test case with as little modification as possible from
the default config file, just enough to reproduce the problem. Here's
the debug log
#=========================================================
FreeRADIUS Version 2.1.10, for host x86_64-redhat-linux-gnu, built on
Mar 24 2011 at 17:49:28
Copyright (C) 1999-2009 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.
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/ntlm_auth
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/opendirectory
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/dynamic_clients
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/virtual-myrealm
including configuration file /etc/raddb/sites-available/default
including configuration file /etc/raddb/sites-enabled/control-socket
main {
user = "radiusd"
group = "radiusd"
allow_core_dumps = no
}
including dictionary file /etc/raddb/dictionary
main {
prefix = "/usr"
localstatedir = "/var"
logdir = "/var/log/radius"
libdir = "/usr/lib64/freeradius"
radacctdir = "/var/log/radius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/var/run/radiusd/radiusd.pid"
checkrad = "/usr/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = yes
auth_badpass = no
auth_goodpass = no
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
radiusd: #### Loading Realms and Home Servers ####
proxy server {
retry_delay = 5
retry_count = 3
default_fallback = no
dead_time = 120
wake_all_if_all_dead = no
}
home_server home-myrealm {
virtual_server = "virtual-myrealm"
port = 0
response_window = 30
max_outstanding = 65536
zombie_period = 40
status_check = "none"
ping_interval = 30
check_interval = 30
num_answers_to_alive = 3
num_pings_to_alive = 3
revive_interval = 300
status_check_timeout = 4
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
home_server_pool pool-myrealm {
home_server = home-myrealm
}
realm myrealm {
pool = pool-myrealm
nostrip
}
realm LOCAL {
}
home_server localhost {
ipaddr = 127.0.0.1
port = 1812
secret = "testing123"
response_window = 20
max_outstanding = 65536
require_message_authenticator = yes
zombie_period = 40
status_check = "status-server"
ping_interval = 30
check_interval = 30
num_answers_to_alive = 3
num_pings_to_alive = 3
revive_interval = 120
status_check_timeout = 4
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
radiusd: #### Loading Clients ####
client localhost {
ipaddr = 127.0.0.1
require_message_authenticator = no
secret = "testing123"
nastype = "other"
}
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating module "exec" from file /etc/raddb/modules/exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_expr
Module: Instantiating module "expr" from file /etc/raddb/modules/expr
Module: Linked to module rlm_expiration
Module: Instantiating module "expiration" from file
/etc/raddb/modules/expiration
expiration {
reply-message = "Password Has Expired "
}
Module: Linked to module rlm_logintime
Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime
logintime {
reply-message = "You are calling outside your allowed timespan "
minimum-timeout = 60
}
}
radiusd: #### Loading Virtual Servers ####
server virtual-myrealm { # from file /etc/raddb/sites-enabled/virtual-myrealm
modules {
Module: Checking authenticate {...} for more modules to load
Module: Linked to module rlm_pap
Module: Instantiating module "pap" from file /etc/raddb/modules/pap
pap {
encryption_scheme = "auto"
auto_header = no
}
Module: Linked to module rlm_chap
Module: Instantiating module "chap" from file /etc/raddb/modules/chap
Module: Linked to module rlm_mschap
Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = no
}
Module: Linked to module rlm_digest
Module: Instantiating module "digest" from file /etc/raddb/modules/digest
Module: Linked to module rlm_unix
Module: Instantiating module "unix" from file /etc/raddb/modules/unix
unix {
radwtmp = "/var/log/radius/radwtmp"
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_preprocess
Module: Instantiating module "preprocess" from file
/etc/raddb/modules/preprocess
preprocess {
huntgroups = "/etc/raddb/huntgroups"
hints = "/etc/raddb/hints"
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
with_alvarion_vsa_hack = no
}
Module: Linked to module rlm_realm
Module: Instantiating module "suffix" from file /etc/raddb/modules/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
Module: Linked to module rlm_files
Module: Instantiating module "files" from file /etc/raddb/modules/files
files {
usersfile = "/etc/raddb/users"
acctusersfile = "/etc/raddb/acct_users"
preproxy_usersfile = "/etc/raddb/preproxy_users"
compat = "no"
}
Module: Checking preacct {...} for more modules to load
Module: Linked to module rlm_acct_unique
Module: Instantiating module "acct_unique" from file
/etc/raddb/modules/acct_unique
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
}
Module: Checking accounting {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating module "detail" from file /etc/raddb/modules/detail
detail {
detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Linked to module rlm_radutmp
Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp
radutmp {
filename = "/var/log/radius/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
perm = 384
callerid = yes
}
Module: Linked to module rlm_attr_filter
Module: Instantiating module "attr_filter.accounting_response" from
file /etc/raddb/modules/attr_filter
attr_filter attr_filter.accounting_response {
attrsfile = "/etc/raddb/attrs.accounting_response"
key = "%{User-Name}"
}
Module: Checking session {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "attr_filter.access_reject" from file
/etc/raddb/modules/attr_filter
attr_filter attr_filter.access_reject {
attrsfile = "/etc/raddb/attrs.access_reject"
key = "%{User-Name}"
}
} # modules
} # server
server { # from file /etc/raddb/radiusd.conf
modules {
Module: Checking authenticate {...} for more modules to load
Module: Checking authorize {...} for more modules to load
Module: Checking preacct {...} for more modules to load
Module: Checking accounting {...} for more modules to load
Module: Checking session {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
}
listen {
type = "acct"
ipaddr = *
port = 0
}
listen {
type = "control"
listen {
socket = "/var/run/radiusd/radiusd.sock"
}
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 35514, id=12, length=64
User-Name = "xxxx at myrealm"
User-Password = "secret"
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] Looking up realm "myrealm" for User-Name = "xxxx at myrealm"
[suffix] Found realm "myrealm"
[suffix] Adding Realm = "myrealm"
[suffix] Proxying request from user xxxx to realm myrealm
[suffix] Preparing to proxy authentication request to realm "myrealm"
++[suffix] returns updated
[files] users: Matched entry xxxx at myrealm at line 205
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
WARNING: Empty pre-proxy section. Using default return values.
>>> Sending proxied request internally to virtual server.
server virtual-myrealm {
# Executing section authorize from file /etc/raddb/sites-available/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] Request already proxied. Ignoring.
++[suffix] returns ok
[files] users: Matched entry xxxx at myrealm at line 205
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
Found Auth-Type = PAP
# Executing group from file /etc/raddb/sites-available/default
+- entering group PAP {...}
[pap] login attempt with password "secret"
[pap] Using clear text password "secret"
[pap] User authenticated successfully
++[pap] returns ok
Login OK: [xxxx at myrealm] (from client localhost port 0 via TLS tunnel)
# Executing section post-auth from file /etc/raddb/sites-available/default
+- entering group post-auth {...}
++[exec] returns noop
} # server virtual-myrealm
Going to the next request
<<< Received proxied response code 2 from internal virtual server.
WARNING: Empty post-proxy section. Using default return values.
Found Auth-Type = Accept
Auth-Type = Accept, accepting the user
Login OK: [xxxx at myrealm] (from client localhost port 0)
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 12 to 127.0.0.1 port 35514
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
#=========================================================
>
> 2) No, you didn't disable EAP.
>
Strange. Even the debug log does not show any eap/TLS-related
configuration (other than "including configuration file
/etc/raddb/modules/inner-eap", which like many modules in
raddb/modules is not used in any later sections).
Anyway, the log seems to indicate that the one giving out "Login OK:
[xxxx at myrealm] (from client localhost port 0 via TLS tunnel)" message
is the virtual server (server virtual-myrealm, whose content is
basically just "$INCLUDE sites-available/default"). And sure enough,
when I disable myrealm-related entries from proxy.conf, the message no
longer appears.
So is the "via TLS tunnel" message a standard response from a virtual
server, or does proxying to a virtual server actually uses TLS tunnel
internally?
--
Fajar
More information about the Freeradius-Users
mailing list