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@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