March 2018 - Freeradius-Users - lists.freeradius.org

Unknown vendor name in attribute name
by Steffen Schwebel 01 Mar '18

01 Mar '18

Greetings o/ I support a radius version 2.2.5 + mysql for a customer of ours. Recently I had to add new Vendor attributes. Using those generates an error and I am stuck. The exact error is: rlm_sql: Failed to create the pair: Unknown vendor name in attribute name "Transmode-ENM-User-Category" rlm_sql (sql): Error getting data from database The SQL query and output: mysql radius_aaa -e "SELECT id, username, attribute, value, op FROM radreply WHERE username ='testuser01'"; +-----+------------+-----------------------------+--------------------+----+ | id | username | attribute | value | op | +-----+------------+-----------------------------+--------------------+----+ | 65 | testuser01 | Cisco-AVPair | "shell:priv-lvl=5" | = | | 66 | testuser01 | Service-Type | NAS-Prompt-User | = | | 67 | testuser01 | Foundry-Privilege-Level | 5 | = | | 89 | testuser01 | Juniper-Local-User-Name | JunOS-Backbone-RO | := | | 132 | testuser01 | Juniper-Local-User-Name | JunOS-CPE-RO | := | | 158 | testuser01 | Juniper-Local-User-Name | remote | := | | 159 | testuser01 | Transmode-ENM-User-Category | 0x1 | += | +-----+------------+-----------------------------+--------------------+----+ Debug output: --- freeradius: FreeRADIUS Version 2.2.5, for host x86_64-pc-linux-gnu, built on Aug 10 2017 at 07:25:15 Copyright (C) 1999-2013 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. For more information about these matters, see the file named COPYRIGHT. Starting - reading configuration files ... including configuration file /etc/freeradius-aaa//radiusd.conf including configuration file /etc/freeradius-aaa//clients.conf including files in directory /etc/freeradius-aaa//modules/ including configuration file /etc/freeradius-aaa//modules/opendirectory including configuration file /etc/freeradius-aaa//modules/echo including configuration file /etc/freeradius-aaa//modules/logintime including configuration file /etc/freeradius-aaa//modules/detail.log including configuration file /etc/freeradius-aaa//modules/passwd including configuration file /etc/freeradius-aaa//modules/linelog including configuration file /etc/freeradius-aaa//modules/attr_rewrite including configuration file /etc/freeradius-aaa//modules/always including configuration file /etc/freeradius-aaa//modules/expiration including configuration file /etc/freeradius-aaa//modules/smsotp including configuration file /etc/freeradius-aaa//modules/dynamic_clients including configuration file /etc/freeradius-aaa//modules/mschap including configuration file /etc/freeradius-aaa//modules/radutmp including configuration file /etc/freeradius-aaa//modules/policy including configuration file /etc/freeradius-aaa//modules/mac2vlan including configuration file /etc/freeradius-aaa//modules/counter including configuration file /etc/freeradius-aaa//modules/acct_unique including configuration file /etc/freeradius-aaa//modules/exec including configuration file /etc/freeradius-aaa//modules/inner-eap including configuration file /etc/freeradius-aaa//modules/realm including configuration file /etc/freeradius-aaa//modules/ippool including configuration file /etc/freeradius-aaa//modules/detail.example.com including configuration file /etc/freeradius-aaa//modules/sql_log including configuration file /etc/freeradius-aaa//modules/wimax including configuration file /etc/freeradius-aaa//modules/ldap including configuration file /etc/freeradius-aaa//modules/mac2ip including configuration file /etc/freeradius-aaa//modules/attr_filter including configuration file /etc/freeradius-aaa//modules/ntlm_auth including configuration file /etc/freeradius-aaa//modules/otp including configuration file /etc/freeradius-aaa//modules/pap including configuration file /etc/freeradius-aaa//modules/chap including configuration file /etc/freeradius-aaa//modules/etc_group including configuration file /etc/freeradius-aaa//modules/preprocess including configuration file /etc/freeradius-aaa//modules/checkval including configuration file /etc/freeradius-aaa//modules/perl including configuration file /etc/freeradius-aaa//modules/krb5 including configuration file /etc/freeradius-aaa//modules/files including configuration file /etc/freeradius-aaa//modules/cui including configuration file /etc/freeradius-aaa//modules/detail including configuration file /etc/freeradius-aaa//modules/digest including configuration file /etc/freeradius-aaa//modules/expr including configuration file /etc/freeradius-aaa//modules/unix including configuration file /etc/freeradius-aaa//modules/smbpasswd including configuration file /etc/freeradius-aaa//modules/sradutmp including configuration file /etc/freeradius-aaa//modules/sqlcounter_expire_on_login including configuration file /etc/freeradius-aaa//modules/pam including configuration file /etc/freeradius-aaa//eap.conf including configuration file /etc/freeradius-aaa//sql.conf including configuration file /etc/freeradius-aaa//sql/mysql/dialup.conf including configuration file /etc/freeradius-aaa//sql/mysql/counter.conf including configuration file /etc/freeradius-aaa//policy.conf including files in directory /etc/freeradius-aaa//sites-enabled/ including configuration file /etc/freeradius-aaa//sites-enabled/default including configuration file /etc/freeradius-aaa//sites-enabled/inner-tunnel main { user = "freerad" group = "freerad" allow_core_dumps = no } including dictionary file /etc/freeradius-aaa//dictionary main { name = "freeradius-aaa" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius-aaa" run_dir = "/var/run/freeradius-aaa" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius-aaa/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 pidfile = "/var/run/freeradius-aaa/freeradius-aaa.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no log { stripped_names = no auth = yes auth_badpass = no auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes allow_vulnerable_openssl = no } } radiusd: #### Loading Realms and Home Servers #### 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/freeradius-aaa//modules/exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /etc/freeradius-aaa//modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/freeradius-aaa//modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/freeradius-aaa//modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file ? modules { Module: Creating Auth-Type = digest Module: Creating Post-Auth-Type = REJECT Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/freeradius-aaa//modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/freeradius-aaa//modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/freeradius-aaa//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/freeradius-aaa//modules/digest Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/freeradius-aaa//modules/unix unix { radwtmp = "/var/log/freeradius-aaa/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/freeradius-aaa//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/freeradius-aaa//certs" pem_file_type = yes private_key_file = "/etc/freeradius-aaa//certs/server.key" certificate_file = "/etc/freeradius-aaa//certs/server.pem" CA_file = "/etc/freeradius-aaa//certs/ca.pem" private_key_password = "whatever" dh_file = "/etc/freeradius-aaa//certs/dh" random_file = "/dev/urandom" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/etc/freeradius-aaa//certs/bootstrap" ecdh_curve = "prime256v1" cache { enable = no lifetime = 24 max_entries = 255 } verify { } } 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/freeradius-aaa//modules/preprocess preprocess { huntgroups = "/etc/freeradius-aaa//huntgroups" hints = "/etc/freeradius-aaa//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 } reading pairlist file /etc/freeradius-aaa//huntgroups reading pairlist file /etc/freeradius-aaa//hints Module: Linked to module rlm_realm Module: Instantiating module "suffix" from file /etc/freeradius-aaa//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/freeradius-aaa//modules/files files { usersfile = "/etc/freeradius-aaa//users" acctusersfile = "/etc/freeradius-aaa//acct_users" preproxy_usersfile = "/etc/freeradius-aaa//preproxy_users" compat = "no" } reading pairlist file /etc/freeradius-aaa//users reading pairlist file /etc/freeradius-aaa//acct_users reading pairlist file /etc/freeradius-aaa//preproxy_users Module: Linked to module rlm_sql Module: Instantiating module "sql" from file /etc/freeradius-aaa//sql.conf sql { driver = "rlm_sql_mysql" server = "127.0.0.1" port = "3306" login = "<secret>" password = "<secret>" radius_db = "radius_aaa" read_groups = yes sqltrace = no sqltracefile = "/var/log/freeradius-aaa/sqltrace.sql" readclients = yes deletestalesessions = yes num_sql_socks = 5 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 dolibarr@127.0.0.1:3306/radius_aaa 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): 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: 4 rlm_sql (sql): Read entry nasname=<HOSTNAME>,shortname=<HOSTNAME>,secret=<secret> rlm_sql (sql): Adding client <IP> (<HOSTNAME>, server=<none>) to clients list rlm_sql (sql): Read entry nasname=<HOSTNAME>,shortname=<HOSTNAME>,secret=<secret> rlm_sql (sql): Adding client <IP> (<HOSTNAME>, server=<none>) to clients list <removed some lines> rlm_sql (sql): Released sql socket id: 4 Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /etc/freeradius-aaa//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/freeradius-aaa//modules/detail detail { detailfile = "/var/log/freeradius-aaa/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/freeradius-aaa//modules/radutmp radutmp { filename = "/var/log/freeradius-aaa/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Linked to module rlm_sql_log Module: Instantiating module "sql_log" from file /etc/freeradius-aaa//modules/sql_log sql_log { path = "/var/log/freeradius-aaa/radacct/sql-relay" Post-Auth = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S');" sql_user_name = "%{%{User-Name}:-DEFAULT}" utf8 = no safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius-aaa//modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/freeradius-aaa//attrs.accounting_response" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius-aaa//attrs.accounting_response 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 "attr_filter.access_reject" from file /etc/freeradius-aaa//modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/freeradius-aaa//attrs.access_reject" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius-aaa//attrs.access_reject } # modules } # server server inner-tunnel { # from file /etc/freeradius-aaa//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 = <IP> port = 1814 } listen { type = "acct" ipaddr = <IP> port = 1815 } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } Listening on authentication address <IP> port 1814 Listening on accounting address <IP> port 1815 Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Ready to process requests. rad_recv: Access-Request packet from host <IP> port 35760, id=91, length=80 User-Name = "testuser01" User-Password = "test1234" NAS-IP-Address = <IP> NAS-Port = 0 Message-Authenticator = 0x61803daee501323cb7312359c83e6d2b # Executing section authorize from file /etc/freeradius-aaa//sites-enabled/default +group authorize { ++update request { sql_xlat expand: %{User-Name} -> testuser01 sql_set_user escaped user --> 'testuser01' expand: SELECT type FROM nas WHERE nasname='%{Packet-Src-IP-Address}' -> SELECT type FROM nas WHERE nasname='<IP>' rlm_sql (sql): Reserving sql socket id: 3 sql_xlat finished rlm_sql (sql): Released sql socket id: 3 expand: %{sql:SELECT type FROM nas WHERE nasname='%{Packet-Src-IP-Address}'} -> other ++} # update request = noop ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "testuser01", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] No EAP-Message, not doing EAP ++[eap] = noop ++[files] = noop [sql] expand: %{User-Name} -> testuser01 [sql] sql_set_user escaped user --> 'testuser01' rlm_sql (sql): Reserving sql socket id: 2 [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 = 'testuser01' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'testuser01' ORDER BY id rlm_sql: Failed to create the pair: Unknown vendor name in attribute name "Transmode-ENM-User-Category" rlm_sql (sql): Error getting data from database [sql] SQL query error; rejecting user rlm_sql (sql): Released sql socket id: 2 ++[sql] = fail +} # group authorize = fail Invalid user: [testuser01] (from client radius1 port 0) Using Post-Auth-Type REJECT # Executing group from file /etc/freeradius-aaa//sites-enabled/default +group REJECT { [sql] expand: %{User-Name} -> testuser01 [sql] sql_set_user escaped user --> 'testuser01' [sql] expand: %{User-Password} -> test1234 [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 ( 'testuser01', 'test1234', 'Access-Reject', '2018-03-01 09:50:43') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testuser01', 'test1234', 'Access-Reject', '2018-03-01 09:50:43') rlm_sql (sql): Reserving sql socket id: 1 rlm_sql (sql): Released sql socket id: 1 ++[sql] = ok [attr_filter.access_reject] expand: %{User-Name} -> testuser01 attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 Sending Access-Reject of id 91 to 217.17.30.116 port 35760 Waking up in 4.9 seconds. --- Any help would be nice. Regards, Steffen Schwebel

2 1

Authenticate via AD and via local "users" file
by DUPALUT, Benjamin 01 Mar '18

01 Mar '18

Hi everyone, I'm using a pfsense server as captive portal to authenticate users on my WiFi network. The captive portal is set to interrogate my freeradius server. My freeradius server can already authenticate users via my AD using winbind. I also need local account (via "users" file) to create some temporary "WiFi" account for guests. My problem is that it seems that when freeradius receive an mschap request, it only interrogate the AD and do not check the local "users" file : *Radtest output :* *root@radius:/etc/freeradius/3.0# radtest test hello localhost 0 testing123Sent Access-Request Id 221 from 0.0.0.0:55019 <http://0.0.0.0:55019> to 127.0.0.1:1812 <http://127.0.0.1:1812> length 74 User-Name = "test" User-Password = "hello" NAS-IP-Address = 127.0.1.1 NAS-Port = 0 Message-Authenticator = 0x00 Cleartext-Password = "hello"Received Access-Accept Id 221 from 127.0.0.1:1812 <http://127.0.0.1:1812> to 0.0.0.0:0 <http://0.0.0.0:0> length 20root@radius:/etc/freeradius/3.0# radtest -t mschap test hello localhost 0 testing123Sent Access-Request Id 57 from 0.0.0.0:45981 <http://0.0.0.0:45981> to 127.0.0.1:1812 <http://127.0.0.1:1812> length 130 User-Name = "test" MS-CHAP-Password = "hello" NAS-IP-Address = 127.0.1.1 NAS-Port = 0 Message-Authenticator = 0x00 Cleartext-Password = "hello" MS-CHAP-Challenge = 0x721c5f615cce85ee MS-CHAP-Response = 0x0001000000000000000000000000000000000000000000000000fd35479230547ed1afaabb4620398d1ab297fc558976fbe5Received Access-Reject Id 57 from 127.0.0.1:1812 <http://127.0.0.1:1812> to 0.0.0.0:0 <http://0.0.0.0:0> length 61 MS-CHAP-Error = "\000E=648 R=0 C=36f192b64ad8bf50 V=2"(0) -: Expected Access-Accept got Access-Reject* *freeradius -X output :* *1) Received Access-Request Id 57 from 127.0.0.1:45981 <http://127.0.0.1:45981> to 127.0.0.1:1812 <http://127.0.0.1:1812> length 130(1) User-Name = "test"(1) NAS-IP-Address = 127.0.1.1(1) NAS-Port = 0(1) Message-Authenticator = 0x2ac9eeb221acb45d57e63c7670667269(1) MS-CHAP-Challenge = 0x721c5f615cce85ee(1) MS-CHAP-Response = 0x0001000000000000000000000000000000000000000000000000fd35479230547ed1afaabb4620398d1ab297fc558976fbe5(1) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default(1) authorize {(1) policy filter_username {(1) if (&User-Name) {(1) if (&User-Name) -> TRUE(1) if (&User-Name) {(1) if (&User-Name =~ / /) {(1) if (&User-Name =~ / /) -> FALSE(1) if (&User-Name =~ /@[^@]*@/ ) {(1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE(1) if (&User-Name =~ /\.\./ ) {(1) if (&User-Name =~ /\.\./ ) -> FALSE(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE(1) if (&User-Name =~ /\.$/) {(1) if (&User-Name =~ /\.$/) -> FALSE(1) if (&User-Name =~ /(a)\./) {(1) if (&User-Name =~ /(a)\./) -> FALSE(1) } # if (&User-Name) = notfound(1) } # policy filter_username = notfound(1) [preprocess] = ok(1) [chap] = noop(1) mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap'(1) [mschap] = ok(1) [digest] = noop(1) suffix: Checking for suffix after "@"(1) suffix: No '@' in User-Name = "test", looking up realm NULL(1) suffix: No such realm "NULL"(1) [suffix] = noop(1) eap: No EAP-Message, not doing EAP(1) [eap] = noop(1) files: users: Matched entry test at line 1(1) [files] = ok(1) [expiration] = noop(1) [logintime] = noop(1) pap: WARNING: Auth-Type already set. Not setting to PAP(1) [pap] = noop(1) } # authorize = ok(1) Found Auth-Type = mschap(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default(1) authenticate {(1) mschap: Found Cleartext-Password, hashing to create NT-Password(1) mschap: Found Cleartext-Password, hashing to create LM-Password(1) mschap: Client is using MS-CHAPv1 with NT-Password(1) mschap: EXPAND %{mschap:User-Name}(1) mschap: --> testrlm_mschap (mschap): Reserved connection (0)(1) mschap: sending authentication request user='test' domain='lan.domain.tld'rlm_mschap (mschap): Released connection (0)rlm_mschap (mschap): Need 5 more connections to reach 10 sparesrlm_mschap (mschap): Opening additional connection (5), 1 of 27 pending slots used(1) mschap: ERROR: No such user [0xC0000064](1) mschap: ERROR: Password has expired. User should retry authentication(1) [mschap] = reject(1) } # authenticate = reject(1) Failed to authenticate the user(1) Using Post-Auth-Type Reject(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default(1) Post-Auth-Type REJECT {(1) attr_filter.access_reject: EXPAND %{User-Name}(1) attr_filter.access_reject: --> test(1) attr_filter.access_reject: Matched entry DEFAULT at line 11(1) [attr_filter.access_reject] = updated(1) [eap] = noop(1) policy remove_reply_message_if_eap {(1) if (&reply:EAP-Message && &reply:Reply-Message) {(1) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE(1) else {(1) [noop] = noop(1) } # else = noop(1) } # policy remove_reply_message_if_eap = noop(1) } # Post-Auth-Type REJECT = updated(1) Delaying response for 1.000000 secondsWaking up in 0.3 seconds.Waking up in 0.6 seconds.(1) Sending delayed response(1) Sent Access-Reject Id 57 from 127.0.0.1:1812 <http://127.0.0.1:1812> to 127.0.0.1:45981 <http://127.0.0.1:45981> length 61(1) MS-CHAP-Error = "\000E=648 R=0 C=36f192b64ad8bf50 V=2"Waking up in 3.9 seconds.(1) Cleaning up request packet ID 57 with timestamp +19* Does anyone has an idea how i can use both authentication methods (AD and "local") simultaneously ? Thanks in advance. Regards, *Benjamin Dupalut* Administrateur système et réseau Service des Moyens Informatiques Généraux (SMIG) ESIEE Paris 2 bd Blaise Pascal - 93162 Noisy-le-Grand Cedex T : +33 1 45 92 66 17 benjamin.dupalut(a)esiee.fr www.esiee.fr / www.cci-paris-idf.fr

2 2

undefined symbol
by Bassem Mettichi 01 Mar '18

01 Mar '18

Hello, iam using freeradius 3.0.16 and in module rediswho iam trying to send Framed-IP-Address in access accept packet. Iam using pairmake_reply but when i start freeradius on mode debug i get this error: pairmake_reply("Reply-Message", "Test", T_OP_EQ); undefined symbol: pairmake_reply an idea how to resolve this issue? is this function still exist on freeradius 3? Thanks Regards Bassem

1 0

authenticate against SHA2 hash in EAP-MSCHAPv2
by Volodymyr Litovka 01 Mar '18

01 Mar '18

Hi colleagues, I'm pretty new in FreeRadius and looks missing something that will allow me to authenticate MSCHAP users agains stored SHA256 hashes. Having the following entries in the "users" file : #doka Cleartext-Password := "q1w2e3" doka SHA2-Password := "AE5A853873043C7B011C6300C464D8D4014BF833697A3C01817D83AA91A53166" I'm trying to authenticate Stronswan connections, which use EAP-MSCHAPv2. In both cases, FreeRadius notes that "pap: WARNING: Auth-Type already set. Not setting to PAP" but while it's not required with Cleartext-Password, it's required (but not called) for SHA2-Password: There are two different debugs: 1) for clear-text password it works: (1) eap: No EAP Start, assuming it's an on-going EAP conversation (1) [eap] = updated (1) files: users: Matched entry doka at line 68 (1) files: EXPAND Hello, %{User-Name} (1) files: --> Hello, doka (1) [files] = ok (1) [expiration] = noop (1) [logintime] = noop (1) pap: WARNING: Auth-Type already set. Not setting to PAP (1) [pap] = noop (1) } # authorize = updated (1) Found Auth-Type = eap (1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (1) authenticate { (1) eap: Expiring EAP session with state 0xa83c0023a83d1a89 (1) eap: Finished EAP session with state 0xa83c0023a83d1a89 (1) eap: Previous EAP request found for state 0xa83c0023a83d1a89, released from the list (1) eap: Peer sent packet with method EAP MSCHAPv2 (26) (1) eap: Calling submodule eap_mschapv2 to process data (1) eap_mschapv2: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (1) eap_mschapv2: authenticate { (1) mschap: Found Cleartext-Password, hashing to create NT-Password (1) mschap: Found Cleartext-Password, hashing to create LM-Password (1) mschap: Creating challenge hash with username: doka (1) mschap: Client is using MS-CHAPv2 (1) mschap: Adding MS-CHAPv2 MPPE keys (1) [mschap] = ok (1) } # authenticate = ok (1) MSCHAP Success 2) while as soon as I switch to SHA2-Password, it stops authenticate requests (1) eap: No EAP Start, assuming it's an on-going EAP conversation (1) [eap] = updated (1) files: users: Matched entry doka at line 69 (1) files: EXPAND Hello, %{User-Name} (1) files: --> Hello, doka (1) [files] = ok (1) [expiration] = noop (1) [logintime] = noop (1) pap: Normalizing SHA2-Password from hex encoding, 64 bytes -> 32 bytes (1) pap: WARNING: Auth-Type already set. Not setting to PAP (1) [pap] = noop (1) } # authorize = updated (1) Found Auth-Type = eap (1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (1) authenticate { (1) eap: Expiring EAP session with state 0x1ba8bb871ba9a1a0 (1) eap: Finished EAP session with state 0x1ba8bb871ba9a1a0 (1) eap: Previous EAP request found for state 0x1ba8bb871ba9a1a0, released from the list (1) eap: Peer sent packet with method EAP MSCHAPv2 (26) (1) eap: Calling submodule eap_mschapv2 to process data (1) eap_mschapv2: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (1) eap_mschapv2: authenticate { (1) mschap: WARNING: No Cleartext-Password configured. Cannot create NT-Password (1) mschap: WARNING: No Cleartext-Password configured. Cannot create LM-Password (1) mschap: Creating challenge hash with username: doka (1) mschap: Client is using MS-CHAPv2 (1) mschap: ERROR: FAILED: No NT/LM-Password. Cannot perform authentication (1) mschap: ERROR: MS-CHAP2-Response is incorrect (1) [mschap] = reject (1) } # authenticate = reject (1) eap: Sending EAP Failure (code 4) ID 1 length 4 (1) eap: Freeing handler (1) [eap] = reject (1) } # authenticate = reject (1) Failed to authenticate the user Configuration is the following: 1) sites-enabled/default : authorize { filter_username preprocess auth_log chap mschap digest suffix eap { ok = return } files -sql -ldap expiration logintime pap } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } mschap digest eap } 2) mods-enabled/eap : eap { default_eap_type = mschapv2 timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = ${max_requests} md5 { } mschapv2 { } } 3) mods-enabled/mschap (unmodified) : mschap { pool { start = ${thread[pool].start_servers} min = ${thread[pool].min_spare_servers} max = ${thread[pool].max_servers} spare = ${thread[pool].max_spare_servers} uses = 0 retry_delay = 30 lifetime = 86400 cleanup_interval = 300 idle_timeout = 600 } passchange { } } 4) mod-enabled/pap (unmodified) : pap { } I will greatly appreciate any help on working around this issue. Please. Thank you! -- Volodymyr Litovka "Vision without Execution is Hallucination." -- Thomas Edison

4 7

User-Name attribute is not included in Access-Accept
by kaoru eto 01 Mar '18

01 Mar '18

Are there any reason why User-Name attribute is not included in Access-Accept when Stripped-User-Name attribute is added by rlm_realm? I think that RFC 3579 seems to require the User-Name attribute in Access-Accept. RFC3579 3. Attributes ---------------------------------------- In order to permit forwarding of the Access-Reply by EAP-unaware proxies, if a User-Name attribute was included in an Access-Request, the RADIUS server MUST include the User-Name attribute in subsequent Access-Accept packets. ---------------------------------------- Configuration for reproduce: proxy.conf ---------------------------------------- #realm "NULL" { # type=radius # authhost=LOCAL # accthost=LOCAL #} ---------------------------------------- -> User-Name attribute is included in Access-Accept. ---------------------------------------- realm "NULL" { type=radius authhost=LOCAL accthost=LOCAL } ---------------------------------------- -> User-Name attribute is not included in Access-Accept. Full degug log at reproduce: ---------------------------------------- /usr/local/radius316/sbin/radiusd -XX Debug: Server was built with: Debug: accounting : yes Debug: authentication : yes Debug: ascend-binary-attributes : yes Debug: coa : yes Debug: control-socket : yes Debug: detail : yes Debug: dhcp : yes Debug: dynamic-clients : yes Debug: osfc2 : no Debug: proxy : yes Debug: regex-pcre : no Debug: regex-posix : yes Debug: regex-posix-extended : yes Debug: session-management : yes Debug: stats : yes Debug: tcp : yes Debug: threads : yes Debug: tls : yes Debug: unlang : yes Debug: vmps : yes Debug: developer : no Debug: Server core libs: Debug: freeradius-server : 3.0.16 Debug: talloc : 2.0.* Debug: ssl : 1.0.1e release Debug: Endianness: Debug: little Debug: Compilation flags: Debug: cppflags : -isystem /usr/local/adapter/account/php/include/php/ext/pcre/pcrelib Debug: cflags : -I. -Isrc -include src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h -include src/freeradius-devel/features.h -include src/freeradius-devel/radpaths.h -fno-strict-aliasing -Wno-date-time -g -O2 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -DNDEBUG -DIS_MODULE=1 Debug: ldflags : Debug: libs : -lcrypto -lssl -ltalloc -lcap -lnsl -lresolv -ldl -lpthread -lreadline Debug: Info: FreeRADIUS Version 3.0.16 Info: Copyright (C) 1999-2017 The FreeRADIUS server project and contributors Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Info: PARTICULAR PURPOSE Info: You may redistribute copies of FreeRADIUS under the terms of the Info: GNU General Public License Info: For more information about these matters, see the file named COPYRIGHT Info: Starting - reading configuration files ... Debug: including dictionary file /usr/local/radius316/share/freeradius/dictionary Debug: including dictionary file /usr/local/radius316/share/freeradius/dictionary.dhcp Debug: including dictionary file /usr/local/radius316/share/freeradius/dictionary.vqp Debug: including dictionary file /usr/local/radius316/etc/raddb/dictionary Debug: including configuration file /usr/local/radius316/etc/raddb/radiusd.conf Debug: including configuration file /usr/local/radius316/etc/raddb/proxy.conf Debug: including configuration file /usr/local/radius316/etc/raddb/clients.conf Debug: including files in directory /usr/local/radius316/etc/raddb/mods-enabled/ Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/echo Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/utf8 Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/cache_eap Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/digest Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/unix Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/ntlm_auth Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/detail Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/linelog Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/expr Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/sradutmp Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/passwd Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/exec Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/pap Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/expiration Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/unpack Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/preprocess Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/radutmp Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/replicate Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/mschap Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/dynamic_clients Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/files Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/eap Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/soh Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/date Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/chap Debug: including configuration file /usr/local/radius316/etc/raddb/mods-enabled/logintime Debug: including files in directory /usr/local/radius316/etc/raddb/policy.d/ Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/debug Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/abfab-tr Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/dhcp Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/operator-name Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/control Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/filter Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/canonicalization Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/moonshot-targeted-ids Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/cui Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Debug: OPTIMIZING (no == yes) --> FALSE Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Debug: OPTIMIZING (no == yes) --> FALSE Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/eap Debug: including configuration file /usr/local/radius316/etc/raddb/policy.d/accounting Debug: including files in directory /usr/local/radius316/etc/raddb/sites-enabled/ Debug: including configuration file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: including configuration file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: main { Debug: security { Debug: allow_core_dumps = no Warning: /usr/local/radius316/etc/raddb/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[472]: The item 'allow_vulnerable_openssl' is defined, but is unused by the configuration Debug: } Debug: name = "radiusd" Debug: prefix = "/usr/local/radius316" Debug: localstatedir = "/usr/local/radius316/var" Debug: logdir = "/usr/local/radius316/var/log/radius" Debug: run_dir = "/usr/local/radius316/var/run/radiusd" Warning: /usr/local/radius316/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[491]: The item 'proxy_requests' is defined, but is unused by the configuration Debug: } Debug: main { Debug: name = "radiusd" Debug: prefix = "/usr/local/radius316" Debug: localstatedir = "/usr/local/radius316/var" Debug: sbindir = "/usr/local/radius316/sbin" Debug: logdir = "/usr/local/radius316/var/log/radius" Debug: run_dir = "/usr/local/radius316/var/run/radiusd" Debug: libdir = "/usr/local/radius316/lib" Debug: radacctdir = "/usr/local/radius316/var/log/radius/radacct" Debug: hostname_lookups = no Debug: max_request_time = 30 Debug: cleanup_delay = 5 Debug: max_requests = 16384 Debug: pidfile = "/usr/local/radius316/var/run/radiusd/radiusd.pid" Debug: checkrad = "/usr/local/radius316/sbin/checkrad" Debug: debug_level = 0 Debug: proxy_requests = yes Debug: log { Debug: stripped_names = no Debug: auth = no Debug: auth_badpass = no Debug: auth_goodpass = no Debug: colourise = yes Debug: msg_denied = "You are already logged in - access denied" Warning: /usr/local/radius316/etc/raddb/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configuration Debug: } Debug: resources { Debug: } Debug: security { Debug: max_attributes = 200 Debug: reject_delay = 1.000000 Debug: status_server = yes Debug: allow_vulnerable_openssl = "yes" Debug: } Warning: /usr/local/radius316/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Warning: /usr/local/radius316/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Debug: } Debug: radiusd: #### Loading Realms and Home Servers #### Debug: proxy server { Debug: retry_delay = 5 Debug: retry_count = 3 Debug: default_fallback = no Debug: dead_time = 120 Debug: wake_all_if_all_dead = no Debug: } Debug: home_server localhost { Debug: ipaddr = 127.0.0.1 Debug: port = 1812 Debug: type = "auth" Debug: secret = "testing123" Debug: response_window = 20.000000 Debug: response_timeouts = 1 Debug: max_outstanding = 65536 Debug: zombie_period = 40 Debug: status_check = "status-server" Debug: ping_interval = 30 Debug: check_interval = 30 Debug: check_timeout = 4 Debug: num_answers_to_alive = 3 Debug: revive_interval = 120 Debug: limit { Debug: max_connections = 16 Debug: max_requests = 0 Debug: lifetime = 0 Debug: idle_timeout = 0 Debug: } Debug: coa { Debug: irt = 2 Debug: mrt = 16 Debug: mrc = 5 Debug: mrd = 30 Debug: } Debug: } Debug: home_server_pool my_auth_failover { Debug: type = fail-over Debug: home_server = localhost Debug: } Debug: realm example.com { Debug: auth_pool = my_auth_failover Debug: } Debug: realm LOCAL { Debug: } Debug: realm NULL { Debug: authhost = LOCAL Debug: accthost = LOCAL Debug: } Debug: radiusd: #### Loading Clients #### Debug: client localhost { Debug: ipaddr = 127.0.0.1 Debug: require_message_authenticator = no Debug: secret = "testing123" Debug: nas_type = "other" Debug: proto = "*" Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Debug: client localhost_ipv6 { Debug: ipv6addr = ::1 Debug: require_message_authenticator = no Debug: secret = "testing123" Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Adding client ::1/128 (::1) to prefix tree 128 Debug: client test { Debug: ipaddr = 192.168.0.0/16 Debug: require_message_authenticator = no Debug: secret = "12345" Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Adding client 192.168.0.0/16 (192.168.0.0) to prefix tree 16 Info: Debugger not attached Debug: # Creating Auth-Type = mschap Debug: # Creating Auth-Type = digest Debug: # Creating Auth-Type = eap Debug: # Creating Auth-Type = PAP Debug: # Creating Auth-Type = CHAP Debug: # Creating Auth-Type = MS-CHAP Debug: radiusd: #### Instantiating modules #### Debug: modules { Debug: Loading rlm_exec with path: /usr/local/radius316/lib/rlm_exec.so Debug: Loaded rlm_exec, checking if it's valid Debug: # Loaded module rlm_exec Debug: # Loading module "echo" from file /usr/local/radius316/etc/raddb/mods-enabled/echo Debug: exec echo { Debug: wait = yes Debug: program = "/bin/echo %{User-Name}" Debug: input_pairs = "request" Debug: output_pairs = "reply" Debug: shell_escape = yes Debug: } Debug: Loading rlm_utf8 with path: /usr/local/radius316/lib/rlm_utf8.so Debug: Loaded rlm_utf8, checking if it's valid Debug: # Loaded module rlm_utf8 Debug: # Loading module "utf8" from file /usr/local/radius316/etc/raddb/mods-enabled/utf8 Debug: Loading rlm_cache with path: /usr/local/radius316/lib/rlm_cache.so Debug: Loaded rlm_cache, checking if it's valid Debug: # Loaded module rlm_cache Debug: # Loading module "cache_eap" from file /usr/local/radius316/etc/raddb/mods-enabled/cache_eap Debug: cache cache_eap { Debug: driver = "rlm_cache_rbtree" Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" Debug: ttl = 15 Debug: max_entries = 0 Debug: epoch = 0 Debug: add_stats = no Debug: } Debug: Loading rlm_digest with path: /usr/local/radius316/lib/rlm_digest.so Debug: Loaded rlm_digest, checking if it's valid Debug: # Loaded module rlm_digest Debug: # Loading module "digest" from file /usr/local/radius316/etc/raddb/mods-enabled/digest Debug: Loading rlm_unix with path: /usr/local/radius316/lib/rlm_unix.so Debug: Loaded rlm_unix, checking if it's valid Debug: # Loaded module rlm_unix Debug: # Loading module "unix" from file /usr/local/radius316/etc/raddb/mods-enabled/unix Debug: unix { Debug: radwtmp = "/usr/local/radius316/var/log/radius/radwtmp" Debug: } Debug: Creating attribute Unix-Group Debug: Loading rlm_attr_filter with path: /usr/local/radius316/lib/rlm_attr_filter.so Debug: Loaded rlm_attr_filter, checking if it's valid Debug: # Loaded module rlm_attr_filter Debug: # Loading module "attr_filter.post-proxy" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: attr_filter attr_filter.post-proxy { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/attr_filter/post-proxy" Debug: key = "%{Realm}" Debug: relaxed = no Debug: } Debug: # Loading module "attr_filter.pre-proxy" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: attr_filter attr_filter.pre-proxy { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/attr_filter/pre-proxy" Debug: key = "%{Realm}" Debug: relaxed = no Debug: } Debug: # Loading module "attr_filter.access_reject" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: attr_filter attr_filter.access_reject { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/attr_filter/access_reject" Debug: key = "%{User-Name}" Debug: relaxed = no Debug: } Debug: # Loading module "attr_filter.access_challenge" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: attr_filter attr_filter.access_challenge { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/attr_filter/access_challenge" Debug: key = "%{User-Name}" Debug: relaxed = no Debug: } Debug: # Loading module "attr_filter.accounting_response" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: attr_filter attr_filter.accounting_response { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/attr_filter/accounting_response" Debug: key = "%{User-Name}" Debug: relaxed = no Debug: } Debug: # Loading module "ntlm_auth" from file /usr/local/radius316/etc/raddb/mods-enabled/ntlm_auth Debug: exec ntlm_auth { Debug: wait = yes Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Debug: shell_escape = yes Debug: } Debug: Loading rlm_detail with path: /usr/local/radius316/lib/rlm_detail.so Debug: Loaded rlm_detail, checking if it's valid Debug: # Loaded module rlm_detail Debug: # Loading module "detail" from file /usr/local/radius316/etc/raddb/mods-enabled/detail Debug: detail { Debug: filename = "/usr/local/radius316/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Debug: header = "%t" Debug: permissions = 384 Debug: locking = no Debug: escape_filenames = no Debug: log_packet_header = no Debug: } Debug: Loading rlm_linelog with path: /usr/local/radius316/lib/rlm_linelog.so Debug: Loaded rlm_linelog, checking if it's valid Debug: # Loaded module rlm_linelog Debug: # Loading module "linelog" from file /usr/local/radius316/etc/raddb/mods-enabled/linelog Debug: linelog { Debug: filename = "/usr/local/radius316/var/log/radius/linelog" Debug: escape_filenames = no Debug: syslog_severity = "info" Debug: permissions = 384 Debug: format = "This is a log message for %{User-Name}" Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Debug: } Debug: # Loading module "log_accounting" from file /usr/local/radius316/etc/raddb/mods-enabled/linelog Debug: linelog log_accounting { Debug: filename = "/usr/local/radius316/var/log/radius/linelog-accounting" Debug: escape_filenames = no Debug: syslog_severity = "info" Debug: permissions = 384 Debug: format = "" Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Debug: } Debug: Loading rlm_always with path: /usr/local/radius316/lib/rlm_always.so Debug: Loaded rlm_always, checking if it's valid Debug: # Loaded module rlm_always Debug: # Loading module "reject" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always reject { Debug: rcode = "reject" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "fail" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always fail { Debug: rcode = "fail" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "ok" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always ok { Debug: rcode = "ok" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "handled" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always handled { Debug: rcode = "handled" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "invalid" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always invalid { Debug: rcode = "invalid" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "userlock" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always userlock { Debug: rcode = "userlock" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "notfound" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always notfound { Debug: rcode = "notfound" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "noop" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always noop { Debug: rcode = "noop" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: # Loading module "updated" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: always updated { Debug: rcode = "updated" Debug: simulcount = 0 Debug: mpp = no Debug: } Debug: Loading rlm_expr with path: /usr/local/radius316/lib/rlm_expr.so Debug: Loaded rlm_expr, checking if it's valid Debug: # Loaded module rlm_expr Debug: # Loading module "expr" from file /usr/local/radius316/etc/raddb/mods-enabled/expr Debug: expr { Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /aeouaaaceeeeiio?uuuayAEOUsAAACEEEEIIO?UUU?" Debug: } Debug: Loading rlm_radutmp with path: /usr/local/radius316/lib/rlm_radutmp.so Debug: Loaded rlm_radutmp, checking if it's valid Debug: # Loaded module rlm_radutmp Debug: # Loading module "sradutmp" from file /usr/local/radius316/etc/raddb/mods-enabled/sradutmp Debug: radutmp sradutmp { Debug: filename = "/usr/local/radius316/var/log/radius/sradutmp" Debug: username = "%{User-Name}" Debug: case_sensitive = yes Debug: check_with_nas = yes Debug: permissions = 420 Debug: caller_id = no Debug: } Debug: Loading rlm_passwd with path: /usr/local/radius316/lib/rlm_passwd.so Debug: Loaded rlm_passwd, checking if it's valid Debug: # Loaded module rlm_passwd Debug: # Loading module "etc_passwd" from file /usr/local/radius316/etc/raddb/mods-enabled/passwd Debug: passwd etc_passwd { Debug: filename = "/etc/passwd" Debug: format = "*User-Name:Crypt-Password:" Debug: delimiter = ":" Debug: ignore_nislike = no Debug: ignore_empty = yes Debug: allow_multiple_keys = no Debug: hash_size = 100 Debug: } Debug: # Loading module "exec" from file /usr/local/radius316/etc/raddb/mods-enabled/exec Debug: exec { Debug: wait = no Debug: input_pairs = "request" Debug: shell_escape = yes Debug: timeout = 10 Debug: } Debug: Loading rlm_pap with path: /usr/local/radius316/lib/rlm_pap.so Debug: Loaded rlm_pap, checking if it's valid Debug: # Loaded module rlm_pap Debug: # Loading module "pap" from file /usr/local/radius316/etc/raddb/mods-enabled/pap Debug: pap { Debug: normalise = yes Debug: } Debug: # Loading module "auth_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: detail auth_log { Debug: filename = "/usr/local/radius316/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Debug: header = "%t" Debug: permissions = 384 Debug: locking = no Debug: escape_filenames = no Debug: log_packet_header = no Debug: } Debug: # Loading module "reply_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: detail reply_log { Debug: filename = "/usr/local/radius316/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Debug: header = "%t" Debug: permissions = 384 Debug: locking = no Debug: escape_filenames = no Debug: log_packet_header = no Debug: } Debug: # Loading module "pre_proxy_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: detail pre_proxy_log { Debug: filename = "/usr/local/radius316/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Debug: header = "%t" Debug: permissions = 384 Debug: locking = no Debug: escape_filenames = no Debug: log_packet_header = no Debug: } Debug: # Loading module "post_proxy_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: detail post_proxy_log { Debug: filename = "/usr/local/radius316/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Debug: header = "%t" Debug: permissions = 384 Debug: locking = no Debug: escape_filenames = no Debug: log_packet_header = no Debug: } Debug: Loading rlm_expiration with path: /usr/local/radius316/lib/rlm_expiration.so Debug: Loaded rlm_expiration, checking if it's valid Debug: # Loaded module rlm_expiration Debug: # Loading module "expiration" from file /usr/local/radius316/etc/raddb/mods-enabled/expiration Debug: Loading rlm_unpack with path: /usr/local/radius316/lib/rlm_unpack.so Debug: Loaded rlm_unpack, checking if it's valid Debug: # Loaded module rlm_unpack Debug: # Loading module "unpack" from file /usr/local/radius316/etc/raddb/mods-enabled/unpack Debug: Loading rlm_preprocess with path: /usr/local/radius316/lib/rlm_preprocess.so Debug: Loaded rlm_preprocess, checking if it's valid Debug: # Loaded module rlm_preprocess Debug: # Loading module "preprocess" from file /usr/local/radius316/etc/raddb/mods-enabled/preprocess Debug: preprocess { Debug: huntgroups = "/usr/local/radius316/etc/raddb/mods-config/preprocess/huntgroups" Debug: hints = "/usr/local/radius316/etc/raddb/mods-config/preprocess/hints" Debug: with_ascend_hack = no Debug: ascend_channels_per_line = 23 Debug: with_ntdomain_hack = no Debug: with_specialix_jetstream_hack = no Debug: with_cisco_vsa_hack = no Debug: with_alvarion_vsa_hack = no Debug: } Debug: # Loading module "radutmp" from file /usr/local/radius316/etc/raddb/mods-enabled/radutmp Debug: radutmp { Debug: filename = "/usr/local/radius316/var/log/radius/radutmp" Debug: username = "%{User-Name}" Debug: case_sensitive = yes Debug: check_with_nas = yes Debug: permissions = 384 Debug: caller_id = yes Debug: } Debug: Loading rlm_replicate with path: /usr/local/radius316/lib/rlm_replicate.so Debug: Loaded rlm_replicate, checking if it's valid Debug: # Loaded module rlm_replicate Debug: # Loading module "replicate" from file /usr/local/radius316/etc/raddb/mods-enabled/replicate Debug: Loading rlm_mschap with path: /usr/local/radius316/lib/rlm_mschap.so Debug: Loaded rlm_mschap, checking if it's valid Debug: # Loaded module rlm_mschap Debug: # Loading module "mschap" from file /usr/local/radius316/etc/raddb/mods-enabled/mschap Debug: mschap { Debug: use_mppe = yes Debug: require_encryption = no Debug: require_strong = no Debug: with_ntdomain_hack = yes Debug: passchange { Debug: } Debug: allow_retry = yes Debug: winbind_retry_with_normalised_username = no Debug: } Debug: Loading rlm_dynamic_clients with path: /usr/local/radius316/lib/rlm_dynamic_clients.so Debug: Loaded rlm_dynamic_clients, checking if it's valid Debug: # Loaded module rlm_dynamic_clients Debug: # Loading module "dynamic_clients" from file /usr/local/radius316/etc/raddb/mods-enabled/dynamic_clients Debug: Loading rlm_realm with path: /usr/local/radius316/lib/rlm_realm.so Debug: Loaded rlm_realm, checking if it's valid Debug: # Loaded module rlm_realm Debug: # Loading module "IPASS" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: realm IPASS { Debug: format = "prefix" Debug: delimiter = "/" Debug: ignore_default = no Debug: ignore_null = no Debug: } Debug: # Loading module "suffix" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: realm suffix { Debug: format = "suffix" Debug: delimiter = "@" Debug: ignore_default = no Debug: ignore_null = no Debug: } Debug: # Loading module "realmpercent" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: realm realmpercent { Debug: format = "suffix" Debug: delimiter = "%" Debug: ignore_default = no Debug: ignore_null = no Debug: } Debug: # Loading module "ntdomain" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: realm ntdomain { Debug: format = "prefix" Debug: delimiter = "\\" Debug: ignore_default = no Debug: ignore_null = no Debug: } Debug: Loading rlm_files with path: /usr/local/radius316/lib/rlm_files.so Debug: Loaded rlm_files, checking if it's valid Debug: # Loaded module rlm_files Debug: # Loading module "files" from file /usr/local/radius316/etc/raddb/mods-enabled/files Debug: files { Debug: filename = "/usr/local/radius316/etc/raddb/mods-config/files/authorize" Debug: acctusersfile = "/usr/local/radius316/etc/raddb/mods-config/files/accounting" Debug: preproxy_usersfile = "/usr/local/radius316/etc/raddb/mods-config/files/pre-proxy" Debug: } Debug: Loading rlm_eap with path: /usr/local/radius316/lib/rlm_eap.so Debug: Loaded rlm_eap, checking if it's valid Debug: # Loaded module rlm_eap Debug: # Loading module "eap" from file /usr/local/radius316/etc/raddb/mods-enabled/eap Debug: eap { Debug: default_eap_type = "md5" Debug: timer_expire = 60 Debug: ignore_unknown_eap_types = no Debug: cisco_accounting_username_bug = no Debug: max_sessions = 16384 Debug: } Debug: Loading rlm_soh with path: /usr/local/radius316/lib/rlm_soh.so Debug: Loaded rlm_soh, checking if it's valid Debug: # Loaded module rlm_soh Debug: # Loading module "soh" from file /usr/local/radius316/etc/raddb/mods-enabled/soh Debug: soh { Debug: dhcp = yes Debug: } Debug: Loading rlm_date with path: /usr/local/radius316/lib/rlm_date.so Debug: Loaded rlm_date, checking if it's valid Debug: # Loaded module rlm_date Debug: # Loading module "date" from file /usr/local/radius316/etc/raddb/mods-enabled/date Debug: date { Debug: format = "%b %e %Y %H:%M:%S %Z" Debug: utc = no Debug: } Debug: Loading rlm_chap with path: /usr/local/radius316/lib/rlm_chap.so Debug: Loaded rlm_chap, checking if it's valid Debug: # Loaded module rlm_chap Debug: # Loading module "chap" from file /usr/local/radius316/etc/raddb/mods-enabled/chap Debug: Loading rlm_logintime with path: /usr/local/radius316/lib/rlm_logintime.so Debug: Loaded rlm_logintime, checking if it's valid Debug: # Loaded module rlm_logintime Debug: # Loading module "logintime" from file /usr/local/radius316/etc/raddb/mods-enabled/logintime Debug: logintime { Debug: minimum_timeout = 60 Debug: } Debug: instantiate { Debug: } Debug: # Instantiating module "cache_eap" from file /usr/local/radius316/etc/raddb/mods-enabled/cache_eap Debug: Loading rlm_cache_rbtree with path: /usr/local/radius316/lib/rlm_cache_rbtree.so Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked Debug: # Instantiating module "attr_filter.post-proxy" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/attr_filter/post-proxy Debug: # Instantiating module "attr_filter.pre-proxy" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/attr_filter/pre-proxy Debug: # Instantiating module "attr_filter.access_reject" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/attr_filter/access_reject Warning: [/usr/local/radius316/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Warning: [/usr/local/radius316/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". Debug: # Instantiating module "attr_filter.access_challenge" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/attr_filter/access_challenge Debug: # Instantiating module "attr_filter.accounting_response" from file /usr/local/radius316/etc/raddb/mods-enabled/attr_filter Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/attr_filter/accounting_response Debug: # Instantiating module "detail" from file /usr/local/radius316/etc/raddb/mods-enabled/detail Debug: # Instantiating module "linelog" from file /usr/local/radius316/etc/raddb/mods-enabled/linelog Debug: # Instantiating module "log_accounting" from file /usr/local/radius316/etc/raddb/mods-enabled/linelog Debug: # Instantiating module "reject" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "fail" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "ok" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "handled" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "invalid" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "userlock" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "notfound" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "noop" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "updated" from file /usr/local/radius316/etc/raddb/mods-enabled/always Debug: # Instantiating module "etc_passwd" from file /usr/local/radius316/etc/raddb/mods-enabled/passwd Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Debug: # Instantiating module "pap" from file /usr/local/radius316/etc/raddb/mods-enabled/pap Debug: # Instantiating module "auth_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Debug: # Instantiating module "reply_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: # Instantiating module "pre_proxy_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: # Instantiating module "post_proxy_log" from file /usr/local/radius316/etc/raddb/mods-enabled/detail.log Debug: # Instantiating module "expiration" from file /usr/local/radius316/etc/raddb/mods-enabled/expiration Debug: # Instantiating module "preprocess" from file /usr/local/radius316/etc/raddb/mods-enabled/preprocess Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/preprocess/huntgroups Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/preprocess/hints Debug: # Instantiating module "mschap" from file /usr/local/radius316/etc/raddb/mods-enabled/mschap Debug: rlm_mschap (mschap): using internal authentication Debug: # Instantiating module "IPASS" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: # Instantiating module "suffix" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: # Instantiating module "realmpercent" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: # Instantiating module "ntdomain" from file /usr/local/radius316/etc/raddb/mods-enabled/realm Debug: # Instantiating module "files" from file /usr/local/radius316/etc/raddb/mods-enabled/files Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/files/authorize Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/files/accounting Debug: reading pairlist file /usr/local/radius316/etc/raddb/mods-config/files/pre-proxy Debug: # Instantiating module "eap" from file /usr/local/radius316/etc/raddb/mods-enabled/eap Debug: Loading rlm_eap_md5 with path: /usr/local/radius316/lib/rlm_eap_md5.so Debug: # Linked to sub-module rlm_eap_md5 Debug: Loading rlm_eap_leap with path: /usr/local/radius316/lib/rlm_eap_leap.so Debug: # Linked to sub-module rlm_eap_leap Debug: Loading rlm_eap_gtc with path: /usr/local/radius316/lib/rlm_eap_gtc.so Debug: # Linked to sub-module rlm_eap_gtc Debug: gtc { Debug: challenge = "Password: " Debug: auth_type = "PAP" Debug: } Debug: Loading rlm_eap_tls with path: /usr/local/radius316/lib/rlm_eap_tls.so Debug: # Linked to sub-module rlm_eap_tls Debug: tls { Debug: tls = "tls-common" Debug: } Debug: tls-config tls-common { Debug: verify_depth = 0 Debug: ca_path = "/usr/local/radius316/etc/raddb/certs" Debug: pem_file_type = yes Debug: private_key_file = "/usr/local/radius316/etc/raddb/certs/server.pem" Debug: certificate_file = "/usr/local/radius316/etc/raddb/certs/server.pem" Debug: ca_file = "/usr/local/radius316/etc/raddb/certs/ca.pem" Debug: private_key_password = "whatever" Debug: dh_file = "/usr/local/radius316/etc/raddb/certs/dh" Debug: fragment_size = 1024 Debug: include_length = yes Debug: auto_chain = yes Debug: check_crl = no Debug: check_all_crl = no Debug: cipher_list = "DEFAULT" Debug: cipher_server_preference = no Debug: ecdh_curve = "prime256v1" Debug: tls_max_version = "" Debug: tls_min_version = "1.0" Debug: cache { Debug: enable = no Debug: lifetime = 24 Debug: max_entries = 255 Debug: } Debug: verify { Debug: skip_if_ocsp_ok = no Debug: } Debug: ocsp { Debug: enable = no Debug: override_cert_url = yes Debug: url = "http://127.0.0.1/ocsp/" Debug: use_nonce = yes Debug: timeout = 0 Debug: softfail = no Debug: } Debug: } Debug: Loading rlm_eap_ttls with path: /usr/local/radius316/lib/rlm_eap_ttls.so Debug: # Linked to sub-module rlm_eap_ttls Debug: ttls { Debug: tls = "tls-common" Debug: default_eap_type = "md5" Debug: copy_request_to_tunnel = no Debug: use_tunneled_reply = no Debug: virtual_server = "inner-tunnel" Debug: include_length = yes Debug: require_client_cert = no Debug: } Debug: tls: Using cached TLS configuration from previous invocation Debug: Loading rlm_eap_peap with path: /usr/local/radius316/lib/rlm_eap_peap.so Debug: # Linked to sub-module rlm_eap_peap Debug: peap { Debug: tls = "tls-common" Debug: default_eap_type = "mschapv2" Debug: copy_request_to_tunnel = no Debug: use_tunneled_reply = no Debug: proxy_tunneled_request_as_eap = yes Debug: virtual_server = "inner-tunnel" Debug: soh = no Debug: require_client_cert = no Debug: } Debug: tls: Using cached TLS configuration from previous invocation Debug: Loading rlm_eap_mschapv2 with path: /usr/local/radius316/lib/rlm_eap_mschapv2.so Debug: # Linked to sub-module rlm_eap_mschapv2 Debug: mschapv2 { Debug: with_ntdomain_hack = no Debug: send_error = no Debug: } Debug: # Instantiating module "logintime" from file /usr/local/radius316/etc/raddb/mods-enabled/logintime Debug: } # modules Debug: radiusd: #### Loading Virtual Servers #### Debug: server { # from file /usr/local/radius316/etc/raddb/radiusd.conf Debug: } # server Debug: server default { # from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: authenticate { Debug: group { Debug: pap Debug: } Debug: group { Debug: chap Debug: } Debug: group { Debug: mschap Debug: } Debug: mschap Debug: digest Debug: eap Debug: } # authenticate Debug: authorize { Debug: policy filter_username { Debug: if (&User-Name) { Debug: if (&User-Name =~ / /) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /@[^@]*@/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /\.\./) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /\.$/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /(a)\./) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Debug: } Debug: reject Debug: } Debug: } Debug: } Debug: preprocess Debug: chap Debug: mschap Debug: digest Debug: suffix Debug: eap Debug: files Warning: Ignoring "sql" (see raddb/mods-available/README.rst) Warning: Ignoring "ldap" (see raddb/mods-available/README.rst) Debug: expiration Debug: logintime Debug: pap Debug: } # authorize Debug: preacct { Debug: preprocess Debug: policy acct_unique { Debug: update { Debug: &Tmp-String-9 := "ai:" Debug: } Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) { Debug: update { Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}" Debug: } Debug: } Debug: else { Debug: update { Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" Debug: } Debug: } Debug: } Debug: suffix Debug: files Debug: } # preacct Debug: accounting { Debug: detail Debug: unix Debug: exec Debug: attr_filter.accounting_response Debug: } # accounting Debug: post-proxy { Debug: eap Debug: } # post-proxy Debug: post-auth { Debug: update { Debug: &reply:[*] += &session-state:[*] Debug: } Debug: exec Debug: policy remove_reply_message_if_eap { Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Debug: update { Debug: &reply:Reply-Message !* ANY Debug: } Debug: } Debug: else { Debug: noop Debug: } Debug: } Debug: group { Debug: attr_filter.access_reject Debug: eap Debug: policy remove_reply_message_if_eap { Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Debug: update { Debug: &reply:Reply-Message !* ANY Debug: } Debug: } Debug: else { Debug: noop Debug: } Debug: } Debug: } Debug: group { Debug: } Debug: } # post-auth Debug: } # server default Debug: server inner-tunnel { # from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: authenticate { Debug: group { Debug: pap Debug: } Debug: group { Debug: chap Debug: } Debug: group { Debug: mschap Debug: } Debug: mschap Debug: eap Debug: } # authenticate Debug: authorize { Debug: policy filter_username { Debug: if (&User-Name) { Debug: if (&User-Name =~ / /) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /@[^@]*@/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /\.\./) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /\.$/) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Debug: } Debug: reject Debug: } Debug: if (&User-Name =~ /(a)\./) { Debug: update { Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Debug: } Debug: reject Debug: } Debug: } Debug: } Debug: chap Debug: mschap Debug: suffix Debug: update { Debug: &control:Proxy-To-Realm := LOCAL Debug: } Debug: eap Debug: files Debug: expiration Debug: logintime Debug: pap Debug: } # authorize Debug: session { Debug: radutmp Debug: } # session Debug: post-proxy { Debug: eap Debug: } # post-proxy Debug: post-auth { Info: # Skipping contents of 'if' as it is always 'false' -- /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel:331 Debug: if (false) { Debug: } Debug: group { Debug: attr_filter.access_reject Debug: update { Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message Debug: } Debug: } Debug: } # post-auth Debug: } # server inner-tunnel Debug: Created signal pipe. Read end FD 5, write end FD 6 Debug: radiusd: #### Opening IP addresses and Ports #### Debug: Loading proto_auth with path: /usr/local/radius316/lib/proto_auth.so Debug: Loading proto_auth failed: /usr/local/radius316/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Debug: Loading library using linker search path(s) Debug: Defaults : /lib:/usr/lib Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Debug: listen { Debug: type = "auth" Debug: ipaddr = * Debug: port = 0 Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Loading proto_acct with path: /usr/local/radius316/lib/proto_acct.so Debug: Loading proto_acct failed: /usr/local/radius316/lib/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Debug: Loading library using linker search path(s) Debug: Defaults : /lib:/usr/lib Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Debug: listen { Debug: type = "acct" Debug: ipaddr = * Debug: port = 0 Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Loading proto_auth with path: /usr/local/radius316/lib/proto_auth.so Debug: Loading proto_auth failed: /usr/local/radius316/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Debug: Loading library using linker search path(s) Debug: Defaults : /lib:/usr/lib Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Debug: listen { Debug: type = "auth" Debug: ipv6addr = :: Debug: port = 0 Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Loading proto_acct with path: /usr/local/radius316/lib/proto_acct.so Debug: Loading proto_acct failed: /usr/local/radius316/lib/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Debug: Loading library using linker search path(s) Debug: Defaults : /lib:/usr/lib Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Debug: listen { Debug: type = "acct" Debug: ipv6addr = :: Debug: port = 0 Debug: limit { Debug: max_connections = 16 Debug: lifetime = 0 Debug: idle_timeout = 30 Debug: } Debug: } Debug: Loading proto_auth with path: /usr/local/radius316/lib/proto_auth.so Debug: Loading proto_auth failed: /usr/local/radius316/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Debug: Loading library using linker search path(s) Debug: Defaults : /lib:/usr/lib Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Debug: listen { Debug: type = "auth" Debug: ipaddr = 127.0.0.1 Debug: port = 18120 Debug: } Debug: Listening on auth address * port 1812 bound to server default Debug: Listening on acct address * port 1813 bound to server default Debug: Listening on auth address :: port 1812 bound to server default Debug: Listening on acct address :: port 1813 bound to server default Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Debug: Opened new proxy socket 'proxy address * port 53124' Debug: Listening on proxy address * port 53124 Debug: Opened new proxy socket 'proxy address :: port 51628' Debug: Listening on proxy address :: port 51628 Info: Ready to process requests Debug: (0) Received Access-Request Id 0 from 192.168.103.4:35803 to 192.168.103.1:1812 length 122 Debug: (0) User-Name = "user001" Debug: (0) NAS-IP-Address = 127.0.0.1 Debug: (0) Calling-Station-Id = "02-00-00-00-00-01" Debug: (0) Framed-MTU = 1400 Debug: (0) NAS-Port-Type = Wireless-802.11 Debug: (0) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (0) EAP-Message = 0x0200000c0175736572303031 Debug: (0) Message-Authenticator = 0x1b713d66546c5df82fc9440221b72bee Debug: (0) session-state: No State attribute Debug: (0) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (0) authorize { Debug: (0) policy filter_username { Debug: (0) if (&User-Name) { Debug: (0) if (&User-Name) -> TRUE Debug: (0) if (&User-Name) { Debug: (0) if (&User-Name =~ / /) { Debug: No matches Debug: (0) if (&User-Name =~ / /) -> FALSE Debug: (0) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (0) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (0) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (0) if (&User-Name =~ /\.$/) -> FALSE Debug: (0) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (0) if (&User-Name =~ /(a)\./) -> FALSE Debug: (0) } # if (&User-Name) = notfound Debug: (0) } # policy filter_username = notfound Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (0) [preprocess] = ok Debug: (0) modsingle[authorize]: calling chap (rlm_chap) Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) Debug: (0) [chap] = noop Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (0) [mschap] = noop Debug: (0) modsingle[authorize]: calling digest (rlm_digest) Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) Debug: (0) [digest] = noop Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) Debug: (0) suffix: Checking for suffix after "@" Debug: (0) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (0) suffix: Found realm "NULL" Debug: (0) suffix: Adding Stripped-User-Name = "user001" Debug: (0) suffix: Adding Realm = "NULL" Debug: (0) suffix: Authentication realm is LOCAL Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (0) [suffix] = ok Debug: (0) modsingle[authorize]: calling eap (rlm_eap) Debug: (0) eap: Peer sent EAP Response (code 2) ID 0 length 12 Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) Debug: (0) [eap] = ok Debug: (0) } # authorize = ok Debug: (0) Found Auth-Type = eap Debug: (0) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (0) authenticate { Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) Debug: (0) eap: Peer sent packet with method EAP Identity (1) Debug: (0) eap: Calling submodule eap_md5 to process data Debug: (0) eap_md5: Issuing MD5 Challenge Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 22 Debug: (0) eap: EAP session adding &reply:State = 0x2943cbb82942cf0f Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (0) [eap] = handled Debug: (0) } # authenticate = handled Debug: (0) Using Post-Auth-Type Challenge Debug: (0) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (0) Challenge { ... } # empty sub-section is ignored Debug: (0) session-state: Nothing to cache Debug: (0) Sent Access-Challenge Id 0 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (0) EAP-Message = 0x0101001604106467fcdc56eaf2330ba7f13f533cc588 Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (0) State = 0x2943cbb82942cf0f1f4c032fd1862a21 Debug: (0) Finished request Debug: Waking up in 4.9 seconds. Debug: (1) Received Access-Request Id 1 from 192.168.103.4:35803 to 192.168.103.1:1812 length 134 Debug: (1) User-Name = "user001" Debug: (1) NAS-IP-Address = 127.0.0.1 Debug: (1) Calling-Station-Id = "02-00-00-00-00-01" Debug: (1) Framed-MTU = 1400 Debug: (1) NAS-Port-Type = Wireless-802.11 Debug: (1) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (1) EAP-Message = 0x020100060319 Debug: (1) State = 0x2943cbb82942cf0f1f4c032fd1862a21 Debug: (1) Message-Authenticator = 0xc82b0685d2ea8c8d20720b0ae20b6706 Debug: (1) session-state: No cached attributes Debug: (1) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (1) authorize { Debug: (1) policy filter_username { Debug: (1) if (&User-Name) { Debug: (1) if (&User-Name) -> TRUE Debug: (1) if (&User-Name) { Debug: (1) if (&User-Name =~ / /) { Debug: No matches Debug: (1) if (&User-Name =~ / /) -> FALSE Debug: (1) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (1) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (1) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (1) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (1) if (&User-Name =~ /\.$/) -> FALSE Debug: (1) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (1) if (&User-Name =~ /(a)\./) -> FALSE Debug: (1) } # if (&User-Name) = notfound Debug: (1) } # policy filter_username = notfound Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (1) [preprocess] = ok Debug: (1) modsingle[authorize]: calling chap (rlm_chap) Debug: (1) modsingle[authorize]: returned from chap (rlm_chap) Debug: (1) [chap] = noop Debug: (1) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (1) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (1) [mschap] = noop Debug: (1) modsingle[authorize]: calling digest (rlm_digest) Debug: (1) modsingle[authorize]: returned from digest (rlm_digest) Debug: (1) [digest] = noop Debug: (1) modsingle[authorize]: calling suffix (rlm_realm) Debug: (1) suffix: Checking for suffix after "@" Debug: (1) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (1) suffix: Found realm "NULL" Debug: (1) suffix: Adding Stripped-User-Name = "user001" Debug: (1) suffix: Adding Realm = "NULL" Debug: (1) suffix: Authentication realm is LOCAL Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (1) [suffix] = ok Debug: (1) modsingle[authorize]: calling eap (rlm_eap) Debug: (1) eap: Peer sent EAP Response (code 2) ID 1 length 6 Debug: (1) eap: No EAP Start, assuming it's an on-going EAP conversation Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) Debug: (1) [eap] = updated Debug: (1) modsingle[authorize]: calling files (rlm_files) Debug: (1) files: users: Matched entry user001 at line 221 Debug: (1) files: ::: FROM 1 TO 0 MAX 1 Debug: (1) files: ::: Examining Reply-Message Debug: Hello, %{User-Name} Debug: Parsed xlat tree: Debug: literal --> Hello, Debug: attribute --> User-Name Debug: (1) files: EXPAND Hello, %{User-Name} Debug: (1) files: --> Hello, user001 Debug: (1) files: ::: APPENDING Reply-Message FROM 0 TO 0 Debug: (1) files: ::: TO in 0 out 0 Debug: (1) modsingle[authorize]: returned from files (rlm_files) Debug: (1) [files] = ok Debug: (1) modsingle[authorize]: calling expiration (rlm_expiration) Debug: (1) modsingle[authorize]: returned from expiration (rlm_expiration) Debug: (1) [expiration] = noop Debug: (1) modsingle[authorize]: calling logintime (rlm_logintime) Debug: (1) modsingle[authorize]: returned from logintime (rlm_logintime) Debug: (1) [logintime] = noop Debug: (1) modsingle[authorize]: calling pap (rlm_pap) WARNING: (1) pap: Auth-Type already set. Not setting to PAP Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) Debug: (1) [pap] = noop Debug: (1) } # authorize = updated Debug: (1) Found Auth-Type = eap Debug: (1) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (1) authenticate { Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) Debug: (1) eap: Expiring EAP session with state 0x2943cbb82942cf0f Debug: (1) eap: Finished EAP session with state 0x2943cbb82942cf0f Debug: (1) eap: Previous EAP request found for state 0x2943cbb82942cf0f, released from the list Debug: (1) eap: Peer sent packet with method EAP NAK (3) Debug: (1) eap: Found mutually acceptable type PEAP (25) Debug: (1) eap: Calling submodule eap_peap to process data Debug: (1) eap_peap: Initiating new EAP-TLS session Debug: (1) eap_peap: [eaptls start] = request Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 6 Debug: (1) eap: EAP session adding &reply:State = 0x2943cbb82841d20f Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (1) [eap] = handled Debug: (1) } # authenticate = handled Debug: (1) Using Post-Auth-Type Challenge Debug: (1) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (1) Challenge { ... } # empty sub-section is ignored Debug: (1) session-state: Nothing to cache Debug: (1) Sent Access-Challenge Id 1 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (1) Reply-Message = "Hello, user001" Debug: (1) EAP-Message = 0x010200061920 Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (1) State = 0x2943cbb82841d20f1f4c032fd1862a21 Debug: (1) Finished request Debug: Waking up in 4.9 seconds. Debug: (2) Received Access-Request Id 2 from 192.168.103.4:35803 to 192.168.103.1:1812 length 293 Debug: (2) User-Name = "user001" Debug: (2) NAS-IP-Address = 127.0.0.1 Debug: (2) Calling-Station-Id = "02-00-00-00-00-01" Debug: (2) Framed-MTU = 1400 Debug: (2) NAS-Port-Type = Wireless-802.11 Debug: (2) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (2) EAP-Message = 0x020200a519800000009b16030100960100009203015a9650accd2e450636c95743fa5ce471555ee10a89cced36c1bbdf4e92a2a7cb00004cc014c00a0039003800880087c00fc00500350084c013c00900330032009a009900450044c00ec004002f00960041c012c00800160013c00dc003000a0007c0 Debug: (2) State = 0x2943cbb82841d20f1f4c032fd1862a21 Debug: (2) Message-Authenticator = 0x925091610982fc04f4f09cdf1dcf1186 Debug: (2) session-state: No cached attributes Debug: (2) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (2) authorize { Debug: (2) policy filter_username { Debug: (2) if (&User-Name) { Debug: (2) if (&User-Name) -> TRUE Debug: (2) if (&User-Name) { Debug: (2) if (&User-Name =~ / /) { Debug: No matches Debug: (2) if (&User-Name =~ / /) -> FALSE Debug: (2) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (2) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (2) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (2) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (2) if (&User-Name =~ /\.$/) -> FALSE Debug: (2) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (2) if (&User-Name =~ /(a)\./) -> FALSE Debug: (2) } # if (&User-Name) = notfound Debug: (2) } # policy filter_username = notfound Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (2) [preprocess] = ok Debug: (2) modsingle[authorize]: calling chap (rlm_chap) Debug: (2) modsingle[authorize]: returned from chap (rlm_chap) Debug: (2) [chap] = noop Debug: (2) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (2) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (2) [mschap] = noop Debug: (2) modsingle[authorize]: calling digest (rlm_digest) Debug: (2) modsingle[authorize]: returned from digest (rlm_digest) Debug: (2) [digest] = noop Debug: (2) modsingle[authorize]: calling suffix (rlm_realm) Debug: (2) suffix: Checking for suffix after "@" Debug: (2) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (2) suffix: Found realm "NULL" Debug: (2) suffix: Adding Stripped-User-Name = "user001" Debug: (2) suffix: Adding Realm = "NULL" Debug: (2) suffix: Authentication realm is LOCAL Debug: (2) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (2) [suffix] = ok Debug: (2) modsingle[authorize]: calling eap (rlm_eap) Debug: (2) eap: Peer sent EAP Response (code 2) ID 2 length 165 Debug: (2) eap: Continuing tunnel setup Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) Debug: (2) [eap] = ok Debug: (2) } # authorize = ok Debug: (2) Found Auth-Type = eap Debug: (2) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (2) authenticate { Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) Debug: (2) eap: Expiring EAP session with state 0x2943cbb82841d20f Debug: (2) eap: Finished EAP session with state 0x2943cbb82841d20f Debug: (2) eap: Previous EAP request found for state 0x2943cbb82841d20f, released from the list Debug: (2) eap: Peer sent packet with method EAP PEAP (25) Debug: (2) eap: Calling submodule eap_peap to process data Debug: (2) eap_peap: Continuing EAP-TLS Debug: (2) eap_peap: Peer sent flags --L Debug: (2) eap_peap: Peer indicated complete TLS record size will be 155 bytes Debug: (2) eap_peap: Got complete TLS record (155 bytes) Debug: (2) eap_peap: [eaptls verify] = length included Debug: (2) eap_peap: (other): before/accept initialization Debug: (2) eap_peap: TLS_accept: before/accept initialization Debug: (2) eap_peap: <<< recv TLS 1.0 Handshake [length 0096], ClientHello Debug: (2) eap_peap: TLS_accept: SSLv3 read client hello A Debug: (2) eap_peap: >>> send TLS 1.0 Handshake [length 003e], ServerHello Debug: (2) eap_peap: TLS_accept: SSLv3 write server hello A Debug: (2) eap_peap: >>> send TLS 1.0 Handshake [length 08d3], Certificate Debug: (2) eap_peap: TLS_accept: SSLv3 write certificate A Debug: (2) eap_peap: >>> send TLS 1.0 Handshake [length 014b], ServerKeyExchange Debug: (2) eap_peap: TLS_accept: SSLv3 write key exchange A Debug: (2) eap_peap: >>> send TLS 1.0 Handshake [length 0004], ServerHelloDone Debug: (2) eap_peap: TLS_accept: SSLv3 write server done A Debug: (2) eap_peap: TLS_accept: SSLv3 flush data Debug: (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A Debug: (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A Debug: (2) eap_peap: In SSL Handshake Phase Debug: (2) eap_peap: In SSL Accept mode Debug: (2) eap_peap: [eaptls process] = handled Debug: (2) eap: Sending EAP Request (code 1) ID 3 length 1004 Debug: (2) eap: EAP session adding &reply:State = 0x2943cbb82b40d20f Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (2) [eap] = handled Debug: (2) } # authenticate = handled Debug: (2) Using Post-Auth-Type Challenge Debug: (2) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (2) Challenge { ... } # empty sub-section is ignored Debug: (2) session-state: Nothing to cache Debug: (2) Sent Access-Challenge Id 2 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (2) EAP-Message = 0x010303ec19c000000a74160301003e0200003a03015a9650c9f8406b23f795268b7d9728863db6131fbcb6bdb2f17c3b9c7a35eeba00c014000012ff01000100000b000403000102000f00010116030108d30b0008cf0008cc0003de308203da308202c2a003020102020101300d06092a864886f70d01 Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (2) State = 0x2943cbb82b40d20f1f4c032fd1862a21 Debug: (2) Finished request Debug: Waking up in 4.9 seconds. Debug: (3) Received Access-Request Id 3 from 192.168.103.4:35803 to 192.168.103.1:1812 length 134 Debug: (3) User-Name = "user001" Debug: (3) NAS-IP-Address = 127.0.0.1 Debug: (3) Calling-Station-Id = "02-00-00-00-00-01" Debug: (3) Framed-MTU = 1400 Debug: (3) NAS-Port-Type = Wireless-802.11 Debug: (3) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (3) EAP-Message = 0x020300061900 Debug: (3) State = 0x2943cbb82b40d20f1f4c032fd1862a21 Debug: (3) Message-Authenticator = 0x13435caaa8eef5857e7508494cc1c865 Debug: (3) session-state: No cached attributes Debug: (3) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (3) authorize { Debug: (3) policy filter_username { Debug: (3) if (&User-Name) { Debug: (3) if (&User-Name) -> TRUE Debug: (3) if (&User-Name) { Debug: (3) if (&User-Name =~ / /) { Debug: No matches Debug: (3) if (&User-Name =~ / /) -> FALSE Debug: (3) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (3) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (3) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (3) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (3) if (&User-Name =~ /\.$/) -> FALSE Debug: (3) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (3) if (&User-Name =~ /(a)\./) -> FALSE Debug: (3) } # if (&User-Name) = notfound Debug: (3) } # policy filter_username = notfound Debug: (3) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (3) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (3) [preprocess] = ok Debug: (3) modsingle[authorize]: calling chap (rlm_chap) Debug: (3) modsingle[authorize]: returned from chap (rlm_chap) Debug: (3) [chap] = noop Debug: (3) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (3) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (3) [mschap] = noop Debug: (3) modsingle[authorize]: calling digest (rlm_digest) Debug: (3) modsingle[authorize]: returned from digest (rlm_digest) Debug: (3) [digest] = noop Debug: (3) modsingle[authorize]: calling suffix (rlm_realm) Debug: (3) suffix: Checking for suffix after "@" Debug: (3) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (3) suffix: Found realm "NULL" Debug: (3) suffix: Adding Stripped-User-Name = "user001" Debug: (3) suffix: Adding Realm = "NULL" Debug: (3) suffix: Authentication realm is LOCAL Debug: (3) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (3) [suffix] = ok Debug: (3) modsingle[authorize]: calling eap (rlm_eap) Debug: (3) eap: Peer sent EAP Response (code 2) ID 3 length 6 Debug: (3) eap: Continuing tunnel setup Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) Debug: (3) [eap] = ok Debug: (3) } # authorize = ok Debug: (3) Found Auth-Type = eap Debug: (3) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (3) authenticate { Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) Debug: (3) eap: Expiring EAP session with state 0x2943cbb82b40d20f Debug: (3) eap: Finished EAP session with state 0x2943cbb82b40d20f Debug: (3) eap: Previous EAP request found for state 0x2943cbb82b40d20f, released from the list Debug: (3) eap: Peer sent packet with method EAP PEAP (25) Debug: (3) eap: Calling submodule eap_peap to process data Debug: (3) eap_peap: Continuing EAP-TLS Debug: (3) eap_peap: Peer sent flags --- Debug: (3) eap_peap: Peer ACKed our handshake fragment Debug: (3) eap_peap: [eaptls verify] = request Debug: (3) eap_peap: [eaptls process] = handled Debug: (3) eap: Sending EAP Request (code 1) ID 4 length 1000 Debug: (3) eap: EAP session adding &reply:State = 0x2943cbb82a47d20f Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (3) [eap] = handled Debug: (3) } # authenticate = handled Debug: (3) Using Post-Auth-Type Challenge Debug: (3) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (3) Challenge { ... } # empty sub-section is ignored Debug: (3) session-state: Nothing to cache Debug: (3) Sent Access-Challenge Id 3 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (3) EAP-Message = 0x010403e8194022f574cdc123f123515bf01861af46940502c871f00829171dc2399cce50c19782bd7fee1d944feb44ba24a7a68f198b9e0772b2d413a4d37505ad76c7311f8818707537cfde955caf818a037edd0004e8308204e4308203cca0030201020209009b296716b43d9494300d06092a864886 Debug: (3) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (3) State = 0x2943cbb82a47d20f1f4c032fd1862a21 Debug: (3) Finished request Debug: Waking up in 4.9 seconds. Debug: (4) Received Access-Request Id 4 from 192.168.103.4:35803 to 192.168.103.1:1812 length 134 Debug: (4) User-Name = "user001" Debug: (4) NAS-IP-Address = 127.0.0.1 Debug: (4) Calling-Station-Id = "02-00-00-00-00-01" Debug: (4) Framed-MTU = 1400 Debug: (4) NAS-Port-Type = Wireless-802.11 Debug: (4) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (4) EAP-Message = 0x020400061900 Debug: (4) State = 0x2943cbb82a47d20f1f4c032fd1862a21 Debug: (4) Message-Authenticator = 0x9b180ea8d3b49ce70efc224a84d4f452 Debug: (4) session-state: No cached attributes Debug: (4) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (4) authorize { Debug: (4) policy filter_username { Debug: (4) if (&User-Name) { Debug: (4) if (&User-Name) -> TRUE Debug: (4) if (&User-Name) { Debug: (4) if (&User-Name =~ / /) { Debug: No matches Debug: (4) if (&User-Name =~ / /) -> FALSE Debug: (4) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (4) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (4) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (4) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (4) if (&User-Name =~ /\.$/) -> FALSE Debug: (4) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (4) if (&User-Name =~ /(a)\./) -> FALSE Debug: (4) } # if (&User-Name) = notfound Debug: (4) } # policy filter_username = notfound Debug: (4) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (4) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (4) [preprocess] = ok Debug: (4) modsingle[authorize]: calling chap (rlm_chap) Debug: (4) modsingle[authorize]: returned from chap (rlm_chap) Debug: (4) [chap] = noop Debug: (4) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (4) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (4) [mschap] = noop Debug: (4) modsingle[authorize]: calling digest (rlm_digest) Debug: (4) modsingle[authorize]: returned from digest (rlm_digest) Debug: (4) [digest] = noop Debug: (4) modsingle[authorize]: calling suffix (rlm_realm) Debug: (4) suffix: Checking for suffix after "@" Debug: (4) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (4) suffix: Found realm "NULL" Debug: (4) suffix: Adding Stripped-User-Name = "user001" Debug: (4) suffix: Adding Realm = "NULL" Debug: (4) suffix: Authentication realm is LOCAL Debug: (4) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (4) [suffix] = ok Debug: (4) modsingle[authorize]: calling eap (rlm_eap) Debug: (4) eap: Peer sent EAP Response (code 2) ID 4 length 6 Debug: (4) eap: Continuing tunnel setup Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) Debug: (4) [eap] = ok Debug: (4) } # authorize = ok Debug: (4) Found Auth-Type = eap Debug: (4) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (4) authenticate { Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) Debug: (4) eap: Expiring EAP session with state 0x2943cbb82a47d20f Debug: (4) eap: Finished EAP session with state 0x2943cbb82a47d20f Debug: (4) eap: Previous EAP request found for state 0x2943cbb82a47d20f, released from the list Debug: (4) eap: Peer sent packet with method EAP PEAP (25) Debug: (4) eap: Calling submodule eap_peap to process data Debug: (4) eap_peap: Continuing EAP-TLS Debug: (4) eap_peap: Peer sent flags --- Debug: (4) eap_peap: Peer ACKed our handshake fragment Debug: (4) eap_peap: [eaptls verify] = request Debug: (4) eap_peap: [eaptls process] = handled Debug: (4) eap: Sending EAP Request (code 1) ID 5 length 694 Debug: (4) eap: EAP session adding &reply:State = 0x2943cbb82d46d20f Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (4) [eap] = handled Debug: (4) } # authenticate = handled Debug: (4) Using Post-Auth-Type Challenge Debug: (4) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (4) Challenge { ... } # empty sub-section is ignored Debug: (4) session-state: Nothing to cache Debug: (4) Sent Access-Challenge Id 4 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (4) EAP-Message = 0x010502b61900130101ff040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e6f72672f6578616d706c655f63612e63726c300d06092a864886f70d010105050003820101003b1d856463526e89dd3ae7e90db7a059ae6154830280ed2ab780 Debug: (4) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (4) State = 0x2943cbb82d46d20f1f4c032fd1862a21 Debug: (4) Finished request Debug: Waking up in 4.9 seconds. Debug: (5) Received Access-Request Id 5 from 192.168.103.4:35803 to 192.168.103.1:1812 length 272 Debug: (5) User-Name = "user001" Debug: (5) NAS-IP-Address = 127.0.0.1 Debug: (5) Calling-Station-Id = "02-00-00-00-00-01" Debug: (5) Framed-MTU = 1400 Debug: (5) NAS-Port-Type = Wireless-802.11 Debug: (5) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (5) EAP-Message = 0x0205009019800000008616030100461000004241047b6bf12f82e35029d5b7c3085566542bfa8a780f25e296c2ffe22aa8f7edad58c652a697cb041e13cc84e737de54e6fb42c176d0c57439f9de9d568e992cddae14030100010116030100306509a0a9e8c31011a63c550b52a9652751e329d42d292c Debug: (5) State = 0x2943cbb82d46d20f1f4c032fd1862a21 Debug: (5) Message-Authenticator = 0x802a0ab93dac5c71fac91d767711c6b0 Debug: (5) session-state: No cached attributes Debug: (5) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (5) authorize { Debug: (5) policy filter_username { Debug: (5) if (&User-Name) { Debug: (5) if (&User-Name) -> TRUE Debug: (5) if (&User-Name) { Debug: (5) if (&User-Name =~ / /) { Debug: No matches Debug: (5) if (&User-Name =~ / /) -> FALSE Debug: (5) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (5) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (5) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (5) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (5) if (&User-Name =~ /\.$/) -> FALSE Debug: (5) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (5) if (&User-Name =~ /(a)\./) -> FALSE Debug: (5) } # if (&User-Name) = notfound Debug: (5) } # policy filter_username = notfound Debug: (5) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (5) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (5) [preprocess] = ok Debug: (5) modsingle[authorize]: calling chap (rlm_chap) Debug: (5) modsingle[authorize]: returned from chap (rlm_chap) Debug: (5) [chap] = noop Debug: (5) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (5) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (5) [mschap] = noop Debug: (5) modsingle[authorize]: calling digest (rlm_digest) Debug: (5) modsingle[authorize]: returned from digest (rlm_digest) Debug: (5) [digest] = noop Debug: (5) modsingle[authorize]: calling suffix (rlm_realm) Debug: (5) suffix: Checking for suffix after "@" Debug: (5) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (5) suffix: Found realm "NULL" Debug: (5) suffix: Adding Stripped-User-Name = "user001" Debug: (5) suffix: Adding Realm = "NULL" Debug: (5) suffix: Authentication realm is LOCAL Debug: (5) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (5) [suffix] = ok Debug: (5) modsingle[authorize]: calling eap (rlm_eap) Debug: (5) eap: Peer sent EAP Response (code 2) ID 5 length 144 Debug: (5) eap: Continuing tunnel setup Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) Debug: (5) [eap] = ok Debug: (5) } # authorize = ok Debug: (5) Found Auth-Type = eap Debug: (5) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (5) authenticate { Debug: (5) modsingle[authenticate]: calling eap (rlm_eap) Debug: (5) eap: Expiring EAP session with state 0x2943cbb82d46d20f Debug: (5) eap: Finished EAP session with state 0x2943cbb82d46d20f Debug: (5) eap: Previous EAP request found for state 0x2943cbb82d46d20f, released from the list Debug: (5) eap: Peer sent packet with method EAP PEAP (25) Debug: (5) eap: Calling submodule eap_peap to process data Debug: (5) eap_peap: Continuing EAP-TLS Debug: (5) eap_peap: Peer sent flags --L Debug: (5) eap_peap: Peer indicated complete TLS record size will be 134 bytes Debug: (5) eap_peap: Got complete TLS record (134 bytes) Debug: (5) eap_peap: [eaptls verify] = length included Debug: (5) eap_peap: <<< recv TLS 1.0 Handshake [length 0046], ClientKeyExchange Debug: (5) eap_peap: TLS_accept: SSLv3 read client key exchange A Debug: (5) eap_peap: <<< recv TLS 1.0 ChangeCipherSpec [length 0001] Debug: (5) eap_peap: <<< recv TLS 1.0 Handshake [length 0010], Finished Debug: (5) eap_peap: TLS_accept: SSLv3 read finished A Debug: (5) eap_peap: >>> send TLS 1.0 ChangeCipherSpec [length 0001] Debug: (5) eap_peap: TLS_accept: SSLv3 write change cipher spec A Debug: (5) eap_peap: >>> send TLS 1.0 Handshake [length 0010], Finished Debug: (5) eap_peap: TLS_accept: SSLv3 write finished A Debug: (5) eap_peap: TLS_accept: SSLv3 flush data Debug: (5) eap_peap: (other): SSL negotiation finished successfully Debug: (5) eap_peap: SSL Connection Established Debug: (5) eap_peap: [eaptls process] = handled Debug: (5) eap: Sending EAP Request (code 1) ID 6 length 65 Debug: (5) eap: EAP session adding &reply:State = 0x2943cbb82c45d20f Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (5) [eap] = handled Debug: (5) } # authenticate = handled Debug: (5) Using Post-Auth-Type Challenge Debug: (5) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (5) Challenge { ... } # empty sub-section is ignored Debug: (5) session-state: Nothing to cache Debug: (5) Sent Access-Challenge Id 5 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (5) EAP-Message = 0x0106004119001403010001011603010030c8541229c98ae3a82ffe682f2a345e23c6854b42d336ab462f41532bdc5c2379909fa148110f3fb23ebb217a3ef5ae37 Debug: (5) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (5) State = 0x2943cbb82c45d20f1f4c032fd1862a21 Debug: (5) Finished request Debug: Waking up in 4.9 seconds. Debug: (6) Received Access-Request Id 6 from 192.168.103.4:35803 to 192.168.103.1:1812 length 134 Debug: (6) User-Name = "user001" Debug: (6) NAS-IP-Address = 127.0.0.1 Debug: (6) Calling-Station-Id = "02-00-00-00-00-01" Debug: (6) Framed-MTU = 1400 Debug: (6) NAS-Port-Type = Wireless-802.11 Debug: (6) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (6) EAP-Message = 0x020600061900 Debug: (6) State = 0x2943cbb82c45d20f1f4c032fd1862a21 Debug: (6) Message-Authenticator = 0xc750e939d8ac2edf556f281b7839d5ed Debug: (6) session-state: No cached attributes Debug: (6) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (6) authorize { Debug: (6) policy filter_username { Debug: (6) if (&User-Name) { Debug: (6) if (&User-Name) -> TRUE Debug: (6) if (&User-Name) { Debug: (6) if (&User-Name =~ / /) { Debug: No matches Debug: (6) if (&User-Name =~ / /) -> FALSE Debug: (6) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (6) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (6) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (6) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (6) if (&User-Name =~ /\.$/) -> FALSE Debug: (6) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (6) if (&User-Name =~ /(a)\./) -> FALSE Debug: (6) } # if (&User-Name) = notfound Debug: (6) } # policy filter_username = notfound Debug: (6) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (6) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (6) [preprocess] = ok Debug: (6) modsingle[authorize]: calling chap (rlm_chap) Debug: (6) modsingle[authorize]: returned from chap (rlm_chap) Debug: (6) [chap] = noop Debug: (6) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (6) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (6) [mschap] = noop Debug: (6) modsingle[authorize]: calling digest (rlm_digest) Debug: (6) modsingle[authorize]: returned from digest (rlm_digest) Debug: (6) [digest] = noop Debug: (6) modsingle[authorize]: calling suffix (rlm_realm) Debug: (6) suffix: Checking for suffix after "@" Debug: (6) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (6) suffix: Found realm "NULL" Debug: (6) suffix: Adding Stripped-User-Name = "user001" Debug: (6) suffix: Adding Realm = "NULL" Debug: (6) suffix: Authentication realm is LOCAL Debug: (6) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (6) [suffix] = ok Debug: (6) modsingle[authorize]: calling eap (rlm_eap) Debug: (6) eap: Peer sent EAP Response (code 2) ID 6 length 6 Debug: (6) eap: Continuing tunnel setup Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) Debug: (6) [eap] = ok Debug: (6) } # authorize = ok Debug: (6) Found Auth-Type = eap Debug: (6) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (6) authenticate { Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) Debug: (6) eap: Expiring EAP session with state 0x2943cbb82c45d20f Debug: (6) eap: Finished EAP session with state 0x2943cbb82c45d20f Debug: (6) eap: Previous EAP request found for state 0x2943cbb82c45d20f, released from the list Debug: (6) eap: Peer sent packet with method EAP PEAP (25) Debug: (6) eap: Calling submodule eap_peap to process data Debug: (6) eap_peap: Continuing EAP-TLS Debug: (6) eap_peap: Peer sent flags --- Debug: (6) eap_peap: Peer ACKed our handshake fragment. handshake is finished Debug: (6) eap_peap: [eaptls verify] = success Debug: (6) eap_peap: [eaptls process] = success Debug: (6) eap_peap: Session established. Decoding tunneled attributes Debug: (6) eap_peap: PEAP state TUNNEL ESTABLISHED Debug: (6) eap: Sending EAP Request (code 1) ID 7 length 43 Debug: (6) eap: EAP session adding &reply:State = 0x2943cbb82f44d20f Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (6) [eap] = handled Debug: (6) } # authenticate = handled Debug: (6) Using Post-Auth-Type Challenge Debug: (6) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (6) Challenge { ... } # empty sub-section is ignored Debug: (6) session-state: Nothing to cache Debug: (6) Sent Access-Challenge Id 6 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (6) EAP-Message = 0x0107002b1900170301002078872f0302529e6c1d0a38f6bba254fe118d1d83dedce3891239700f81903c4c Debug: (6) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (6) State = 0x2943cbb82f44d20f1f4c032fd1862a21 Debug: (6) Finished request Debug: Waking up in 4.9 seconds. Debug: (7) Received Access-Request Id 7 from 192.168.103.4:35803 to 192.168.103.1:1812 length 208 Debug: (7) User-Name = "user001" Debug: (7) NAS-IP-Address = 127.0.0.1 Debug: (7) Calling-Station-Id = "02-00-00-00-00-01" Debug: (7) Framed-MTU = 1400 Debug: (7) NAS-Port-Type = Wireless-802.11 Debug: (7) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (7) EAP-Message = 0x02070050190017030100204fb3b96911243fd0144b333b148cc3620d6191104852ebc0d4e1387637fcc114170301002038fc888ef05140c952536d48b0dbdf74fec7d4db064c8d4d5e1839854df72468 Debug: (7) State = 0x2943cbb82f44d20f1f4c032fd1862a21 Debug: (7) Message-Authenticator = 0x29b362e5abb7a5dce7a730b7fcbafb68 Debug: (7) session-state: No cached attributes Debug: (7) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (7) authorize { Debug: (7) policy filter_username { Debug: (7) if (&User-Name) { Debug: (7) if (&User-Name) -> TRUE Debug: (7) if (&User-Name) { Debug: (7) if (&User-Name =~ / /) { Debug: No matches Debug: (7) if (&User-Name =~ / /) -> FALSE Debug: (7) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (7) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (7) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (7) if (&User-Name =~ /\.$/) -> FALSE Debug: (7) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (7) if (&User-Name =~ /(a)\./) -> FALSE Debug: (7) } # if (&User-Name) = notfound Debug: (7) } # policy filter_username = notfound Debug: (7) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (7) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (7) [preprocess] = ok Debug: (7) modsingle[authorize]: calling chap (rlm_chap) Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) Debug: (7) [chap] = noop Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (7) [mschap] = noop Debug: (7) modsingle[authorize]: calling digest (rlm_digest) Debug: (7) modsingle[authorize]: returned from digest (rlm_digest) Debug: (7) [digest] = noop Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) Debug: (7) suffix: Checking for suffix after "@" Debug: (7) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (7) suffix: Found realm "NULL" Debug: (7) suffix: Adding Stripped-User-Name = "user001" Debug: (7) suffix: Adding Realm = "NULL" Debug: (7) suffix: Authentication realm is LOCAL Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (7) [suffix] = ok Debug: (7) modsingle[authorize]: calling eap (rlm_eap) Debug: (7) eap: Peer sent EAP Response (code 2) ID 7 length 80 Debug: (7) eap: Continuing tunnel setup Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) Debug: (7) [eap] = ok Debug: (7) } # authorize = ok Debug: (7) Found Auth-Type = eap Debug: (7) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (7) authenticate { Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) Debug: (7) eap: Expiring EAP session with state 0x2943cbb82f44d20f Debug: (7) eap: Finished EAP session with state 0x2943cbb82f44d20f Debug: (7) eap: Previous EAP request found for state 0x2943cbb82f44d20f, released from the list Debug: (7) eap: Peer sent packet with method EAP PEAP (25) Debug: (7) eap: Calling submodule eap_peap to process data Debug: (7) eap_peap: Continuing EAP-TLS Debug: (7) eap_peap: Peer sent flags --- Debug: (7) eap_peap: [eaptls verify] = ok Debug: (7) eap_peap: Done initial handshake Debug: (7) eap_peap: [eaptls process] = ok Debug: (7) eap_peap: Session established. Decoding tunneled attributes Debug: (7) eap_peap: PEAP state WAITING FOR INNER IDENTITY Debug: (7) eap_peap: Identity - user001 Debug: (7) eap_peap: Got inner identity 'user001' Debug: (7) eap_peap: Setting default EAP type for tunneled EAP session Debug: (7) eap_peap: Got tunneled request Debug: (7) eap_peap: EAP-Message = 0x0207000c0175736572303031 Debug: (7) eap_peap: Setting User-Name to user001 Debug: (7) eap_peap: Sending tunneled request to inner-tunnel Debug: (7) eap_peap: EAP-Message = 0x0207000c0175736572303031 Debug: (7) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (7) eap_peap: User-Name = "user001" Debug: (7) Virtual server inner-tunnel received request Debug: (7) EAP-Message = 0x0207000c0175736572303031 Debug: (7) FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (7) User-Name = "user001" WARNING: (7) Outer and inner identities are the same. User privacy is compromised. Debug: (7) server inner-tunnel { Debug: (7) session-state: No State attribute Debug: (7) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (7) authorize { Debug: (7) policy filter_username { Debug: (7) if (&User-Name) { Debug: (7) if (&User-Name) -> TRUE Debug: (7) if (&User-Name) { Debug: (7) if (&User-Name =~ / /) { Debug: No matches Debug: (7) if (&User-Name =~ / /) -> FALSE Debug: (7) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (7) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (7) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (7) if (&User-Name =~ /\.$/) -> FALSE Debug: (7) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (7) if (&User-Name =~ /(a)\./) -> FALSE Debug: (7) } # if (&User-Name) = notfound Debug: (7) } # policy filter_username = notfound Debug: (7) modsingle[authorize]: calling chap (rlm_chap) Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) Debug: (7) [chap] = noop Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (7) [mschap] = noop Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) Debug: (7) suffix: Checking for suffix after "@" Debug: (7) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (7) suffix: Found realm "NULL" Debug: (7) suffix: Adding Stripped-User-Name = "user001" Debug: (7) suffix: Adding Realm = "NULL" Debug: (7) suffix: Authentication realm is LOCAL Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (7) [suffix] = ok Debug: (7) update control { Debug: (7) &Proxy-To-Realm := LOCAL Debug: (7) } # update control = noop Debug: (7) modsingle[authorize]: calling eap (rlm_eap) Debug: (7) eap: Peer sent EAP Response (code 2) ID 7 length 12 Debug: (7) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) Debug: (7) [eap] = ok Debug: (7) } # authorize = ok Debug: (7) Found Auth-Type = eap Debug: (7) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (7) authenticate { Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) Debug: (7) eap: Peer sent packet with method EAP Identity (1) Debug: (7) eap: Calling submodule eap_mschapv2 to process data Debug: (7) eap_mschapv2: Issuing Challenge Debug: (7) eap: Sending EAP Request (code 1) ID 8 length 43 Debug: (7) eap: EAP session adding &reply:State = 0xdd839a9add8b801f Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (7) [eap] = handled Debug: (7) } # authenticate = handled Debug: (7) } # server inner-tunnel Debug: (7) Virtual server sending reply Debug: (7) EAP-Message = 0x0108002b1a0108002610434844dc565ffd451886618b17851d1d667265657261646975732d332e302e3136 Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (7) State = 0xdd839a9add8b801f0849ec4832efac1b Debug: (7) eap_peap: Got tunneled reply code 11 Debug: (7) eap_peap: EAP-Message = 0x0108002b1a0108002610434844dc565ffd451886618b17851d1d667265657261646975732d332e302e3136 Debug: (7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (7) eap_peap: State = 0xdd839a9add8b801f0849ec4832efac1b Debug: (7) eap_peap: Got tunneled reply RADIUS code 11 Debug: (7) eap_peap: EAP-Message = 0x0108002b1a0108002610434844dc565ffd451886618b17851d1d667265657261646975732d332e302e3136 Debug: (7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (7) eap_peap: State = 0xdd839a9add8b801f0849ec4832efac1b Debug: (7) eap_peap: Got tunneled Access-Challenge Debug: (7) eap: Sending EAP Request (code 1) ID 8 length 75 Debug: (7) eap: EAP session adding &reply:State = 0x2943cbb82e4bd20f Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (7) [eap] = handled Debug: (7) } # authenticate = handled Debug: (7) Using Post-Auth-Type Challenge Debug: (7) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (7) Challenge { ... } # empty sub-section is ignored Debug: (7) session-state: Nothing to cache Debug: (7) Sent Access-Challenge Id 7 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (7) EAP-Message = 0x0108004b190017030100408edc3ae6efbc07c472cfc542e9857e9bd52f0e4b3ae3cd7abffcb7a8622de78cf914f2f0598e189bf606db0a07a4c7b175a44d8c640b7a2b0a073470f7989d82 Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (7) State = 0x2943cbb82e4bd20f1f4c032fd1862a21 Debug: (7) Finished request Debug: Waking up in 4.9 seconds. Debug: (8) Received Access-Request Id 8 from 192.168.103.4:35803 to 192.168.103.1:1812 length 272 Debug: (8) User-Name = "user001" Debug: (8) NAS-IP-Address = 127.0.0.1 Debug: (8) Calling-Station-Id = "02-00-00-00-00-01" Debug: (8) Framed-MTU = 1400 Debug: (8) NAS-Port-Type = Wireless-802.11 Debug: (8) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (8) EAP-Message = 0x020800901900170301002016909a115395a0323d9563e5781f2b4db697d4638c88ee7172b3cd9c91bbd3931703010060f3b4652d82b1d03fbedfd9fc7454f767f07084c0aacaa49946245c4501d58aa79c876f482f594bd93bb33b3597457ab70c75f31dd6a92bfcfaca9a43d85a03f44047bb39d0a9f6 Debug: (8) State = 0x2943cbb82e4bd20f1f4c032fd1862a21 Debug: (8) Message-Authenticator = 0x6fb7e37d968169ea17e83c1f74376fe3 Debug: (8) session-state: No cached attributes Debug: (8) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (8) authorize { Debug: (8) policy filter_username { Debug: (8) if (&User-Name) { Debug: (8) if (&User-Name) -> TRUE Debug: (8) if (&User-Name) { Debug: (8) if (&User-Name =~ / /) { Debug: No matches Debug: (8) if (&User-Name =~ / /) -> FALSE Debug: (8) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (8) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (8) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (8) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (8) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (8) if (&User-Name =~ /\.$/) -> FALSE Debug: (8) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (8) if (&User-Name =~ /(a)\./) -> FALSE Debug: (8) } # if (&User-Name) = notfound Debug: (8) } # policy filter_username = notfound Debug: (8) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (8) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (8) [preprocess] = ok Debug: (8) modsingle[authorize]: calling chap (rlm_chap) Debug: (8) modsingle[authorize]: returned from chap (rlm_chap) Debug: (8) [chap] = noop Debug: (8) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (8) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (8) [mschap] = noop Debug: (8) modsingle[authorize]: calling digest (rlm_digest) Debug: (8) modsingle[authorize]: returned from digest (rlm_digest) Debug: (8) [digest] = noop Debug: (8) modsingle[authorize]: calling suffix (rlm_realm) Debug: (8) suffix: Checking for suffix after "@" Debug: (8) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (8) suffix: Found realm "NULL" Debug: (8) suffix: Adding Stripped-User-Name = "user001" Debug: (8) suffix: Adding Realm = "NULL" Debug: (8) suffix: Authentication realm is LOCAL Debug: (8) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (8) [suffix] = ok Debug: (8) modsingle[authorize]: calling eap (rlm_eap) Debug: (8) eap: Peer sent EAP Response (code 2) ID 8 length 144 Debug: (8) eap: Continuing tunnel setup Debug: (8) modsingle[authorize]: returned from eap (rlm_eap) Debug: (8) [eap] = ok Debug: (8) } # authorize = ok Debug: (8) Found Auth-Type = eap Debug: (8) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (8) authenticate { Debug: (8) modsingle[authenticate]: calling eap (rlm_eap) Debug: (8) eap: Expiring EAP session with state 0xdd839a9add8b801f Debug: (8) eap: Finished EAP session with state 0x2943cbb82e4bd20f Debug: (8) eap: Previous EAP request found for state 0x2943cbb82e4bd20f, released from the list Debug: (8) eap: Peer sent packet with method EAP PEAP (25) Debug: (8) eap: Calling submodule eap_peap to process data Debug: (8) eap_peap: Continuing EAP-TLS Debug: (8) eap_peap: Peer sent flags --- Debug: (8) eap_peap: [eaptls verify] = ok Debug: (8) eap_peap: Done initial handshake Debug: (8) eap_peap: [eaptls process] = ok Debug: (8) eap_peap: Session established. Decoding tunneled attributes Debug: (8) eap_peap: PEAP state phase2 Debug: (8) eap_peap: EAP method MSCHAPv2 (26) Debug: (8) eap_peap: Got tunneled request Debug: (8) eap_peap: EAP-Message = 0x020800421a0208003d31dffbe084cb63e78ecccf21e28bbe241800000000000000007b30af8fc9faff7be191756ab68d7dfa78db08c808f4ba4c0075736572303031 Debug: (8) eap_peap: Setting User-Name to user001 Debug: (8) eap_peap: Sending tunneled request to inner-tunnel Debug: (8) eap_peap: EAP-Message = 0x020800421a0208003d31dffbe084cb63e78ecccf21e28bbe241800000000000000007b30af8fc9faff7be191756ab68d7dfa78db08c808f4ba4c0075736572303031 Debug: (8) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (8) eap_peap: User-Name = "user001" Debug: (8) eap_peap: State = 0xdd839a9add8b801f0849ec4832efac1b Debug: (8) Virtual server inner-tunnel received request Debug: (8) EAP-Message = 0x020800421a0208003d31dffbe084cb63e78ecccf21e28bbe241800000000000000007b30af8fc9faff7be191756ab68d7dfa78db08c808f4ba4c0075736572303031 Debug: (8) FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (8) User-Name = "user001" Debug: (8) State = 0xdd839a9add8b801f0849ec4832efac1b WARNING: (8) Outer and inner identities are the same. User privacy is compromised. Debug: (8) server inner-tunnel { Debug: (8) session-state: No cached attributes Debug: (8) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (8) authorize { Debug: (8) policy filter_username { Debug: (8) if (&User-Name) { Debug: (8) if (&User-Name) -> TRUE Debug: (8) if (&User-Name) { Debug: (8) if (&User-Name =~ / /) { Debug: No matches Debug: (8) if (&User-Name =~ / /) -> FALSE Debug: (8) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (8) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (8) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (8) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (8) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (8) if (&User-Name =~ /\.$/) -> FALSE Debug: (8) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (8) if (&User-Name =~ /(a)\./) -> FALSE Debug: (8) } # if (&User-Name) = notfound Debug: (8) } # policy filter_username = notfound Debug: (8) modsingle[authorize]: calling chap (rlm_chap) Debug: (8) modsingle[authorize]: returned from chap (rlm_chap) Debug: (8) [chap] = noop Debug: (8) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (8) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (8) [mschap] = noop Debug: (8) modsingle[authorize]: calling suffix (rlm_realm) Debug: (8) suffix: Checking for suffix after "@" Debug: (8) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (8) suffix: Found realm "NULL" Debug: (8) suffix: Adding Stripped-User-Name = "user001" Debug: (8) suffix: Adding Realm = "NULL" Debug: (8) suffix: Authentication realm is LOCAL Debug: (8) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (8) [suffix] = ok Debug: (8) update control { Debug: (8) &Proxy-To-Realm := LOCAL Debug: (8) } # update control = noop Debug: (8) modsingle[authorize]: calling eap (rlm_eap) Debug: (8) eap: Peer sent EAP Response (code 2) ID 8 length 66 Debug: (8) eap: No EAP Start, assuming it's an on-going EAP conversation Debug: (8) modsingle[authorize]: returned from eap (rlm_eap) Debug: (8) [eap] = updated Debug: (8) modsingle[authorize]: calling files (rlm_files) Debug: (8) files: users: Matched entry user001 at line 221 Debug: (8) files: ::: FROM 1 TO 0 MAX 1 Debug: (8) files: ::: Examining Reply-Message Debug: Hello, %{User-Name} Debug: Parsed xlat tree: Debug: literal --> Hello, Debug: attribute --> User-Name Debug: (8) files: EXPAND Hello, %{User-Name} Debug: (8) files: --> Hello, user001 Debug: (8) files: ::: APPENDING Reply-Message FROM 0 TO 0 Debug: (8) files: ::: TO in 0 out 0 Debug: (8) modsingle[authorize]: returned from files (rlm_files) Debug: (8) [files] = ok Debug: (8) modsingle[authorize]: calling expiration (rlm_expiration) Debug: (8) modsingle[authorize]: returned from expiration (rlm_expiration) Debug: (8) [expiration] = noop Debug: (8) modsingle[authorize]: calling logintime (rlm_logintime) Debug: (8) modsingle[authorize]: returned from logintime (rlm_logintime) Debug: (8) [logintime] = noop Debug: (8) modsingle[authorize]: calling pap (rlm_pap) WARNING: (8) pap: Auth-Type already set. Not setting to PAP Debug: (8) modsingle[authorize]: returned from pap (rlm_pap) Debug: (8) [pap] = noop Debug: (8) } # authorize = updated Debug: (8) Found Auth-Type = eap Debug: (8) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (8) authenticate { Debug: (8) modsingle[authenticate]: calling eap (rlm_eap) Debug: (8) eap: Expiring EAP session with state 0xdd839a9add8b801f Debug: (8) eap: Finished EAP session with state 0xdd839a9add8b801f Debug: (8) eap: Previous EAP request found for state 0xdd839a9add8b801f, released from the list Debug: (8) eap: Peer sent packet with method EAP MSCHAPv2 (26) Debug: (8) eap: Calling submodule eap_mschapv2 to process data Debug: (8) eap_mschapv2: # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (8) eap_mschapv2: authenticate { Debug: (8) eap_mschapv2: modsingle[authenticate]: calling mschap (rlm_mschap) Debug: (8) mschap: Found Cleartext-Password, hashing to create NT-Password Debug: (8) mschap: Found Cleartext-Password, hashing to create LM-Password Debug: (8) mschap: Creating challenge hash with username: user001 Debug: (8) mschap: Client is using MS-CHAPv2 Debug: (8) mschap: Adding MS-CHAPv2 MPPE keys Debug: (8) modsingle[authenticate]: returned from mschap (rlm_mschap) Debug: (8) [mschap] = ok Debug: (8) } # authenticate = ok Debug: (8) MSCHAP Success Debug: (8) eap: Sending EAP Request (code 1) ID 9 length 51 Debug: (8) eap: EAP session adding &reply:State = 0xdd839a9adc8a801f Debug: (8) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (8) [eap] = handled Debug: (8) } # authenticate = handled Debug: (8) } # server inner-tunnel Debug: (8) Virtual server sending reply Debug: (8) Reply-Message = "Hello, user001" Debug: (8) EAP-Message = 0x010900331a0308002e533d46424134344533344236334434394632443445344338433338374144443936303438353030423942 Debug: (8) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (8) State = 0xdd839a9adc8a801f0849ec4832efac1b Debug: (8) eap_peap: Got tunneled reply code 11 Debug: (8) eap_peap: Reply-Message = "Hello, user001" Debug: (8) eap_peap: EAP-Message = 0x010900331a0308002e533d46424134344533344236334434394632443445344338433338374144443936303438353030423942 Debug: (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (8) eap_peap: State = 0xdd839a9adc8a801f0849ec4832efac1b Debug: (8) eap_peap: Got tunneled reply RADIUS code 11 Debug: (8) eap_peap: Reply-Message = "Hello, user001" Debug: (8) eap_peap: EAP-Message = 0x010900331a0308002e533d46424134344533344236334434394632443445344338433338374144443936303438353030423942 Debug: (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (8) eap_peap: State = 0xdd839a9adc8a801f0849ec4832efac1b Debug: (8) eap_peap: Got tunneled Access-Challenge Debug: (8) eap: Sending EAP Request (code 1) ID 9 length 91 Debug: (8) eap: EAP session adding &reply:State = 0x2943cbb8214ad20f Debug: (8) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (8) [eap] = handled Debug: (8) } # authenticate = handled Debug: (8) Using Post-Auth-Type Challenge Debug: (8) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (8) Challenge { ... } # empty sub-section is ignored Debug: (8) session-state: Nothing to cache Debug: (8) Sent Access-Challenge Id 8 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (8) EAP-Message = 0x0109005b19001703010050026c4b63f2767496800d97e7d870ddb7a23d111ad9512d7286ce85a42d24e5637ea21a5ffff590bd27160c8991e24c7b7f081024cadd8bb0924ae5a41ad73c6e2df7cd2a7fe51c4b97b9ba41cb1ea438 Debug: (8) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (8) State = 0x2943cbb8214ad20f1f4c032fd1862a21 Debug: (8) Finished request Debug: Waking up in 4.9 seconds. Debug: (9) Received Access-Request Id 9 from 192.168.103.4:35803 to 192.168.103.1:1812 length 208 Debug: (9) User-Name = "user001" Debug: (9) NAS-IP-Address = 127.0.0.1 Debug: (9) Calling-Station-Id = "02-00-00-00-00-01" Debug: (9) Framed-MTU = 1400 Debug: (9) NAS-Port-Type = Wireless-802.11 Debug: (9) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (9) EAP-Message = 0x0209005019001703010020e6b2cca18ea3e00655346abc1915d85ffa1fed44d57777ab5ffeb345848ca06f1703010020a4d333dc756b3fc6597302e21839dc5d42345f8a4b5ac4fa592edbc5f427e4d5 Debug: (9) State = 0x2943cbb8214ad20f1f4c032fd1862a21 Debug: (9) Message-Authenticator = 0x989fa5998f7dc32799916347db85c2f0 Debug: (9) session-state: No cached attributes Debug: (9) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (9) authorize { Debug: (9) policy filter_username { Debug: (9) if (&User-Name) { Debug: (9) if (&User-Name) -> TRUE Debug: (9) if (&User-Name) { Debug: (9) if (&User-Name =~ / /) { Debug: No matches Debug: (9) if (&User-Name =~ / /) -> FALSE Debug: (9) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (9) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (9) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (9) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (9) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (9) if (&User-Name =~ /\.$/) -> FALSE Debug: (9) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (9) if (&User-Name =~ /(a)\./) -> FALSE Debug: (9) } # if (&User-Name) = notfound Debug: (9) } # policy filter_username = notfound Debug: (9) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (9) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (9) [preprocess] = ok Debug: (9) modsingle[authorize]: calling chap (rlm_chap) Debug: (9) modsingle[authorize]: returned from chap (rlm_chap) Debug: (9) [chap] = noop Debug: (9) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (9) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (9) [mschap] = noop Debug: (9) modsingle[authorize]: calling digest (rlm_digest) Debug: (9) modsingle[authorize]: returned from digest (rlm_digest) Debug: (9) [digest] = noop Debug: (9) modsingle[authorize]: calling suffix (rlm_realm) Debug: (9) suffix: Checking for suffix after "@" Debug: (9) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (9) suffix: Found realm "NULL" Debug: (9) suffix: Adding Stripped-User-Name = "user001" Debug: (9) suffix: Adding Realm = "NULL" Debug: (9) suffix: Authentication realm is LOCAL Debug: (9) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (9) [suffix] = ok Debug: (9) modsingle[authorize]: calling eap (rlm_eap) Debug: (9) eap: Peer sent EAP Response (code 2) ID 9 length 80 Debug: (9) eap: Continuing tunnel setup Debug: (9) modsingle[authorize]: returned from eap (rlm_eap) Debug: (9) [eap] = ok Debug: (9) } # authorize = ok Debug: (9) Found Auth-Type = eap Debug: (9) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (9) authenticate { Debug: (9) modsingle[authenticate]: calling eap (rlm_eap) Debug: (9) eap: Expiring EAP session with state 0xdd839a9adc8a801f Debug: (9) eap: Finished EAP session with state 0x2943cbb8214ad20f Debug: (9) eap: Previous EAP request found for state 0x2943cbb8214ad20f, released from the list Debug: (9) eap: Peer sent packet with method EAP PEAP (25) Debug: (9) eap: Calling submodule eap_peap to process data Debug: (9) eap_peap: Continuing EAP-TLS Debug: (9) eap_peap: Peer sent flags --- Debug: (9) eap_peap: [eaptls verify] = ok Debug: (9) eap_peap: Done initial handshake Debug: (9) eap_peap: [eaptls process] = ok Debug: (9) eap_peap: Session established. Decoding tunneled attributes Debug: (9) eap_peap: PEAP state phase2 Debug: (9) eap_peap: EAP method MSCHAPv2 (26) Debug: (9) eap_peap: Got tunneled request Debug: (9) eap_peap: EAP-Message = 0x020900061a03 Debug: (9) eap_peap: Setting User-Name to user001 Debug: (9) eap_peap: Sending tunneled request to inner-tunnel Debug: (9) eap_peap: EAP-Message = 0x020900061a03 Debug: (9) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (9) eap_peap: User-Name = "user001" Debug: (9) eap_peap: State = 0xdd839a9adc8a801f0849ec4832efac1b Debug: (9) Virtual server inner-tunnel received request Debug: (9) EAP-Message = 0x020900061a03 Debug: (9) FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (9) User-Name = "user001" Debug: (9) State = 0xdd839a9adc8a801f0849ec4832efac1b WARNING: (9) Outer and inner identities are the same. User privacy is compromised. Debug: (9) server inner-tunnel { Debug: (9) session-state: No cached attributes Debug: (9) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (9) authorize { Debug: (9) policy filter_username { Debug: (9) if (&User-Name) { Debug: (9) if (&User-Name) -> TRUE Debug: (9) if (&User-Name) { Debug: (9) if (&User-Name =~ / /) { Debug: No matches Debug: (9) if (&User-Name =~ / /) -> FALSE Debug: (9) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (9) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (9) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (9) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (9) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (9) if (&User-Name =~ /\.$/) -> FALSE Debug: (9) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (9) if (&User-Name =~ /(a)\./) -> FALSE Debug: (9) } # if (&User-Name) = notfound Debug: (9) } # policy filter_username = notfound Debug: (9) modsingle[authorize]: calling chap (rlm_chap) Debug: (9) modsingle[authorize]: returned from chap (rlm_chap) Debug: (9) [chap] = noop Debug: (9) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (9) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (9) [mschap] = noop Debug: (9) modsingle[authorize]: calling suffix (rlm_realm) Debug: (9) suffix: Checking for suffix after "@" Debug: (9) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (9) suffix: Found realm "NULL" Debug: (9) suffix: Adding Stripped-User-Name = "user001" Debug: (9) suffix: Adding Realm = "NULL" Debug: (9) suffix: Authentication realm is LOCAL Debug: (9) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (9) [suffix] = ok Debug: (9) update control { Debug: (9) &Proxy-To-Realm := LOCAL Debug: (9) } # update control = noop Debug: (9) modsingle[authorize]: calling eap (rlm_eap) Debug: (9) eap: Peer sent EAP Response (code 2) ID 9 length 6 Debug: (9) eap: No EAP Start, assuming it's an on-going EAP conversation Debug: (9) modsingle[authorize]: returned from eap (rlm_eap) Debug: (9) [eap] = updated Debug: (9) modsingle[authorize]: calling files (rlm_files) Debug: (9) files: users: Matched entry user001 at line 221 Debug: (9) files: ::: FROM 1 TO 0 MAX 1 Debug: (9) files: ::: Examining Reply-Message Debug: Hello, %{User-Name} Debug: Parsed xlat tree: Debug: literal --> Hello, Debug: attribute --> User-Name Debug: (9) files: EXPAND Hello, %{User-Name} Debug: (9) files: --> Hello, user001 Debug: (9) files: ::: APPENDING Reply-Message FROM 0 TO 0 Debug: (9) files: ::: TO in 0 out 0 Debug: (9) modsingle[authorize]: returned from files (rlm_files) Debug: (9) [files] = ok Debug: (9) modsingle[authorize]: calling expiration (rlm_expiration) Debug: (9) modsingle[authorize]: returned from expiration (rlm_expiration) Debug: (9) [expiration] = noop Debug: (9) modsingle[authorize]: calling logintime (rlm_logintime) Debug: (9) modsingle[authorize]: returned from logintime (rlm_logintime) Debug: (9) [logintime] = noop Debug: (9) modsingle[authorize]: calling pap (rlm_pap) WARNING: (9) pap: Auth-Type already set. Not setting to PAP Debug: (9) modsingle[authorize]: returned from pap (rlm_pap) Debug: (9) [pap] = noop Debug: (9) } # authorize = updated Debug: (9) Found Auth-Type = eap Debug: (9) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (9) authenticate { Debug: (9) modsingle[authenticate]: calling eap (rlm_eap) Debug: (9) eap: Expiring EAP session with state 0xdd839a9adc8a801f Debug: (9) eap: Finished EAP session with state 0xdd839a9adc8a801f Debug: (9) eap: Previous EAP request found for state 0xdd839a9adc8a801f, released from the list Debug: (9) eap: Peer sent packet with method EAP MSCHAPv2 (26) Debug: (9) eap: Calling submodule eap_mschapv2 to process data Debug: (9) eap: Sending EAP Success (code 3) ID 9 length 4 Debug: (9) eap: Freeing handler Debug: (9) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (9) [eap] = ok Debug: (9) } # authenticate = ok Debug: (9) # Executing section post-auth from file /usr/local/radius316/etc/raddb/sites-enabled/inner-tunnel Debug: (9) post-auth { Debug: (9) if (0) { Debug: (9) if (0) -> FALSE Debug: (9) } # post-auth = noop Debug: (9) } # server inner-tunnel Debug: (9) Virtual server sending reply Debug: (9) Reply-Message = "Hello, user001" Debug: (9) MS-MPPE-Encryption-Policy = Encryption-Allowed Debug: (9) MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed Debug: (9) MS-MPPE-Send-Key = 0x52f0a4d62c799846cb66b0c4b9facf46 Debug: (9) MS-MPPE-Recv-Key = 0x85e293c68203953767f28f443264f752 Debug: (9) EAP-Message = 0x03090004 Debug: (9) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (9) Stripped-User-Name = "user001" Debug: (9) eap_peap: Got tunneled reply code 2 Debug: (9) eap_peap: Reply-Message = "Hello, user001" Debug: (9) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed Debug: (9) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed Debug: (9) eap_peap: MS-MPPE-Send-Key = 0x52f0a4d62c799846cb66b0c4b9facf46 Debug: (9) eap_peap: MS-MPPE-Recv-Key = 0x85e293c68203953767f28f443264f752 Debug: (9) eap_peap: EAP-Message = 0x03090004 Debug: (9) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (9) eap_peap: Stripped-User-Name = "user001" Debug: (9) eap_peap: Got tunneled reply RADIUS code 2 Debug: (9) eap_peap: Reply-Message = "Hello, user001" Debug: (9) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed Debug: (9) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed Debug: (9) eap_peap: MS-MPPE-Send-Key = 0x52f0a4d62c799846cb66b0c4b9facf46 Debug: (9) eap_peap: MS-MPPE-Recv-Key = 0x85e293c68203953767f28f443264f752 Debug: (9) eap_peap: EAP-Message = 0x03090004 Debug: (9) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 Debug: (9) eap_peap: Stripped-User-Name = "user001" Debug: (9) eap_peap: Tunneled authentication was successful Debug: (9) eap_peap: SUCCESS Debug: (9) eap: Sending EAP Request (code 1) ID 10 length 43 Debug: (9) eap: EAP session adding &reply:State = 0x2943cbb82049d20f Debug: (9) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (9) [eap] = handled Debug: (9) } # authenticate = handled Debug: (9) Using Post-Auth-Type Challenge Debug: (9) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (9) Challenge { ... } # empty sub-section is ignored Debug: (9) session-state: Nothing to cache Debug: (9) Sent Access-Challenge Id 9 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (9) EAP-Message = 0x010a002b19001703010020233db118534b880c9726d364a32d21a9fe91b240bf59d137d9031d058232679b Debug: (9) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (9) State = 0x2943cbb82049d20f1f4c032fd1862a21 Debug: (9) Finished request Debug: Waking up in 4.9 seconds. Debug: (10) Received Access-Request Id 10 from 192.168.103.4:35803 to 192.168.103.1:1812 length 208 Debug: (10) User-Name = "user001" Debug: (10) NAS-IP-Address = 127.0.0.1 Debug: (10) Calling-Station-Id = "02-00-00-00-00-01" Debug: (10) Framed-MTU = 1400 Debug: (10) NAS-Port-Type = Wireless-802.11 Debug: (10) Connect-Info = "CONNECT 11Mbps 802.11b" Debug: (10) EAP-Message = 0x020a0050190017030100209f98e0fbaed989b14b18056301932f1fccb40f29ee0f24c7040aecb0c411d5d11703010020cefc95176eada8f429f4fd2a60ea5fd3cd9367e7d28bfe8f5de5368909ab46eb Debug: (10) State = 0x2943cbb82049d20f1f4c032fd1862a21 Debug: (10) Message-Authenticator = 0x60fb779e75a1882a2076f91a7d3b9aa1 Debug: (10) session-state: No cached attributes Debug: (10) # Executing section authorize from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (10) authorize { Debug: (10) policy filter_username { Debug: (10) if (&User-Name) { Debug: (10) if (&User-Name) -> TRUE Debug: (10) if (&User-Name) { Debug: (10) if (&User-Name =~ / /) { Debug: No matches Debug: (10) if (&User-Name =~ / /) -> FALSE Debug: (10) if (&User-Name =~ /@[^@]*@/ ) { Debug: No matches Debug: (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Debug: (10) if (&User-Name =~ /\.\./ ) { Debug: No matches Debug: (10) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Debug: No matches Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Debug: (10) if (&User-Name =~ /\.$/) { Debug: No matches Debug: (10) if (&User-Name =~ /\.$/) -> FALSE Debug: (10) if (&User-Name =~ /(a)\./) { Debug: No matches Debug: (10) if (&User-Name =~ /(a)\./) -> FALSE Debug: (10) } # if (&User-Name) = notfound Debug: (10) } # policy filter_username = notfound Debug: (10) modsingle[authorize]: calling preprocess (rlm_preprocess) Debug: (10) modsingle[authorize]: returned from preprocess (rlm_preprocess) Debug: (10) [preprocess] = ok Debug: (10) modsingle[authorize]: calling chap (rlm_chap) Debug: (10) modsingle[authorize]: returned from chap (rlm_chap) Debug: (10) [chap] = noop Debug: (10) modsingle[authorize]: calling mschap (rlm_mschap) Debug: (10) modsingle[authorize]: returned from mschap (rlm_mschap) Debug: (10) [mschap] = noop Debug: (10) modsingle[authorize]: calling digest (rlm_digest) Debug: (10) modsingle[authorize]: returned from digest (rlm_digest) Debug: (10) [digest] = noop Debug: (10) modsingle[authorize]: calling suffix (rlm_realm) Debug: (10) suffix: Checking for suffix after "@" Debug: (10) suffix: No '@' in User-Name = "user001", looking up realm NULL Debug: (10) suffix: Found realm "NULL" Debug: (10) suffix: Adding Stripped-User-Name = "user001" Debug: (10) suffix: Adding Realm = "NULL" Debug: (10) suffix: Authentication realm is LOCAL Debug: (10) modsingle[authorize]: returned from suffix (rlm_realm) Debug: (10) [suffix] = ok Debug: (10) modsingle[authorize]: calling eap (rlm_eap) Debug: (10) eap: Peer sent EAP Response (code 2) ID 10 length 80 Debug: (10) eap: Continuing tunnel setup Debug: (10) modsingle[authorize]: returned from eap (rlm_eap) Debug: (10) [eap] = ok Debug: (10) } # authorize = ok Debug: (10) Found Auth-Type = eap Debug: (10) # Executing group from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (10) authenticate { Debug: (10) modsingle[authenticate]: calling eap (rlm_eap) Debug: (10) eap: Expiring EAP session with state 0x2943cbb82049d20f Debug: (10) eap: Finished EAP session with state 0x2943cbb82049d20f Debug: (10) eap: Previous EAP request found for state 0x2943cbb82049d20f, released from the list Debug: (10) eap: Peer sent packet with method EAP PEAP (25) Debug: (10) eap: Calling submodule eap_peap to process data Debug: (10) eap_peap: Continuing EAP-TLS Debug: (10) eap_peap: Peer sent flags --- Debug: (10) eap_peap: [eaptls verify] = ok Debug: (10) eap_peap: Done initial handshake Debug: (10) eap_peap: [eaptls process] = ok Debug: (10) eap_peap: Session established. Decoding tunneled attributes Debug: (10) eap_peap: PEAP state send tlv success Debug: (10) eap_peap: Received EAP-TLV response Debug: (10) eap_peap: Success Debug: (10) eap: Sending EAP Success (code 3) ID 10 length 4 Debug: (10) eap: Freeing handler Debug: (10) modsingle[authenticate]: returned from eap (rlm_eap) Debug: (10) [eap] = ok Debug: (10) } # authenticate = ok Debug: (10) # Executing section post-auth from file /usr/local/radius316/etc/raddb/sites-enabled/default Debug: (10) post-auth { Debug: (10) update { Debug: (10) No attributes updated Debug: (10) } # update = noop Debug: (10) modsingle[post-auth]: calling exec (rlm_exec) Debug: (10) modsingle[post-auth]: returned from exec (rlm_exec) Debug: (10) [exec] = noop Debug: (10) policy remove_reply_message_if_eap { Debug: (10) if (&reply:EAP-Message && &reply:Reply-Message) { Debug: (10) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Debug: (10) else { Debug: (10) modsingle[post-auth]: calling noop (rlm_always) Debug: (10) modsingle[post-auth]: returned from noop (rlm_always) Debug: (10) [noop] = noop Debug: (10) } # else = noop Debug: (10) } # policy remove_reply_message_if_eap = noop Debug: (10) } # post-auth = noop Debug: (10) Sent Access-Accept Id 10 from 192.168.103.1:1812 to 192.168.103.4:35803 length 0 Debug: (10) MS-MPPE-Recv-Key = 0x944325c05f97f4830c134ea2d9a743585de3623d6cba3c41f5f1905d1f7d3bfb Debug: (10) MS-MPPE-Send-Key = 0xafdf7f18840c908f1f8a10d22abb6a50375a288c13751155ab0f94042c84886e Debug: (10) EAP-Message = 0x030a0004 Debug: (10) Message-Authenticator = 0x00000000000000000000000000000000 Debug: (10) Finished request Debug: Waking up in 4.6 seconds. ---------------------------------------- etokaoru

4 4