- Freeradius-Users - lists.freeradius.org

Re: EAP-PEAP-GTC issue
by Arjan Sinnige 17 Dec '16

17 Dec '16

Alan DeKok Wrote : > Something is going wrong with TLS. What is going wrong? Upgrade to v3 to get better error messages. Ok I've created a test freeradius server on 3.0.13 Full Debug below... Still stumped by this.. Phone must be dead or cisco NAS issues ?? This does not look like a configuration error AFAIK. (Which isn't much) Any suggestions ? Arjan FreeRADIUS Version 3.0.13 Copyright (C) 1999-2016 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 dictionary file /usr/share/freeradius/dictionary including dictionary file /usr/share/freeradius/dictionary.dhcp including dictionary file /usr/share/freeradius/dictionary.vqp including dictionary file /etc/freeradius/dictionary including configuration file /etc/freeradius/radiusd.conf including configuration file /etc/freeradius/proxy.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/mods-enabled/ including configuration file /etc/freeradius/mods-enabled/replicate including configuration file /etc/freeradius/mods-enabled/echo including configuration file /etc/freeradius/mods-enabled/sradutmp including configuration file /etc/freeradius/mods-enabled/cache_eap including configuration file /etc/freeradius/mods-enabled/detail including configuration file /etc/freeradius/mods-enabled/date including configuration file /etc/freeradius/mods-enabled/radutmp including configuration file /etc/freeradius/mods-enabled/expr including configuration file /etc/freeradius/mods-enabled/realm including configuration file /etc/freeradius/mods-enabled/attr_filter including configuration file /etc/freeradius/mods-enabled/ldap including configuration file /etc/freeradius/mods-enabled/eap including configuration file /etc/freeradius/mods-enabled/soh including configuration file /etc/freeradius/mods-enabled/passwd including configuration file /etc/freeradius/mods-enabled/chap including configuration file /etc/freeradius/mods-enabled/unix including configuration file /etc/freeradius/mods-enabled/preprocess including configuration file /etc/freeradius/mods-enabled/always including configuration file /etc/freeradius/mods-enabled/logintime including configuration file /etc/freeradius/mods-enabled/digest including configuration file /etc/freeradius/mods-enabled/linelog including configuration file /etc/freeradius/mods-enabled/utf8 including configuration file /etc/freeradius/mods-enabled/detail.log including configuration file /etc/freeradius/mods-enabled/files including configuration file /etc/freeradius/mods-enabled/dynamic_clients including configuration file /etc/freeradius/mods-enabled/expiration including configuration file /etc/freeradius/mods-enabled/unpack including configuration file /etc/freeradius/mods-enabled/pap including configuration file /etc/freeradius/mods-enabled/mschap including configuration file /etc/freeradius/mods-enabled/exec including configuration file /etc/freeradius/mods-enabled/ntlm_auth including files in directory /etc/freeradius/policy.d/ including configuration file /etc/freeradius/policy.d/moonshot-targeted-ids including configuration file /etc/freeradius/policy.d/control including configuration file /etc/freeradius/policy.d/debug including configuration file /etc/freeradius/policy.d/eap including configuration file /etc/freeradius/policy.d/filter including configuration file /etc/freeradius/policy.d/canonicalization including configuration file /etc/freeradius/policy.d/abfab-tr including configuration file /etc/freeradius/policy.d/accounting including configuration file /etc/freeradius/policy.d/cui including configuration file /etc/freeradius/policy.d/operator-name including configuration file /etc/freeradius/policy.d/dhcp including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/inner-tunnel including configuration file /etc/freeradius/sites-enabled/default main { security { user = "freerad" group = "freerad" allow_core_dumps = no } name = "freeradius" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" } main { name = "freeradius" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no colourise = yes msg_denied = "You are already logged in - access denied" } resources { } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = <<< secret >>> response_window = 20.000000 response_timeouts = 1 max_outstanding = 65536 zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 check_timeout = 4 num_answers_to_alive = 3 revive_interval = 120 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" proto = "*" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client localhost_ipv6 { ipv6addr = ::1 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client TESTNET { ipaddr = 192.168.109.194 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Debugger not attached # Creating Auth-Type = mschap # Creating Auth-Type = eap # Creating Auth-Type = PAP # Creating Auth-Type = CHAP # Creating Auth-Type = MS-CHAP # Creating Auth-Type = digest radiusd: #### Instantiating modules #### modules { # Loaded module rlm_replicate # Loading module "replicate" from file /etc/freeradius/mods-enabled/replicate # Loaded module rlm_exec # Loading module "echo" from file /etc/freeradius/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loaded module rlm_radutmp # Loading module "sradutmp" from file /etc/freeradius/mods-enabled/sradutmp radutmp sradutmp { filename = "/var/log/freeradius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_cache # Loading module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap cache cache_eap { driver = "rlm_cache_rbtree" key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" ttl = 15 max_entries = 0 epoch = 0 add_stats = no } # Loaded module rlm_detail # Loading module "detail" from file /etc/freeradius/mods-enabled/detail detail { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loaded module rlm_date # Loading module "date" from file /etc/freeradius/mods-enabled/date date { format = "%b %e %Y %H:%M:%S %Z" } # Loading module "radutmp" from file /etc/freeradius/mods-enabled/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 384 caller_id = yes } # Loaded module rlm_expr # Loading module "expr" from file /etc/freeradius/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" } # Loaded module rlm_realm # Loading module "IPASS" from file /etc/freeradius/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /etc/freeradius/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } # Loading module "realmpercent" from file /etc/freeradius/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /etc/freeradius/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\\" ignore_default = no ignore_null = no } # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/etc/freeradius/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/etc/freeradius/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/etc/freeradius/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/etc/freeradius/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/etc/freeradius/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Loaded module rlm_ldap # Loading module "ldap" from file /etc/freeradius/mods-enabled/ldap ldap { server = "192.168.109.192" identity = "cn=admin,dc=example,dc=com" password = <<< secret >>> sasl { } user { scope = "sub" access_positive = yes sasl { } } group { filter = "(objectClass=posixGroup)" scope = "sub" name_attribute = "cn" membership_attribute = "memberOf" membership_filter = "(|(member=%{control:Ldap-UserDn})(memberUid=%{%{Stripped-User-Name}:-%{User-Name}}))" cacheable_name = no cacheable_dn = no } client { filter = "(objectClass=radiusClient)" scope = "sub" base_dn = "dc=example,dc=com" } profile { } options { ldap_debug = 40 chase_referrals = yes rebind = yes net_timeout = 1 res_timeout = 10 srv_timelimit = 3 idle = 60 probes = 3 interval = 3 } tls { start_tls = no } } Creating attribute LDAP-Group # Loaded module rlm_eap # Loading module "eap" from file /etc/freeradius/mods-enabled/eap eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 16384 } # Loaded module rlm_soh # Loading module "soh" from file /etc/freeradius/mods-enabled/soh soh { dhcp = yes } # Loaded module rlm_passwd # Loading module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd passwd etc_passwd { filename = "/etc/passwd" format = "*User-Name:Crypt-Password:" delimiter = ":" ignore_nislike = no ignore_empty = yes allow_multiple_keys = no hash_size = 100 } # Loaded module rlm_chap # Loading module "chap" from file /etc/freeradius/mods-enabled/chap # Loaded module rlm_unix # Loading module "unix" from file /etc/freeradius/mods-enabled/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_preprocess # Loading module "preprocess" from file /etc/freeradius/mods-enabled/preprocess preprocess { huntgroups = "/etc/freeradius/mods-config/preprocess/huntgroups" hints = "/etc/freeradius/mods-config/preprocess/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 } # Loaded module rlm_always # Loading module "reject" from file /etc/freeradius/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /etc/freeradius/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /etc/freeradius/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /etc/freeradius/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /etc/freeradius/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /etc/freeradius/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /etc/freeradius/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /etc/freeradius/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /etc/freeradius/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_logintime # Loading module "logintime" from file /etc/freeradius/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loaded module rlm_digest # Loading module "digest" from file /etc/freeradius/mods-enabled/digest # Loaded module rlm_linelog # Loading module "linelog" from file /etc/freeradius/mods-enabled/linelog linelog { filename = "/var/log/freeradius/linelog" escape_filenames = no syslog_severity = "info" permissions = 384 format = "This is a log message for %{User-Name}" reference = "messages.%{%{reply:Packet-Type}:-default}" } # Loading module "log_accounting" from file /etc/freeradius/mods-enabled/linelog linelog log_accounting { filename = "/var/log/freeradius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_utf8 # Loading module "utf8" from file /etc/freeradius/mods-enabled/utf8 # Loading module "auth_log" from file /etc/freeradius/mods-enabled/detail.log detail auth_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "reply_log" from file /etc/freeradius/mods-enabled/detail.log detail reply_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log detail pre_proxy_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log detail post_proxy_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loaded module rlm_files # Loading module "files" from file /etc/freeradius/mods-enabled/files files { filename = "/etc/freeradius/mods-config/files/authorize" acctusersfile = "/etc/freeradius/mods-config/files/accounting" preproxy_usersfile = "/etc/freeradius/mods-config/files/pre-proxy" } # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /etc/freeradius/mods-enabled/dynamic_clients # Loaded module rlm_expiration # Loading module "expiration" from file /etc/freeradius/mods-enabled/expiration # Loaded module rlm_unpack # Loading module "unpack" from file /etc/freeradius/mods-enabled/unpack # Loaded module rlm_pap # Loading module "pap" from file /etc/freeradius/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_mschap # Loading module "mschap" from file /etc/freeradius/mods-enabled/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes passchange { } allow_retry = yes } # Loading module "exec" from file /etc/freeradius/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loading module "ntlm_auth" from file /etc/freeradius/mods-enabled/ntlm_auth exec ntlm_auth { wait = yes program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" shell_escape = yes } instantiate { } # Instantiating module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked # Instantiating module "detail" from file /etc/freeradius/mods-enabled/detail # Instantiating module "IPASS" from file /etc/freeradius/mods-enabled/realm # Instantiating module "suffix" from file /etc/freeradius/mods-enabled/realm # Instantiating module "realmpercent" from file /etc/freeradius/mods-enabled/realm # Instantiating module "ntdomain" from file /etc/freeradius/mods-enabled/realm # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/access_reject [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/accounting_response # Instantiating module "ldap" from file /etc/freeradius/mods-enabled/ldap rlm_ldap: libldap vendor: OpenLDAP, version: 20442 accounting { reference = "%{tolower:type.%{Acct-Status-Type}}" } post-auth { reference = "." } rlm_ldap (ldap): Initialising connection pool pool { start = 5 min = 3 max = 32 spare = 10 uses = 0 lifetime = 0 cleanup_interval = 30 idle_timeout = 60 retry_delay = 30 spread = no } rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (1), 1 of 31 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (2), 1 of 30 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (3), 1 of 29 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (4), 1 of 28 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful # Instantiating module "eap" from file /etc/freeradius/mods-enabled/eap # Linked to sub-module rlm_eap_md5 # Linked to sub-module rlm_eap_leap # Linked to sub-module rlm_eap_gtc gtc { challenge = "Password: " auth_type = "PAP" } # Linked to sub-module rlm_eap_tls tls { tls = "tls-common" } tls-config tls-common { verify_depth = 0 ca_path = "/etc/freeradius/certs" pem_file_type = yes private_key_file = "/etc/freeradius/certs/server.pem" certificate_file = "/etc/freeradius/certs/server.pem" ca_file = "/etc/freeradius/certs/ca.pem" private_key_password = <<< secret >>> dh_file = "/etc/freeradius/certs/dh" fragment_size = 1024 include_length = yes auto_chain = yes check_crl = no check_all_crl = no cipher_list = "DEFAULT" cipher_server_preference = no ecdh_curve = "prime256v1" cache { enable = yes lifetime = 24 max_entries = 255 } verify { skip_if_ocsp_ok = no } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = no } } # Linked to sub-module rlm_eap_ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = yes virtual_server = "inner-tunnel" include_length = yes require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_peap peap { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = yes proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_mschapv2 mschapv2 { with_ntdomain_hack = no send_error = no } # Instantiating module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no # Instantiating module "preprocess" from file /etc/freeradius/mods-enabled/preprocess reading pairlist file /etc/freeradius/mods-config/preprocess/huntgroups reading pairlist file /etc/freeradius/mods-config/preprocess/hints # Instantiating module "reject" from file /etc/freeradius/mods-enabled/always # Instantiating module "fail" from file /etc/freeradius/mods-enabled/always # Instantiating module "ok" from file /etc/freeradius/mods-enabled/always # Instantiating module "handled" from file /etc/freeradius/mods-enabled/always # Instantiating module "invalid" from file /etc/freeradius/mods-enabled/always # Instantiating module "userlock" from file /etc/freeradius/mods-enabled/always # Instantiating module "notfound" from file /etc/freeradius/mods-enabled/always # Instantiating module "noop" from file /etc/freeradius/mods-enabled/always # Instantiating module "updated" from file /etc/freeradius/mods-enabled/always # Instantiating module "logintime" from file /etc/freeradius/mods-enabled/logintime # Instantiating module "linelog" from file /etc/freeradius/mods-enabled/linelog # Instantiating module "log_accounting" from file /etc/freeradius/mods-enabled/linelog # Instantiating module "auth_log" from file /etc/freeradius/mods-enabled/detail.log rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output # Instantiating module "reply_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "files" from file /etc/freeradius/mods-enabled/files reading pairlist file /etc/freeradius/mods-config/files/authorize reading pairlist file /etc/freeradius/mods-config/files/accounting reading pairlist file /etc/freeradius/mods-config/files/pre-proxy # Instantiating module "expiration" from file /etc/freeradius/mods-enabled/expiration # Instantiating module "pap" from file /etc/freeradius/mods-enabled/pap # Instantiating module "mschap" from file /etc/freeradius/mods-enabled/mschap rlm_mschap (mschap): using internal authentication } # modules radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/radiusd.conf } # server server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel # Loading authenticate {...} # Loading authorize {...} # Loading session {...} # Loading post-proxy {...} # Loading post-auth {...} # Skipping contents of 'if' as it is always 'false' -- /etc/freeradius/sites-enabled/inner-tunnel:378 } # server inner-tunnel server default { # from file /etc/freeradius/sites-enabled/default # Loading authenticate {...} # Loading authorize {...} # Loading preacct {...} # Loading accounting {...} Ignoring "sql" (see raddb/mods-available/README.rst) # Loading post-proxy {...} # Loading post-auth {...} } # server default radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } listen { type = "auth" ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipv6addr = :: port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipv6addr = :: port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on proxy address * port 36053 Listening on proxy address :: port 48334 Ready to process requests (0) Received Access-Request Id 137 from 192.168.109.194:49205 to 192.168.109.32:1812 length 131 (0) NAS-IP-Address = 192.168.109.194 (0) NAS-Port-Type = Ethernet (0) NAS-Port = 63 (0) User-Name = "ssipwifi1" (0) Acct-Session-Id = "0500170C" (0) Called-Station-Id = "00-87-31-4B-4A-D9" (0) Calling-Station-Id = "00-15-65-AF-D2-23" (0) EAP-Message = 0x02e1000e01737369707769666931 (0) Message-Authenticator = 0x868bbf71d03afb0dba448373c27b32af (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /(a)\./) { (0) if (&User-Name =~ /(a)\./) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (0) suffix: No such realm "NULL" (0) [suffix] = noop (0) eap: Peer sent EAP Response (code 2) ID 225 length 14 (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) } # authorize = ok (0) Found Auth-Type = eap (0) # Executing group from file /etc/freeradius/sites-enabled/default (0) authenticate { (0) eap: Peer sent packet with method EAP Identity (1) (0) eap: Calling submodule eap_peap to process data (0) eap_peap: Initiating new EAP-TLS session (0) eap_peap: Flushing SSL sessions (of #0) (0) eap_peap: [eaptls start] = request (0) eap: Sending EAP Request (code 1) ID 226 length 6 (0) eap: EAP session adding &reply:State = 0xaee2953fae008c08 (0) [eap] = handled (0) } # authenticate = handled (0) Using Post-Auth-Type Challenge (0) Post-Auth-Type sub-section not found. Ignoring. (0) # Executing group from file /etc/freeradius/sites-enabled/default (0) Sent Access-Challenge Id 137 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (0) EAP-Message = 0x01e200061920 (0) Message-Authenticator = 0x00000000000000000000000000000000 (0) State = 0xaee2953fae008c082f6a02169119b8d9 (0) Finished request Waking up in 4.9 seconds. (1) Received Access-Request Id 138 from 192.168.109.194:49205 to 192.168.109.32:1812 length 141 (1) NAS-IP-Address = 192.168.109.194 (1) NAS-Port-Type = Ethernet (1) NAS-Port = 63 (1) User-Name = "ssipwifi1" (1) Acct-Session-Id = "0500170C" (1) State = 0xaee2953fae008c082f6a02169119b8d9 (1) Called-Station-Id = "00-87-31-4B-4A-D9" (1) Calling-Station-Id = "00-15-65-AF-D2-23" (1) EAP-Message = 0x02e200060315 (1) Message-Authenticator = 0x2a5a61031a6bdcf65fc002f6d966d822 (1) session-state: No cached attributes (1) # Executing section authorize from file /etc/freeradius/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] = noop (1) [digest] = noop (1) suffix: Checking for suffix after "@" (1) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (1) suffix: No such realm "NULL" (1) [suffix] = noop (1) eap: Peer sent EAP Response (code 2) ID 226 length 6 (1) eap: No EAP Start, assuming it's an on-going EAP conversation (1) [eap] = updated (1) [files] = noop rlm_ldap (ldap): Reserved connection (0) (1) ldap: EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}}) (1) ldap: --> (uid=ssipwifi1) (1) ldap: Performing search in "ou=Users,dc=example,dc=com" with filter "(uid=ssipwifi1)", scope "sub" (1) ldap: Waiting for search result... (1) ldap: User object found at DN "cn=SIP-WIFI-1 SIP-WIFI-1,ou=Users,dc=example,dc=com" (1) ldap: Processing user attributes (1) ldap: control:Password-With-Header += '{SSHA}w/lNsXIXXXXXXXXXXXXX0h1eaRhMGVt' (1) ldap: control:NT-Password += 0x433233423237334534XXXXXXXXXXXXXXXXXXXXXXXXX37453735423031304341 (1) ldap: control:Ldap-PrimaryGroupId += 10004 rlm_ldap (ldap): Released connection (0) Need 5 more connections to reach 10 spares rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots used rlm_ldap (ldap): Connecting to ldap://192.168.109.192:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful (1) [ldap] = updated (1) [expiration] = noop (1) [logintime] = noop (1) pap: Converted: &control:Password-With-Header -> &control:SSHA1-Password (1) pap: Removing &control:Password-With-Header (1) pap: Normalizing NT-Password from hex encoding, 32 bytes -> 16 bytes (1) pap: Normalizing SSHA1-Password from base64 encoding, 32 bytes -> 24 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/sites-enabled/default (1) authenticate { (1) eap: Expiring EAP session with state 0xaee2953fae008c08 (1) eap: Finished EAP session with state 0xaee2953fae008c08 (1) eap: Previous EAP request found for state 0xaee2953fae008c08, released from the list (1) eap: Peer sent packet with method EAP NAK (3) (1) eap: Found mutually acceptable type TTLS (21) (1) eap: Calling submodule eap_ttls to process data (1) eap_ttls: Initiating new EAP-TLS session (1) eap_ttls: [eaptls start] = request (1) eap: Sending EAP Request (code 1) ID 227 length 6 (1) eap: EAP session adding &reply:State = 0xaee2953faf018008 (1) [eap] = handled (1) } # authenticate = handled (1) Using Post-Auth-Type Challenge (1) Post-Auth-Type sub-section not found. Ignoring. (1) # Executing group from file /etc/freeradius/sites-enabled/default (1) Sent Access-Challenge Id 138 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (1) EAP-Message = 0x01e300061520 (1) Message-Authenticator = 0x00000000000000000000000000000000 (1) State = 0xaee2953faf0180082f6a02169119b8d9 (1) Finished request Waking up in 4.9 seconds. (2) Received Access-Request Id 139 from 192.168.109.194:49205 to 192.168.109.32:1812 length 239 (2) NAS-IP-Address = 192.168.109.194 (2) NAS-Port-Type = Ethernet (2) NAS-Port = 63 (2) User-Name = "ssipwifi1" (2) Acct-Session-Id = "0500170C" (2) State = 0xaee2953faf0180082f6a02169119b8d9 (2) Called-Station-Id = "00-87-31-4B-4A-D9" (2) Calling-Station-Id = "00-15-65-AF-D2-23" (2) EAP-Message = 0x02e300681500160301005d01000059030158548b761ec832a5d5f5d9a42c19c9c2ee80bf9acf4cd0773b032b009eb413d600003200390038003500160013000a00330032002f00070066000500040063006200150012000900650064006000140011000800030100 (2) Message-Authenticator = 0xc2e44bd0275ac4c299fb30237c2ed6e8 (2) session-state: No cached attributes (2) # Executing section authorize from file /etc/freeradius/sites-enabled/default (2) authorize { (2) policy filter_username { (2) if (&User-Name) { (2) if (&User-Name) -> TRUE (2) if (&User-Name) { (2) if (&User-Name =~ / /) { (2) if (&User-Name =~ / /) -> FALSE (2) if (&User-Name =~ /@[^@]*@/ ) { (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (2) if (&User-Name =~ /\.\./ ) { (2) if (&User-Name =~ /\.\./ ) -> FALSE (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (2) if (&User-Name =~ /\.$/) { (2) if (&User-Name =~ /\.$/) -> FALSE (2) if (&User-Name =~ /(a)\./) { (2) if (&User-Name =~ /(a)\./) -> FALSE (2) } # if (&User-Name) = notfound (2) } # policy filter_username = notfound (2) [preprocess] = ok (2) [chap] = noop (2) [mschap] = noop (2) [digest] = noop (2) suffix: Checking for suffix after "@" (2) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (2) suffix: No such realm "NULL" (2) [suffix] = noop (2) eap: Peer sent EAP Response (code 2) ID 227 length 104 (2) eap: Continuing tunnel setup (2) [eap] = ok (2) } # authorize = ok (2) Found Auth-Type = eap (2) # Executing group from file /etc/freeradius/sites-enabled/default (2) authenticate { (2) eap: Expiring EAP session with state 0xaee2953faf018008 (2) eap: Finished EAP session with state 0xaee2953faf018008 (2) eap: Previous EAP request found for state 0xaee2953faf018008, released from the list (2) eap: Peer sent packet with method EAP TTLS (21) (2) eap: Calling submodule eap_ttls to process data (2) eap_ttls: Authenticate (2) eap_ttls: Continuing EAP-TLS (2) eap_ttls: [eaptls verify] = ok (2) eap_ttls: Done initial handshake (2) eap_ttls: (other): before/accept initialization (2) eap_ttls: TLS_accept: before/accept initialization (2) eap_ttls: <<< recv TLS 1.0 Handshake [length 005d], ClientHello (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: >>> send TLS 1.0 Handshake [length 004a], ServerHello (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: >>> send TLS 1.0 Handshake [length 08a7], Certificate (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: >>> send TLS 1.0 Handshake [length 030d], ServerKeyExchange (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: >>> send TLS 1.0 Handshake [length 0004], ServerHelloDone (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: TLS_accept: unknown state (2) eap_ttls: TLS_accept: Need to read more data: unknown state (2) eap_ttls: TLS_accept: Need to read more data: unknown state (2) eap_ttls: In SSL Handshake Phase (2) eap_ttls: In SSL Accept mode (2) eap_ttls: [eaptls process] = handled (2) eap: Sending EAP Request (code 1) ID 228 length 1004 (2) eap: EAP session adding &reply:State = 0xaee2953fac068008 (2) [eap] = handled (2) } # authenticate = handled (2) Using Post-Auth-Type Challenge (2) Post-Auth-Type sub-section not found. Ignoring. (2) # Executing group from file /etc/freeradius/sites-enabled/default (2) Sent Access-Challenge Id 139 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (2) EAP-Message = 0x01e403ec15c000000c16160301004a020000460301d556064763720c86a98591833e5f928ea804b46ead813e9697735ec86f9cf959202571a53d735077767e0b8daa97ff14d760789e4526a13b6f6c81b909e8ddc9bd00390016030108a70b0008a30008a00003cd308203c9308202b1a0030201020201 (2) Message-Authenticator = 0x00000000000000000000000000000000 (2) State = 0xaee2953fac0680082f6a02169119b8d9 (2) Finished request Waking up in 4.9 seconds. (3) Received Access-Request Id 140 from 192.168.109.194:49205 to 192.168.109.32:1812 length 141 (3) NAS-IP-Address = 192.168.109.194 (3) NAS-Port-Type = Ethernet (3) NAS-Port = 63 (3) User-Name = "ssipwifi1" (3) Acct-Session-Id = "0500170C" (3) State = 0xaee2953fac0680082f6a02169119b8d9 (3) Called-Station-Id = "00-87-31-4B-4A-D9" (3) Calling-Station-Id = "00-15-65-AF-D2-23" (3) EAP-Message = 0x02e400061500 (3) Message-Authenticator = 0x37f29c0a8107b349eddea0d46e2893d1 (3) session-state: No cached attributes (3) # Executing section authorize from file /etc/freeradius/sites-enabled/default (3) authorize { (3) policy filter_username { (3) if (&User-Name) { (3) if (&User-Name) -> TRUE (3) if (&User-Name) { (3) if (&User-Name =~ / /) { (3) if (&User-Name =~ / /) -> FALSE (3) if (&User-Name =~ /@[^@]*@/ ) { (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (3) if (&User-Name =~ /\.\./ ) { (3) if (&User-Name =~ /\.\./ ) -> FALSE (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (3) if (&User-Name =~ /\.$/) { (3) if (&User-Name =~ /\.$/) -> FALSE (3) if (&User-Name =~ /(a)\./) { (3) if (&User-Name =~ /(a)\./) -> FALSE (3) } # if (&User-Name) = notfound (3) } # policy filter_username = notfound (3) [preprocess] = ok (3) [chap] = noop (3) [mschap] = noop (3) [digest] = noop (3) suffix: Checking for suffix after "@" (3) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (3) suffix: No such realm "NULL" (3) [suffix] = noop (3) eap: Peer sent EAP Response (code 2) ID 228 length 6 (3) eap: Continuing tunnel setup (3) [eap] = ok (3) } # authorize = ok (3) Found Auth-Type = eap (3) # Executing group from file /etc/freeradius/sites-enabled/default (3) authenticate { (3) eap: Expiring EAP session with state 0xaee2953fac068008 (3) eap: Finished EAP session with state 0xaee2953fac068008 (3) eap: Previous EAP request found for state 0xaee2953fac068008, released from the list (3) eap: Peer sent packet with method EAP TTLS (21) (3) eap: Calling submodule eap_ttls to process data (3) eap_ttls: Authenticate (3) eap_ttls: Continuing EAP-TLS (3) eap_ttls: Peer ACKed our handshake fragment (3) eap_ttls: [eaptls verify] = request (3) eap_ttls: [eaptls process] = handled (3) eap: Sending EAP Request (code 1) ID 229 length 1004 (3) eap: EAP session adding &reply:State = 0xaee2953fad078008 (3) [eap] = handled (3) } # authenticate = handled (3) Using Post-Auth-Type Challenge (3) Post-Auth-Type sub-section not found. Ignoring. (3) # Executing group from file /etc/freeradius/sites-enabled/default (3) Sent Access-Challenge Id 140 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (3) EAP-Message = 0x01e503ec15c000000c16eaa7da144e42143e058d4c5294b556c131f792cac9cd6e7a30df9358fa6182906aa8cea1ef7e0c71329922ae6dacb5c1dd0c30aa1a1021f94ac6d92fb0be9027d4364cdef7887b1e140004cd308204c9308203b1a0030201020209008c96fc367ca63be9300d06092a864886f7 (3) Message-Authenticator = 0x00000000000000000000000000000000 (3) State = 0xaee2953fad0780082f6a02169119b8d9 (3) Finished request Waking up in 4.9 seconds. (4) Received Access-Request Id 141 from 192.168.109.194:49205 to 192.168.109.32:1812 length 141 (4) NAS-IP-Address = 192.168.109.194 (4) NAS-Port-Type = Ethernet (4) NAS-Port = 63 (4) User-Name = "ssipwifi1" (4) Acct-Session-Id = "0500170C" (4) State = 0xaee2953fad0780082f6a02169119b8d9 (4) Called-Station-Id = "00-87-31-4B-4A-D9" (4) Calling-Station-Id = "00-15-65-AF-D2-23" (4) EAP-Message = 0x02e500061500 (4) Message-Authenticator = 0xef7e59b53b2f254ecb41f48138094c29 (4) session-state: No cached attributes (4) # Executing section authorize from file /etc/freeradius/sites-enabled/default (4) authorize { (4) policy filter_username { (4) if (&User-Name) { (4) if (&User-Name) -> TRUE (4) if (&User-Name) { (4) if (&User-Name =~ / /) { (4) if (&User-Name =~ / /) -> FALSE (4) if (&User-Name =~ /@[^@]*@/ ) { (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (4) if (&User-Name =~ /\.\./ ) { (4) if (&User-Name =~ /\.\./ ) -> FALSE (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (4) if (&User-Name =~ /\.$/) { (4) if (&User-Name =~ /\.$/) -> FALSE (4) if (&User-Name =~ /(a)\./) { (4) if (&User-Name =~ /(a)\./) -> FALSE (4) } # if (&User-Name) = notfound (4) } # policy filter_username = notfound (4) [preprocess] = ok (4) [chap] = noop (4) [mschap] = noop (4) [digest] = noop (4) suffix: Checking for suffix after "@" (4) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (4) suffix: No such realm "NULL" (4) [suffix] = noop (4) eap: Peer sent EAP Response (code 2) ID 229 length 6 (4) eap: Continuing tunnel setup (4) [eap] = ok (4) } # authorize = ok (4) Found Auth-Type = eap (4) # Executing group from file /etc/freeradius/sites-enabled/default (4) authenticate { (4) eap: Expiring EAP session with state 0xaee2953fad078008 (4) eap: Finished EAP session with state 0xaee2953fad078008 (4) eap: Previous EAP request found for state 0xaee2953fad078008, released from the list (4) eap: Peer sent packet with method EAP TTLS (21) (4) eap: Calling submodule eap_ttls to process data (4) eap_ttls: Authenticate (4) eap_ttls: Continuing EAP-TLS (4) eap_ttls: Peer ACKed our handshake fragment (4) eap_ttls: [eaptls verify] = request (4) eap_ttls: [eaptls process] = handled (4) eap: Sending EAP Request (code 1) ID 230 length 1004 (4) eap: EAP session adding &reply:State = 0xaee2953faa048008 (4) [eap] = handled (4) } # authenticate = handled (4) Using Post-Auth-Type Challenge (4) Post-Auth-Type sub-section not found. Ignoring. (4) # Executing group from file /etc/freeradius/sites-enabled/default (4) Sent Access-Challenge Id 141 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (4) EAP-Message = 0x01e603ec15c000000c1622687474703a2f2f7777772e736165616d7374657264616d2e636f6d2f63612e63726c300d06092a864886f70d01010b05000382010100dbe3cc84a7372bcbfb9704deb26aeeafa8d549ac5fff21be2705b1e145bcf7d7665b5b27b6cbc2c730f168805fca2b32356bac539c62 (4) Message-Authenticator = 0x00000000000000000000000000000000 (4) State = 0xaee2953faa0480082f6a02169119b8d9 (4) Finished request Waking up in 4.9 seconds. (5) Received Access-Request Id 142 from 192.168.109.194:49205 to 192.168.109.32:1812 length 141 (5) NAS-IP-Address = 192.168.109.194 (5) NAS-Port-Type = Ethernet (5) NAS-Port = 63 (5) User-Name = "ssipwifi1" (5) Acct-Session-Id = "0500170C" (5) State = 0xaee2953faa0480082f6a02169119b8d9 (5) Called-Station-Id = "00-87-31-4B-4A-D9" (5) Calling-Station-Id = "00-15-65-AF-D2-23" (5) EAP-Message = 0x02e600061500 (5) Message-Authenticator = 0x5306556bb8fce31af804aad6b7bd0786 (5) session-state: No cached attributes (5) # Executing section authorize from file /etc/freeradius/sites-enabled/default (5) authorize { (5) policy filter_username { (5) if (&User-Name) { (5) if (&User-Name) -> TRUE (5) if (&User-Name) { (5) if (&User-Name =~ / /) { (5) if (&User-Name =~ / /) -> FALSE (5) if (&User-Name =~ /@[^@]*@/ ) { (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (5) if (&User-Name =~ /\.\./ ) { (5) if (&User-Name =~ /\.\./ ) -> FALSE (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (5) if (&User-Name =~ /\.$/) { (5) if (&User-Name =~ /\.$/) -> FALSE (5) if (&User-Name =~ /(a)\./) { (5) if (&User-Name =~ /(a)\./) -> FALSE (5) } # if (&User-Name) = notfound (5) } # policy filter_username = notfound (5) [preprocess] = ok (5) [chap] = noop (5) [mschap] = noop (5) [digest] = noop (5) suffix: Checking for suffix after "@" (5) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (5) suffix: No such realm "NULL" (5) [suffix] = noop (5) eap: Peer sent EAP Response (code 2) ID 230 length 6 (5) eap: Continuing tunnel setup (5) [eap] = ok (5) } # authorize = ok (5) Found Auth-Type = eap (5) # Executing group from file /etc/freeradius/sites-enabled/default (5) authenticate { (5) eap: Expiring EAP session with state 0xaee2953faa048008 (5) eap: Finished EAP session with state 0xaee2953faa048008 (5) eap: Previous EAP request found for state 0xaee2953faa048008, released from the list (5) eap: Peer sent packet with method EAP TTLS (21) (5) eap: Calling submodule eap_ttls to process data (5) eap_ttls: Authenticate (5) eap_ttls: Continuing EAP-TLS (5) eap_ttls: Peer ACKed our handshake fragment (5) eap_ttls: [eaptls verify] = request (5) eap_ttls: [eaptls process] = handled (5) eap: Sending EAP Request (code 1) ID 231 length 122 (5) eap: EAP session adding &reply:State = 0xaee2953fab058008 (5) [eap] = handled (5) } # authenticate = handled (5) Using Post-Auth-Type Challenge (5) Post-Auth-Type sub-section not found. Ignoring. (5) # Executing group from file /etc/freeradius/sites-enabled/default (5) Sent Access-Challenge Id 142 from 192.168.109.32:1812 to 192.168.109.194:49205 length 0 (5) EAP-Message = 0x01e7007a158000000c16911d3bd3d36043b4edaa42d5a2159ffa79bc8af054a7e80d6685c936cc9756b1df3815dec7d729b9de88d88ef67f6e22ff4187231709cd5f04aadea96e4e5e813da5406eb28d25e5870cadf0656854fdf1f5a813d3da07bbf1e21860d6399a01cc20538e92eff516030100040e (5) Message-Authenticator = 0x00000000000000000000000000000000 (5) State = 0xaee2953fab0580082f6a02169119b8d9 (5) Finished request Waking up in 4.9 seconds. (6) Received Access-Request Id 143 from 192.168.109.194:49205 to 192.168.109.32:1812 length 148 (6) NAS-IP-Address = 192.168.109.194 (6) NAS-Port-Type = Ethernet (6) NAS-Port = 63 (6) User-Name = "ssipwifi1" (6) Acct-Session-Id = "0500170C" (6) State = 0xaee2953fab0580082f6a02169119b8d9 (6) Called-Station-Id = "00-87-31-4B-4A-D9" (6) Calling-Station-Id = "00-15-65-AF-D2-23" (6) EAP-Message = 0x02e7000d150015030100020233 (6) Message-Authenticator = 0x81205696b3a6fcc2330bcaa65d6a7c27 (6) session-state: No cached attributes (6) # Executing section authorize from file /etc/freeradius/sites-enabled/default (6) authorize { (6) policy filter_username { (6) if (&User-Name) { (6) if (&User-Name) -> TRUE (6) if (&User-Name) { (6) if (&User-Name =~ / /) { (6) if (&User-Name =~ / /) -> FALSE (6) if (&User-Name =~ /@[^@]*@/ ) { (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (6) if (&User-Name =~ /\.\./ ) { (6) if (&User-Name =~ /\.\./ ) -> FALSE (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (6) if (&User-Name =~ /\.$/) { (6) if (&User-Name =~ /\.$/) -> FALSE (6) if (&User-Name =~ /(a)\./) { (6) if (&User-Name =~ /(a)\./) -> FALSE (6) } # if (&User-Name) = notfound (6) } # policy filter_username = notfound (6) [preprocess] = ok (6) [chap] = noop (6) [mschap] = noop (6) [digest] = noop (6) suffix: Checking for suffix after "@" (6) suffix: No '@' in User-Name = "ssipwifi1", looking up realm NULL (6) suffix: No such realm "NULL" (6) [suffix] = noop (6) eap: Peer sent EAP Response (code 2) ID 231 length 13 (6) eap: Continuing tunnel setup (6) [eap] = ok (6) } # authorize = ok (6) Found Auth-Type = eap (6) # Executing group from file /etc/freeradius/sites-enabled/default (6) authenticate { (6) eap: Expiring EAP session with state 0xaee2953fab058008 (6) eap: Finished EAP session with state 0xaee2953fab058008 (6) eap: Previous EAP request found for state 0xaee2953fab058008, released from the list (6) eap: Peer sent packet with method EAP TTLS (21) (6) eap: Calling submodule eap_ttls to process data (6) eap_ttls: Authenticate (6) eap_ttls: Continuing EAP-TLS (6) eap_ttls: [eaptls verify] = ok (6) eap_ttls: Done initial handshake (6) eap_ttls: <<< recv TLS 1.0 Alert [length 0002], fatal decrypt_error (6) eap_ttls: ERROR: TLS Alert read:fatal:decrypt error (6) eap_ttls: ERROR: TLS_accept: Failed in unknown state (6) eap_ttls: ERROR: Failed in __FUNCTION__ (SSL_read) (6) eap_ttls: ERROR: error:1409441B:SSL routines:ssl3_read_bytes:tlsv1 alert decrypt error (6) eap_ttls: ERROR: error:140940E5:SSL routines:ssl3_read_bytes:ssl handshake failure (6) eap_ttls: ERROR: System call (I/O) error (-1) (6) eap_ttls: ERROR: TLS receive handshake failed during operation (6) eap_ttls: ERROR: [eaptls process] = fail (6) eap: ERROR: Failed continuing EAP TTLS (21) session. EAP sub-module failed (6) eap: Sending EAP Failure (code 4) ID 231 length 4 (6) eap: Failed in EAP select (6) [eap] = invalid (6) } # authenticate = invalid (6) Failed to authenticate the user (6) Using Post-Auth-Type Reject (6) # Executing group from file /etc/freeradius/sites-enabled/default (6) Post-Auth-Type REJECT { (6) attr_filter.access_reject: EXPAND %{User-Name} (6) attr_filter.access_reject: --> ssipwifi1 (6) attr_filter.access_reject: Matched entry DEFAULT at line 11 (6) [attr_filter.access_reject] = updated (6) [eap] = noop (6) policy remove_reply_message_if_eap { (6) if (&reply:EAP-Message && &reply:Reply-Message) { (6) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (6) else { (6) [noop] = noop (6) } # else = noop (6) } # policy remove_reply_message_if_eap = noop (6) } # Post-Auth-Type REJECT = updated (6) Delaying response for 1.000000 seconds Waking up in 0.3 seconds. Waking up in 0.6 seconds. (6) Sending delayed response (6) Sent Access-Reject Id 143 from 192.168.109.32:1812 to 192.168.109.194:49205 length 44 (6) EAP-Message = 0x04e70004 (6) Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.8 seconds. (0) Cleaning up request packet ID 137 with timestamp +36 (1) Cleaning up request packet ID 138 with timestamp +36 (2) Cleaning up request packet ID 139 with timestamp +36 (3) Cleaning up request packet ID 140 with timestamp +36 (4) Cleaning up request packet ID 141 with timestamp +36 (5) Cleaning up request packet ID 142 with timestamp +36 (6) Cleaning up request packet ID 143 with timestamp +36 Ready to process requests

2 1

Re: Freeradius 3.0.12 - Cisco EAP-Fast Supported?
by Kevin Morrison 16 Dec '16

16 Dec '16

Hi Alan, Thank you for your assistance with this! I worked with my network engineer today and we were able to confirm that PEAP works to authenticate, but when changed over to EAP-FAST, it fails as before. I have a debug log of PEAP working and then EAP-FAST failing, however, it is pretty dang large at over 4k lines in Notepad++. I am attaching the text file, with some information changed to protect internal names, MAC addresses, etc. I am extremely grateful for whatever help you can render me. Warmest regards, Kevin Morrison Systems Administrator T: +1 (704) 378-9235 C: +1 (980) 255-9668 kmorrison(a)vectorusa.com VectorUSA 2520 Whitehall Park Drive, Suite 300 Charlotte, NC 28273 Customer Service: +1 (877) 569-8800 -----Original Message----- Date: Wed, 14 Dec 2016 16:21:15 -0500 From: Alan DeKok <aland(a)deployingradius.com> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: Freeradius 3.0.12 - Cisco EAP-Fast Supported? Message-ID: <04774D10-8DB6-409F-9589-8FC7DFAE5A55(a)deployingradius.com> Content-Type: text/plain; charset=us-ascii > On Dec 14, 2016, at 3:54 PM, Kevin Morrison <kmorrison(a)vectorusa.com> wrote: > > Greetings folks, > > This is my first time posting to this mailing list, I am hoping you can answer a question/help me out. Does the newest Freeradius version 3.0.12 support the CISCO version of EAP-FAST? It's been tested against other EAP-FAST implementations. > I have been trying to get the newly created EAP FAST module to work with a Cisco WLC and Cisco device to authenticate via EAP-Fast, but I keep getting the error message about: > > (37) mschap: Client is using MS-CHAPv2 > (37) mschap: ERROR: MS-CHAP2-Response is incorrect The full debug may be more useful. > I am running on CentOS 7, as well. > > If the answer is Yes to supporting Cisco EAP FAST, then I can definitely provide the full output of radiusd -X for assistance. If the same password works for PEAP (try it), it should also work for EAP-FAST. Alan DeKok. ------------------------------ Subject: Digest Footer - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html ------------------------------ End of Freeradius-Users Digest, Vol 140, Issue 23 *************************************************

2 5

EAP-PEAP-GTC issue
by Arjan Sinnige 15 Dec '16

15 Dec '16

Hi guys, Last week I got 20 new phones (3 models) and I got 18 of them working but 2 of them are a model which can only do EAP-MD5, EAP-PEAP-GTC and EAP-TTLS-EAP-GTC. (Yealink W52P) My system is 2.2.10 from git (love to upgrade to 3.0 but that will have to wait. Will happen in first half 2017 though.. The other phones connect up with EAP-PEAP-MSCHAPv2 which works without a hitch. So I assume my uploaded CA certificates are ok. I have +/- 300 students connecting with Windows/OSX/Linux/Android/ipads/iphones and Windows Phone without an issue. But GTC is new for me.. Is there working support for GTC in 2.2.10 (build from git last march)?? When looking at the logs I notice these things : - it never gets to the inner-tunnel - TTLS does not seem to finish. [ttls] TLS_accept: unknown state [ttls] TLS_accept: unknown state [ttls] TLS_accept: unknown state [ttls] TLS_accept: Need to read more data: unknown state [ttls] TLS_accept: Need to read more data: unknown state - I get a fatal error. (My only guess to this is that my switch could be stopping after a number of retries(cannot disable this), or my phones are broken.) [ttls] <<< TLS 1.0 Alert [length 0002], fatal decrypt_error TLS Alert read:fatal:decrypt error TLS_accept: failed in unknown state rlm_eap: SSL error error:1409441B:SSL routines:ssl3_read_bytes:tlsv1 alert decrypt error SSL: SSL_read failed inside of TLS (-1), TLS session fails. Any hints for me ?? Arjan Sinnige Full Debug : root@studentserv:/home/sinnige# freeradius -X freeradius: FreeRADIUS Version 2.2.10, for host x86_64-pc-linux-gnu, built on Mar 20 2016 at 19:51:40 Copyright (C) 1999-2015 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/radiusd.conf including configuration file /etc/freeradius/proxy.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/modules/ including configuration file /etc/freeradius/modules/files including configuration file /etc/freeradius/modules/checkval including configuration file /etc/freeradius/modules/mschap including configuration file /etc/freeradius/modules/dhcp_sqlippool including configuration file /etc/freeradius/modules/rediswho including configuration file /etc/freeradius/modules/cui including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login including configuration file /etc/freeradius/modules/detail.example.com including configuration file /etc/freeradius/modules/otp including configuration file /etc/freeradius/modules/linelog including configuration file /etc/freeradius/modules/pap including configuration file /etc/freeradius/modules/passwd including configuration file /etc/freeradius/modules/ippool including configuration file /etc/freeradius/modules/etc_group including configuration file /etc/freeradius/modules/digest including configuration file /etc/freeradius/modules/krb5 including configuration file /etc/freeradius/modules/radutmp including configuration file /etc/freeradius/modules/smsotp including configuration file /etc/freeradius/modules/replicate including configuration file /etc/freeradius/modules/detail.log including configuration file /etc/freeradius/modules/inner-eap including configuration file /etc/freeradius/modules/redis including configuration file /etc/freeradius/modules/ntlm_auth including configuration file /etc/freeradius/modules/logintime including configuration file /etc/freeradius/modules/detail including configuration file /etc/freeradius/modules/echo including configuration file /etc/freeradius/modules/chap including configuration file /etc/freeradius/modules/soh including configuration file /etc/freeradius/modules/expr including configuration file /etc/freeradius/modules/perl including configuration file /etc/freeradius/modules/smbpasswd including configuration file /etc/freeradius/modules/attr_filter including configuration file /etc/freeradius/modules/pam including configuration file /etc/freeradius/modules/opendirectory including configuration file /etc/freeradius/modules/attr_rewrite including configuration file /etc/freeradius/modules/policy including configuration file /etc/freeradius/modules/ldap including configuration file /etc/freeradius/modules/mac2ip including configuration file /etc/freeradius/modules/wimax including configuration file /etc/freeradius/modules/acct_unique including configuration file /etc/freeradius/modules/dynamic_clients including configuration file /etc/freeradius/modules/unix including configuration file /etc/freeradius/modules/counter including configuration file /etc/freeradius/modules/realm including configuration file /etc/freeradius/modules/preprocess including configuration file /etc/freeradius/modules/radrelay including configuration file /etc/freeradius/modules/sradutmp including configuration file /etc/freeradius/modules/sql_log including configuration file /etc/freeradius/modules/exec including configuration file /etc/freeradius/modules/expiration including configuration file /etc/freeradius/modules/cache including configuration file /etc/freeradius/modules/mac2vlan including configuration file /etc/freeradius/modules/always including configuration file /etc/freeradius/eap.conf including configuration file /etc/freeradius/policy.conf including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/inner-tunnel including configuration file /etc/freeradius/sites-enabled/default main { user = "root" group = "root" allow_core_dumps = no } including dictionary file /etc/freeradius/dictionary main { name = "freeradius" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 51200 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = yes auth_badpass = no auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes allow_vulnerable_openssl = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = "testing123" response_window = 20 max_outstanding = 65536 require_message_authenticator = yes zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 num_answers_to_alive = 3 num_pings_to_alive = 3 revive_interval = 120 status_check_timeout = 4 coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client 192.168.109.190 { require_message_authenticator = no secret = "MYPASSWORD" shortname = "SwitchStack" nastype = "cisco" } client 192.168.109.194 { require_message_authenticator = no secret = "MYPASSWORD" shortname = "SwitchStack" nastype = "cisco" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /etc/freeradius/modules/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/radiusd.conf modules { Module: Creating Auth-Type = digest Module: Creating Auth-Type = LDAP Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/freeradius/modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/freeradius/modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/freeradius/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/modules/digest Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/freeradius/modules/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Module: Linked to module rlm_ldap Module: Instantiating module "ldap" from file /etc/freeradius/modules/ldap ldap { server = "127.0.0.1" port = 389 password = "MYPASSWORD" expect_password = yes identity = "cn=admin,dc=example,dc=com" net_timeout = 1 timeout = 4 timelimit = 3 max_uses = 0 tls_mode = no start_tls = no tls_require_cert = "allow" tls { start_tls = no require_cert = "allow" } basedn = "ou=Users,dc=example,dc=com" filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})" base_filter = "(ou=Users)" auto_header = no access_attr_used_for_allow = yes groupname_attribute = "cn" groupmembership_filter = "(&(cn=*)(memberUid=%{%Stripped-User-Name}:-%{User-Name}}))" groupmembership_attribute = "radiusGroupName" dictionary_mapping = "/etc/freeradius/ldap.attrmap" ldap_debug = 0 ldap_connections_number = 5 compare_check_items = no do_xlat = yes edir_account_policy_check = no set_auth_type = yes keepalive { idle = 60 probes = 3 interval = 3 } } rlm_ldap: Registering ldap_groupcmp for Ldap-Group rlm_ldap: Registering ldap_xlat with xlat_name ldap rlm_ldap: reading ldap<->radius mappings from file /etc/freeradius/ldap.attrmap rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$ rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$ rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling-Station-Id rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password rlm_ldap: LDAP sambaLmPassword mapped to RADIUS LM-Password rlm_ldap: LDAP sambaNtPassword mapped to RADIUS NT-Password rlm_ldap: LDAP dBCSPwd mapped to RADIUS LM-Password rlm_ldap: LDAP userPassword mapped to RADIUS Password-With-Header rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address rlm_ldap: LDAP gidNumber mapped to RADIUS Ldap-PrimaryGroupId rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed-Compression rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX-Network rlm_ldap: LDAP radiusClass mapped to RADIUS Class rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination-Action rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message rlm_ldap: LDAP radiusTunnelType mapped to RADIUS Tunnel-Type rlm_ldap: LDAP radiusTunnelMediumType mapped to RADIUS Tunnel-Medium-Type rlm_ldap: LDAP radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id conns: 0x120aab0 Module: Linked to module rlm_always Module: Instantiating module "reject" from file /etc/freeradius/modules/always always reject { rcode = "reject" simulcount = 0 mpp = no } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/freeradius/eap.conf eap { default_eap_type = "peap" 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/certs" pem_file_type = yes private_key_file = "/etc/freeradius/certs/server.key" certificate_file = "/etc/freeradius/certs/server.pem" CA_file = "/etc/freeradius/certs/ca.pem" private_key_password = "whatever" dh_file = "/etc/freeradius/certs/dh" random_file = "/dev/urandom" fragment_size = 1024 include_length = yes check_crl = no check_all_crl = no cipher_list = "DEFAULT" make_cert_command = "/etc/freeradius/certs/bootstrap" ecdh_curve = "prime256v1" cache { enable = no lifetime = 24 max_entries = 255 } verify { } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = no } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "peap" copy_request_to_tunnel = no use_tunneled_reply = yes 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 = yes 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/modules/preprocess preprocess { huntgroups = "/etc/freeradius/huntgroups" hints = "/etc/freeradius/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/huntgroups reading pairlist file /etc/freeradius/hints Module: Linked to module rlm_realm Module: Instantiating module "suffix" from file /etc/freeradius/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/modules/files files { usersfile = "/etc/freeradius/users" acctusersfile = "/etc/freeradius/acct_users" preproxy_usersfile = "/etc/freeradius/preproxy_users" compat = "no" } reading pairlist file /etc/freeradius/users reading pairlist file /etc/freeradius/acct_users reading pairlist file /etc/freeradius/preproxy_users Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating module "detail" from file /etc/freeradius/modules/detail detail { detailfile = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no escape_filenames = no } Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/freeradius/attrs.accounting_response" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius/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/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/freeradius/attrs.access_reject" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius/attrs.access_reject } # modules } # server server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 0 } listen { type = "acct" ipaddr = * port = 0 } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } ... adding new socket proxy address * port 42916 Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=222, length=131 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x0201000e01737369707769666931 Message-Authenticator = 0xa26adbccad03de7fe70b5f55ca50e571 # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 1 length 14 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] = updated ++[files] = noop [ldap] performing user authorization for ssipwifi1 [ldap] expand: %{Stripped-User-Name} -> [ldap] ... expanding second conditional [ldap] expand: %{User-Name} -> ssipwifi1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ssipwifi1) [ldap] expand: ou=Users,dc=example,dc=com -> ou=Users,dc=example,dc=com [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] attempting LDAP reconnection [ldap] (re)connect to 127.0.0.1:389, authentication 0 [ldap] bind as cn=admin,dc=example,dc=com/MYPASSWORD to 127.0.0.1:389 [ldap] waiting for bind result ... [ldap] Bind was successful [ldap] performing search in ou=Users,dc=example,dc=com, with filter (uid=ssipwifi1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] gidNumber -> Ldap-PrimaryGroupId == 10004 [ldap] userPassword -> Password-With-Header == "{SSHA}w/lNsXIc3dQXXXXXXXXXXXXXXeaRhMGVt" [ldap] sambaNtPassword -> NT-Password == 0x433233423237334534XXXXXXXXXXXXXXX83546314337453735423031304341 [ldap] looking for reply items in directory... [ldap] ldap_release_conn: Release Id: 0 ++[ldap] = ok ++[expiration] = noop ++[logintime] = noop [pap] Normalizing NT-Password from hex encoding [pap] Normalizing SSHA1-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] = noop +} # group authorize = updated Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 222 to 192.168.109.194 port 49205 EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f32699e803792eac5869d440 Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=223, length=141 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f32699e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x020200060315 Message-Authenticator = 0x47c58cec3484eaff137af8e0f896b447 # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 2 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] = updated ++[files] = noop [ldap] performing user authorization for ssipwifi1 [ldap] expand: %{Stripped-User-Name} -> [ldap] ... expanding second conditional [ldap] expand: %{User-Name} -> ssipwifi1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ssipwifi1) [ldap] expand: ou=Users,dc=example,dc=com -> ou=Users,dc=example,dc=com [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in ou=Users,dc=example,dc=com, with filter (uid=ssipwifi1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] gidNumber -> Ldap-PrimaryGroupId == 10004 [ldap] userPassword -> Password-With-Header == "{SSHA}w/lNsXIc3dQXXXXXXXXXXXXXXeaRhMGVt" [ldap] sambaNtPassword -> NT-Password == 0x433233423237334534XXXXXXXXXXXXXXX83546314337453735423031304341 [ldap] looking for reply items in directory... [ldap] ldap_release_conn: Release Id: 0 ++[ldap] = ok ++[expiration] = noop ++[logintime] = noop [pap] Normalizing NT-Password from hex encoding [pap] Normalizing SSHA1-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] = noop +} # group authorize = updated Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP NAK [eap] EAP-NAK asked for EAP-Type/ttls [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 223 to 192.168.109.194 port 49205 EAP-Message = 0x010300061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f22795e803792eac5869d440 Finished request 1. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=224, length=239 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f22795e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x020300681500160301005d01000059030158530887210f58d8d6b244c838f96da45450f4f86718340d1896a196652d37cc00003200390038003500160013000a00330032002f00070066000500040063006200150012000900650064006000140011000800030100 Message-Authenticator = 0xdb90c4d7b9b838a214d0de5f6470923f # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 3 length 104 [eap] Continuing tunnel setup. ++[eap] = ok +} # group authorize = ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] eaptls_verify returned 7 [ttls] Done initial handshake [ttls] (other): before/accept initialization [ttls] TLS_accept: before/accept initialization [ttls] <<< TLS 1.0 Handshake [length 005d], ClientHello [ttls] TLS_accept: unknown state [ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello [ttls] TLS_accept: unknown state [ttls] >>> TLS 1.0 Handshake [length 08a7], Certificate [ttls] TLS_accept: unknown state [ttls] >>> TLS 1.0 Handshake [length 030d], ServerKeyExchange [ttls] TLS_accept: unknown state [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [ttls] TLS_accept: unknown state [ttls] TLS_accept: unknown state [ttls] TLS_accept: unknown state [ttls] TLS_accept: Need to read more data: unknown state [ttls] TLS_accept: Need to read more data: unknown state In SSL Handshake Phase In SSL Accept mode [ttls] eaptls_process returned 13 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 224 to 192.168.109.194 port 49205 EAP-Message = 0x0104040015c000000bf6160301002a0200002603018df62fac61181c5738eaaf644f67a012285e5fe2cc6ef541bcc9fb2a274c4d680000390016030108a70b0008a30008a00003cd308203c9308202b1a003020102020101300d06092a864886f70d01010b050030818c310b3009060355040613024e4c310b300906035504080c024e483112301006035504070c09416d7374657264616d31163014060355040a0c0d53414520416d7374657264616d3120301e06092a864886f70d0109011611612e73696e6e696765407361652e6564753122302006035504030c1953414520436572746966696361746520417574686f72697479301e170d313630 EAP-Message = 0x3332323136353935385a170d3236303332303136353935385a3075310b3009060355040613024e4c310b300906035504080c024e4831163014060355040a0c0d53414520416d7374657264616d311f301d06035504030c16534145205365727665722043657274696669636174653120301e06092a864886f70d0109011611612e73696e6e696765407361652e65647530820122300d06092a864886f70d01010105000382010f003082010a0282010100a8e646288e90248e347514a9562adc1c669654454ec7634463cf7f6ff0d37a9c45413ec38f49eb9cfac08ff1ff9c3c41d64136357aece8334d35a32fae50e057154b2b3c66ed0413827928f2 EAP-Message = 0xdc908db4ca4a43180b46e3078da30a62ce15a45a0d95947aba8a8f511c2b0fbb6606bb3fdb91d814cbe24e25611e93ad1f435ea3014cc5204430fab1b5f678e5bcf1b2683013482f71e090746fb4126921036fb2cdc3e6497cd9f85b557229527a2ab56a0d76336f987e28195572c6e7f654e8dd8c7688d671fe3d178e25428a2a431e053885df4625a791287dbdfaea10f3dfc32476cb8cbe87992c0710628d5b5736be3ec785e59d88508333640cc7b5e9051d0203010001a34c304a30130603551d25040c300a06082b0601050507030130330603551d1f042c302a3028a026a0248622687474703a2f2f7777772e736165616d7374657264616d2e EAP-Message = 0x636f6d2f63612e63726c300d06092a864886f70d01010b050003820101004ed2a48cbc22c9a4b49ad922f3ebebe5d4e25ff70f41790eb52d2c2be30fada0536b2cf0191fa25e9714f76873115edc08621d308165aee6bf10adda3168462230a93073e4d62fd0f151d8b35691f1c668ae3e4f6c17338cdd16181420fb13087ee166711fcc05caf181753fcb53ecce5fec499e6bbefbdcf518c0b5150d73f272b1cabac3f082b23b900c8f4a76e956367c02f64ff93d67a8c2231746c1993cd477d4502809c33b8c5277a334dc499c6f9ade0d4657adeaa7da144e42143e058d4c5294b556c131f792cac9cd6e7a30df9358fa6182906aa8cea1ef7e0c71 EAP-Message = 0x329922ae6dacb5c1dd0c30aa Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f12095e803792eac5869d440 Finished request 2. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=225, length=141 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f12095e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x020400061500 Message-Authenticator = 0xc2641a7ce4c8ecb0a0fa877c97250bbf # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] = ok +} # group authorize = ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 225 to 192.168.109.194 port 49205 EAP-Message = 0x0105040015c000000bf61a1021f94ac6d92fb0be9027d4364cdef7887b1e140004cd308204c9308203b1a0030201020209008c96fc367ca63be9300d06092a864886f70d01010b050030818c310b3009060355040613024e4c310b300906035504080c024e483112301006035504070c09416d7374657264616d31163014060355040a0c0d53414520416d7374657264616d3120301e06092a864886f70d0109011611612e73696e6e696765407361652e6564753122302006035504030c1953414520436572746966696361746520417574686f72697479301e170d3136303332323136343935385a170d3236303332303136343935385a30818c310b EAP-Message = 0x3009060355040613024e4c310b300906035504080c024e483112301006035504070c09416d7374657264616d31163014060355040a0c0d53414520416d7374657264616d3120301e06092a864886f70d0109011611612e73696e6e696765407361652e6564753122302006035504030c1953414520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100de6649176647c36cbec1bc7545e5ab88c8ab3bd57d63e6cac9d0a28676d45477cd54f5a09e5026506c37db77e7216cecc63fe1f1685daa101ff58f0232ce8e63e0df9e9d934c7086bb76f4d676f4c97c2b5c EAP-Message = 0x24084676e3a03c055fbf6483a21b3996618ffc52e9b0e3843eb75a604e1936071a307eb09be8392ede3d55355d1d80be2b2ae4943bde3fc0e577cc5603d854bb39d1298dabd3896d1cb206f018bba68c1e399f6a2590290544a51a38cd89fddc5661bffdadd912653d0289dc80c6bda51342319638b3977265b289e34e998acb615339f2f9ae9bb97b70fd42bdce98c326f03cb91a1705abcf6f51ec997fdbdea598fe21a8e1552999e0bed71c4b0203010001a382012a30820126301d0603551d0e0416041431193dc758d4d6c2f73a147365c3cd0d39a238833081c10603551d230481b93081b6801431193dc758d4d6c2f73a147365c3cd0d39a238 EAP-Message = 0x83a18192a4818f30818c310b3009060355040613024e4c310b300906035504080c024e483112301006035504070c09416d7374657264616d31163014060355040a0c0d53414520416d7374657264616d3120301e06092a864886f70d0109011611612e73696e6e696765407361652e6564753122302006035504030c1953414520436572746966696361746520417574686f726974798209008c96fc367ca63be9300c0603551d13040530030101ff30330603551d1f042c302a3028a026a0248622687474703a2f2f7777772e736165616d7374657264616d2e636f6d2f63612e63726c300d06092a864886f70d01010b05000382010100dbe3cc84a7 EAP-Message = 0x372bcbfb9704deb26aeeafa8 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f02195e803792eac5869d440 Finished request 3. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=226, length=141 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f02195e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x020500061500 Message-Authenticator = 0x6fc6823020c04432d9acf82f0c9ee2c2 # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] = ok +} # group authorize = ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 226 to 192.168.109.194 port 49205 EAP-Message = 0x0106040015c000000bf6d549ac5fff21be2705b1e145bcf7d7665b5b27b6cbc2c730f168805fca2b32356bac539c62e383a77d29c940ddd0757fc9cf07bd7978b8074973474e76dbea9adb2fd2db612de5c78098f30236cc501bb9980c3b798535b40a9660b5533a083b0882dea880d2899bd515a797b381be09d4c7174cc19492d683d11cd381b7f2cab27109b64e91d7ccccf9b58b3f80d2fcd44aa4dad8405c516663edbc4dfca0a8ee682635307b2f458290bbc430ea2975d31822a546ea4f87f645864750dd184169b44b0d02e93ac54ff225e6f4f74a579e230953832fc90092f10ba94efa2b070e67d44338a7fb3488a6bf56c7487216030103 EAP-Message = 0x0d0c0003090100d22106c0a5b03700957f1cb02d3b9766efbb63576466492685ee475d6ed4c1565f1b3c2e0a5f8281c29398ad39093232179f2c838c3e413fa982c7906e1bbce2e8977a9f477656115b5059ba1ef44053ec2e86b9fc5d029992ae0acfe1a7895db3bb9436198319d28cfe44e1be3a5b67253956dd11543dd2c01cf1fbd68a19914c36fa76420c7032b5b8d4804b3641164bcbbf78241cd5a148a5748fb6b472d68051da53e660c513bb97e55511db9ac81c5b725a9e13a61a1da813cb8da5f7a2e5e7aab5e638ea3c64d995c6398ff1ba4b7b909b8ef7ac962a1c197e13f9a3af91c5789e7fa0480352cd88b224b12b3ce48a86478e97 EAP-Message = 0xf06fc2ff6e318e8744eb0001020100c3e72471fecb556c93dd53d51acde1f3729dcae17952767bd763cb16293b64b6d0d65eed6799d4d66d360eb8f51195742183036ee7a1b181f4e019a995d29436bceef78c8d9453c57cc5bb3af8308c5407b60ab5670084894907d4280dd97b35aef727c77086f9633d2feca8cdede8eb5fd0818a7e837f474aa2e624abe54357653105501ae950e57f0bf00cd725b561636842f1d64261bf13e137c4e34df1111a06d6cd094435a6a365df538b8606ccef7373b4bbc75b18b0cd5c3ba94b5a3350df915d3b8473b5cc9f3f4ac33004cbfe9339fcb20d0f083a88df3933e8b61c32708947b20fa099db88abe16938 EAP-Message = 0x7b835550d3ce2717c53f8937aa84fa764547010061532482fba13e2b8741883cd54c0254234beaaadff4e6cd9c29b0aed7afd8df3103da418cb71e4e290be7a2e373c31176d0dcd1f922dd3a7507a7b10adbc17bac6d1cd0999d5936703274856263c2c2d9d7d5430f319991ffe7c45c2b1383e8bb1c1da85d8faac14408affd9da642cb4a2db936ba18a711ea9ffd90154cb986e2dd444585787152e3cbb08133ce5bfd206ae3ff56b165026b394c4b20e4a17167030eaae2ffd7f42ade0bcee706f34a63220dd0a6f0a0e3825ca65daa6bb8bef72115a7b55a69812304f12374274353b570d0f1dcbe794e63f9e34b6bc965b3ed240edee6969000b8 EAP-Message = 0x217354c3ccaf26f033f83583 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f72295e803792eac5869d440 Finished request 4. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=227, length=141 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f72295e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x020600061500 Message-Authenticator = 0x4e3105a4d4c92d23c6f2ba0bb7cb7cd1 # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 6 length 6 [eap] Continuing tunnel setup. ++[eap] = ok +} # group authorize = ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] = handled +} # group authenticate = handled Sending Access-Challenge of id 227 to 192.168.109.194 port 49205 EAP-Message = 0x0107001e158000000bf6538bc8711672573639644816030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3248093f62395e803792eac5869d440 Finished request 5. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 192.168.109.194 port 49205, id=228, length=148 NAS-IP-Address = 192.168.109.194 NAS-Port-Type = Ethernet NAS-Port = 63 User-Name = "ssipwifi1" Acct-Session-Id = "05001068" State = 0xf3248093f62395e803792eac5869d440 Called-Station-Id = "00-87-31-4B-4A-D9" Calling-Station-Id = "00-15-65-AF-D2-23" EAP-Message = 0x0207000d150015030100020233 Message-Authenticator = 0xe509af21a3d2eb70c5d6faf28cda7bb1 # Executing section authorize from file /etc/freeradius/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop ++[mschap] = noop ++[digest] = noop [suffix] No '@' in User-Name = "ssipwifi1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] EAP packet type response id 7 length 13 [eap] Continuing tunnel setup. ++[eap] = ok +} # group authorize = ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +group authenticate { [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] eaptls_verify returned 7 [ttls] Done initial handshake [ttls] <<< TLS 1.0 Alert [length 0002], fatal decrypt_error TLS Alert read:fatal:decrypt error TLS_accept: failed in unknown state rlm_eap: SSL error error:1409441B:SSL routines:ssl3_read_bytes:tlsv1 alert decrypt error SSL: SSL_read failed inside of TLS (-1), TLS session fails. TLS receive handshake failed during operation [ttls] eaptls_process returned 4 [eap] Handler failed in EAP/ttls [eap] Failed in EAP select ++[eap] = invalid +} # group authenticate = invalid Failed to authenticate the user. Login incorrect (TLS Alert read:fatal:decrypt error): [ssipwifi1] (from client SwitchStack port 63 cli 00-15-65-AF-D2-23) Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +group REJECT { [attr_filter.access_reject] expand: %{User-Name} -> ssipwifi1 attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Delaying reject of request 6 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 6 Sending Access-Reject of id 228 to 192.168.109.194 port 49205 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.7 seconds.

2 1

FreeRadius LDAP group verification
by Stefan Sundberg 15 Dec '16

15 Dec '16

Hi I am using FreeRadius 3 to authenicate Wifi users with WPA2 enterprise which are then checked in a OpenLDAP directory. This is working fine as long as I accept that all users in base_dn = 'ou=People,dc=example,dc=se' can use the Wifi. To guard againt this I have worked to implement LDAP Group checking in FreeRadius 3 and this seems not to to be working. Even if I mess up the filter settings under the ”Group” section in /usr/local/etc/raddb/mods-enabled/ldap, FreeRadius gladly accepts the user as long as the user/password is OK. The Group section does not seem to affect the process at all. I am using FreeRadius 3.0.12 and OpenLDAP 2.4.44 which are running happily on FreeBSD 10.3 i386. Best Regards Stefan Sundberg User section of the FreeRadius ldap file: user { # Where to start searching in the tree for users base_dn = 'ou=People,dc=example,dc=se' # Filter for user objects, should be specific enough # to identify a single user object. # # For Active Directory, you should use # "samaccountname=" instead of "uid=" # filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})" } Group section of the FreeRadius ldap file: group { # Where to start searching in the tree for groups base_dn = 'ou=Groups,dc=example,dc=se' # Filter for group objects, should match all available # group objects a user might be a member of. # Radius is an existing LDAP Group under 'ou=Groups,dc=example,dc=se' filter = '(cn=Radius)' # Attribute that uniquely identifies a group. # Is used when converting group DNs to group # names. name_attribute = cn # Filter to find group objects a user is a member of. # That is, group objects with attributes that # identify members (the inverse of membership_attribute). membership_filter = "(|(member=%{control:Ldap-UserDn})(memberUid=%{%{Stripped-User-Name}:-%{User-Name}}))" # The attribute in user objects which contain the names # or DNs of groups a user is a member of. # Unless a conversion between group name and group DN is # needed, there's no requirement for the group objects # referenced to actually exist. membership_attribute = 'memberUid' } Debug print of radiusd -X: (0) Received Access-Request Id 48 from 192.168.5.250:3759 to 192.168.5.249:1812 length 117 (0) User-Name = "myuser" (0) Acct-Session-Id = "1481748386W82ujh" (0) NAS-IP-Address = 127.0.0.1 (0) NAS-Identifier = "Localhost" (0) NAS-Port = 0 (0) Calling-Station-Id = "1115551212" (0) User-Password = "password" (0) Message-Authenticator = 0x5e20b42290bb652cd15b5355b41d0b4d (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /(a)\./) { (0) if (&User-Name =~ /(a)\./) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: No '@' in User-Name = "myuser", looking up realm NULL (0) suffix: No such realm "NULL" (0) [suffix] = noop (0) eap: No EAP-Message, not doing EAP (0) [eap] = noop (0) [files] = noop rlm_ldap (ldap): Reserved connection (0) (0) ldap: EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}}) (0) ldap: --> (uid=myuser) (0) ldap: Performing search in "ou=People,dc=example,dc=se" with filter "(uid=myuser)", scope "sub" (0) ldap: Waiting for search result... (0) ldap: User object found at DN "uid=myuser,ou=People,dc=example,dc=se" (0) ldap: Processing user attributes (0) ldap: control:Password-With-Header += 'password' rlm_ldap (ldap): Released connection (0) rlm_ldap (ldap): Need 5 more connections to reach 10 spares rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots used rlm_ldap (ldap): Connecting to ldap://localhost:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful (0) [ldap] = updated (0) [expiration] = noop (0) [logintime] = noop (0) pap: No {...} in Password-With-Header, re-writing to Cleartext-Password (0) pap: Removing &control:Password-With-Header (0) [pap] = updated (0) } # authorize = updated (0) Found Auth-Type = PAP (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) Auth-Type PAP { (0) pap: Login attempt with password (0) pap: Comparing with "known good" Cleartext-Password (0) pap: User authenticated successfully (0) [pap] = ok (0) } # Auth-Type PAP = ok (0) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default (0) post-auth { (0) update { (0) No attributes updated (0) } # update = noop (0) [exec] = noop (0) policy remove_reply_message_if_eap { (0) if (&reply:EAP-Message && &reply:Reply-Message) { (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (0) else { (0) [noop] = noop (0) } # else = noop (0) } # policy remove_reply_message_if_eap = noop (0) } # post-auth = noop (0) Login OK: [myuser/password] (from client ts01 port 0 cli 1115551212) (0) Sent Access-Accept Id 48 from 192.168.5.249:1812 to 192.168.5.250:3759 length 0 (0) Finished request Waking up in 4.9 seconds. (0) Cleaning up request packet ID 48 with timestamp +33 Ready to process requests

2 2

Re: Cross platform secure login on wpa2
by Brian Candler 15 Dec '16

15 Dec '16

On 15/12/2016 09:23, Henti Smith wrote: > That is correct. I just can't find the documentation to outline how to > achieve this, hence using two documents each, detailing one component > and ending up where I am. > > If I can be pointed in a direction of some documentation that covers > exactly that, it would help a great load. > OK. I don't have that I'm afraid. I have one pointer which may help. In your EAP outer config (the "default" virtual server) you may want something like this: eap { ok = return updated = return # << new } This is to ensure that any modules you put after this aren't invoked during an EAP exchange, except at the very end. The problem I found originally was with a config like this: eap { ok = return } mypolicy In "mypolicy" I was setting Auth-Type := reject in some circumstances, based on group membership. This was resulting in the user being rejected part-way through the EAP exchange, because (1) during one of the intermediate EAP steps, the eap module returns "updated" instead of "ok", and so it fell through to the next step of the default server; and (2) at that point, mypolicy was seeing the outer (anonymous) identity, not the true identity of the user. I'm afraid I don't know how to invoke the krb5 module. In the documentation at https://wiki.freeradius.org/modules/Rlm_krb5 it says: Auth-Type Kerberos { krb5 } However it's not at all clear to me how Auth-Type := Kerberos is set in the first place. You may have to do this explicitly in the inner tunnel virtual server, e.g. at the end of the authorize section put something like Auth-Type = Kerberos (the '=' operator will set it only if it's not already been set to something else already) Looking through the source: the rlm_krb5 module doesn't have an authorize hook which could do this. However the rlm_pap module appears to have functionality to set the auth type to its own name. Hence, if you create an instance of the rlm_pap module called "Kerberos" this may do what you want; but this is not mentioned in the rlm_pap manpage. Regards, Brian.

1 0

Freeradius 3.0.12 - Cisco EAP-Fast Supported?
by Kevin Morrison 14 Dec '16

14 Dec '16

Greetings folks, This is my first time posting to this mailing list, I am hoping you can answer a question/help me out. Does the newest Freeradius version 3.0.12 support the CISCO version of EAP-FAST? I have been trying to get the newly created EAP FAST module to work with a Cisco WLC and Cisco device to authenticate via EAP-Fast, but I keep getting the error message about: (37) mschap: Client is using MS-CHAPv2 (37) mschap: ERROR: MS-CHAP2-Response is incorrect I am running on CentOS 7, as well. If the answer is Yes to supporting Cisco EAP FAST, then I can definitely provide the full output of radiusd -X for assistance. Thank you! Kevin Morrison Systems Administrator T: +1 (704) 378-9235 C: +1 (980) 255-9668 kmorrison(a)vectorusa.com<mailto:kmorrison@vectorusa.com> VectorUSA 2520 Whitehall Park Drive, Suite 300 Charlotte, NC 28273 Customer Service: +1 (877) 569-8800 [cid:AVectorUSA_logo_com_on_white.bmp]<www.vectorusa.com>

3 2

802.1x
by James Cloos 14 Dec '16

14 Dec '16

Configuring a router to query a givenradius server is well and widely documented, but all of the docs and tuts I've found skip the question of what to put in the radius server for doing 802.1x authentication. Can anyone here provide any details? My goal is username/passwd auth, at least for now. Thank you. -JimC -- James Cloos <cloos(a)jhcloos.com> OpenPGP: 0x997A9F17ED7DAEA6

3 4

Freeradius incorrect acctstoptime
by Sachin Yadav 11 Dec '16

11 Dec '16

Hi, We have a large deployment of about 600 NAS (mixed openwrt/mikrotik/others). I have noticed that for some records, incorrect acctstoptime was marked while user session was still going on and accounting was happening. So following is the flow - 1. Use login on hotspot, accounting starts2. After sometime (5-7 minutes), acctstoptime populates with a datetime value, while user is surfing3. user keep surfing and accounting keep happening.4. I have run radius in debug mode and captured log, NAS did not send any accounting stop packet.5. I have also observed around 26 records out of 110 current logged in users have same acctstoptime timestamp value and acctterminatecause value as either NULL or 0. Looks like a query is making incorrect updates. I am using FR 2x an can't update to 3 right now. Have observed following query in logs, which might be an issue - UPDATE radacct SET acctstoptime = '2016-12-08 12:13:26', acctsessiontime = unix_timestamp('2016-12-08 12:13:26') - unix_timestamp(acctstarttime), acctterminatecause = '', acctstopdelay = 0 WHERE acctstoptime IS NULL AND nasipaddress = '192.168.182.1' AND acctstarttime <= '2016-12-08 12:13:26' Or there may be some mis-configuration as our end. Kindly let me know.

7 11

authentication error message (eap-ttls)
by yukou katori 10 Dec '16

10 Dec '16

Hi, I'm trying EAP-TTLS.Now I'm testing with wpa_supplicant-2.5 for preparation.But I got the following error.This is freeradius-3.0.11(and openssl-1.0.2g).I didn't customize mods-available/eap at all. Anybody can suggest what could be wrong? Regards, /// error in debug by radiusd -XX:Thu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP MD5 (4) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 1 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed): [eapol_test(a)aikon.jp] (from client localhost port 0 via TLS tunnel)(snip)Thu Dec 8 00:32:07 2016 : Debug: (7) Sent Access-Reject Id 7 from 127.0.0.1:1812 to 127.0.0.1:54818 length 44 /// compiling command:freeradius:./configure --with-openssl --with-openssl-lib-dir=/usr/local/openssl/lib --with-openssl-include-dir=/usr/local/openssl/includeopenssl:./config shared --prefix=/usr/local/openssl /// config of wpa_supplicant-2.5cat eap-ttls.confnetwork={ eap=TTLS identity="eapol_test(a)aikon.jp" anonymous_identity="anonymous" password="tester" phase2="autheap=MD5"}# https://networkradius.com/doc/FreeRADIUS-Implementation-Ch6.pdf /// executing command by wpa_supplicant-2.5:./eapol_test -c eap-ttls.conf -s tester -a 127.0.0.1 /// config of "users":cat /usr/local/etc/raddb/userseapol_test(a)aikon.jp Cleartext-Password := "tester" /// config of "clients.conf"client localhost { ipaddr = 127.0.0.1 proto = * secret = tester require_message_authenticator = no nas_type = other limit { max_connections = 16 lifetime = 0 idle_timeout = 30 }} /// whole debug:Thu Dec 8 00:32:06 2016 : Debug: (0) Received Access-Request Id 0 from 127.0.0.1:54818 to 127.0.0.1:1812 length 126Thu Dec 8 00:32:06 2016 : Debug: (0) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (0) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (0) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (0) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (0) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (0) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (0) EAP-Message = 0x0200000e01616e6f6e796d6f7573Thu Dec 8 00:32:06 2016 : Debug: (0) Message-Authenticator = 0x6a5b44af24891d9347e01cbd71cec798Thu Dec 8 00:32:06 2016 : Debug: (0) session-state: No State attributeThu Dec 8 00:32:06 2016 : Debug: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) authorize {Thu Dec 8 00:32:06 2016 : Debug: (0) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (0) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (0) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (0) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Peer sent EAP Response (code 2) ID 0 length 14Thu Dec 8 00:32:06 2016 : Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (0) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (0) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Peer sent packet with method EAP Identity (1)Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (0) eap_md5: Issuing MD5 ChallengeThu Dec 8 00:32:06 2016 : Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (0) eap: EAP session adding &reply:State = 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (0) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (0) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (0) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (0) Sent Access-Challenge Id 0 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (0) EAP-Message = 0x010100160410148be0314430ffefaa02aa4393a87209Thu Dec 8 00:32:06 2016 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (0) State = 0x10c1717110c075fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (0) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (1) Received Access-Request Id 1 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (1) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (1) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (1) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (1) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (1) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (1) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (1) EAP-Message = 0x020100060315Thu Dec 8 00:32:06 2016 : Debug: (1) State = 0x10c1717110c075fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (1) Message-Authenticator = 0x931aa8ba75de18053d596ecb4e0fcccdThu Dec 8 00:32:06 2016 : Debug: (1) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) authorize {Thu Dec 8 00:32:06 2016 : Debug: (1) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (1) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling chap (rlm_chap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from chap (rlm_chap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling mschap (rlm_mschap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from mschap (rlm_mschap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling digest (rlm_digest) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from digest (rlm_digest) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling suffix (rlm_realm) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (1) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (1) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Peer sent EAP Response (code 2) ID 1 length 6Thu Dec 8 00:32:06 2016 : Debug: (1) eap: No EAP Start, assuming it's an on-going EAP conversationThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [eap] = updatedThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling files (rlm_files) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from files (rlm_files) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [files] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling expiration (rlm_expiration) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from expiration (rlm_expiration) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [expiration] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling logintime (rlm_logintime) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from logintime (rlm_logintime) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [logintime] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling pap (rlm_pap) for request 1Thu Dec 8 00:32:06 2016 : WARNING: (1) pap: No "known good" password found for the user. Not setting Auth-TypeThu Dec 8 00:32:06 2016 : WARNING: (1) pap: Authentication will fail unless a "known good" password is availableThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [pap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) } # authorize = updatedThu Dec 8 00:32:06 2016 : Debug: (1) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Expiring EAP session with state 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (1) eap: Finished EAP session with state 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (1) eap: Previous EAP request found for state 0x10c1717110c075fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (1) eap: Peer sent packet with method EAP NAK (3)Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Found mutually acceptable type TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: Initiating new EAP-TLS sessionThu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: Flushing SSL sessions (of #0)Thu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: [eaptls start] = requestThu Dec 8 00:32:06 2016 : Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 6Thu Dec 8 00:32:06 2016 : Debug: (1) eap: EAP session adding &reply:State = 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (1) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (1) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (1) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (1) Sent Access-Challenge Id 1 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (1) EAP-Message = 0x010200061520Thu Dec 8 00:32:06 2016 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (1) State = 0x10c1717111c364fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (1) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (2) Received Access-Request Id 2 from 127.0.0.1:54818 to 127.0.0.1:1812 length 423Thu Dec 8 00:32:06 2016 : Debug: (2) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (2) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (2) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (2) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (2) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (2) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (2) EAP-Message = 0x0202012315001603010118010001140303cae0610d1e6b8100c007621e34def0ebe6cf945950b45515aba196cc342a1288000082c030c02cc028c024c014c00a00a3009f006b006a0039003800880087c032c02ec02ac026c00fc005009d003d00350084c012c00800160013c00dc003000ac02fc02bc0Thu Dec 8 00:32:06 2016 : Debug: (2) State = 0x10c1717111c364fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (2) Message-Authenticator = 0x910cc0b973e5dbf44407b7281379ebf2Thu Dec 8 00:32:06 2016 : Debug: (2) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) authorize {Thu Dec 8 00:32:06 2016 : Debug: (2) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (2) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling chap (rlm_chap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from chap (rlm_chap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling mschap (rlm_mschap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from mschap (rlm_mschap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling digest (rlm_digest) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from digest (rlm_digest) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling suffix (rlm_realm) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (2) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (2) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from suffix (rlm_realm) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 2 length 291Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (2) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (2) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Expiring EAP session with state 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (2) eap: Finished EAP session with state 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (2) eap: Previous EAP request found for state 0x10c1717111c364fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (2) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: (other): before/accept initializationThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: before/accept initializationThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: <<< recv TLS 1.2 [length 0118]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 read client hello AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 005e]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write server hello AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 0813]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write certificate AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 014d]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write key exchange AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 0004]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write server done AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 flush dataThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 read client certificate AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: In SSL Handshake PhaseThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: In SSL Accept modeThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (2) eap: Sending EAP Request (code 1) ID 3 length 1004Thu Dec 8 00:32:06 2016 : Debug: (2) eap: EAP session adding &reply:State = 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (2) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (2) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (2) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (2) Sent Access-Challenge Id 2 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (2) EAP-Message = 0x010303ec15c0000009d6160303005e0200005a03039e4ca71cf04c8e662d2936617c41d9f3a5b54ea05741888a6f933888fec2110d203344cf5126fb4cf727a39331e315f534a64dde1d6d8c12c35b10a710ec96d857c030000012ff01000100000b000403000102000f00010116030308130b00080f00Thu Dec 8 00:32:06 2016 : Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (2) State = 0x10c1717112c264fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (2) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (3) Received Access-Request Id 3 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (3) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (3) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (3) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (3) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (3) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (3) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (3) EAP-Message = 0x020300061500Thu Dec 8 00:32:06 2016 : Debug: (3) State = 0x10c1717112c264fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (3) Message-Authenticator = 0x9f42a30edc80a507954951c07a942441Thu Dec 8 00:32:06 2016 : Debug: (3) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) authorize {Thu Dec 8 00:32:06 2016 : Debug: (3) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (3) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling chap (rlm_chap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from chap (rlm_chap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling mschap (rlm_mschap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from mschap (rlm_mschap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling digest (rlm_digest) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from digest (rlm_digest) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling suffix (rlm_realm) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (3) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (3) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from suffix (rlm_realm) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Peer sent EAP Response (code 2) ID 3 length 6Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (3) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (3) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Expiring EAP session with state 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (3) eap: Finished EAP session with state 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (3) eap: Previous EAP request found for state 0x10c1717112c264fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (3) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Peer ACKed our handshake fragmentThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: [eaptls verify] = requestThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (3) eap: Sending EAP Request (code 1) ID 4 length 1004Thu Dec 8 00:32:06 2016 : Debug: (3) eap: EAP session adding &reply:State = 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (3) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (3) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (3) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (3) Sent Access-Challenge Id 3 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (3) EAP-Message = 0x010403ec15c0000009d6add6d7bffc0f82cf52e869ceddc3a2612a034c6143e26901836d38631698ce516bd8bf8bc1a41f19bc403054b7ae6a0ff6bcd57233f0d9771c3123bfc18ca1c19f8b9d2eb9b44e27397129f22af1f806ec15491dbddd9505ff28bda45dfcfb77430f3abad91cc809df05032072Thu Dec 8 00:32:06 2016 : Debug: (3) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (3) State = 0x10c1717113c564fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (3) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (4) Received Access-Request Id 4 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (4) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (4) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (4) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (4) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (4) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (4) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (4) EAP-Message = 0x020400061500Thu Dec 8 00:32:06 2016 : Debug: (4) State = 0x10c1717113c564fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (4) Message-Authenticator = 0x54d84b9e194fc9f2e4f34e2c0e1a757eThu Dec 8 00:32:06 2016 : Debug: (4) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) authorize {Thu Dec 8 00:32:06 2016 : Debug: (4) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (4) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling chap (rlm_chap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from chap (rlm_chap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling mschap (rlm_mschap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from mschap (rlm_mschap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling digest (rlm_digest) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from digest (rlm_digest) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling suffix (rlm_realm) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (4) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (4) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from suffix (rlm_realm) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Peer sent EAP Response (code 2) ID 4 length 6Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (4) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (4) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Expiring EAP session with state 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (4) eap: Finished EAP session with state 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (4) eap: Previous EAP request found for state 0x10c1717113c564fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (4) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Peer ACKed our handshake fragmentThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: [eaptls verify] = requestThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (4) eap: Sending EAP Request (code 1) ID 5 length 540Thu Dec 8 00:32:06 2016 : Debug: (4) eap: EAP session adding &reply:State = 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (4) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (4) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (4) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (4) Sent Access-Challenge Id 4 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (4) EAP-Message = 0x0105021c1580000009d6cf3138ddf0922ae5628ffcfed6f592c1d5cca8d32af57f60de724642996952991b8d6f0078f6b530bb3b269c6735e97bb69f59773a5eed5d161a61b433cbfc8264257c2211af3bb752f857422cd4b639c6949edf2cfcdbf6842b7486ae2e5eb3af34e54a0de2ad5167953b036eThu Dec 8 00:32:06 2016 : Debug: (4) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (4) State = 0x10c1717114c464fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (4) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (5) Received Access-Request Id 5 from 127.0.0.1:54818 to 127.0.0.1:1812 length 262Thu Dec 8 00:32:06 2016 : Debug: (5) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (5) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (5) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (5) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (5) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (5) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (5) EAP-Message = 0x020500841500160303004610000042410463a7f35b4f786657607e68c82ab4c2c506d9b924d1a9d7f7ac206bece71d89b09ef287573206209a61e433957cec614a0ea4a9fbd1f74d408c090a9e9a681a0a14030300010116030300282551dc6df862b4c0b9b3d9966d271166a153c14d3a16888963f35fThu Dec 8 00:32:06 2016 : Debug: (5) State = 0x10c1717114c464fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (5) Message-Authenticator = 0x85f0021449b941960ec494ca1f4dfd33Thu Dec 8 00:32:06 2016 : Debug: (5) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) authorize {Thu Dec 8 00:32:06 2016 : Debug: (5) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (5) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling chap (rlm_chap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from chap (rlm_chap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling mschap (rlm_mschap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from mschap (rlm_mschap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling digest (rlm_digest) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from digest (rlm_digest) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling suffix (rlm_realm) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (5) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (5) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from suffix (rlm_realm) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Peer sent EAP Response (code 2) ID 5 length 132Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (5) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (5) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authenticate]: calling eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Expiring EAP session with state 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (5) eap: Finished EAP session with state 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (5) eap: Previous EAP request found for state 0x10c1717114c464fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (5) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0046]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read certificate verify AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0001]Thu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0010]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read finished AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: >>> send TLS 1.2 [length 0001]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 write change cipher spec AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: >>> send TLS 1.2 [length 0010]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 write finished AThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 flush dataThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: (other): SSL negotiation finished successfullyThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: SSL Connection EstablishedThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (5) eap: Sending EAP Request (code 1) ID 6 length 61Thu Dec 8 00:32:06 2016 : Debug: (5) eap: EAP session adding &reply:State = 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (5) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (5) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (5) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (5) Sent Access-Challenge Id 5 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (5) EAP-Message = 0x0106003d1580000000331403030001011603030028d5b079448020ce1c9bf134d5880343cb224288a99a70bc4cffb37b4b9c97b647b0b50d6777b89330Thu Dec 8 00:32:06 2016 : Debug: (5) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (5) State = 0x10c1717115c764fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (5) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (6) Received Access-Request Id 6 from 127.0.0.1:54818 to 127.0.0.1:1812 length 197Thu Dec 8 00:32:06 2016 : Debug: (6) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (6) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (6) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (6) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (6) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x02060043150017030300382551dc6df862b4c1fb3201bf926b3071e7d350336ff5ef1ff5edc880e6d53e93007d8a60473a076291807fbe200f78dcc8890c11e0700e30Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x10c1717115c764fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x4d8fb4e15b352bea3f05a46e1b4dbeb6Thu Dec 8 00:32:06 2016 : Debug: (6) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) authorize {Thu Dec 8 00:32:06 2016 : Debug: (6) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling digest (rlm_digest) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from digest (rlm_digest) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (6) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent EAP Response (code 2) ID 6 length 67Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (6) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (6) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Expiring EAP session with state 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (6) eap: Finished EAP session with state 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (6) eap: Previous EAP request found for state 0x10c1717115c764fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: [eaptls process] = okThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Session established. Proceeding to decode tunneled attributesThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled requestThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: EAP-Message = 0x02000018016561706f6c5f74657374406e6f6b69612e6a70Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled identity of eapol_test(a)aikon.jpThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Setting default EAP type for tunneled EAP sessionThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Sending tunneled requestThu Dec 8 00:32:06 2016 : Debug: (6) Virtual server inner-tunnel received requestThu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x02000018016561706f6c5f74657374406e6f6b69612e6a70Thu Dec 8 00:32:06 2016 : Debug: (6) FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) server inner-tunnel {Thu Dec 8 00:32:06 2016 : Debug: (6) session-state: No State attributeThu Dec 8 00:32:06 2016 : Debug: (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) authorize {Thu Dec 8 00:32:06 2016 : Debug: (6) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: Adding 1 matchesThu Dec 8 00:32:06 2016 : Debug: Clearing 1 matchesThu Dec 8 00:32:06 2016 : Debug: Adding 3 matchesThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: Clearing 3 matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Looking up realm "aikon.jp" for User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: No such realm "aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (6) update control {Thu Dec 8 00:32:06 2016 : Debug: (6) &Proxy-To-Realm := LOCALThu Dec 8 00:32:06 2016 : Debug: (6) } # update control = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent EAP Response (code 2) ID 0 length 24Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (6) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (6) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent packet with method EAP Identity (1)Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (6) eap_md5: Issuing MD5 ChallengeThu Dec 8 00:32:06 2016 : Debug: (6) eap: Sending EAP Request (code 1) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP session adding &reply:State = 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # server inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) Virtual server sending replyThu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x01010016041046421c99242454f962d77aa1e66b8b5eThu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x5848df875849db2ae267ce7fbe5ae0c4Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled Access-ChallengeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Sending EAP Request (code 1) ID 7 length 71Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP session adding &reply:State = 0x10c1717116c664fcThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (6) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (6) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (6) Sent Access-Challenge Id 6 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x0107004715800000003d1703030038d5b079448020ce1df42a341c4d030197afb3c4041e27f8465ff2d7f896aa3ab4433ffeebe6810b7579683e59ad495d7578d1c571bd339e54Thu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x10c1717116c664fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (6) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (7) Received Access-Request Id 7 from 127.0.0.1:54818 to 127.0.0.1:1812 length 197Thu Dec 8 00:32:06 2016 : Debug: (7) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (7) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (7) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (7) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (7) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x02070043150017030300382551dc6df862b4c2cdd2391feaa04414f9442a24998738878a8bdab227da23be15154d2585607e7be9088483a675011b99bb783380c85edbThu Dec 8 00:32:06 2016 : Debug: (7) State = 0x10c1717116c664fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (7) Message-Authenticator = 0x3206542628e88eab17036a42d150300bThu Dec 8 00:32:06 2016 : Debug: (7) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) authorize {Thu Dec 8 00:32:06 2016 : Debug: (7) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling digest (rlm_digest) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from digest (rlm_digest) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (7) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent EAP Response (code 2) ID 7 length 67Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (7) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (7) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Expiring EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Finished EAP session with state 0x10c1717116c664fcThu Dec 8 00:32:06 2016 : Debug: (7) eap: Previous EAP request found for state 0x10c1717116c664fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: [eaptls process] = okThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Session established. Proceeding to decode tunneled attributesThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Got tunneled requestThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: EAP-Message = 0x020100160410247c68784de86a2369dd6851989c7746Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Sending tunneled requestThu Dec 8 00:32:06 2016 : Debug: (7) Virtual server inner-tunnel received requestThu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x020100160410247c68784de86a2369dd6851989c7746Thu Dec 8 00:32:06 2016 : Debug: (7) FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) State = 0x5848df875849db2ae267ce7fbe5ae0c4Thu Dec 8 00:32:06 2016 : Debug: (7) server inner-tunnel {Thu Dec 8 00:32:06 2016 : Debug: (7) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) authorize {Thu Dec 8 00:32:06 2016 : Debug: (7) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: Adding 1 matchesThu Dec 8 00:32:06 2016 : Debug: Clearing 1 matchesThu Dec 8 00:32:06 2016 : Debug: Adding 3 matchesThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: Clearing 3 matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Looking up realm "aikon.jp" for User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: No such realm "aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (7) update control {Thu Dec 8 00:32:06 2016 : Debug: (7) &Proxy-To-Realm := LOCALThu Dec 8 00:32:06 2016 : Debug: (7) } # update control = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent EAP Response (code 2) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (7) eap: No EAP Start, assuming it's an on-going EAP conversationThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling files (rlm_files) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from files (rlm_files) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [files] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling expiration (rlm_expiration) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from expiration (rlm_expiration) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [expiration] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling logintime (rlm_logintime) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from logintime (rlm_logintime) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [logintime] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling pap (rlm_pap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from pap (rlm_pap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [pap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # authorize = updatedThu Dec 8 00:32:06 2016 : Debug: (7) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Expiring EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Finished EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Previous EAP request found for state 0x5848df875849db2a, released from the listThu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent packet with method EAP MD5 (4)Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (7) eap_md5: Cleartext-Password is required for EAP-MD5 authenticationThu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP MD5 (4) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 1 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed): [eapol_test(a)aikon.jp] (from client localhost port 0 via TLS tunnel)Thu Dec 8 00:32:06 2016 : Debug: (7) Using Post-Auth-Type RejectThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) Post-Auth-Type REJECT {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: Parsed xlat tree:Thu Dec 8 00:32:06 2016 : Debug: attribute --> User-NameThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EXPAND %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: --> eapol_test(a)aikon.jpThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Matched entry DEFAULT at line 11Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EAP-Message = 0x04010004 allowed by EAP-Message =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [attr_filter.access_reject] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) update outer.session-state {Thu Dec 8 00:32:06 2016 : Debug: (7) &Module-Failure-Message := &request:Module-Failure-Message -> 'eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed'Thu Dec 8 00:32:06 2016 : Debug: (7) } # update outer.session-state = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # Post-Auth-Type REJECT = updatedThu Dec 8 00:32:06 2016 : Debug: (7) } # server inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) Virtual server sending replyThu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x04010004Thu Dec 8 00:32:06 2016 : Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Got tunneled Access-RejectThu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP TTLS (21) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 7 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed): [anonymous] (from client localhost port 0 cli 02-00-00-00-00-01)Thu Dec 8 00:32:06 2016 : Debug: (7) Using Post-Auth-Type RejectThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) Post-Auth-Type REJECT {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: Parsed xlat tree:Thu Dec 8 00:32:06 2016 : Debug: attribute --> User-NameThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EXPAND %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: --> anonymousThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Matched entry DEFAULT at line 11Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EAP-Message = 0x04070004 allowed by EAP-Message =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [attr_filter.access_reject] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Reply already contained an EAP-Message, not inserting EAP-FailureThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) policy remove_reply_message_if_eap {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&reply:EAP-Message && &reply:Reply-Message) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) else {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling noop (rlm_always) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from noop (rlm_always) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [noop] = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # else = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # policy remove_reply_message_if_eap = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # Post-Auth-Type REJECT = updatedThu Dec 8 00:32:06 2016 : Debug: (7) Delaying response for 1.000000 secondsThu Dec 8 00:32:06 2016 : Debug: Waking up in 0.3 seconds.Thu Dec 8 00:32:06 2016 : Debug: Waking up in 0.6 seconds.Thu Dec 8 00:32:07 2016 : Debug: (7) Sending delayed responseThu Dec 8 00:32:07 2016 : Debug: (7) Sent Access-Reject Id 7 from 127.0.0.1:1812 to 127.0.0.1:54818 length 44Thu Dec 8 00:32:07 2016 : Debug: (7) EAP-Message = 0x04070004Thu Dec 8 00:32:07 2016 : Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:07 2016 : Debug: Waking up in 3.9 seconds.Thu Dec 8 00:32:11 2016 : Debug: (0) Cleaning up request packet ID 0 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (1) Cleaning up request packet ID 1 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (2) Cleaning up request packet ID 2 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (3) Cleaning up request packet ID 3 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (4) Cleaning up request packet ID 4 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (5) Cleaning up request packet ID 5 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (6) Cleaning up request packet ID 6 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (7) Cleaning up request packet ID 7 with timestamp +204Thu Dec 8 00:32:11 2016 : Info: Ready to process requests

2 2

Variable expansion for SQL attributes
by Javier Matos Odut 09 Dec '16

09 Dec '16

Hello, I have FreeRADIUS running with a sql database in production. I am using the sql database to set user's check and reply attributes. The problem I have is that there are some attributes that I need to set them at runtime depending on the NAS identity (or any other FreeRADIUS variable), so I have to edit the configuration file and add something like this: if (...) { update control { Pool-Name := "%{NAS-Identifier}" } } Please, ignore the fact that I am updating the Pool-Name attribute. It is just an example but it has sense in my case to let users switch between NAS and IP pools automatically. I want to be able to use variables in attributes column (for radcheck, radreply, radgroupcheck, and radgroupreply tables). Then FreeRADIUS will get those values for attributes and expand or evaluate them replacing variable placeholders for concrete values. I don't want to modify the configuration file to store any user's configuration as I am currently doing. Will that feature make sense? I can help in programming it or even make a donation to have someone help me in doing this. I post a request on Github: https://github.com/FreeRADIUS/freeradius-server/issues/1870 I was suggested to use SQL xlat expansion %{sql:SELECT ...} but that is not useful in my case because I don't want to customize requests. Regards, Javier

2 5