EAP fails when proxying to a realm
Christopher Manigan
cmanigan at towerstream.com
Thu Jun 28 18:33:27 CEST 2012
I am trying to use MSCHAPv2 to authenticate users. This works ok, except when I try to proxy to a realm. Pasted below is the debug of a user trying to authenticate. The realm is a prefix of the username. What I see buried in the debug is:
# radiusd -X
FreeRADIUS Version 2.1.11, for host i686-pc-linux-gnu, built on Jun 28 2012 at 11:37:39
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/detail
including configuration file /etc/raddb/modules/opendirectory
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/dynamic_clients
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/redis
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/ntlm_auth
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/rediswho
including configuration file /etc/raddb/modules/soh
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/krb5
including configuration file /etc/raddb/modules/ldap
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/replicate
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/sql.conf
including configuration file /etc/raddb/sql/mysql/dialup.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/control-socket
main {
allow_core_dumps = no
}
including dictionary file /etc/raddb/dictionary
main {
name = "radiusd"
prefix = "/usr"
localstatedir = "/var"
sbindir = "/usr/sbin"
logdir = "/var/log/radius"
run_dir = "/var/run/radiusd"
libdir = "/usr/lib/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 = no
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 localhost {
ipaddr = 127.0.0.1
port = 1812
type = "auth+acct"
secret = "t0werstream"
response_window = 20
max_outstanding = 65536
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
}
realm myrealm {
auth_pool = mypool
}
realm LOCAL {
}
home_server_pool my_auth_failover {
type = fail-over
home_server = localhost
}
radiusd: #### Loading Clients ####
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 { # from file /etc/raddb/radiusd.conf
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
allow_retry = yes
}
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: Linked to module rlm_eap
Module: Instantiating module "eap" from file /etc/raddb/eap.conf
eap {
default_eap_type = "md5"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
Module: Linked to sub-module rlm_eap_md5
Module: Instantiating eap-md5
Module: Linked to sub-module rlm_eap_leap
Module: Instantiating eap-leap
Module: Linked to sub-module rlm_eap_gtc
Module: Instantiating eap-gtc
gtc {
challenge = "Password: "
auth_type = "PAP"
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
CA_path = "/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/etc/raddb/certs/server.pem"
certificate_file = "/etc/raddb/certs/server.pem"
CA_file = "/etc/raddb/certs/ca.pem"
private_key_password = "whatever"
dh_file = "/etc/raddb/certs/dh"
random_file = "/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = no
cipher_list = "DEFAULT"
make_cert_command = "/etc/raddb/certs/bootstrap"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
}
ocsp {
enable = no
override_cert_url = yes
url = "http://127.0.0.1/ocsp/"
}
}
Module: Linked to sub-module rlm_eap_ttls
Module: Instantiating eap-ttls
ttls {
default_eap_type = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = no
virtual_server = "inner-tunnel"
include_length = yes
}
Module: Linked to sub-module rlm_eap_peap
Module: Instantiating eap-peap
peap {
default_eap_type = "mschapv2"
copy_request_to_tunnel = no
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel"
soh = no
}
Module: Linked to sub-module rlm_eap_mschapv2
Module: Instantiating eap-mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
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_detail
Module: Instantiating module "auth_log" from file /etc/raddb/modules/detail.log
detail auth_log {
detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Linked to module rlm_realm
Module: Instantiating module "IPASS" from file /etc/raddb/modules/realm
realm IPASS {
format = "prefix"
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: Linked to module rlm_sql
Module: Instantiating module "sql" from file /etc/raddb/sql.conf
sql {
driver = "rlm_sql_mysql"
server = "localhost"
port = ""
login = "radius"
password = "password"
radius_db = "radiusdb"
read_groups = yes
sqltrace = no
sqltracefile = "/var/log/radius/sqltrace.sql"
readclients = yes
deletestalesessions = yes
num_sql_socks = 50
lifetime = 0
max_queries = 0
sql_user_name = "%{User-Name}"
default_user_profile = ""
nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id"
authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id"
authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id"
accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'"
accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')"
accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')"
group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority"
connect_failure_retry_delay = 60
simul_count_query = ""
simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL"
postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')"
safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
}
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius at localhost:/radiusdb
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): starting 5
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5
rlm_sql (sql): Connected new DB handle, #5
rlm_sql (sql): starting 6
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql (sql): Connected new DB handle, #6
rlm_sql (sql): starting 7
rlm_sql (sql): Attempting to connect rlm_sql_mysql #7
rlm_sql_mysql: Starting connect to MySQL server for #7
rlm_sql (sql): Connected new DB handle, #7
rlm_sql (sql): starting 8
rlm_sql (sql): Attempting to connect rlm_sql_mysql #8
rlm_sql_mysql: Starting connect to MySQL server for #8
rlm_sql (sql): Connected new DB handle, #8
rlm_sql (sql): starting 9
rlm_sql (sql): Attempting to connect rlm_sql_mysql #9
rlm_sql_mysql: Starting connect to MySQL server for #9
rlm_sql (sql): Connected new DB handle, #9
rlm_sql (sql): starting 10
rlm_sql (sql): Attempting to connect rlm_sql_mysql #10
rlm_sql_mysql: Starting connect to MySQL server for #10
rlm_sql (sql): Connected new DB handle, #10
rlm_sql (sql): starting 11
rlm_sql (sql): Attempting to connect rlm_sql_mysql #11
rlm_sql_mysql: Starting connect to MySQL server for #11
rlm_sql (sql): Connected new DB handle, #11
rlm_sql (sql): starting 12
rlm_sql (sql): Attempting to connect rlm_sql_mysql #12
rlm_sql_mysql: Starting connect to MySQL server for #12
rlm_sql (sql): Connected new DB handle, #12
rlm_sql (sql): starting 13
rlm_sql (sql): Attempting to connect rlm_sql_mysql #13
rlm_sql_mysql: Starting connect to MySQL server for #13
rlm_sql (sql): Connected new DB handle, #13
rlm_sql (sql): starting 14
rlm_sql (sql): Attempting to connect rlm_sql_mysql #14
rlm_sql_mysql: Starting connect to MySQL server for #14
rlm_sql (sql): Connected new DB handle, #14
rlm_sql (sql): starting 15
rlm_sql (sql): Attempting to connect rlm_sql_mysql #15
rlm_sql_mysql: Starting connect to MySQL server for #15
rlm_sql (sql): Connected new DB handle, #15
rlm_sql (sql): starting 16
rlm_sql (sql): Attempting to connect rlm_sql_mysql #16
rlm_sql_mysql: Starting connect to MySQL server for #16
rlm_sql (sql): Connected new DB handle, #16
rlm_sql (sql): starting 17
rlm_sql (sql): Attempting to connect rlm_sql_mysql #17
rlm_sql_mysql: Starting connect to MySQL server for #17
rlm_sql (sql): Connected new DB handle, #17
rlm_sql (sql): starting 18
rlm_sql (sql): Attempting to connect rlm_sql_mysql #18
rlm_sql_mysql: Starting connect to MySQL server for #18
rlm_sql (sql): Connected new DB handle, #18
rlm_sql (sql): starting 19
rlm_sql (sql): Attempting to connect rlm_sql_mysql #19
rlm_sql_mysql: Starting connect to MySQL server for #19
rlm_sql (sql): Connected new DB handle, #19
rlm_sql (sql): starting 20
rlm_sql (sql): Attempting to connect rlm_sql_mysql #20
rlm_sql_mysql: Starting connect to MySQL server for #20
rlm_sql (sql): Connected new DB handle, #20
rlm_sql (sql): starting 21
rlm_sql (sql): Attempting to connect rlm_sql_mysql #21
rlm_sql_mysql: Starting connect to MySQL server for #21
rlm_sql (sql): Connected new DB handle, #21
rlm_sql (sql): starting 22
rlm_sql (sql): Attempting to connect rlm_sql_mysql #22
rlm_sql_mysql: Starting connect to MySQL server for #22
rlm_sql (sql): Connected new DB handle, #22
rlm_sql (sql): starting 23
rlm_sql (sql): Attempting to connect rlm_sql_mysql #23
rlm_sql_mysql: Starting connect to MySQL server for #23
rlm_sql (sql): Connected new DB handle, #23
rlm_sql (sql): starting 24
rlm_sql (sql): Attempting to connect rlm_sql_mysql #24
rlm_sql_mysql: Starting connect to MySQL server for #24
rlm_sql (sql): Connected new DB handle, #24
rlm_sql (sql): starting 25
rlm_sql (sql): Attempting to connect rlm_sql_mysql #25
rlm_sql_mysql: Starting connect to MySQL server for #25
rlm_sql (sql): Connected new DB handle, #25
rlm_sql (sql): starting 26
rlm_sql (sql): Attempting to connect rlm_sql_mysql #26
rlm_sql_mysql: Starting connect to MySQL server for #26
rlm_sql (sql): Connected new DB handle, #26
rlm_sql (sql): starting 27
rlm_sql (sql): Attempting to connect rlm_sql_mysql #27
rlm_sql_mysql: Starting connect to MySQL server for #27
rlm_sql (sql): Connected new DB handle, #27
rlm_sql (sql): starting 28
rlm_sql (sql): Attempting to connect rlm_sql_mysql #28
rlm_sql_mysql: Starting connect to MySQL server for #28
rlm_sql (sql): Connected new DB handle, #28
rlm_sql (sql): starting 29
rlm_sql (sql): Attempting to connect rlm_sql_mysql #29
rlm_sql_mysql: Starting connect to MySQL server for #29
rlm_sql (sql): Connected new DB handle, #29
rlm_sql (sql): starting 30
rlm_sql (sql): Attempting to connect rlm_sql_mysql #30
rlm_sql_mysql: Starting connect to MySQL server for #30
rlm_sql (sql): Connected new DB handle, #30
rlm_sql (sql): starting 31
rlm_sql (sql): Attempting to connect rlm_sql_mysql #31
rlm_sql_mysql: Starting connect to MySQL server for #31
rlm_sql (sql): Connected new DB handle, #31
rlm_sql (sql): starting 32
rlm_sql (sql): Attempting to connect rlm_sql_mysql #32
rlm_sql_mysql: Starting connect to MySQL server for #32
rlm_sql (sql): Connected new DB handle, #32
rlm_sql (sql): starting 33
rlm_sql (sql): Attempting to connect rlm_sql_mysql #33
rlm_sql_mysql: Starting connect to MySQL server for #33
rlm_sql (sql): Connected new DB handle, #33
rlm_sql (sql): starting 34
rlm_sql (sql): Attempting to connect rlm_sql_mysql #34
rlm_sql_mysql: Starting connect to MySQL server for #34
rlm_sql (sql): Connected new DB handle, #34
rlm_sql (sql): starting 35
rlm_sql (sql): Attempting to connect rlm_sql_mysql #35
rlm_sql_mysql: Starting connect to MySQL server for #35
rlm_sql (sql): Connected new DB handle, #35
rlm_sql (sql): starting 36
rlm_sql (sql): Attempting to connect rlm_sql_mysql #36
rlm_sql_mysql: Starting connect to MySQL server for #36
rlm_sql (sql): Connected new DB handle, #36
rlm_sql (sql): starting 37
rlm_sql (sql): Attempting to connect rlm_sql_mysql #37
rlm_sql_mysql: Starting connect to MySQL server for #37
rlm_sql (sql): Connected new DB handle, #37
rlm_sql (sql): starting 38
rlm_sql (sql): Attempting to connect rlm_sql_mysql #38
rlm_sql_mysql: Starting connect to MySQL server for #38
rlm_sql (sql): Connected new DB handle, #38
rlm_sql (sql): starting 39
rlm_sql (sql): Attempting to connect rlm_sql_mysql #39
rlm_sql_mysql: Starting connect to MySQL server for #39
rlm_sql (sql): Connected new DB handle, #39
rlm_sql (sql): starting 40
rlm_sql (sql): Attempting to connect rlm_sql_mysql #40
rlm_sql_mysql: Starting connect to MySQL server for #40
rlm_sql (sql): Connected new DB handle, #40
rlm_sql (sql): starting 41
rlm_sql (sql): Attempting to connect rlm_sql_mysql #41
rlm_sql_mysql: Starting connect to MySQL server for #41
rlm_sql (sql): Connected new DB handle, #41
rlm_sql (sql): starting 42
rlm_sql (sql): Attempting to connect rlm_sql_mysql #42
rlm_sql_mysql: Starting connect to MySQL server for #42
rlm_sql (sql): Connected new DB handle, #42
rlm_sql (sql): starting 43
rlm_sql (sql): Attempting to connect rlm_sql_mysql #43
rlm_sql_mysql: Starting connect to MySQL server for #43
rlm_sql (sql): Connected new DB handle, #43
rlm_sql (sql): starting 44
rlm_sql (sql): Attempting to connect rlm_sql_mysql #44
rlm_sql_mysql: Starting connect to MySQL server for #44
rlm_sql (sql): Connected new DB handle, #44
rlm_sql (sql): starting 45
rlm_sql (sql): Attempting to connect rlm_sql_mysql #45
rlm_sql_mysql: Starting connect to MySQL server for #45
rlm_sql (sql): Connected new DB handle, #45
rlm_sql (sql): starting 46
rlm_sql (sql): Attempting to connect rlm_sql_mysql #46
rlm_sql_mysql: Starting connect to MySQL server for #46
rlm_sql (sql): Connected new DB handle, #46
rlm_sql (sql): starting 47
rlm_sql (sql): Attempting to connect rlm_sql_mysql #47
rlm_sql_mysql: Starting connect to MySQL server for #47
rlm_sql (sql): Connected new DB handle, #47
rlm_sql (sql): starting 48
rlm_sql (sql): Attempting to connect rlm_sql_mysql #48
rlm_sql_mysql: Starting connect to MySQL server for #48
rlm_sql (sql): Connected new DB handle, #48
rlm_sql (sql): starting 49
rlm_sql (sql): Attempting to connect rlm_sql_mysql #49
rlm_sql_mysql: Starting connect to MySQL server for #49
rlm_sql (sql): Connected new DB handle, #49
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas
rlm_sql (sql): Reserving sql socket id: 49
rlm_sql (sql): Read entry nasname=127.0.0.1,shortname=localhost,secret=secret
rlm_sql (sql): Adding client 127.0.0.1 (localhost, server=<none>) to clients list
rlm_sql (sql): Released sql socket id: 49
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: Instantiating module "suffix" from file /etc/raddb/modules/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
Module: Checking accounting {...} for more modules to load
Module: Instantiating module "detail" from file /etc/raddb/modules/detail
detail {
detailfile = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-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-proxy {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "reply_log" from file /etc/raddb/modules/detail.log
detail reply_log {
detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
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 inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
modules {
Module: Checking authenticate {...} for more modules to load
Module: Checking authorize {...} for more modules to load
Module: Checking session {...} for more modules to load
Module: Checking post-proxy {...} 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"
}
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18120
}
... adding new socket proxy address * port 41620
... adding new socket proxy address * port 46995
... adding new socket proxy address * port 43755
... adding new socket proxy address * port 35210
... adding new socket proxy address * port 53936
... adding new socket proxy address * port 60364
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 69.38.220.74 port 33457, id=25, length=227
User-Name = "myrealm/chris"
Calling-Station-Id = "78-D6-F0-9B-62-97"
NAS-IP-Address = 69.38.220.74
NAS-Port = 1
Called-Station-Id = "74-91-1A-63-49-58:My Wi-Fi"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "74-91-1A-63-49-58"
Connect-Info = "CONNECT 802.11g/n"
WISPr-Location-Name = "Lab"
EAP-Message = 0x0200001101737072696e742f6368726973
Vendor-25053-Attr-3 = 0x537072696e742057692d4669
Message-Authenticator = 0x41f70f465513dc906b544110465b80ad
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/69.38.220.74/auth-detail-20120628
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/69.38.220.74/auth-detail-20120628
[auth_log] expand: %t -> Thu Jun 28 12:19:22 2012
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[IPASS] Looking up realm "myrealm" for User-Name = "myrealm/chris"
[IPASS] Found realm "myrealm"
[IPASS] Adding Stripped-User-Name = "chris"
[IPASS] Adding Realm = "myrealm"
[IPASS] Proxying request from user chris to realm myrealm
[IPASS] Preparing to proxy authentication request to realm "myrealm"
++[IPASS] returns updated
[eap] Request is supposed to be proxied to Realm myrealm. Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql] expand: %{User-Name} -> myrealm/chris
[sql] sql_set_user escaped user --> 'myrealm/chris'
rlm_sql (sql): Reserving sql socket id: 48
[sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'myrealm/chris' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'myrealm/chris' ORDER BY priority
rlm_sql (sql): Released sql socket id: 48
[sql] User myrealm/chris not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
WARNING: Empty pre-proxy section. Using default return values.
Sending Access-Request of id 22 to 127.0.0.1 port 1812
User-Name = "chris"
Calling-Station-Id = "78-D6-F0-9B-62-97"
NAS-IP-Address = 1.1.1.1
NAS-Port = 1
Called-Station-Id = "74-91-1A-63-49-58:My Wi-Fi"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "74-91-1A-63-49-58"
Connect-Info = "CONNECT 802.11g/n"
WISPr-Location-Name = "Lab"
EAP-Message = 0x0200001101737072696e742f6368726973
Vendor-25053-Attr-3 = 0x537072696e742057692d4669
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x3235
Proxying request 0 to home server 127.0.0.1 port 1812
Sending Access-Request of id 22 to 127.0.0.1 port 1812
User-Name = "chris"
Calling-Station-Id = "78-D6-F0-9B-62-97"
NAS-IP-Address = 1.1.1.1
NAS-Port = 1
Called-Station-Id = "74-91-1A-63-49-58:My Wi-Fi"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "74-91-1A-63-49-58"
Connect-Info = "CONNECT 802.11g/n"
WISPr-Location-Name = "Lab"
EAP-Message = 0x0200001101737072696e742f6368726973
Vendor-25053-Attr-3 = 0x537072696e742057692d4669
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x3235
Going to the next request
Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=22, length=224
User-Name = "chris"
Calling-Station-Id = "78-D6-F0-9B-62-97"
NAS-IP-Address = 1.1.1.1
NAS-Port = 1
Called-Station-Id = "74-91-1A-63-49-58:My Wi-Fi"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "74-91-1A-63-49-58"
Connect-Info = "CONNECT 802.11g/n"
WISPr-Location-Name = "Lab"
EAP-Message = 0x0200001101737072696e742f6368726973
Vendor-25053-Attr-3 = 0x537072696e742057692d4669
Message-Authenticator = 0x89165f7b9f6f2901f98df17bc6ad51b1
Proxy-State = 0x3235
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/127.0.0.1/auth-detail-20120628
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/127.0.0.1/auth-detail-20120628
[auth_log] expand: %t -> Thu Jun 28 12:19:22 2012
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[IPASS] No '/' in User-Name = "chris", looking up realm NULL
[IPASS] No such realm "NULL"
++[IPASS] returns noop
[eap] EAP packet type response id 0 length 17
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> chris
[sql] sql_set_user escaped user --> 'chris'
rlm_sql (sql): Reserving sql socket id: 47
[sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'chris' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'chris' ORDER BY priority
rlm_sql (sql): Released sql socket id: 47
[sql] User chris not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Identity does not match User-Name, setting from EAP Identity.
[eap] Failed in handler
++[eap] returns invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group REJECT {...}
[sql] expand: %{User-Name} -> chris
[sql] sql_set_user escaped user --> 'chris'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[sql] expand: %{Chap-Password} ->
[sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'chris', '', 'Access-Reject', '2012-06-28 12:19:22')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'chris', '', 'Access-Reject', '2012-06-28 12:19:22')
rlm_sql (sql): Reserving sql socket id: 46
rlm_sql (sql): Released sql socket id: 46
++[sql] returns ok
[attr_filter.access_reject] expand: %{User-Name} -> chris
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 1 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 1
Sending Access-Reject of id 22 to 127.0.0.1 port 1814
Proxy-State = 0x3235
Waking up in 4.9 seconds.
rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=22, length=24
Proxy-State = 0x3235
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Using Post-Auth-Type Reject
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group REJECT {...}
[sql] expand: %{User-Name} -> myrealm/chris
[sql] sql_set_user escaped user --> 'myrealm/chris'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[sql] expand: %{Chap-Password} ->
[sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'myrealm/chris', '', 'Access-Reject', '2012-06-28 12:19:22')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'myrealm/chris', '', 'Access-Reject', '2012-06-28 12:19:22')
rlm_sql (sql): Reserving sql socket id: 45
rlm_sql (sql): Released sql socket id: 45
++[sql] returns ok
[attr_filter.access_reject] expand: %{User-Name} -> myrealm/chris
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Sending Access-Reject of id 25 to 69.38.220.74 port 33457
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 1 ID 22 with timestamp +7
Cleaning up request 0 ID 25 with timestamp +7
Ready to process requests.
Thanks,
Chris
More information about the Freeradius-Users
mailing list