- Freeradius-Users - lists.freeradius.org

Re: upgrade freeradius vom 2.1.12 to 3.0.x
by Peter Hutchison 25 Feb '16

25 Feb '16

You can use the unofficial Freeradius 3.x package repository for Freeradius 3 packages. Add the PPA site to /etc/apt/sources.list file so you can use apt-get etc. https://launchpad.net/~freeradius/+archive/ubuntu/stable-3.0 Peter Hutchison University of Huddersfield inspiring tomorrow's professionals. [http://marketing.hud.ac.uk/_HOSTED/EmailSig2014/EmailSigFooter.jpg] This transmission is confidential and may be legally privileged. If you receive it in error, please notify us immediately by e-mail and remove it from your system. If the content of this e-mail does not relate to the business of the University of Huddersfield, then we do not endorse it and will accept no liability.

6 12

iPad PEAP MSCHAPv2
by Óscar Remírez de Ganuza Satrústegui 25 Feb '16

25 Feb '16

Good afternoon, As I told on a previous email, we are migrating previous radius (2.1.9) authentication to a new instance of freeradius (3.0.10). I am experiencing some problems authenticating some devices. I have previously tested with eapol_test that the new freeradius is working ok with both: - EAP TTLS - PAP - PEAP - MSCHAPv2 But when testing PEAP on some devices, it is not working properly. It looks I am getting authorized properly, and even authenticated: (11) [mschap] = ok (11) } # Auth-Type MS-CHAP = ok (11) MSCHAP Success But I am not getting a final Access-Accept (nor an Access-Reject), and it the authentication fails.... Any idea where could be the problem? Thanks a lot! 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 dictionary file /usr/local/etc2/freeradius/share/freeradius/dictionary including dictionary file /usr/local/etc2/freeradius/share/freeradius/dictionary.dhcp including dictionary file /usr/local/etc2/freeradius/share/freeradius/dictionary.vqp including dictionary file /usr/local/etc2/freeradius/etc/raddb/dictionary including configuration file /usr/local/etc2/freeradius/etc/raddb/radiusd.conf including configuration file /usr/local/etc2/freeradius/etc/raddb/proxy.conf including configuration file /usr/local/etc2/freeradius/etc/raddb/clients.conf including files in directory /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/cache_eap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/chap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/digest including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/dhcp including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/dynamic_clients including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/eap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/echo including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/exec including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/expiration including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/expr including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/files including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/linelog including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/logintime including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/mschap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ntlm_auth including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/pap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/passwd including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/preprocess including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/radutmp including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/replicate including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/soh including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/sradutmp including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/unix including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/unpack including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/utf8 including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ldap including configuration file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ippool including files in directory /usr/local/etc2/freeradius/etc/raddb/policy.d/ including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/abfab-tr including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/accounting including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/canonicalization including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/control including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/cui including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/debug including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/dhcp including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/eap including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/filter including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/operator-name including configuration file /usr/local/etc2/freeradius/etc/raddb/policy.d/unav.policies including files in directory /usr/local/etc2/freeradius/etc/raddb/sites-enabled/ including configuration file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default including configuration file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel including configuration file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/status main { security { user = "radius" group = "radius" allow_core_dumps = no } name = "radiusd" prefix = "/usr/local/etc2/freeradius" localstatedir = "/usr/local/etc2/freeradius/var" logdir = "/usr/local/etc2/freeradius/var/log/radius" run_dir = "/usr/local/etc2/freeradius/var/run/radiusd" } main { name = "radiusd" prefix = "/usr/local/etc2/freeradius" localstatedir = "/usr/local/etc2/freeradius/var" sbindir = "/usr/local/etc2/freeradius/sbin" logdir = "/usr/local/etc2/freeradius/var/log/radius" run_dir = "/usr/local/etc2/freeradius/var/run/radiusd" libdir = "/usr/local/etc2/freeradius/lib" radacctdir = "/usr/local/etc2/freeradius/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/usr/local/etc2/freeradius/var/run/radiusd/radiusd.pid" checkrad = "/usr/local/etc2/freeradius/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = yes 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 allow_vulnerable_openssl = "CVE-2014-0160" } } 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 radiusproxy1 { ipaddr = 159.23xxxx port = 1812 type = "auth+acct" 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 = 60 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server radiusproxy2 { ipaddr = 159.237xxx port = 1812 type = "auth+acct" 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 = 60 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } realm ~^(.*\.)?unav\.es$ { } realm UNAV-PDC-01 { } realm LOCAL { } realm NULL { } home_server_pool radiusproxy_pool { type = fail-over home_server = xxx home_server = xxx } realm ~.+$ { pool = radiusproxy_pool nostrip } home_server_pool my_auth_failover { type = fail-over home_server = localhost } 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 WirelessSW_Dere { ipaddr = xxx netmask = 32 require_message_authenticator = no secret = <<< secret >>> shortname = "WirelessSW" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client WirelessSW_PRE { ipaddr = xxx netmask = 32 require_message_authenticator = no secret = <<< secret >>> shortname = "WirelessSW" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Debugger not attached # Creating Auth-Type = digest # Creating Autz-Type = Status-Server radiusd: #### Instantiating modules #### # Loaded module rlm_always # Loading module "reject" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Loaded module rlm_cache # Loading module "cache_eap" from file /usr/local/etc2/freeradius/etc/raddb/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_chap # Loading module "chap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/chap # Loaded module rlm_detail # Loading module "detail" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail detail { filename = "/usr/local/etc2/freeradius/var/log/radius/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 } # Loading module "auth_log" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log detail auth_log { filename = "/usr/local/etc2/freeradius/var/log/radius/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 /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log detail reply_log { filename = "/usr/local/etc2/freeradius/var/log/radius/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 /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log detail pre_proxy_log { filename = "/usr/local/etc2/freeradius/var/log/radius/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 /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log detail post_proxy_log { filename = "/usr/local/etc2/freeradius/var/log/radius/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_digest # Loading module "digest" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/digest # Loaded module rlm_dhcp # Loading module "dhcp" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/dhcp # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/dynamic_clients # Loaded module rlm_eap # Loading module "eap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 16384 } # Loaded module rlm_exec # Loading module "echo" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loading module "exec" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loaded module rlm_expiration # Loading module "expiration" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/expiration # Loaded module rlm_expr # Loading module "expr" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" } # Loaded module rlm_files # Loading module "files" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/files files { filename = "/usr/local/etc2/freeradius/etc/raddb/mods-config/files/authorize" acctusersfile = "/usr/local/etc2/freeradius/etc/raddb/mods-config/files/accounting" preproxy_usersfile = "/usr/local/etc2/freeradius/etc/raddb/mods-config/files/pre-proxy" } # Loaded module rlm_linelog # Loading module "linelog" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/linelog linelog { filename = "/usr/local/etc2/freeradius/var/log/radius/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 /usr/local/etc2/freeradius/etc/raddb/mods-enabled/linelog linelog log_accounting { filename = "/usr/local/etc2/freeradius/var/log/radius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_logintime # Loading module "logintime" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loaded module rlm_mschap # Loading module "mschap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Response}:-00}" passchange { } allow_retry = yes } # Loading module "ntlm_auth" from file /usr/local/etc2/freeradius/etc/raddb/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 } # Loaded module rlm_pap # Loading module "pap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_passwd # Loading module "etc_passwd" from file /usr/local/etc2/freeradius/etc/raddb/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_preprocess # Loading module "preprocess" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/preprocess preprocess { huntgroups = "/usr/local/etc2/freeradius/etc/raddb/mods-config/preprocess/huntgroups" hints = "/usr/local/etc2/freeradius/etc/raddb/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_radutmp # Loading module "radutmp" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/radutmp radutmp { filename = "/usr/local/etc2/freeradius/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 384 caller_id = yes } # Loaded module rlm_realm # Loading module "IPASS" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = yes } # Loading module "realmpercent" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\\" ignore_default = no ignore_null = no } # Loaded module rlm_replicate # Loading module "replicate" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/replicate # Loaded module rlm_soh # Loading module "soh" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/soh soh { dhcp = yes } # Loading module "sradutmp" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/sradutmp radutmp sradutmp { filename = "/usr/local/etc2/freeradius/var/log/radius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_unix # Loading module "unix" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/unix unix { radwtmp = "/usr/local/etc2/freeradius/var/log/radius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_unpack # Loading module "unpack" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/unpack # Loaded module rlm_utf8 # Loading module "utf8" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/utf8 # Loaded module rlm_ldap # Loading module "ldap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ldap ldap { server = "ldap.unav.es" identity = "cn=radiusOp,dc=unav,dc=es" password = <<< secret >>> sasl { } user { scope = "sub" access_positive = yes sasl { } } group { filter = "(objectClass=posixGroup)" scope = "sub" name_attribute = "cn" membership_attribute = "member" cacheable_name = no cacheable_dn = no } client { filter = "(objectClass=radiusClient)" scope = "sub" base_dn = "ou=radius,o=accounts,dc=unav,dc=es" } 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 = yes } } Creating attribute LDAP-Group # Loaded module rlm_ippool # Loading module "VPN_IPSEC_CUN" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ippool ippool VPN_IPSEC_CUN { filename = "/usr/local/etc2/freeradius/etc/raddb/db.ippool.VPN.IPSEC.CUN" ip_index = "/usr/local/etc2/freeradius/etc/raddb/db.ipindex.VPN.IPSEC.CUN" key = "%{Acct-Session-Id}" range_start = xxx range_stop = xxx netmask = 255.255.255.0 cache_size = 255 override = no maximum_timeout = 0 } instantiate { } modules { # Instantiating module "reject" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "fail" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "ok" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "handled" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "invalid" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "userlock" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "notfound" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "noop" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "updated" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/always # Instantiating module "attr_filter.post-proxy" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/access_reject # Instantiating module "attr_filter.access_challenge" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/attr_filter reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/attr_filter/accounting_response # Instantiating module "cache_eap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/cache_eap rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked # Instantiating module "detail" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail # Instantiating module "auth_log" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output # Instantiating module "reply_log" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/detail.log # Instantiating module "eap" from file /usr/local/etc2/freeradius/etc/raddb/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 { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 ca_path = "/usr/local/etc2/freeradius/etc/raddb/certs" pem_file_type = yes private_key_file = "/usr/local/etc2/freeradius/etc/raddb/certs/radius.unav.es_privatekey.pem" certificate_file = "/usr/local/etc2/freeradius/etc/raddb/certs/radius.unav.es_cert.pem" ca_file = "/usr/local/etc2/freeradius/etc/raddb/certs/TERENASSL_PATH.pem" dh_file = "/usr/local/etc2/freeradius/etc/raddb/certs/dh" fragment_size = 1024 include_length = yes check_crl = no check_all_crl = no cipher_list = "DEFAULT" ecdh_curve = "prime256v1" cache { enable = yes 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 } } # Linked to sub-module rlm_eap_ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = yes use_tunneled_reply = no 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 = yes use_tunneled_reply = no 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 "expiration" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/expiration # Instantiating module "files" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/files reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/files/authorize reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/files/users.vpn reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/files/accounting reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/files/pre-proxy # Instantiating module "linelog" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/linelog # Instantiating module "log_accounting" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/linelog # Instantiating module "logintime" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/logintime # Instantiating module "mschap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/mschap rlm_mschap (mschap): authenticating by calling 'ntlm_auth' # Instantiating module "pap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/pap # Instantiating module "etc_passwd" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/passwd rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no # Instantiating module "preprocess" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/preprocess reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/preprocess/huntgroups reading pairlist file /usr/local/etc2/freeradius/etc/raddb/mods-config/preprocess/hints # Instantiating module "IPASS" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm # Instantiating module "suffix" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm # Instantiating module "realmpercent" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm # Instantiating module "ntdomain" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/realm # Instantiating module "ldap" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ldap rlm_ldap: libldap vendor: OpenLDAP, version: 20439 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://ldap.unav.es: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://ldap.unav.es: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://ldap.unav.es: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://ldap.unav.es: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://ldap.unav.es:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful # Instantiating module "VPN_IPSEC_CUN" from file /usr/local/etc2/freeradius/etc/raddb/mods-enabled/ippool } # modules radiusd: #### Loading Virtual Servers #### server { # from file /usr/local/etc2/freeradius/etc/raddb/radiusd.conf } # server server default { # from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default # Loading authenticate {...} # Loading authorize {...} # Loading preacct {...} # Loading accounting {...} # Loading session {...} # Loading pre-proxy {...} # Loading post-proxy {...} # Loading post-auth {...} } # server default server inner-tunnel { # from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel # Loading authenticate {...} # Loading authorize {...} # Loading session {...} # Loading post-proxy {...} # Loading post-auth {...} } # server inner-tunnel server status { # from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/status # Loading authorize {...} } # server status radiusd: #### Opening IP addresses and Ports #### 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 } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } listen { type = "status" ipaddr = 127.0.0.1 port = 18121 client admin { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } } 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 auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on status address 127.0.0.1 port 18121 bound to server status Listening on proxy address * port 48633 Listening on proxy address :: port 36571 Ready to process requests (0) Received Access-Request Id 32 from xxxxxx:45903 to xxx12.225:1812 length 215 (0) User-Name = "oscarrdg(a)unav.es" (0) NAS-IP-Address = xxx (0) NAS-Port = 0 (0) NAS-Identifier = "xxx (0) NAS-Port-Type = Wireless-802.11 (0) Calling-Station-Id = "344DF73C9C98" (0) Called-Station-Id = "001A1E003250" (0) Service-Type = Framed-User (0) Framed-MTU = 1100 (0) EAP-Message = 0x02010015016f7363617272646740756e61762e6573 (0) Aruba-Essid-Name = "eduroam-pre" (0) Aruba-Location-Id = "10.9.1" (0) Aruba-AP-Group = "Amigos" (0) Aruba-Device-Type = "Android" (0) Message-Authenticator = 0xaf370dcdcf5551f50dbe03c00a1b1a67 (0) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (0) authorize { (0) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (0) [preprocess] = ok (0) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (0) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxx/auth-detail-20151119 (0) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxx/auth-detail-20151119 (0) auth_log: EXPAND %t (0) auth_log: --> Thu Nov 19 16:13:11 2015 (0) [auth_log] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (0) suffix: Found realm "~^(.*\.)?unav\.es$" (0) suffix: Adding Stripped-User-Name = "oscarrdg" (0) suffix: Adding Realm = "unav.es" (0) suffix: Authentication realm is LOCAL (0) [suffix] = ok (0) ntdomain: Request already has destination realm set. Ignoring (0) [ntdomain] = noop (0) eap: Peer sent EAP Response (code 2) ID 1 length 21 (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (0) authenticate { (0) eap: Peer sent packet with method EAP Identity (1) (0) eap: Calling submodule eap_md5 to process data (0) eap_md5: Issuing MD5 Challenge (0) eap: Sending EAP Request (code 1) ID 2 length 22 (0) eap: EAP session adding &reply:State = 0x4a7c50d94a7e547d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (0) Sent Access-Challenge Id 32 from xxx:1812 to xxx:45903 length 0 (0) EAP-Message = 0x0102001604106a56e58dbbd858bd44f49a49b03bb1d7 (0) Message-Authenticator = 0x00000000000000000000000000000000 (0) State = 0x4a7c50d94a7e547df1395bb8ee5037b2 (0) Finished request Waking up in 4.9 seconds. (1) Received Access-Request Id 237 from xxxxxx:45903 to xx.225:1812 length 218 (1) User-Name = "oscarrdg(a)unav.es" (1) NAS-IP-Address = xxxxxx (1) NAS-Port = 0 (1) NAS-Identifier = "xxxxxx" (1) NAS-Port-Type = Wireless-802.11 (1) Calling-Station-Id = "344DF73C9C98" (1) Called-Station-Id = "001A1E003250" (1) Service-Type = Framed-User (1) Framed-MTU = 1100 (1) EAP-Message = 0x020200060319 (1) State = 0x4a7c50d94a7e547df1395bb8ee5037b2 (1) Aruba-Essid-Name = "eduroam-pre" (1) Aruba-Location-Id = "10.9.1" (1) Aruba-AP-Group = "Amigos" (1) Aruba-Device-Type = "Android" (1) Message-Authenticator = 0x84aefd176e8b40d09dbe4a527366c8b7 (1) session-state: No cached attributes (1) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (1) authorize { (1) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (1) [preprocess] = ok (1) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (1) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (1) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (1) auth_log: EXPAND %t (1) auth_log: --> Thu Nov 19 16:13:11 2015 (1) [auth_log] = ok (1) [chap] = noop (1) [mschap] = noop (1) [digest] = noop (1) suffix: Checking for suffix after "@" (1) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (1) suffix: Found realm "~^(.*\.)?unav\.es$" (1) suffix: Adding Stripped-User-Name = "oscarrdg" (1) suffix: Adding Realm = "unav.es" (1) suffix: Authentication realm is LOCAL (1) [suffix] = ok (1) ntdomain: Request already has destination realm set. Ignoring (1) [ntdomain] = noop (1) eap: Peer sent EAP Response (code 2) ID 2 length 6 (1) eap: No EAP Start, assuming it's an on-going EAP conversation (1) [eap] = updated (1) policy unav.authorize.default { (1) if ( "%{client:group}" == "wireless" ) { (1) EXPAND %{client:group} (1) --> wireless (1) if ( "%{client:group}" == "wireless" ) -> TRUE (1) if ( "%{client:group}" == "wireless" ) { (1) if ( Aruba-Essid-Name == "eduroam" || Aruba-Essid-Name == "eduroam-pre" ) { (1) if ( Aruba-Essid-Name == "eduroam" || Aruba-Essid-Name == "eduroam-pre" ) -> TRUE (1) if ( Aruba-Essid-Name == "eduroam" || Aruba-Essid-Name == "eduroam-pre" ) { (1) policy unav.reject.eduroam.baddomain { (1) if ( Realm =~ /myabc\.com$/i ) { (1) if ( Realm =~ /myabc\.com$/i ) -> FALSE (1) if ( Realm =~ /wlan\.[[:alnum:]]+\.[[:alnum:]]+\.3gppnetwork\.org$/i ) { (1) if ( Realm =~ /wlan\.[[:alnum:]]+\.[[:alnum:]]+\.3gppnetwork\.org$/i ) -> FALSE (1) if ( Realm =~ /gmail\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) { (1) if ( Realm =~ /gmail\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) -> FALSE (1) if ( Realm =~ /yahoo\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) { (1) if ( Realm =~ /yahoo\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) -> FALSE (1) if ( Realm =~ /hotmail\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) { (1) if ( Realm =~ /hotmail\.co(m|\.[[:alnum:]][[:alnum:]])$/i ) -> FALSE (1) } # policy unav.reject.eduroam.baddomain = updated (1) if ( Service-Type == "Login-User" ) { (1) if ( Service-Type == "Login-User" ) -> FALSE (1) } # if ( Aruba-Essid-Name == "eduroam" || Aruba-Essid-Name == "eduroam-pre" ) = updated (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping else for request 1: Preceding "if" was taken (1) } # if ( "%{client:group}" == "wireless" ) = updated (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping elsif for request 1: Preceding "if" was taken (1) ... skipping else for request 1: Preceding "if" was taken (1) } # policy unav.authorize.default = updated (1) [expiration] = noop (1) [logintime] = noop (1) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type (1) pap: WARNING: Authentication will fail unless a "known good" password is available (1) [pap] = noop (1) if (control:Cleartext-Password) { (1) if (control:Cleartext-Password) -> FALSE (1) } # authorize = updated (1) Found Auth-Type = EAP (1) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (1) authenticate { (1) eap: Expiring EAP session with state 0x4a7c50d94a7e547d (1) eap: Finished EAP session with state 0x4a7c50d94a7e547d (1) eap: Previous EAP request found for state 0x4a7c50d94a7e547d, released from the list (1) eap: Peer sent packet with method EAP NAK (3) (1) eap: Found mutually acceptable type PEAP (25) (1) eap: Calling submodule eap_peap to process data (1) eap_peap: Initiating new EAP-TLS session (1) eap_peap: Flushing SSL sessions (of #0) (1) eap_peap: [eaptls start] = request (1) eap: Sending EAP Request (code 1) ID 3 length 6 (1) eap: EAP session adding &reply:State = 0x4a7c50d94b7f497d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (1) Sent Access-Challenge Id 237 from xxx12.225:1812 to xxxxxx:45903 length 0 (1) EAP-Message = 0x010300061920 (1) Message-Authenticator = 0x00000000000000000000000000000000 (1) State = 0x4a7c50d94b7f497df1395bb8ee5037b2 (1) Finished request Waking up in 4.9 seconds. (2) Received Access-Request Id 126 from xxxxxx:45903 to xxx12.225:1812 length 380 (2) User-Name = "oscarrdg(a)unav.es" (2) NAS-IP-Address = xxxxxx (2) NAS-Port = 0 (2) NAS-Identifier = "xxxxxx" (2) NAS-Port-Type = Wireless-802.11 (2) Calling-Station-Id = "344DF73C9C98" (2) Called-Station-Id = "001A1E003250" (2) Service-Type = Framed-User (2) Framed-MTU = 1100 (2) EAP-Message = 0x020300a819800000009e160301009901000095030389bc40fcda2b3a01d0bd76bc2cd77cc2a31e6d59aa10c82aba3cd714a628ceca00003cc02cc030009fc02bc02f009ec00ac024c014c0280039006bc009c023c013c02700330067c007c011009d009c0035003d002f003c00050004000a00ff010000 (2) State = 0x4a7c50d94b7f497df1395bb8ee5037b2 (2) Aruba-Essid-Name = "eduroam-pre" (2) Aruba-Location-Id = "10.9.1" (2) Aruba-AP-Group = "Amigos" (2) Aruba-Device-Type = "Android" (2) Message-Authenticator = 0x5a70fd8f3ee58367fba8226efb8fca04 (2) session-state: No cached attributes (2) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (2) authorize { (2) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (2) [preprocess] = ok (2) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (2) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (2) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (2) auth_log: EXPAND %t (2) auth_log: --> Thu Nov 19 16:13:11 2015 (2) [auth_log] = ok (2) [chap] = noop (2) [mschap] = noop (2) [digest] = noop (2) suffix: Checking for suffix after "@" (2) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (2) suffix: Found realm "~^(.*\.)?unav\.es$" (2) suffix: Adding Stripped-User-Name = "oscarrdg" (2) suffix: Adding Realm = "unav.es" (2) suffix: Authentication realm is LOCAL (2) [suffix] = ok (2) ntdomain: Request already has destination realm set. Ignoring (2) [ntdomain] = noop (2) eap: Peer sent EAP Response (code 2) ID 3 length 168 (2) eap: Continuing tunnel setup (2) [eap] = ok (2) } # authorize = ok (2) Found Auth-Type = EAP (2) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (2) authenticate { (2) eap: Expiring EAP session with state 0x4a7c50d94b7f497d (2) eap: Finished EAP session with state 0x4a7c50d94b7f497d (2) eap: Previous EAP request found for state 0x4a7c50d94b7f497d, released from the list (2) eap: Peer sent packet with method EAP PEAP (25) (2) eap: Calling submodule eap_peap to process data (2) eap_peap: Continuing EAP-TLS (2) eap_peap: Peer indicated complete TLS record size will be 158 bytes (2) eap_peap: Got complete TLS record (158 bytes) (2) eap_peap: [eaptls verify] = length included (2) eap_peap: (other): before/accept initialization (2) eap_peap: TLS_accept: before/accept initialization (2) eap_peap: <<< TLS 1.2 [length 0099] (2) eap_peap: TLS_accept: SSLv3 read client hello A (2) eap_peap: >>> TLS 1.2 [length 0059] (2) eap_peap: TLS_accept: SSLv3 write server hello A (2) eap_peap: >>> TLS 1.2 [length 11ce] (2) eap_peap: TLS_accept: SSLv3 write certificate A (2) eap_peap: >>> TLS 1.2 [length 014d] (2) eap_peap: TLS_accept: SSLv3 write key exchange A (2) eap_peap: >>> TLS 1.2 [length 0004] (2) eap_peap: TLS_accept: SSLv3 write server done A (2) eap_peap: TLS_accept: SSLv3 flush data (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A (2) eap_peap: In SSL Handshake Phase (2) eap_peap: In SSL Accept mode (2) eap_peap: [eaptls process] = handled (2) eap: Sending EAP Request (code 1) ID 4 length 1004 (2) eap: EAP session adding &reply:State = 0x4a7c50d94878497d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (2) Sent Access-Challenge Id 126 from xxx12.225:1812 to xxxxxx:45903 length 0 (2) EAP-Message = 0x010403ec19c00000138c1603030059020000550303564de7077094b72f12c56237fbc9affbe100f088a0685fec0f9239b56ae77d0620e7b0567766cb019801cfbfed0facaa4f74a4e4e1bf48c6e2807b179ab3eab127c03000000dff01000100000b00040300010216030311ce0b0011ca0011c70004a5 (2) Message-Authenticator = 0x00000000000000000000000000000000 (2) State = 0x4a7c50d94878497df1395bb8ee5037b2 (2) Finished request Waking up in 4.9 seconds. (3) Received Access-Request Id 64 from xxxxxx:45903 to xxx12.225:1812 length 218 (3) User-Name = "oscarrdg(a)unav.es" (3) NAS-IP-Address = xxxxxx (3) NAS-Port = 0 (3) NAS-Identifier = "xxxxxx" (3) NAS-Port-Type = Wireless-802.11 (3) Calling-Station-Id = "344DF73C9C98" (3) Called-Station-Id = "001A1E003250" (3) Service-Type = Framed-User (3) Framed-MTU = 1100 (3) EAP-Message = 0x020400061900 (3) State = 0x4a7c50d94878497df1395bb8ee5037b2 (3) Aruba-Essid-Name = "eduroam-pre" (3) Aruba-Location-Id = "10.9.1" (3) Aruba-AP-Group = "Amigos" (3) Aruba-Device-Type = "Android" (3) Message-Authenticator = 0x3aec9ff6dcbdf02f48d43f32e48157e4 (3) session-state: No cached attributes (3) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (3) authorize { (3) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (3) [preprocess] = ok (3) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (3) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (3) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (3) auth_log: EXPAND %t (3) auth_log: --> Thu Nov 19 16:13:11 2015 (3) [auth_log] = ok (3) [chap] = noop (3) [mschap] = noop (3) [digest] = noop (3) suffix: Checking for suffix after "@" (3) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (3) suffix: Found realm "~^(.*\.)?unav\.es$" (3) suffix: Adding Stripped-User-Name = "oscarrdg" (3) suffix: Adding Realm = "unav.es" (3) suffix: Authentication realm is LOCAL (3) [suffix] = ok (3) ntdomain: Request already has destination realm set. Ignoring (3) [ntdomain] = noop (3) eap: Peer sent EAP Response (code 2) ID 4 length 6 (3) eap: Continuing tunnel setup (3) [eap] = ok (3) } # authorize = ok (3) Found Auth-Type = EAP (3) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (3) authenticate { (3) eap: Expiring EAP session with state 0x4a7c50d94878497d (3) eap: Finished EAP session with state 0x4a7c50d94878497d (3) eap: Previous EAP request found for state 0x4a7c50d94878497d, released from the list (3) eap: Peer sent packet with method EAP PEAP (25) (3) eap: Calling submodule eap_peap to process data (3) eap_peap: Continuing EAP-TLS (3) eap_peap: Peer ACKed our handshake fragment (3) eap_peap: [eaptls verify] = request (3) eap_peap: [eaptls process] = handled (3) eap: Sending EAP Request (code 1) ID 5 length 1000 (3) eap: EAP session adding &reply:State = 0x4a7c50d94979497d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (3) Sent Access-Challenge Id 64 from xxx12.225:1812 to xxxxxx:45903 length 0 (3) EAP-Message = 0x010503e819402e73692e756e61762e6573820f7261646975732e756e61762e656475300d06092a864886f70d010105050003820101008d5a00339dca417d4b5b7c98c5d05763925d58ea76ff6431c64313da556a5d759f867846b256881352385407721c3b81539755438573a805ecb0acdf0a94a9f874 (3) Message-Authenticator = 0x00000000000000000000000000000000 (3) State = 0x4a7c50d94979497df1395bb8ee5037b2 (3) Finished request Waking up in 4.9 seconds. (4) Received Access-Request Id 234 from xxxxxx:45903 to xxx12.225:1812 length 218 (4) User-Name = "oscarrdg(a)unav.es" (4) NAS-IP-Address = xxxxxx (4) NAS-Port = 0 (4) NAS-Identifier = "xxxxxx" (4) NAS-Port-Type = Wireless-802.11 (4) Calling-Station-Id = "344DF73C9C98" (4) Called-Station-Id = "001A1E003250" (4) Service-Type = Framed-User (4) Framed-MTU = 1100 (4) EAP-Message = 0x020500061900 (4) State = 0x4a7c50d94979497df1395bb8ee5037b2 (4) Aruba-Essid-Name = "eduroam-pre" (4) Aruba-Location-Id = "10.9.1" (4) Aruba-AP-Group = "Amigos" (4) Aruba-Device-Type = "Android" (4) Message-Authenticator = 0x8a034f3911b75ff877975ad4bec02ff4 (4) session-state: No cached attributes (4) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (4) authorize { (4) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (4) [preprocess] = ok (4) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (4) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (4) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (4) auth_log: EXPAND %t (4) auth_log: --> Thu Nov 19 16:13:11 2015 (4) [auth_log] = ok (4) [chap] = noop (4) [mschap] = noop (4) [digest] = noop (4) suffix: Checking for suffix after "@" (4) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (4) suffix: Found realm "~^(.*\.)?unav\.es$" (4) suffix: Adding Stripped-User-Name = "oscarrdg" (4) suffix: Adding Realm = "unav.es" (4) suffix: Authentication realm is LOCAL (4) [suffix] = ok (4) ntdomain: Request already has destination realm set. Ignoring (4) [ntdomain] = noop (4) eap: Peer sent EAP Response (code 2) ID 5 length 6 (4) eap: Continuing tunnel setup (4) [eap] = ok (4) } # authorize = ok (4) Found Auth-Type = EAP (4) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (4) authenticate { (4) eap: Expiring EAP session with state 0x4a7c50d94979497d (4) eap: Finished EAP session with state 0x4a7c50d94979497d (4) eap: Previous EAP request found for state 0x4a7c50d94979497d, released from the list (4) eap: Peer sent packet with method EAP PEAP (25) (4) eap: Calling submodule eap_peap to process data (4) eap_peap: Continuing EAP-TLS (4) eap_peap: Peer ACKed our handshake fragment (4) eap_peap: [eaptls verify] = request (4) eap_peap: [eaptls process] = handled (4) eap: Sending EAP Request (code 1) ID 6 length 1000 (4) eap: EAP session adding &reply:State = 0x4a7c50d94e7a497d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (4) Sent Access-Challenge Id 234 from xxx12.225:1812 to xxxxxx:45903 length 0 (4) EAP-Message = 0x010603e8194002010030180603551d200411300f300d060b2b06010401b2310102021d30440603551d1f043d303b3039a037a0358633687474703a2f2f63726c2e7573657274727573742e636f6d2f55544e2d5553455246697273742d48617264776172652e63726c307406082b060105050701010468 (4) Message-Authenticator = 0x00000000000000000000000000000000 (4) State = 0x4a7c50d94e7a497df1395bb8ee5037b2 (4) Finished request Waking up in 4.9 seconds. (5) Received Access-Request Id 230 from xxxxxx:45903 to xxx12.225:1812 length 218 (5) User-Name = "oscarrdg(a)unav.es" (5) NAS-IP-Address = xxxxxx (5) NAS-Port = 0 (5) NAS-Identifier = "xxxxxx" (5) NAS-Port-Type = Wireless-802.11 (5) Calling-Station-Id = "344DF73C9C98" (5) Called-Station-Id = "001A1E003250" (5) Service-Type = Framed-User (5) Framed-MTU = 1100 (5) EAP-Message = 0x020600061900 (5) State = 0x4a7c50d94e7a497df1395bb8ee5037b2 (5) Aruba-Essid-Name = "eduroam-pre" (5) Aruba-Location-Id = "10.9.1" (5) Aruba-AP-Group = "Amigos" (5) Aruba-Device-Type = "Android" (5) Message-Authenticator = 0x27a324ae82db56460d95f8e34748e3a8 (5) session-state: No cached attributes (5) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (5) authorize { (5) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (5) [preprocess] = ok (5) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (5) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (5) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (5) auth_log: EXPAND %t (5) auth_log: --> Thu Nov 19 16:13:11 2015 (5) [auth_log] = ok (5) [chap] = noop (5) [mschap] = noop (5) [digest] = noop (5) suffix: Checking for suffix after "@" (5) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (5) suffix: Found realm "~^(.*\.)?unav\.es$" (5) suffix: Adding Stripped-User-Name = "oscarrdg" (5) suffix: Adding Realm = "unav.es" (5) suffix: Authentication realm is LOCAL (5) [suffix] = ok (5) ntdomain: Request already has destination realm set. Ignoring (5) [ntdomain] = noop (5) eap: Peer sent EAP Response (code 2) ID 6 length 6 (5) eap: Continuing tunnel setup (5) [eap] = ok (5) } # authorize = ok (5) Found Auth-Type = EAP (5) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (5) authenticate { (5) eap: Expiring EAP session with state 0x4a7c50d94e7a497d (5) eap: Finished EAP session with state 0x4a7c50d94e7a497d (5) eap: Previous EAP request found for state 0x4a7c50d94e7a497d, released from the list (5) eap: Peer sent packet with method EAP PEAP (25) (5) eap: Calling submodule eap_peap to process data (5) eap_peap: Continuing EAP-TLS (5) eap_peap: Peer ACKed our handshake fragment (5) eap_peap: [eaptls verify] = request (5) eap_peap: [eaptls process] = handled (5) eap: Sending EAP Request (code 1) ID 7 length 1000 (5) eap: EAP session adding &reply:State = 0x4a7c50d94f7b497d (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 /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (5) Sent Access-Challenge Id 230 from xxx12.225:1812 to xxxxxx:45903 length 0 (5) EAP-Message = 0x010703e8194007386ec3a55e23bc459b7b50c1c9308fdbe52b7ad35bfb33401ea0d59817bc8b87c389d35da08eb2aaaaf68e698806c5fa8921f3089d692e09339b290d460f8ccc4934b06951bdf906cd68ad664cbc3eac61bd0a880ec8df3dee7c044c9d0a5e6b91d6eec7ed288dab4d878973d06ea4d0 (5) Message-Authenticator = 0x00000000000000000000000000000000 (5) State = 0x4a7c50d94f7b497df1395bb8ee5037b2 (5) Finished request Waking up in 4.9 seconds. (6) Received Access-Request Id 168 from xxxxxx:45903 to xxx12.225:1812 length 218 (6) User-Name = "oscarrdg(a)unav.es" (6) NAS-IP-Address = xxxxxx (6) NAS-Port = 0 (6) NAS-Identifier = "xxxxxx" (6) NAS-Port-Type = Wireless-802.11 (6) Calling-Station-Id = "344DF73C9C98" (6) Called-Station-Id = "001A1E003250" (6) Service-Type = Framed-User (6) Framed-MTU = 1100 (6) EAP-Message = 0x020700061900 (6) State = 0x4a7c50d94f7b497df1395bb8ee5037b2 (6) Aruba-Essid-Name = "eduroam-pre" (6) Aruba-Location-Id = "10.9.1" (6) Aruba-AP-Group = "Amigos" (6) Aruba-Device-Type = "Android" (6) Message-Authenticator = 0x4cf19771edbbc663364c4e61d84ea4ca (6) session-state: No cached attributes (6) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (6) authorize { (6) policy filter_username { (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 =~ /\.\./ ) { (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) } # policy filter_username = notfound (6) [preprocess] = ok (6) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (6) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (6) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (6) auth_log: EXPAND %t (6) auth_log: --> Thu Nov 19 16:13:11 2015 (6) [auth_log] = ok (6) [chap] = noop (6) [mschap] = noop (6) [digest] = noop (6) suffix: Checking for suffix after "@" (6) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (6) suffix: Found realm "~^(.*\.)?unav\.es$" (6) suffix: Adding Stripped-User-Name = "oscarrdg" (6) suffix: Adding Realm = "unav.es" (6) suffix: Authentication realm is LOCAL (6) [suffix] = ok (6) ntdomain: Request already has destination realm set. Ignoring (6) [ntdomain] = noop (6) eap: Peer sent EAP Response (code 2) ID 7 length 6 (6) eap: Continuing tunnel setup (6) [eap] = ok (6) } # authorize = ok (6) Found Auth-Type = EAP (6) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (6) authenticate { (6) eap: Expiring EAP session with state 0x4a7c50d94f7b497d (6) eap: Finished EAP session with state 0x4a7c50d94f7b497d (6) eap: Previous EAP request found for state 0x4a7c50d94f7b497d, released from the list (6) eap: Peer sent packet with method EAP PEAP (25) (6) eap: Calling submodule eap_peap to process data (6) eap_peap: Continuing EAP-TLS (6) eap_peap: Peer ACKed our handshake fragment (6) eap_peap: [eaptls verify] = request (6) eap_peap: [eaptls process] = handled (6) eap: Sending EAP Request (code 1) ID 8 length 1000 (6) eap: EAP session adding &reply:State = 0x4a7c50d94c74497d (6) [eap] = handled (6) } # authenticate = handled (6) Using Post-Auth-Type Challenge (6) Post-Auth-Type sub-section not found. Ignoring. (6) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (6) Sent Access-Challenge Id 168 from xxx12.225:1812 to xxxxxx:45903 length 0 (6) EAP-Message = 0x010803e81940e8329e74cac89054e9c65f0f789d9a403c0eac61aa5e148f9e87a16a50dcd79a4eaf05b3a671949c71b350600ac7139d38078602a8e9a869261890ab4cb04f23ab3a4f84d8dfce9fe1696fbbd742d76b44e4c7adee6d415f725a710837b37965a459a09437f7002f0dc29272dad03872db (6) Message-Authenticator = 0x00000000000000000000000000000000 (6) State = 0x4a7c50d94c74497df1395bb8ee5037b2 (6) Finished request Waking up in 4.8 seconds. (7) Received Access-Request Id 112 from xxxxxx:45903 to xxx12.225:1812 length 218 (7) User-Name = "oscarrdg(a)unav.es" (7) NAS-IP-Address = xxxxxx (7) NAS-Port = 0 (7) NAS-Identifier = "xxxxxx" (7) NAS-Port-Type = Wireless-802.11 (7) Calling-Station-Id = "344DF73C9C98" (7) Called-Station-Id = "001A1E003250" (7) Service-Type = Framed-User (7) Framed-MTU = 1100 (7) EAP-Message = 0x020800061900 (7) State = 0x4a7c50d94c74497df1395bb8ee5037b2 (7) Aruba-Essid-Name = "eduroam-pre" (7) Aruba-Location-Id = "10.9.1" (7) Aruba-AP-Group = "Amigos" (7) Aruba-Device-Type = "Android" (7) Message-Authenticator = 0x15bf70b018be20dac76d5bdc4532dc08 (7) session-state: No cached attributes (7) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (7) authorize { (7) policy filter_username { (7) if (!&User-Name) { (7) if (!&User-Name) -> FALSE (7) if (&User-Name =~ / /) { (7) if (&User-Name =~ / /) -> FALSE (7) if (&User-Name =~ /@.*@/ ) { (7) if (&User-Name =~ /@.*@/ ) -> FALSE (7) if (&User-Name =~ /\.\./ ) { (7) if (&User-Name =~ /\.\./ ) -> FALSE (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (7) if (&User-Name =~ /\.$/) { (7) if (&User-Name =~ /\.$/) -> FALSE (7) if (&User-Name =~ /(a)\./) { (7) if (&User-Name =~ /(a)\./) -> FALSE (7) } # policy filter_username = notfound (7) [preprocess] = ok (7) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (7) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (7) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (7) auth_log: EXPAND %t (7) auth_log: --> Thu Nov 19 16:13:11 2015 (7) [auth_log] = ok (7) [chap] = noop (7) [mschap] = noop (7) [digest] = noop (7) suffix: Checking for suffix after "@" (7) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (7) suffix: Found realm "~^(.*\.)?unav\.es$" (7) suffix: Adding Stripped-User-Name = "oscarrdg" (7) suffix: Adding Realm = "unav.es" (7) suffix: Authentication realm is LOCAL (7) [suffix] = ok (7) ntdomain: Request already has destination realm set. Ignoring (7) [ntdomain] = noop (7) eap: Peer sent EAP Response (code 2) ID 8 length 6 (7) eap: Continuing tunnel setup (7) [eap] = ok (7) } # authorize = ok (7) Found Auth-Type = EAP (7) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (7) authenticate { (7) eap: Expiring EAP session with state 0x4a7c50d94c74497d (7) eap: Finished EAP session with state 0x4a7c50d94c74497d (7) eap: Previous EAP request found for state 0x4a7c50d94c74497d, released from the list (7) eap: Peer sent packet with method EAP PEAP (25) (7) eap: Calling submodule eap_peap to process data (7) eap_peap: Continuing EAP-TLS (7) eap_peap: Peer ACKed our handshake fragment (7) eap_peap: [eaptls verify] = request (7) eap_peap: [eaptls process] = handled (7) eap: Sending EAP Request (code 1) ID 9 length 40 (7) eap: EAP session adding &reply:State = 0x4a7c50d94d75497d (7) [eap] = handled (7) } # authenticate = handled (7) Using Post-Auth-Type Challenge (7) Post-Auth-Type sub-section not found. Ignoring. (7) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (7) Sent Access-Challenge Id 112 from xxx12.225:1812 to xxxxxx:45903 length 0 (7) EAP-Message = 0x0109002819007b286bccc4f4c141f4ea5ef8a1b16dd15183d01b5b81d5a4c616030300040e000000 (7) Message-Authenticator = 0x00000000000000000000000000000000 (7) State = 0x4a7c50d94d75497df1395bb8ee5037b2 (7) Finished request Waking up in 4.8 seconds. (8) Received Access-Request Id 251 from xxxxxx:45903 to xxx12.225:1812 length 348 (8) User-Name = "oscarrdg(a)unav.es" (8) NAS-IP-Address = xxxxxx (8) NAS-Port = 0 (8) NAS-Identifier = "xxxxxx" (8) NAS-Port-Type = Wireless-802.11 (8) Calling-Station-Id = "344DF73C9C98" (8) Called-Station-Id = "001A1E003250" (8) Service-Type = Framed-User (8) Framed-MTU = 1100 (8) EAP-Message = 0x0209008819800000007e160303004610000042410497d6d49495961db556fda8b469384d890ed741e0f137449e864c9a78bac1d3300980cf8556274e7270cfd6d411d7dee9cd216a49a794311cb559d577fdbeb832140303000101160303002800000000000000001e3ac64ea847ecf6941ba645884a54 (8) State = 0x4a7c50d94d75497df1395bb8ee5037b2 (8) Aruba-Essid-Name = "eduroam-pre" (8) Aruba-Location-Id = "10.9.1" (8) Aruba-AP-Group = "Amigos" (8) Aruba-Device-Type = "Android" (8) Message-Authenticator = 0x863b805103353c3f87d71a7ead7cb041 (8) session-state: No cached attributes (8) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (8) authorize { (8) policy filter_username { (8) if (!&User-Name) { (8) if (!&User-Name) -> FALSE (8) if (&User-Name =~ / /) { (8) if (&User-Name =~ / /) -> FALSE (8) if (&User-Name =~ /@.*@/ ) { (8) if (&User-Name =~ /@.*@/ ) -> FALSE (8) if (&User-Name =~ /\.\./ ) { (8) if (&User-Name =~ /\.\./ ) -> FALSE (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (8) if (&User-Name =~ /\.$/) { (8) if (&User-Name =~ /\.$/) -> FALSE (8) if (&User-Name =~ /(a)\./) { (8) if (&User-Name =~ /(a)\./) -> FALSE (8) } # policy filter_username = notfound (8) [preprocess] = ok (8) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (8) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (8) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (8) auth_log: EXPAND %t (8) auth_log: --> Thu Nov 19 16:13:11 2015 (8) [auth_log] = ok (8) [chap] = noop (8) [mschap] = noop (8) [digest] = noop (8) suffix: Checking for suffix after "@" (8) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (8) suffix: Found realm "~^(.*\.)?unav\.es$" (8) suffix: Adding Stripped-User-Name = "oscarrdg" (8) suffix: Adding Realm = "unav.es" (8) suffix: Authentication realm is LOCAL (8) [suffix] = ok (8) ntdomain: Request already has destination realm set. Ignoring (8) [ntdomain] = noop (8) eap: Peer sent EAP Response (code 2) ID 9 length 136 (8) eap: Continuing tunnel setup (8) [eap] = ok (8) } # authorize = ok (8) Found Auth-Type = EAP (8) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (8) authenticate { (8) eap: Expiring EAP session with state 0x4a7c50d94d75497d (8) eap: Finished EAP session with state 0x4a7c50d94d75497d (8) eap: Previous EAP request found for state 0x4a7c50d94d75497d, released from the list (8) eap: Peer sent packet with method EAP PEAP (25) (8) eap: Calling submodule eap_peap to process data (8) eap_peap: Continuing EAP-TLS (8) eap_peap: Peer indicated complete TLS record size will be 126 bytes (8) eap_peap: Got complete TLS record (126 bytes) (8) eap_peap: [eaptls verify] = length included (8) eap_peap: <<< TLS 1.2 [length 0046] (8) eap_peap: TLS_accept: SSLv3 read client key exchange A (8) eap_peap: <<< TLS 1.2 [length 0001] (8) eap_peap: <<< TLS 1.2 [length 0010] (8) eap_peap: TLS_accept: SSLv3 read finished A (8) eap_peap: >>> TLS 1.2 [length 0001] (8) eap_peap: TLS_accept: SSLv3 write change cipher spec A (8) eap_peap: >>> TLS 1.2 [length 0010] (8) eap_peap: TLS_accept: SSLv3 write finished A (8) eap_peap: TLS_accept: SSLv3 flush data (8) eap_peap: (other): SSL negotiation finished successfully (8) eap_peap: SSL Connection Established (8) eap_peap: [eaptls process] = handled (8) eap: Sending EAP Request (code 1) ID 10 length 57 (8) eap: EAP session adding &reply:State = 0x4a7c50d94276497d (8) [eap] = handled (8) } # authenticate = handled (8) Using Post-Auth-Type Challenge (8) Post-Auth-Type sub-section not found. Ignoring. (8) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (8) Sent Access-Challenge Id 251 from xxx12.225:1812 to xxxxxx:45903 length 0 (8) EAP-Message = 0x010a0039190014030300010116030300286a2a84ab3ae80e62498198297caa9815c5334160580029e175eff17a7ecb2046472a0c0a01428bea (8) Message-Authenticator = 0x00000000000000000000000000000000 (8) State = 0x4a7c50d94276497df1395bb8ee5037b2 (8) Finished request Waking up in 4.8 seconds. (9) Received Access-Request Id 182 from xxxxxx:45903 to xxx12.225:1812 length 218 (9) User-Name = "oscarrdg(a)unav.es" (9) NAS-IP-Address = xxxxxx (9) NAS-Port = 0 (9) NAS-Identifier = "xxxxxx" (9) NAS-Port-Type = Wireless-802.11 (9) Calling-Station-Id = "344DF73C9C98" (9) Called-Station-Id = "001A1E003250" (9) Service-Type = Framed-User (9) Framed-MTU = 1100 (9) EAP-Message = 0x020a00061900 (9) State = 0x4a7c50d94276497df1395bb8ee5037b2 (9) Aruba-Essid-Name = "eduroam-pre" (9) Aruba-Location-Id = "10.9.1" (9) Aruba-AP-Group = "Amigos" (9) Aruba-Device-Type = "Android" (9) Message-Authenticator = 0x87e40768b0a6aedf20a4315cfe75d952 (9) session-state: No cached attributes (9) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (9) authorize { (9) policy filter_username { (9) if (!&User-Name) { (9) if (!&User-Name) -> FALSE (9) if (&User-Name =~ / /) { (9) if (&User-Name =~ / /) -> FALSE (9) if (&User-Name =~ /@.*@/ ) { (9) if (&User-Name =~ /@.*@/ ) -> FALSE (9) if (&User-Name =~ /\.\./ ) { (9) if (&User-Name =~ /\.\./ ) -> FALSE (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (9) if (&User-Name =~ /\.$/) { (9) if (&User-Name =~ /\.$/) -> FALSE (9) if (&User-Name =~ /(a)\./) { (9) if (&User-Name =~ /(a)\./) -> FALSE (9) } # policy filter_username = notfound (9) [preprocess] = ok (9) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (9) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (9) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (9) auth_log: EXPAND %t (9) auth_log: --> Thu Nov 19 16:13:11 2015 (9) [auth_log] = ok (9) [chap] = noop (9) [mschap] = noop (9) [digest] = noop (9) suffix: Checking for suffix after "@" (9) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (9) suffix: Found realm "~^(.*\.)?unav\.es$" (9) suffix: Adding Stripped-User-Name = "oscarrdg" (9) suffix: Adding Realm = "unav.es" (9) suffix: Authentication realm is LOCAL (9) [suffix] = ok (9) ntdomain: Request already has destination realm set. Ignoring (9) [ntdomain] = noop (9) eap: Peer sent EAP Response (code 2) ID 10 length 6 (9) eap: Continuing tunnel setup (9) [eap] = ok (9) } # authorize = ok (9) Found Auth-Type = EAP (9) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (9) authenticate { (9) eap: Expiring EAP session with state 0x4a7c50d94276497d (9) eap: Finished EAP session with state 0x4a7c50d94276497d (9) eap: Previous EAP request found for state 0x4a7c50d94276497d, released from the list (9) eap: Peer sent packet with method EAP PEAP (25) (9) eap: Calling submodule eap_peap to process data (9) eap_peap: Continuing EAP-TLS (9) eap_peap: Peer ACKed our handshake fragment. handshake is finished (9) eap_peap: [eaptls verify] = success (9) eap_peap: [eaptls process] = success (9) eap_peap: Session established. Decoding tunneled attributes (9) eap_peap: PEAP state TUNNEL ESTABLISHED (9) eap: Sending EAP Request (code 1) ID 11 length 40 (9) eap: EAP session adding &reply:State = 0x4a7c50d94377497d (9) [eap] = handled (9) } # authenticate = handled (9) Using Post-Auth-Type Challenge (9) Post-Auth-Type sub-section not found. Ignoring. (9) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (9) Sent Access-Challenge Id 182 from xxx12.225:1812 to xxxxxx:45903 length 0 (9) EAP-Message = 0x010b00281900170303001d6a2a84ab3ae80e6307de0ca3236f93adbf36e1a25d41545a9a71de0be3 (9) Message-Authenticator = 0x00000000000000000000000000000000 (9) State = 0x4a7c50d94377497df1395bb8ee5037b2 (9) Finished request Waking up in 4.8 seconds. (10) Received Access-Request Id 92 from xxxxxx:45903 to xxx12.225:1812 length 264 (10) User-Name = "oscarrdg(a)unav.es" (10) NAS-IP-Address = xxxxxx (10) NAS-Port = 0 (10) NAS-Identifier = "xxxxxx" (10) NAS-Port-Type = Wireless-802.11 (10) Calling-Station-Id = "344DF73C9C98" (10) Called-Station-Id = "001A1E003250" (10) Service-Type = Framed-User (10) Framed-MTU = 1100 (10) EAP-Message = 0x020b00341900170303002900000000000000019b4ab8036a75b9c14b9fbef72722cf152e7eae150e66cd2df891b0db7b49041513 (10) State = 0x4a7c50d94377497df1395bb8ee5037b2 (10) Aruba-Essid-Name = "eduroam-pre" (10) Aruba-Location-Id = "10.9.1" (10) Aruba-AP-Group = "Amigos" (10) Aruba-Device-Type = "Android" (10) Message-Authenticator = 0x3ed798db1779514513dd6cf8a43755bc (10) session-state: No cached attributes (10) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (10) authorize { (10) policy filter_username { (10) if (!&User-Name) { (10) if (!&User-Name) -> FALSE (10) if (&User-Name =~ / /) { (10) if (&User-Name =~ / /) -> FALSE (10) if (&User-Name =~ /@.*@/ ) { (10) if (&User-Name =~ /@.*@/ ) -> FALSE (10) if (&User-Name =~ /\.\./ ) { (10) if (&User-Name =~ /\.\./ ) -> FALSE (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (10) if (&User-Name =~ /\.$/) { (10) if (&User-Name =~ /\.$/) -> FALSE (10) if (&User-Name =~ /(a)\./) { (10) if (&User-Name =~ /(a)\./) -> FALSE (10) } # policy filter_username = notfound (10) [preprocess] = ok (10) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (10) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (10) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (10) auth_log: EXPAND %t (10) auth_log: --> Thu Nov 19 16:13:11 2015 (10) [auth_log] = ok (10) [chap] = noop (10) [mschap] = noop (10) [digest] = noop (10) suffix: Checking for suffix after "@" (10) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (10) suffix: Found realm "~^(.*\.)?unav\.es$" (10) suffix: Adding Stripped-User-Name = "oscarrdg" (10) suffix: Adding Realm = "unav.es" (10) suffix: Authentication realm is LOCAL (10) [suffix] = ok (10) ntdomain: Request already has destination realm set. Ignoring (10) [ntdomain] = noop (10) eap: Peer sent EAP Response (code 2) ID 11 length 52 (10) eap: Continuing tunnel setup (10) [eap] = ok (10) } # authorize = ok (10) Found Auth-Type = EAP (10) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (10) authenticate { (10) eap: Expiring EAP session with state 0x4a7c50d94377497d (10) eap: Finished EAP session with state 0x4a7c50d94377497d (10) eap: Previous EAP request found for state 0x4a7c50d94377497d, released from the list (10) eap: Peer sent packet with method EAP PEAP (25) (10) eap: Calling submodule eap_peap to process data (10) eap_peap: Continuing EAP-TLS (10) eap_peap: [eaptls verify] = ok (10) eap_peap: Done initial handshake (10) eap_peap: [eaptls process] = ok (10) eap_peap: Session established. Decoding tunneled attributes (10) eap_peap: PEAP state WAITING FOR INNER IDENTITY (10) eap_peap: Identity - oscarrdg(a)unav.es (10) eap_peap: Got inner identity 'oscarrdg(a)unav.es' (10) eap_peap: Setting default EAP type for tunneled EAP session (10) eap_peap: Got tunneled request (10) eap_peap: EAP-Message = 0x020b0015016f7363617272646740756e61762e6573 (10) eap_peap: Setting User-Name to oscarrdg(a)unav.es (10) eap_peap: Sending tunneled request to inner-tunnel (10) eap_peap: EAP-Message = 0x020b0015016f7363617272646740756e61762e6573 (10) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (10) eap_peap: User-Name = "oscarrdg(a)unav.es" (10) eap_peap: NAS-IP-Address = xxxxxx (10) eap_peap: NAS-Port = 0 (10) eap_peap: NAS-Identifier = "xxxxxx" (10) eap_peap: NAS-Port-Type = Wireless-802.11 (10) eap_peap: Calling-Station-Id = "344DF73C9C98" (10) eap_peap: Called-Station-Id = "001A1E003250" (10) eap_peap: Service-Type = Framed-User (10) eap_peap: Framed-MTU = 1100 (10) eap_peap: Aruba-Essid-Name = "eduroam-pre" (10) eap_peap: Aruba-Location-Id = "10.9.1" (10) eap_peap: Aruba-AP-Group = "Amigos" (10) eap_peap: Aruba-Device-Type = "Android" (10) eap_peap: Event-Timestamp = "Nov 19 2015 16:13:11 CET" (10) Virtual server inner-tunnel received request (10) EAP-Message = 0x020b0015016f7363617272646740756e61762e6573 (10) FreeRADIUS-Proxied-To = 127.0.0.1 (10) User-Name = "oscarrdg(a)unav.es" (10) NAS-IP-Address = xxxxxx (10) NAS-Port = 0 (10) NAS-Identifier = "xxxxxx" (10) NAS-Port-Type = Wireless-802.11 (10) Calling-Station-Id = "344DF73C9C98" (10) Called-Station-Id = "001A1E003250" (10) Service-Type = Framed-User (10) Framed-MTU = 1100 (10) Aruba-Essid-Name = "eduroam-pre" (10) Aruba-Location-Id = "10.9.1" (10) Aruba-AP-Group = "Amigos" (10) Aruba-Device-Type = "Android" (10) Event-Timestamp = "Nov 19 2015 16:13:11 CET" (10) server inner-tunnel { (10) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel (10) authorize { (10) [chap] = noop (10) [mschap] = noop (10) suffix: Checking for suffix after "@" (10) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (10) suffix: Found realm "~^(.*\.)?unav\.es$" (10) suffix: Adding Stripped-User-Name = "oscarrdg" (10) suffix: Adding Realm = "unav.es" (10) suffix: Authentication realm is LOCAL (10) [suffix] = ok (10) ntdomain: Request already has destination realm set. Ignoring (10) [ntdomain] = noop (10) update control { (10) &Proxy-To-Realm := LOCAL (10) } # update control = noop (10) eap: Peer sent EAP Response (code 2) ID 11 length 21 (10) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (10) [eap] = ok (10) } # authorize = ok (10) Found Auth-Type = EAP (10) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel (10) authenticate { (10) eap: Peer sent packet with method EAP Identity (1) (10) eap: Calling submodule eap_mschapv2 to process data (10) eap_mschapv2: Issuing Challenge (10) eap: Sending EAP Request (code 1) ID 12 length 43 (10) eap: EAP session adding &reply:State = 0x739669f1739a7348 (10) [eap] = handled (10) } # authenticate = handled (10) } # server inner-tunnel (10) Virtual server sending reply (10) EAP-Message = 0x010c002b1a010c0026109be6bd2966f7837a669e8c6ec412fec8667265657261646975732d332e302e3130 (10) Message-Authenticator = 0x00000000000000000000000000000000 (10) State = 0x739669f1739a7348a02455fb687f2caa (10) eap_peap: Got tunneled reply code 11 (10) eap_peap: EAP-Message = 0x010c002b1a010c0026109be6bd2966f7837a669e8c6ec412fec8667265657261646975732d332e302e3130 (10) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (10) eap_peap: State = 0x739669f1739a7348a02455fb687f2caa (10) eap_peap: Got tunneled reply RADIUS code 11 (10) eap_peap: EAP-Message = 0x010c002b1a010c0026109be6bd2966f7837a669e8c6ec412fec8667265657261646975732d332e302e3130 (10) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (10) eap_peap: State = 0x739669f1739a7348a02455fb687f2caa (10) eap_peap: Got tunneled Access-Challenge (10) eap: Sending EAP Request (code 1) ID 12 length 74 (10) eap: EAP session adding &reply:State = 0x4a7c50d94070497d (10) [eap] = handled (10) } # authenticate = handled (10) Using Post-Auth-Type Challenge (10) Post-Auth-Type sub-section not found. Ignoring. (10) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (10) Sent Access-Challenge Id 92 from xxx12.225:1812 to xxxxxx:45903 length 0 (10) EAP-Message = 0x010c004a1900170303003f6a2a84ab3ae80e6445376747acac3a67092800521bd121ed59a9f1d8a3e4558a30aea29eae313c5e6b4befec0d80e2fbdd0f7c8ce5d3d791f671f36e56facd (10) Message-Authenticator = 0x00000000000000000000000000000000 (10) State = 0x4a7c50d94070497df1395bb8ee5037b2 (10) Finished request Waking up in 4.8 seconds. (11) Received Access-Request Id 240 from xxxxxx:45903 to xxx12.225:1812 length 318 (11) User-Name = "oscarrdg(a)unav.es" (11) NAS-IP-Address = xxxxxx (11) NAS-Port = 0 (11) NAS-Identifier = "xxxxxx" (11) NAS-Port-Type = Wireless-802.11 (11) Calling-Station-Id = "344DF73C9C98" (11) Called-Station-Id = "001A1E003250" (11) Service-Type = Framed-User (11) Framed-MTU = 1100 (11) EAP-Message = 0x020c006a1900170303005f000000000000000253f426d0e803b2f101d786b3751058056be43652b9dfc3ef648ed4fa31005509bd18cfeea0fae8d7c1e20a69507c7355e0f78b6d034f70f812ce1d73e78815d519b082725844b86344c1ae97ccd9d6232d64a6c67831e3 (11) State = 0x4a7c50d94070497df1395bb8ee5037b2 (11) Aruba-Essid-Name = "eduroam-pre" (11) Aruba-Location-Id = "10.9.1" (11) Aruba-AP-Group = "Amigos" (11) Aruba-Device-Type = "Android" (11) Message-Authenticator = 0xfc041f435db6453937530e6ad7ad9998 (11) session-state: No cached attributes (11) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (11) authorize { (11) policy filter_username { (11) if (!&User-Name) { (11) if (!&User-Name) -> FALSE (11) if (&User-Name =~ / /) { (11) if (&User-Name =~ / /) -> FALSE (11) if (&User-Name =~ /@.*@/ ) { (11) if (&User-Name =~ /@.*@/ ) -> FALSE (11) if (&User-Name =~ /\.\./ ) { (11) if (&User-Name =~ /\.\./ ) -> FALSE (11) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (11) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (11) if (&User-Name =~ /\.$/) { (11) if (&User-Name =~ /\.$/) -> FALSE (11) if (&User-Name =~ /(a)\./) { (11) if (&User-Name =~ /(a)\./) -> FALSE (11) } # policy filter_username = notfound (11) [preprocess] = ok (11) auth_log: EXPAND /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (11) auth_log: --> /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (11) auth_log: /usr/local/etc2/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/etc2/freeradius/var/log/radius/radacct/xxxxxx/auth-detail-20151119 (11) auth_log: EXPAND %t (11) auth_log: --> Thu Nov 19 16:13:11 2015 (11) [auth_log] = ok (11) [chap] = noop (11) [mschap] = noop (11) [digest] = noop (11) suffix: Checking for suffix after "@" (11) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (11) suffix: Found realm "~^(.*\.)?unav\.es$" (11) suffix: Adding Stripped-User-Name = "oscarrdg" (11) suffix: Adding Realm = "unav.es" (11) suffix: Authentication realm is LOCAL (11) [suffix] = ok (11) ntdomain: Request already has destination realm set. Ignoring (11) [ntdomain] = noop (11) eap: Peer sent EAP Response (code 2) ID 12 length 106 (11) eap: Continuing tunnel setup (11) [eap] = ok (11) } # authorize = ok (11) Found Auth-Type = EAP (11) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (11) authenticate { (11) eap: Expiring EAP session with state 0x739669f1739a7348 (11) eap: Finished EAP session with state 0x4a7c50d94070497d (11) eap: Previous EAP request found for state 0x4a7c50d94070497d, released from the list (11) eap: Peer sent packet with method EAP PEAP (25) (11) eap: Calling submodule eap_peap to process data (11) eap_peap: Continuing EAP-TLS (11) eap_peap: [eaptls verify] = ok (11) eap_peap: Done initial handshake (11) eap_peap: [eaptls process] = ok (11) eap_peap: Session established. Decoding tunneled attributes (11) eap_peap: PEAP state phase2 (11) eap_peap: EAP method MSCHAPv2 (26) (11) eap_peap: Got tunneled request (11) eap_peap: EAP-Message = 0x020c004b1a020c00463116ba4ea3b0d512edfb61cc1111d4f2310000000000000000d4ced6b15b809861069531ec2cb89e3001db98c94f9018e8006f7363617272646740756e61762e6573 (11) eap_peap: Setting User-Name to oscarrdg(a)unav.es (11) eap_peap: Sending tunneled request to inner-tunnel (11) eap_peap: EAP-Message = 0x020c004b1a020c00463116ba4ea3b0d512edfb61cc1111d4f2310000000000000000d4ced6b15b809861069531ec2cb89e3001db98c94f9018e8006f7363617272646740756e61762e6573 (11) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (11) eap_peap: User-Name = "oscarrdg(a)unav.es" (11) eap_peap: State = 0x739669f1739a7348a02455fb687f2caa (11) eap_peap: NAS-IP-Address = xxxxxx (11) eap_peap: NAS-Port = 0 (11) eap_peap: NAS-Identifier = "xxxxxx" (11) eap_peap: NAS-Port-Type = Wireless-802.11 (11) eap_peap: Calling-Station-Id = "344DF73C9C98" (11) eap_peap: Called-Station-Id = "001A1E003250" (11) eap_peap: Service-Type = Framed-User (11) eap_peap: Framed-MTU = 1100 (11) eap_peap: Aruba-Essid-Name = "eduroam-pre" (11) eap_peap: Aruba-Location-Id = "10.9.1" (11) eap_peap: Aruba-AP-Group = "Amigos" (11) eap_peap: Aruba-Device-Type = "Android" (11) eap_peap: Event-Timestamp = "Nov 19 2015 16:13:11 CET" (11) Virtual server inner-tunnel received request (11) EAP-Message = 0x020c004b1a020c00463116ba4ea3b0d512edfb61cc1111d4f2310000000000000000d4ced6b15b809861069531ec2cb89e3001db98c94f9018e8006f7363617272646740756e61762e6573 (11) FreeRADIUS-Proxied-To = 127.0.0.1 (11) User-Name = "oscarrdg(a)unav.es" (11) State = 0x739669f1739a7348a02455fb687f2caa (11) NAS-IP-Address = xxxxxx (11) NAS-Port = 0 (11) NAS-Identifier = "xxxxxx" (11) NAS-Port-Type = Wireless-802.11 (11) Calling-Station-Id = "344DF73C9C98" (11) Called-Station-Id = "001A1E003250" (11) Service-Type = Framed-User (11) Framed-MTU = 1100 (11) Aruba-Essid-Name = "eduroam-pre" (11) Aruba-Location-Id = "10.9.1" (11) Aruba-AP-Group = "Amigos" (11) Aruba-Device-Type = "Android" (11) Event-Timestamp = "Nov 19 2015 16:13:11 CET" (11) server inner-tunnel { (11) session-state: No cached attributes (11) # Executing section authorize from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel (11) authorize { (11) [chap] = noop (11) [mschap] = noop (11) suffix: Checking for suffix after "@" (11) suffix: Looking up realm "unav.es" for User-Name = "oscarrdg(a)unav.es" (11) suffix: Found realm "~^(.*\.)?unav\.es$" (11) suffix: Adding Stripped-User-Name = "oscarrdg" (11) suffix: Adding Realm = "unav.es" (11) suffix: Authentication realm is LOCAL (11) [suffix] = ok (11) ntdomain: Request already has destination realm set. Ignoring (11) [ntdomain] = noop (11) update control { (11) &Proxy-To-Realm := LOCAL (11) } # update control = noop (11) eap: Peer sent EAP Response (code 2) ID 12 length 75 (11) eap: No EAP Start, assuming it's an on-going EAP conversation (11) [eap] = updated (11) policy unav.authorize.inner { (11) if ( "%{client:group}" == 'wireless' ) { (11) EXPAND %{client:group} (11) --> wireless (11) if ( "%{client:group}" == 'wireless' ) -> TRUE (11) if ( "%{client:group}" == 'wireless' ) { (11) policy unav.reject.otherdomain { (11) if ( Realm == "NULL" || Realm =~ /^(.*\.)?unav\.es$/ || Realm == "UNAV-PDC-01" ) { (11) if ( Realm == "NULL" || Realm =~ /^(.*\.)?unav\.es$/ || Realm == "UNAV-PDC-01" ) -> TRUE (11) ( Realm == "NULL" || Realm =~ /^(.*\.)?unav\.es$/ || Realm == "UNAV-PDC-01" ) { ... } # empty sub-section is ignored (11) ... skipping else for request 11: Preceding "if" was taken (11) } # policy unav.reject.otherdomain = updated (11) policy unav.reject.bloqueado { (11) if ( Ldap-Group == "unav.radius.bloqueado" ) { (11) Searching for user in group "unav.radius.bloqueado" rlm_ldap (ldap): Reserved connection (0) (11) EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}}) (11) --> (uid=oscarrdg) (11) Performing search in "ou=radius,o=accounts,dc=unav,dc=es" with filter "(uid=oscarrdg)", scope "sub" (11) Waiting for search result... (11) User object found at DN "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es" (11) Checking user object's member attributes (11) Performing unfiltered search in "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Processing member value "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ssl" (11) Processing member value "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.eapol.n1" (11) Processing member value "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.wifi.n1" (11) Processing member value "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid= unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ssl.si" (11) Processing member value "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ipsec" 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://ldap.unav.es:389 TLS: certificate [CN=AddTrust External CA Root,OU=AddTrust External TTP Network,O=AddTrust AB,C=SE] is not valid - error -8172:Peer's certificate issuer has been marked as not trusted by the user.. rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful (11) User is not a member of "unav.radius.bloqueado" (11) if ( Ldap-Group == "unav.radius.bloqueado" ) -> FALSE (11) } # policy unav.reject.bloqueado = updated rlm_ldap (ldap): Reserved connection (1) (11) ldap: EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}}) (11) ldap: --> (uid=oscarrdg) (11) ldap: Performing search in "ou=radius,o=accounts,dc=unav,dc=es" with filter "(uid=oscarrdg)", scope "sub" (11) ldap: Waiting for search result... (11) ldap: User object found at DN "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es" (11) ldap: Processing user attributes (11) ldap: control:Password-With-Header += '{sha}0sURRyN1nxp/BMx+Q5nBqwR7CB0=' rlm_ldap (ldap): Released connection (1) (11) [ldap] = updated (11) update reply { (11) EXPAND %{request:User-Name} (11) --> oscarrdg(a)unav.es (11) &User-Name = oscarrdg(a)unav.es (11) } # update reply = noop (11) if ( Ldap-Group == "unav.radius.wifi.all" ) { (11) Searching for user in group "unav.radius.wifi.all" rlm_ldap (ldap): Reserved connection (2) (11) Using user DN from request "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es" (11) Checking user object's member attributes (11) Performing unfiltered search in "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Processing member value "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ssl" (11) Processing member value "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.eapol.n1" (11) Processing member value "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.wifi.n1" (11) Processing member value "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ssl.si,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ssl.si" (11) Processing member value "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ipsec,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ipsec" rlm_ldap (ldap): Released connection (2) (11) User is not a member of "unav.radius.wifi.all" (11) if ( Ldap-Group == "unav.radius.wifi.all" ) -> FALSE (11) elsif ( Ldap-Group == "unav.radius.wifi.n1" ) { (11) Searching for user in group "unav.radius.wifi.n1" rlm_ldap (ldap): Reserved connection (3) (11) Using user DN from request "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es" (11) Checking user object's member attributes (11) Performing unfiltered search in "uid=oscarrdg,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Processing member value "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.vpn.ssl,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.vpn.ssl" (11) Processing member value "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.eapol.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.eapol.n1" (11) Processing member value "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" as a DN (11) Resolving group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" to group name (11) Performing unfiltered search in "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es", scope "base" (11) Waiting for search result... (11) Group DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,dc=es" resolves to name "unav.radius.wifi.n1" (11) User found in group "unav.radius.wifi.n1". Comparison between membership: name (resolved from DN "uid=unav.radius.wifi.n1,ou=groups,ou=radius,o=accounts,dc=unav,d?"), check: name rlm_ldap (ldap): Released connection (3) (11) elsif ( Ldap-Group == "unav.radius.wifi.n1" ) -> TRUE (11) elsif ( Ldap-Group == "unav.radius.wifi.n1" ) { (11) update reply { (11) &Reply-Message += 'role.n1' (11) &Aruba-User-Role := 'role.n1' (11) } # update reply = noop (11) } # elsif ( Ldap-Group == "unav.radius.wifi.n1" ) = noop (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping else for request 11: Preceding "if" was taken (11) } # if ( "%{client:group}" == 'wireless' ) = updated (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping elsif for request 11: Preceding "if" was taken (11) ... skipping else for request 11: Preceding "if" was taken (11) } # policy unav.authorize.inner = updated (11) [expiration] = noop (11) [logintime] = noop (11) pap: Converted: Password-With-Header -> SHA1-Password (11) pap: Removing &control:Password-With-Header (11) pap: Normalizing SHA1-Password from base64 encoding, 28 bytes -> 20 bytes (11) pap: WARNING: Auth-Type already set. Not setting to PAP (11) [pap] = noop (11) if (control:Cleartext-Password) { (11) if (control:Cleartext-Password) -> FALSE (11) } # authorize = updated (11) Found Auth-Type = EAP (11) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel (11) authenticate { (11) eap: Expiring EAP session with state 0x739669f1739a7348 (11) eap: Finished EAP session with state 0x739669f1739a7348 (11) eap: Previous EAP request found for state 0x739669f1739a7348, released from the list (11) eap: Peer sent packet with method EAP MSCHAPv2 (26) (11) eap: Calling submodule eap_mschapv2 to process data (11) eap_mschapv2: # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/inner-tunnel (11) eap_mschapv2: Auth-Type MS-CHAP { (11) mschap: Creating challenge hash with username: oscarrdg(a)unav.es (11) mschap: Client is using MS-CHAPv2 (11) mschap: Executing: /usr/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Response}:-00}: (11) mschap: EXPAND --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} (11) mschap: --> --username=oscarrdg (11) mschap: Creating challenge hash with username: oscarrdg(a)unav.es (11) mschap: EXPAND --challenge=%{%{mschap:Challenge}:-00} (11) mschap: --> --challenge=c159f634076ecce6 (11) mschap: EXPAND --nt-response=%{%{mschap:NT-Response}:-00} (11) mschap: --> --nt-response=d4ced6b15b809861069531ec2cb89e3001db98c94f9018e8 (11) mschap: Program returned code (0) and output 'NT_KEY: 751E91FBC94E37990A2A5B973C29E4D3' (11) mschap: Adding MS-CHAPv2 MPPE keys (11) [mschap] = ok (11) } # Auth-Type MS-CHAP = ok (11) MSCHAP Success (11) eap: Sending EAP Request (code 1) ID 13 length 51 (11) eap: EAP session adding &reply:State = 0x739669f1729b7348 (11) [eap] = handled (11) } # authenticate = handled (11) } # server inner-tunnel (11) Virtual server sending reply (11) User-Name = "oscarrdg(a)unav.es" (11) Reply-Message += "role.n1" (11) Aruba-User-Role := "role.n1" (11) EAP-Message = 0x010d00331a030c002e533d38443639364430423633413735314239363137343538304636313145354531323335434636443942 (11) Message-Authenticator = 0x00000000000000000000000000000000 (11) State = 0x739669f1729b7348a02455fb687f2caa (11) eap_peap: Got tunneled reply code 11 (11) eap_peap: User-Name = "oscarrdg(a)unav.es" (11) eap_peap: Reply-Message += "role.n1" (11) eap_peap: Aruba-User-Role := "role.n1" (11) eap_peap: EAP-Message = 0x010d00331a030c002e533d38443639364430423633413735314239363137343538304636313145354531323335434636443942 (11) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (11) eap_peap: State = 0x739669f1729b7348a02455fb687f2caa (11) eap_peap: Got tunneled reply RADIUS code 11 (11) eap_peap: User-Name = "oscarrdg(a)unav.es" (11) eap_peap: Reply-Message += "role.n1" (11) eap_peap: Aruba-User-Role := "role.n1" (11) eap_peap: EAP-Message = 0x010d00331a030c002e533d38443639364430423633413735314239363137343538304636313145354531323335434636443942 (11) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (11) eap_peap: State = 0x739669f1729b7348a02455fb687f2caa (11) eap_peap: Got tunneled Access-Challenge (11) eap: Sending EAP Request (code 1) ID 13 length 82 (11) eap: EAP session adding &reply:State = 0x4a7c50d94171497d (11) [eap] = handled (11) } # authenticate = handled (11) Using Post-Auth-Type Challenge (11) Post-Auth-Type sub-section not found. Ignoring. (11) # Executing group from file /usr/local/etc2/freeradius/etc/raddb/sites-enabled/default (11) Sent Access-Challenge Id 240 from xxx:1812 to xxxxxx:45903 length 0 (11) EAP-Message = 0x010d0052190017030300476a2a84ab3ae80e65df331667562db833be49b2c3281f498c160a1da57850e4c4db22bfebfcec126265d589bbfe90d31b5ded9e845dd71e0e30a7911af58f1d022b04703a397886 (11) Message-Authenticator = 0x00000000000000000000000000000000 (11) State = 0x4a7c50d94171497df1395bb8ee5037b2 (11) Finished request Waking up in 4.7 seconds. *Oscar Remírez de Ganuza Satrústegui* IT Services Universidad de Navarra Tel. +34 948425600 x803130 http://www.unav.edu/web/it/

4 9

"TLS section "tls" missing, trying to use legacy configuration" log message in 3.0.10
by Thomas Stather 25 Feb '16

25 Feb '16

Hi I am seeing the following in my radius (3.0.10) log: ... Tue Feb 23 11:23:13 2016 : Info: rlm_ldap: libldap vendor: OpenLDAP, version: 20439 Tue Feb 23 11:23:13 2016 : Info: TLS section "tls" missing, trying to use legacy configuration ... However, i have the "tls" section in my /mods-enabled/ldap config file: tls { start_tls = yes ca_file = /etc/ssl/certs/ca-bundle.pem require_cert = "demand" } What am i doing wrong? Best, Thomas -- Thomas Stather IT Services Tel: +49 6221-486 628 Fax: +49 6221-486 561 ------------------------------------------------------------------------ Max Planck Institute for Medical Research (MPImF) Jahnstrasse 29, 69120 Heidelberg Germany

2 2

Attempting to use the
by Alex Sharaz 24 Feb '16

24 Feb '16

In mods-available/mschap ..... FR 3.0.11 # An alternative to using ntlm_auth is to connect to the # winbind daemon directly for authentication. This option # is likely to be faster and may be useful on busy systems, # but is less well tested. # # Using this option requires libwbclient from Samba 4.2.1 # or later to be installed. Make sure that ntlm_auth above is # commented out. # winbind_username = "%{mschap:User-Name}" winbind_domain = "%{mschap:NT-Domain}" So I'm building a FR package and have tried to use the above config, but I get 'winbind' auth not enabled at compiled time when I try and start FR. Looks like configure ran with $ ./configure --build x86_64-linux-gnu --config-cache --disable-developer --disable-openssl-version-check --prefix=/usr --exec-prefix=/usr --mandir=/usr/share/man --sysconfdir=/etc --libdir=/usr/lib/freeradius --datadir=/usr/share --localstatedir=/var --with-raddbdir=/etc/freeradius --with-logdir=/var/log/freeradius --with-large-files --with-udpfromto --without-rlm_eap_tnc --with-rlm_sql_postgresql_lib_dir=/usr/lib --with-rlm_sql_postgresql_include_dir=/usr/include/postgresql --with-iodbc-include-dir=/usr/include/iodbc --without-rlm_eap_ikev2 --without-rlm_sql_oracle --without-rlm_sql_unixodbc What do I add to add winbind auth? What I actually ran was dpkg-buildpackage -b -uc I've got samba-dev installed and libwbclient is installed Rgds Alex

3 2

IPv6 address allocating.
by koch＠inbox.lv 24 Feb '16

24 Feb '16

Good day. Does exist any freeradius modules for subj.? Or I'll need to write my own one? :) Thanks for the answer.

3 2

upgrade freeradius vom 2.1.12 to 3.0.x
by Kiefer, Jonas 24 Feb '16

24 Feb '16

Hello freeradius-users, iam seaching for a how to tutorial to upgrade my freeradius server from the version 2.1.12 to 3.0.x. iam using ubuntu 14.04 lts and also tried it with apt-get update & upgrade. But in this case there are nothing new stuff to update for me. How can i do it? Best regards Jonas

3 2

Dynamic User Help
by J Kephart 24 Feb '16

24 Feb '16

We provide AAA services to a variety of client businesses across North America, and we use FreeRADIUS as the final piece of our authentication process. Because our clients' customers are unknown until they attempt to connect to the network, all user radius credentials are created dynamically, after an initial authentication via another method (typically, credit card charges, access codes, etc.); once that initial auth is complete, we create a credential using the user devices' MAC address to ensure uniqueness, and to facilitate the MAC auth feature of the gateway devices we employ, which permits immediate reconnection following idle time-out without having to open a browser (a limitation of the gateway devices). Of concern to us is that we don't want a user to authenticate in one place of business for which we provide service, then move to another client site, at which MAC authentication is enabled, and have the device automatically connected at the second location. This is mainly due to differences in service offerings at different client sites. What we're looking to do is create an additional table in the radius database. That table would contain the following fields: id primary table key callingstationid self-explanatory nasid identifies the specific site the user is at, and corresponds to our own internal site id nasportid the vlan the user is in groupname the group to which the user is assigned in radusergroup As we create each user's credentials, we'll populate this new table with the information indicated. For each VLAN the user connects to, there would be a separate row so that, as he moves from vlan to vlan, we can update the group assignment in radusergroup so that he'd get the proper group attributes. Does this sound like something that could work? If so, I need a bit of help understanding where we'd put the table query (and the construction of it) in whichever file it should be in (e.g., sites-enabled/default?). The goal is to perform the query, and if there's a corresponding row match, do an update on the username in radusergroup to set the proper group id, and then continue normal processing; if there is no match, we'd simply reject the connection, which would force the gateway to redirect to a captive portal server for initial authentication, as described above). For me, the sticking point is where and how to put the SQL query, so I'd appreciate any pointers I can get. And, too, if there's a better way of doing this, I'd welcome any advice! I hope I've provided enough information to start. Many thanks in advance! Jim

2 7

How to increase number of SIP-AVP in reply
by Aqs Younas 23 Feb '16

23 Feb '16

Hi, I am setting these SIP-AVP's in freeradius reply to opensips. But see freeradius sending only one(first)AVP back to opensips. Mon Feb 22 19:54:51 2016 : Debug: rlm_python:authenticate: 'reply:SIP-AVP' = 'allowedCallTime:86400' Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: FROM 1 TO 0 MAX 1 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: Examining SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: APPENDING SIP-AVP FROM 0 TO 0 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: TO in 0 out 0 Mon Feb 22 19:54:51 2016 : Debug: rlm_python:authenticate: 'reply:SIP-AVP' = 'isCname:No' Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: FROM 1 TO 1 MAX 2 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: Examining SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: TO in 1 out 1 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: to[0] = SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: rlm_python:authenticate: 'reply:SIP-AVP' = 'accountCode:6034604325' Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: FROM 1 TO 1 MAX 2 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: Examining SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: TO in 1 out 1 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: to[0] = SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: rlm_python:authenticate: 'reply:SIP-AVP' = 'rtp_proxy:No' Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: FROM 1 TO 1 MAX 2 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: Examining SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: TO in 1 out 1 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: to[0] = SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: rlm_python:authenticate: 'reply:SIP-AVP' = 'callrecording:No' Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: FROM 1 TO 1 MAX 2 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: Examining SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: TO in 1 out 1 Mon Feb 22 19:54:51 2016 : Debug: (0) python: ::: to[0] = SIP-AVP Mon Feb 22 19:54:51 2016 : Debug: (0) modsingle[authenticate]: returned from python (rlm_python) for request 0 Mon Feb 22 19:54:51 2016 : Debug: (0) [python] = ok Mon Feb 22 19:54:51 2016 : Debug: (0) } # Auth-Type Python = ok Mon Feb 22 19:54:51 2016 : Debug: (0) # Executing section post-auth from file /usr/local/radius01/etc/raddb/sites-enabled/default Mon Feb 22 19:54:51 2016 : Debug: (0) post-auth { Mon Feb 22 19:54:51 2016 : Debug: (0) update { Mon Feb 22 19:54:51 2016 : Debug: (0) No attributes updated Mon Feb 22 19:54:51 2016 : Debug: (0) } # update = noop Mon Feb 22 19:54:51 2016 : Debug: (0) modsingle[post-auth]: calling exec (rlm_exec) for request 0 Mon Feb 22 19:54:51 2016 : Debug: (0) modsingle[post-auth]: returned from exec (rlm_exec) for request 0 Mon Feb 22 19:54:51 2016 : Debug: (0) [exec] = noop Mon Feb 22 19:54:51 2016 : Debug: (0) } # post-auth = noop *Mon Feb 22 19:54:51 2016 : Debug: (0) Sent Access-Accept Id 86 from 127.0.0.1:1812 <http://127.0.0.1:1812> to 127.0.0.1:47158 <http://127.0.0.1:47158> length 0* *Mon Feb 22 19:54:51 2016 : Debug: (0) SIP-AVP = "allowedCallTime:86400"* Mon Feb 22 19:54:51 2016 : Debug: (0) Finished request Mon Feb 22 19:54:51 2016 : Debug: Waking up in 4.9 seconds. Mon Feb 22 19:54:56 2016 : Debug: (0) Cleaning up request packet ID 86 with timestamp +8 Mon Feb 22 19:54:56 2016 : Info: Ready to process requests I see these is somewhere MAX limit for AVP set, but can't figure out where it is set. I am using freeradius 3.0.11. In freeradius 2.2.9 i was able to set multiple AVPs in reply. Any pointer is much appreciated. Thanks in Advance.

2 4

freeradius update attributes in access-accept reply
by Kiefer, Jonas 23 Feb '16

23 Feb '16

Hello freeradius-users, Iam running freeradius on ubuntu 14.04 LTS with mysql and daloradius. Now i trie to authenticate a user via RADIUS on a Procurve Switch. But the problem is that the configured service-type attribute are not send in the Access-Accept message. Only in the Access-Challenge messages the attribute where send tot he procurve switch. I need it in the Access-Accept reply message. This is my logfile from the radiusserver: Tue Feb 23 15:45:33 2016 : Info: FreeRADIUS Version 2.1.12, for host x86_64-pc-linux-gnu, built on Aug 26 2015 at 14:47:03 Tue Feb 23 15:45:33 2016 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. Tue Feb 23 15:45:33 2016 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Tue Feb 23 15:45:33 2016 : Info: PARTICULAR PURPOSE. Tue Feb 23 15:45:33 2016 : Info: You may redistribute copies of FreeRADIUS under the terms of the Tue Feb 23 15:45:33 2016 : Info: GNU General Public License v2. Tue Feb 23 15:45:33 2016 : Info: Starting - reading configuration files ... Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/radiusd.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/proxy.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/clients.conf Tue Feb 23 15:45:33 2016 : Debug: including files in directory /etc/freeradius/modules/ Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/passwd Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/preprocess Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mschap Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/radutmp Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/smsotp Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sradutmp Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/unix Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/replicate Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/smbpasswd Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/checkval Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/acct_unique Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/wimax Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/files Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/pap Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/realm Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/etc_group Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/soh Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sql_log Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/opendirectory Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/perl Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail.log Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mac2vlan Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/echo Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/linelog Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/redis Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/attr_filter Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/chap Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mac2ip Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/expiration Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/digest Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/pam Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/counter Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/always Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/cui Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/logintime Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/expr Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/inner-eap Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail.example.com Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ldap Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/otp Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ippool Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/rediswho Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/exec Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/policy Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/krb5 Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/eap.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql/mysql/dialup.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql/mysql/counter.conf Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/policy.conf Tue Feb 23 15:45:33 2016 : Debug: including files in directory /etc/freeradius/sites-enabled/ Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:33 2016 : Debug: main { Tue Feb 23 15:45:33 2016 : Debug: user = "freerad" Tue Feb 23 15:45:33 2016 : Debug: group = "freerad" Tue Feb 23 15:45:33 2016 : Debug: allow_core_dumps = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: including dictionary file /etc/freeradius/dictionary Tue Feb 23 15:45:33 2016 : Debug: main { Tue Feb 23 15:45:33 2016 : Debug: name = "freeradius" Tue Feb 23 15:45:33 2016 : Debug: prefix = "/usr" Tue Feb 23 15:45:33 2016 : Debug: localstatedir = "/var" Tue Feb 23 15:45:33 2016 : Debug: sbindir = "/usr/sbin" Tue Feb 23 15:45:33 2016 : Debug: logdir = "/var/log/freeradius" Tue Feb 23 15:45:33 2016 : Debug: run_dir = "/var/run/freeradius" Tue Feb 23 15:45:33 2016 : Debug: libdir = "/usr/lib/freeradius" Tue Feb 23 15:45:33 2016 : Debug: radacctdir = "/var/log/freeradius/radacct" Tue Feb 23 15:45:33 2016 : Debug: hostname_lookups = no Tue Feb 23 15:45:33 2016 : Debug: max_request_time = 30 Tue Feb 23 15:45:33 2016 : Debug: cleanup_delay = 5 Tue Feb 23 15:45:33 2016 : Debug: max_requests = 1024 Tue Feb 23 15:45:33 2016 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Tue Feb 23 15:45:33 2016 : Debug: checkrad = "/usr/sbin/checkrad" Tue Feb 23 15:45:33 2016 : Debug: debug_level = 0 Tue Feb 23 15:45:33 2016 : Debug: proxy_requests = yes Tue Feb 23 15:45:33 2016 : Debug: log { Tue Feb 23 15:45:33 2016 : Debug: stripped_names = no Tue Feb 23 15:45:33 2016 : Debug: auth = no Tue Feb 23 15:45:33 2016 : Debug: auth_badpass = no Tue Feb 23 15:45:33 2016 : Debug: auth_goodpass = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: security { Tue Feb 23 15:45:33 2016 : Debug: max_attributes = 200 Tue Feb 23 15:45:33 2016 : Debug: reject_delay = 1 Tue Feb 23 15:45:33 2016 : Debug: status_server = yes Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue Feb 23 15:45:33 2016 : Debug: proxy server { Tue Feb 23 15:45:33 2016 : Debug: retry_delay = 5 Tue Feb 23 15:45:33 2016 : Debug: retry_count = 3 Tue Feb 23 15:45:33 2016 : Debug: default_fallback = no Tue Feb 23 15:45:33 2016 : Debug: dead_time = 120 Tue Feb 23 15:45:33 2016 : Debug: wake_all_if_all_dead = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: home_server localhost { Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1 Tue Feb 23 15:45:33 2016 : Debug: port = 1812 Tue Feb 23 15:45:33 2016 : Debug: type = "auth" Tue Feb 23 15:45:33 2016 : Debug: secret = "testing123" Tue Feb 23 15:45:33 2016 : Debug: response_window = 20 Tue Feb 23 15:45:33 2016 : Debug: max_outstanding = 65536 Tue Feb 23 15:45:33 2016 : Debug: require_message_authenticator = yes Tue Feb 23 15:45:33 2016 : Debug: zombie_period = 40 Tue Feb 23 15:45:33 2016 : Debug: status_check = "status-server" Tue Feb 23 15:45:33 2016 : Debug: ping_interval = 30 Tue Feb 23 15:45:33 2016 : Debug: check_interval = 30 Tue Feb 23 15:45:33 2016 : Debug: num_answers_to_alive = 3 Tue Feb 23 15:45:33 2016 : Debug: num_pings_to_alive = 3 Tue Feb 23 15:45:33 2016 : Debug: revive_interval = 120 Tue Feb 23 15:45:33 2016 : Debug: status_check_timeout = 4 Tue Feb 23 15:45:33 2016 : Debug: coa { Tue Feb 23 15:45:33 2016 : Debug: irt = 2 Tue Feb 23 15:45:33 2016 : Debug: mrt = 16 Tue Feb 23 15:45:33 2016 : Debug: mrc = 5 Tue Feb 23 15:45:33 2016 : Debug: mrd = 30 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: home_server_pool my_auth_failover { Tue Feb 23 15:45:33 2016 : Debug: type = fail-over Tue Feb 23 15:45:33 2016 : Debug: home_server = localhost Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: realm example.com { Tue Feb 23 15:45:33 2016 : Debug: auth_pool = my_auth_failover Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: realm LOCAL { Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Clients #### Tue Feb 23 15:45:33 2016 : Debug: client localhost { Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1 Tue Feb 23 15:45:33 2016 : Debug: require_message_authenticator = no Tue Feb 23 15:45:33 2016 : Debug: secret = "testing123" Tue Feb 23 15:45:33 2016 : Debug: nastype = "other" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Instantiating modules #### Tue Feb 23 15:45:33 2016 : Debug: instantiate { Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_exec, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_exec Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "exec" from file /etc/freeradius/modules/exec Tue Feb 23 15:45:33 2016 : Debug: exec { Tue Feb 23 15:45:33 2016 : Debug: wait = no Tue Feb 23 15:45:33 2016 : Debug: input_pairs = "request" Tue Feb 23 15:45:33 2016 : Debug: shell_escape = yes Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_expr, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_expr Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_expiration, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_expiration Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration Tue Feb 23 15:45:33 2016 : Debug: expiration { Tue Feb 23 15:45:33 2016 : Debug: reply-message = "Password Has Expired " Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_logintime, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_logintime Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime Tue Feb 23 15:45:33 2016 : Debug: logintime { Tue Feb 23 15:45:33 2016 : Debug: reply-message = "You are calling outside your allowed timespan " Tue Feb 23 15:45:33 2016 : Debug: minimum-timeout = 60 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Virtual Servers #### Tue Feb 23 15:45:33 2016 : Debug: server { # from file /etc/freeradius/radiusd.conf Tue Feb 23 15:45:33 2016 : Debug: modules { Tue Feb 23 15:45:33 2016 : Debug: Module: Creating Auth-Type = digest Tue Feb 23 15:45:33 2016 : Debug: Module: Creating Post-Auth-Type = REJECT Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_pap, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_pap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "pap" from file /etc/freeradius/modules/pap Tue Feb 23 15:45:33 2016 : Debug: pap { Tue Feb 23 15:45:33 2016 : Debug: encryption_scheme = "auto" Tue Feb 23 15:45:33 2016 : Debug: auto_header = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_chap, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_chap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "chap" from file /etc/freeradius/modules/chap Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_mschap, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_mschap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap Tue Feb 23 15:45:33 2016 : Debug: mschap { Tue Feb 23 15:45:33 2016 : Debug: use_mppe = yes Tue Feb 23 15:45:33 2016 : Debug: require_encryption = yes Tue Feb 23 15:45:33 2016 : Debug: require_strong = yes Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = yes Tue Feb 23 15:45:33 2016 : Debug: allow_retry = yes Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_digest, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_digest Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "digest" from file /etc/freeradius/modules/digest Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_unix, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_unix Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "unix" from file /etc/freeradius/modules/unix Tue Feb 23 15:45:33 2016 : Debug: unix { Tue Feb 23 15:45:33 2016 : Debug: radwtmp = "/var/log/freeradius/radwtmp" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_eap, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_eap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "eap" from file /etc/freeradius/eap.conf Tue Feb 23 15:45:33 2016 : Debug: eap { Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "md5" Tue Feb 23 15:45:33 2016 : Debug: timer_expire = 60 Tue Feb 23 15:45:33 2016 : Debug: ignore_unknown_eap_types = no Tue Feb 23 15:45:33 2016 : Debug: cisco_accounting_username_bug = no Tue Feb 23 15:45:33 2016 : Debug: max_sessions = 4096 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_md5 Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-md5 Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_leap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-leap Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_gtc Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-gtc Tue Feb 23 15:45:33 2016 : Debug: gtc { Tue Feb 23 15:45:33 2016 : Debug: challenge = "Password: " Tue Feb 23 15:45:33 2016 : Debug: auth_type = "PAP" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_tls Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-tls Tue Feb 23 15:45:33 2016 : Debug: tls { Tue Feb 23 15:45:33 2016 : Debug: rsa_key_exchange = no Tue Feb 23 15:45:33 2016 : Debug: dh_key_exchange = yes Tue Feb 23 15:45:33 2016 : Debug: rsa_key_length = 512 Tue Feb 23 15:45:33 2016 : Debug: dh_key_length = 512 Tue Feb 23 15:45:33 2016 : Debug: verify_depth = 0 Tue Feb 23 15:45:33 2016 : Debug: CA_path = "/etc/freeradius/certs" Tue Feb 23 15:45:33 2016 : Debug: pem_file_type = yes Tue Feb 23 15:45:33 2016 : Debug: private_key_file = "/etc/freeradius/certs/server.key" Tue Feb 23 15:45:33 2016 : Debug: certificate_file = "/etc/freeradius/certs/server.pem" Tue Feb 23 15:45:33 2016 : Debug: CA_file = "/etc/freeradius/certs/ca.pem" Tue Feb 23 15:45:33 2016 : Debug: private_key_password = "whatever" Tue Feb 23 15:45:33 2016 : Debug: dh_file = "/etc/freeradius/certs/dh" Tue Feb 23 15:45:33 2016 : Debug: random_file = "/dev/urandom" Tue Feb 23 15:45:33 2016 : Debug: fragment_size = 1024 Tue Feb 23 15:45:33 2016 : Debug: include_length = yes Tue Feb 23 15:45:33 2016 : Debug: check_crl = no Tue Feb 23 15:45:33 2016 : Debug: cipher_list = "DEFAULT" Tue Feb 23 15:45:33 2016 : Debug: make_cert_command = "/etc/freeradius/certs/bootstrap" Tue Feb 23 15:45:33 2016 : Debug: ecdh_curve = "prime256v1" Tue Feb 23 15:45:33 2016 : Debug: cache { Tue Feb 23 15:45:33 2016 : Debug: enable = no Tue Feb 23 15:45:33 2016 : Debug: lifetime = 24 Tue Feb 23 15:45:33 2016 : Debug: max_entries = 255 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: verify { Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: ocsp { Tue Feb 23 15:45:33 2016 : Debug: enable = no Tue Feb 23 15:45:33 2016 : Debug: override_cert_url = yes Tue Feb 23 15:45:33 2016 : Debug: url = "http://127.0.0.1/ocsp/" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_ttls Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-ttls Tue Feb 23 15:45:33 2016 : Debug: ttls { Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "md5" Tue Feb 23 15:45:33 2016 : Debug: copy_request_to_tunnel = no Tue Feb 23 15:45:33 2016 : Debug: use_tunneled_reply = yes Tue Feb 23 15:45:33 2016 : Debug: virtual_server = "inner-tunnel" Tue Feb 23 15:45:33 2016 : Debug: include_length = yes Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_peap Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-peap Tue Feb 23 15:45:33 2016 : Debug: peap { Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "mschapv2" Tue Feb 23 15:45:33 2016 : Debug: copy_request_to_tunnel = no Tue Feb 23 15:45:33 2016 : Debug: use_tunneled_reply = yes Tue Feb 23 15:45:33 2016 : Debug: proxy_tunneled_request_as_eap = yes Tue Feb 23 15:45:33 2016 : Debug: virtual_server = "inner-tunnel" Tue Feb 23 15:45:33 2016 : Debug: soh = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-mschapv2 Tue Feb 23 15:45:33 2016 : Debug: mschapv2 { Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = no Tue Feb 23 15:45:33 2016 : Debug: send_error = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_preprocess, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_preprocess Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess Tue Feb 23 15:45:33 2016 : Debug: preprocess { Tue Feb 23 15:45:33 2016 : Debug: huntgroups = "/etc/freeradius/huntgroups" Tue Feb 23 15:45:33 2016 : Debug: hints = "/etc/freeradius/hints" Tue Feb 23 15:45:33 2016 : Debug: with_ascend_hack = no Tue Feb 23 15:45:33 2016 : Debug: ascend_channels_per_line = 23 Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = no Tue Feb 23 15:45:33 2016 : Debug: with_specialix_jetstream_hack = no Tue Feb 23 15:45:33 2016 : Debug: with_cisco_vsa_hack = no Tue Feb 23 15:45:33 2016 : Debug: with_alvarion_vsa_hack = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_realm, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_realm Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm Tue Feb 23 15:45:33 2016 : Debug: realm suffix { Tue Feb 23 15:45:33 2016 : Debug: format = "suffix" Tue Feb 23 15:45:33 2016 : Debug: delimiter = "@" Tue Feb 23 15:45:33 2016 : Debug: ignore_default = no Tue Feb 23 15:45:33 2016 : Debug: ignore_null = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_sql, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_sql Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "sql" from file /etc/freeradius/sql.conf Tue Feb 23 15:45:33 2016 : Debug: sql { Tue Feb 23 15:45:33 2016 : Debug: driver = "rlm_sql_mysql" Tue Feb 23 15:45:33 2016 : Debug: server = "localhost" Tue Feb 23 15:45:33 2016 : Debug: port = "" Tue Feb 23 15:45:33 2016 : Debug: login = "freeradius" Tue Feb 23 15:45:33 2016 : Debug: password = "radius123" Tue Feb 23 15:45:33 2016 : Debug: radius_db = "radius" Tue Feb 23 15:45:33 2016 : Debug: read_groups = yes Tue Feb 23 15:45:33 2016 : Debug: sqltrace = yes Tue Feb 23 15:45:33 2016 : Debug: sqltracefile = "/var/log/freeradius/sqltrace.sql" Tue Feb 23 15:45:33 2016 : Debug: readclients = yes Tue Feb 23 15:45:33 2016 : Debug: deletestalesessions = yes Tue Feb 23 15:45:33 2016 : Debug: num_sql_socks = 5 Tue Feb 23 15:45:33 2016 : Debug: lifetime = 0 Tue Feb 23 15:45:33 2016 : Debug: max_queries = 0 Tue Feb 23 15:45:33 2016 : Debug: sql_user_name = "%{User-Name}" Tue Feb 23 15:45:33 2016 : Debug: default_user_profile = "" Tue Feb 23 15:45:33 2016 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Tue Feb 23 15:45:33 2016 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Feb 23 15:45:33 2016 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Feb 23 15:45:33 2016 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Feb 23 15:45:33 2016 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Feb 23 15:45:33 2016 : Debug: accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" Tue Feb 23 15:45:33 2016 : Debug: accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 23 15:45:33 2016 : Debug: accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" Tue Feb 23 15:45:33 2016 : Debug: accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')" Tue Feb 23 15:45:33 2016 : Debug: accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 23 15:45:33 2016 : Debug: accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 23 15:45:33 2016 : Debug: accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')" Tue Feb 23 15:45:33 2016 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" Tue Feb 23 15:45:33 2016 : Debug: connect_failure_retry_delay = 60 Tue Feb 23 15:45:33 2016 : Debug: simul_count_query = "" Tue Feb 23 15:45:33 2016 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Tue Feb 23 15:45:33 2016 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Tue Feb 23 15:45:33 2016 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect to freeradius@localhost:/radius Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 0 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #0 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 1 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #1 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 2 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #2 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 3 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #3 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 4 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #4 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Processing generate_sql_clients Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql_mysql: query: SELECT id, nasname, shortname, type, secret, server FROM nas Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Read entry nasname=192.168.6.211,shortname=test,secret=radius123 Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Adding client 192.168.6.211 (test, server=<none>) to clients list Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Released sql socket id: 4 Tue Feb 23 15:45:33 2016 : Debug: Module: Checking preacct {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_acct_unique Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique Tue Feb 23 15:45:33 2016 : Debug: acct_unique { Tue Feb 23 15:45:33 2016 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_files, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_files Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "files" from file /etc/freeradius/modules/files Tue Feb 23 15:45:33 2016 : Debug: files { Tue Feb 23 15:45:33 2016 : Debug: usersfile = "/etc/freeradius/users" Tue Feb 23 15:45:33 2016 : Debug: acctusersfile = "/etc/freeradius/acct_users" Tue Feb 23 15:45:33 2016 : Debug: preproxy_usersfile = "/etc/freeradius/preproxy_users" Tue Feb 23 15:45:33 2016 : Debug: compat = "no" Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Checking accounting {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_detail, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_detail Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "detail" from file /etc/freeradius/modules/detail Tue Feb 23 15:45:33 2016 : Debug: detail { Tue Feb 23 15:45:33 2016 : Debug: detailfile = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Tue Feb 23 15:45:33 2016 : Debug: header = "%t" Tue Feb 23 15:45:33 2016 : Debug: detailperm = 384 Tue Feb 23 15:45:33 2016 : Debug: dirperm = 493 Tue Feb 23 15:45:33 2016 : Debug: locking = no Tue Feb 23 15:45:33 2016 : Debug: log_packet_header = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_radutmp, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_radutmp Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp Tue Feb 23 15:45:33 2016 : Debug: radutmp { Tue Feb 23 15:45:33 2016 : Debug: filename = "/var/log/freeradius/radutmp" Tue Feb 23 15:45:33 2016 : Debug: username = "%{User-Name}" Tue Feb 23 15:45:33 2016 : Debug: case_sensitive = yes Tue Feb 23 15:45:33 2016 : Debug: check_with_nas = yes Tue Feb 23 15:45:33 2016 : Debug: perm = 384 Tue Feb 23 15:45:33 2016 : Debug: callerid = yes Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_attr_filter Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter Tue Feb 23 15:45:33 2016 : Debug: attr_filter attr_filter.accounting_response { Tue Feb 23 15:45:33 2016 : Debug: attrsfile = "/etc/freeradius/attrs.accounting_response" Tue Feb 23 15:45:33 2016 : Debug: key = "%{User-Name}" Tue Feb 23 15:45:33 2016 : Debug: relaxed = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: Module: Checking session {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter Tue Feb 23 15:45:33 2016 : Debug: attr_filter attr_filter.access_reject { Tue Feb 23 15:45:33 2016 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject" Tue Feb 23 15:45:33 2016 : Debug: key = "%{User-Name}" Tue Feb 23 15:45:33 2016 : Debug: relaxed = no Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: } # modules Tue Feb 23 15:45:33 2016 : Debug: } # server Tue Feb 23 15:45:33 2016 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:33 2016 : Debug: modules { Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking session {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 23 15:45:33 2016 : Debug: } # modules Tue Feb 23 15:45:33 2016 : Debug: } # server Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Feb 23 15:45:33 2016 : Debug: listen { Tue Feb 23 15:45:33 2016 : Debug: type = "auth" Tue Feb 23 15:45:33 2016 : Debug: ipaddr = * Tue Feb 23 15:45:33 2016 : Debug: port = 0 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: listen { Tue Feb 23 15:45:33 2016 : Debug: type = "acct" Tue Feb 23 15:45:33 2016 : Debug: ipaddr = * Tue Feb 23 15:45:33 2016 : Debug: port = 0 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Debug: listen { Tue Feb 23 15:45:33 2016 : Debug: type = "auth" Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1 Tue Feb 23 15:45:33 2016 : Debug: port = 18120 Tue Feb 23 15:45:33 2016 : Debug: } Tue Feb 23 15:45:33 2016 : Info: ... adding new socket proxy address * port 54611 Tue Feb 23 15:45:33 2016 : Debug: Listening on authentication address * port 1812 Tue Feb 23 15:45:33 2016 : Debug: Listening on accounting address * port 1813 Tue Feb 23 15:45:33 2016 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Tue Feb 23 15:45:33 2016 : Debug: Listening on proxy address * port 1814 Tue Feb 23 15:45:33 2016 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=142, length=116 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User EAP-Message = 0x020000090131323334 Message-Authenticator = 0x17ebe7cb3727cfa3b2fde0893d30241a MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 0 length 9 Tue Feb 23 15:45:41 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns updated Tue Feb 23 15:45:41 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:41 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] User found in radcheck table Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] User found in group HP-Procurve-Admin Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Released sql socket id: 3 Tue Feb 23 15:45:41 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:41 2016 : Info: ++[expiration] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[logintime] returns noop Tue Feb 23 15:45:41 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 23 15:45:41 2016 : Info: ++[pap] returns noop Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!! Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: !!! Please update your configuration so that the "known good" !!! Tue Feb 23 15:45:41 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!! Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:41 2016 : Info: [eap] EAP Identity Tue Feb 23 15:45:41 2016 : Info: [eap] processing type md5 Tue Feb 23 15:45:41 2016 : Debug: rlm_eap_md5: Issuing Challenge Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 142 to 192.168.6.211 port 1812 Service-Type = Administrative-User EAP-Message = 0x01010016041092556e11d1495a77ac213fbf04b83b8d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860d487b663cf1bfd5de864a48 Tue Feb 23 15:45:41 2016 : Info: Finished request 0. Tue Feb 23 15:45:41 2016 : Debug: Going to the next request Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=143, length=131 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860d487b663cf1bfd5de864a48 EAP-Message = 0x020100060319 Message-Authenticator = 0xae7630668dd6118c160131b4cefec517 MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 1 length 6 Tue Feb 23 15:45:41 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns updated Tue Feb 23 15:45:41 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:41 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] User found in radcheck table Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Info: [sql] User found in group HP-Procurve-Admin Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Released sql socket id: 2 Tue Feb 23 15:45:41 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:41 2016 : Info: ++[expiration] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[logintime] returns noop Tue Feb 23 15:45:41 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 23 15:45:41 2016 : Info: ++[pap] returns noop Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!! Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: !!! Please update your configuration so that the "known good" !!! Tue Feb 23 15:45:41 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!! Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:41 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:41 2016 : Info: [eap] EAP NAK Tue Feb 23 15:45:41 2016 : Info: [eap] EAP-NAK asked for EAP-Type/peap Tue Feb 23 15:45:41 2016 : Info: [eap] processing type tls Tue Feb 23 15:45:41 2016 : Info: [tls] Initiate Tue Feb 23 15:45:41 2016 : Info: [tls] Start returned 1 Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 143 to 192.168.6.211 port 1812 Service-Type = Administrative-User EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860c4b66663cf1bfd5de864a48 Tue Feb 23 15:45:41 2016 : Info: Finished request 1. Tue Feb 23 15:45:41 2016 : Debug: Going to the next request Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=144, length=211 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860c4b66663cf1bfd5de864a48 EAP-Message = 0x020200561900160303004b010000470303ab6769c0d58d7f9d9e64e9ab8b98b5fd91331b6289cea731d117c81ab3d7f2f900000c003d0035003c002f000a000901000012000d000e000c060105010401030102010101 Message-Authenticator = 0x3bd3a5d1bd573a86245aa80ae07478ff MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 2 length 86 Tue Feb 23 15:45:41 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:41 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:41 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:41 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:41 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:41 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:41 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:41 2016 : Info: [peap] (other): before/accept initialization Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: before/accept initialization Tue Feb 23 15:45:41 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 004b], ClientHello Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 read client hello A Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write server hello A Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 02e6], Certificate Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write certificate A Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write server done A Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 flush data Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Feb 23 15:45:41 2016 : Debug: In SSL Handshake Phase Tue Feb 23 15:45:41 2016 : Debug: In SSL Accept mode Tue Feb 23 15:45:41 2016 : Info: [peap] eaptls_process returned 13 Tue Feb 23 15:45:41 2016 : Info: [peap] EAPTLS_HANDLED Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 144 to 192.168.6.211 port 1812 EAP-Message = 0x010303291900160301002a02000026030134c2c8fe81a89853a504ac4216bfcd1fc0eda05b01ad8c4b3e03edff9e43127d0000350016030102e60b0002e20002df0002dc308202d8308201c0a003020102020900a0b10d9f121dd008300d06092a864886f70d01010b05003024312230200603550403131972616469757330322d6b657363682e636c617373656e2e6465301e170d3136303232323039333634395a170d3236303231393039333634395a3024312230200603550403131972616469757330322d6b657363682e636c617373656e2e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100971a63c43d EAP-Message = 0xf2b17bc57816c5c71129af0b0c5f5a204a9a95eaef60de83596dd0a29042c1a605502c5b95d73d9ca51609c2d41815e3c81a31dbd0ce43d20f9e206b1dd4dc2218b66d1a30d32a546d50ede101691f8df4d64ecd20896a1ca61163ef880b81d3243d647adb27bc943a379185208308203ee571f2d2d665e419e945e8d4bfe75b602b557222bbba56036f38cfc25f79e5cb03fc851cef447313c4474fa32dc4aa7bf3ed62eabcce51e15d5c575847982dc313f7e9621f0b4c7a6a33867bc0e396867f60977bf172e789850bf1b9a46a2594912b4f2b0eccfef51d2a87b2b3f534bf1485bf19c74dbbc1fea76340ab52c8cef84c19a7d1038d89f9c90203 EAP-Message = 0x010001a30d300b30090603551d1304023000300d06092a864886f70d01010b05000382010100218b7b3a3c12279ed2e0f5ff559a9ca32bb24f41262e22544b73dfc8876e0aff872161dd12f4855679b928fa34327111dc74c4cc45371f9661a23eaebea0824669534c78a630229e06c56a772ade4024d1042e4f3f96d1fa6d8055cc594e4f24b0517a5a554816ebfa557b5f5524695dbcdb92fe59323c0dcae23169a10e17964fdfc0d583537be90c080356747c652d2d44d77725fd36fced8cd5801cbf98a9cb7e25c1f332f303287a3e98c1cc67aefb8f02dc1e03c8b2555935b7cc389f50ee01f0f19a3211e35406654c242f3f3804b8f94776ef56 EAP-Message = 0x4f29c6c98be03ab4ca56f65f6c340b40867a94d719979692f3e5bfad7caec05cc561380b09056f7cdf16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860f4a66663cf1bfd5de864a48 Tue Feb 23 15:45:41 2016 : Info: Finished request 2. Tue Feb 23 15:45:41 2016 : Debug: Going to the next request Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=145, length=459 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860f4a66663cf1bfd5de864a48 EAP-Message = 0x0203014c190016030101061000010201005dfdb2a2b54c590ef5d7cc360c6473c1486587d785b79ffead7bc460be2704428796e2b114874b8968c95ac964d71fcfe5d5ade81f82988dad45ca9b08c5205e269138b22ed0f6b339254f0fbf249b965f134aa59fbbeb310006de279dbea43115459743bb9d34520dae23c4db996e07cad77a149ad9da0e2b94a3effa431a113ddecddddba449674bb643465d7f6a32541a51d0560c24643f5d4953e8da3761c7d6555d45f789e8c2db692768f57ed65a395752e943fe7beb2a7c74b6b3ed661a2dfba98f899806a90a51a95ee14d11eb19014bc9a867d570b0e1dc29b2114864ffcc7e3a7e79ee4d6cfbd0 EAP-Message = 0x669aa7029cc07705cacc9d17cbf59a69fac73ac41403010001011603010030c7788739c5cc92d32780d2a3adddd296b748bdf783510c22ce44c3cb34d24aa031e9ed04ff61d09c0668d082dd4646e3 Message-Authenticator = 0x635e498c0eec7a5cccbe224717e8c348 MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 3 length 253 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 read finished A Tue Feb 23 15:45:42 2016 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Tue Feb 23 15:45:42 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 write finished A Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 flush data Tue Feb 23 15:45:42 2016 : Info: [peap] (other): SSL negotiation finished successfully Tue Feb 23 15:45:42 2016 : Debug: SSL Connection Established Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 13 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_HANDLED Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 145 to 192.168.6.211 port 1812 EAP-Message = 0x0104004119001403010001011603010030ea9ac534b5665ede970c0f2b17eeaef50b4889af5b2f1c0cb08c51c504fe230d42017d37df12ae7e23b8e38815a58993 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860e4d66663cf1bfd5de864a48 Tue Feb 23 15:45:42 2016 : Info: Finished request 3. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=146, length=131 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860e4d66663cf1bfd5de864a48 EAP-Message = 0x020400061900 Message-Authenticator = 0x70b79c3d9fa53cd08bb48bd815a0a2af MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 4 length 6 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] Received TLS ACK Tue Feb 23 15:45:42 2016 : Info: [peap] ACK handshake is finished Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 3 Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 3 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_SUCCESS Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state TUNNEL ESTABLISHED Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 146 to 192.168.6.211 port 1812 EAP-Message = 0x0105002b190017030100202b8a05992bfcee61c127eb4722aca63f80d3dfcc7bab78c60a3c41a659a10fb8 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f86094c66663cf1bfd5de864a48 Tue Feb 23 15:45:42 2016 : Info: Finished request 4. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=147, length=168 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f86094c66663cf1bfd5de864a48 EAP-Message = 0x0205002b1900170301002022f3c45761dfa101968af468f6a95339b01c176d48a72061254682aa6d1d7c5a Message-Authenticator = 0x1a5d2573de10c5ea6a9d1f2aee5625fd MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 5 length 43 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state WAITING FOR INNER IDENTITY Tue Feb 23 15:45:42 2016 : Info: [peap] Identity - 1234 Tue Feb 23 15:45:42 2016 : Info: [peap] Got inner identity '1234' Tue Feb 23 15:45:42 2016 : Info: [peap] Setting default EAP type for tunneled EAP session. Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request EAP-Message = 0x020500090131323334 server { Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234 Sending tunneled request EAP-Message = 0x020500090131323334 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "1234" server inner-tunnel { Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 5 length 9 Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 1 Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 1 Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!! Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] EAP Identity Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2 Tue Feb 23 15:45:42 2016 : Debug: rlm_eap_mschapv2: Issuing Challenge Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled } # server inner-tunnel Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x0106001e1a01060019108f9ae5e1e773168c098f021e5eb93d4831323334 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x6162be1b6164a4ac160d1d957d730383 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0106001e1a01060019108f9ae5e1e773168c098f021e5eb93d4831323334 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x6162be1b6164a4ac160d1d957d730383 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 01 06 00 19 10 8f 9a e5 e1 e7 73 16 8c 09 8f PEAP tunnel data out 0010: 02 1e 5e b9 3d 48 31 32 33 34 Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 147 to 192.168.6.211 port 1812 EAP-Message = 0x0106003b1900170301003067bf2338238b7bca8ef7ef4051623cf7eb1d140c350fc2cf1506a4f97d1e64494141be8566aaa6351f18cdcd51c2bad0 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f86084f66663cf1bfd5de864a48 Tue Feb 23 15:45:42 2016 : Info: Finished request 5. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=148, length=216 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f86084f66663cf1bfd5de864a48 EAP-Message = 0x0206005b19001703010050c54c0374d48331d44c233ddf239ed06afcdf5825bb291bb909009b9d0381bbb4c1caa824a57ed00f1764b4ce50d13cb6299d20f22d24ec58d9d53fad9462b355ae34b84835129fcfb2093a461d567048 Message-Authenticator = 0xd7fb5217628dd8369628f52948d02c67 MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 6 length 91 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state phase2 Tue Feb 23 15:45:42 2016 : Info: [peap] EAP type mschapv2 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request EAP-Message = 0x0206003f1a0206003a31da54aae7ed025f63818a1f7b17cd934800000000000000006941aa38ea42622be320ddeca697b590fef937d30cd993760031323334 server { Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234 Sending tunneled request EAP-Message = 0x0206003f1a0206003a31da54aae7ed025f63818a1f7b17cd934800000000000000006941aa38ea42622be320ddeca697b590fef937d30cd993760031323334 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "1234" State = 0x6162be1b6164a4ac160d1d957d730383 server inner-tunnel { Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 6 length 63 Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 0 Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 0 Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!! Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/mschapv2 Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2 Tue Feb 23 15:45:42 2016 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: [mschapv2] +- entering group MS-CHAP {...} Tue Feb 23 15:45:42 2016 : Info: [mschap] Creating challenge hash with username: 1234 Tue Feb 23 15:45:42 2016 : Info: [mschap] Told to do MS-CHAPv2 for 1234 with NT-Password Tue Feb 23 15:45:42 2016 : Info: [mschap] adding MS-CHAPv2 MPPE keys Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns ok Tue Feb 23 15:45:42 2016 : Debug: MSCHAP Success Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled } # server inner-tunnel Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x010700331a0306002e533d31453141333445313845333144453634323243303744374444463833423436314635434132424136 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x6162be1b6065a4ac160d1d957d730383 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010700331a0306002e533d31453141333445313845333144453634323243303744374444463833423436314635434132424136 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x6162be1b6065a4ac160d1d957d730383 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 03 06 00 2e 53 3d 31 45 31 41 33 34 45 31 38 PEAP tunnel data out 0010: 45 33 31 44 45 36 34 32 32 43 30 37 44 37 44 44 PEAP tunnel data out 0020: 46 38 33 42 34 36 31 46 35 43 41 32 42 41 36 Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 148 to 192.168.6.211 port 1812 EAP-Message = 0x0107005b19001703010050c4d6781c42a769e49995eddde0f39054a452a415ba7033be63f401fa2c876c2fed4d926e97a11a7c5ca625adfd746efcb3e0736f62c967ba51ee0718385ee5daaa58ac9529d80821fdc70c1efa6154c0 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860b4e66663cf1bfd5de864a48 Tue Feb 23 15:45:42 2016 : Info: Finished request 6. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=149, length=168 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860b4e66663cf1bfd5de864a48 EAP-Message = 0x0207002b190017030100203bd61645e3583319a411219921d8df3471af6a1012bf51c9f59dbac842803fe4 Message-Authenticator = 0x1428e10214392763b0e798d4ce4b9738 MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 7 length 43 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state phase2 Tue Feb 23 15:45:42 2016 : Info: [peap] EAP type mschapv2 Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request EAP-Message = 0x020700061a03 server { Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234 Sending tunneled request EAP-Message = 0x020700061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "1234" State = 0x6162be1b6065a4ac160d1d957d730383 server inner-tunnel { Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 7 length 6 Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 4 Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!! Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!! Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/mschapv2 Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2 Tue Feb 23 15:45:42 2016 : Info: [eap] Freeing handler Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel Tue Feb 23 15:45:42 2016 : Info: +- entering group post-auth {...} Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Password} -> Tue Feb 23 15:45:42 2016 : Info: [sql] ... expanding second conditional Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{Chap-Password} -> Tue Feb 23 15:45:42 2016 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Info: [sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 3 Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:42 2016 : Info: expand: %{request:User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: ++[outer.reply] returns ok } # server inner-tunnel Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 2 MS-MPPE-Encryption-Policy = 0x00000002 MS-MPPE-Encryption-Types = 0x00000004 MS-MPPE-Send-Key = 0x912567151985026409e260663b70aa06 MS-MPPE-Recv-Key = 0x02a930052a14bd9b484e190eaabd4b49 EAP-Message = 0x03070004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "1234" Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 2 MS-MPPE-Encryption-Policy = 0x00000002 MS-MPPE-Encryption-Types = 0x00000004 MS-MPPE-Send-Key = 0x912567151985026409e260663b70aa06 MS-MPPE-Recv-Key = 0x02a930052a14bd9b484e190eaabd4b49 EAP-Message = 0x03070004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "1234" Tue Feb 23 15:45:42 2016 : Info: [peap] Tunneled authentication was successful. Tue Feb 23 15:45:42 2016 : Info: [peap] SUCCESS Tue Feb 23 15:45:42 2016 : Info: [peap] Saving tunneled attributes for later Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled Sending Access-Challenge of id 149 to 192.168.6.211 port 1812 User-Name = "1234" Service-Type = Administrative-User EAP-Message = 0x0108002b190017030100202db20bbce3b72afa194b4f3d3bc314eaa7406a57c511ba71b42d2ffce72d01fc Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0d497f860a4166663cf1bfd5de864a48 Tue Feb 23 15:45:42 2016 : Info: Finished request 7. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=150, length=168 User-Name = "1234" NAS-IP-Address = 211.6.168.192 NAS-Identifier = "SWITCH01-TEST" NAS-Port-Type = Virtual Service-Type = NAS-Prompt-User State = 0x0d497f860a4166663cf1bfd5de864a48 EAP-Message = 0x0208002b19001703010020358541ebeef1d422e9a8abf682c3ff01eccba593fee137a12c3d3fe651a8c471 Message-Authenticator = 0xd046b2197cd82e8855887dbd74e9edd3 MS-RAS-Vendor = 184549376 Calling-Station-Id = "192.168.14.114" Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...} Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL" Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 8 length 43 Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup. Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...} Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7 Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state send tlv success Tue Feb 23 15:45:42 2016 : Info: [peap] Received EAP-TLV response. Tue Feb 23 15:45:42 2016 : Info: [peap] Success Tue Feb 23 15:45:42 2016 : Info: [peap] Using saved attributes from the original Access-Accept User-Name = "1234" Tue Feb 23 15:45:42 2016 : Info: [eap] Freeing handler Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok Tue Feb 23 15:45:42 2016 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default Tue Feb 23 15:45:42 2016 : Info: +- entering group post-auth {...} Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234 Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234' Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Password} -> Tue Feb 23 15:45:42 2016 : Info: [sql] ... expanding second conditional Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{Chap-Password} -> Tue Feb 23 15:45:42 2016 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Info: [sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42') Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 2 Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok Tue Feb 23 15:45:42 2016 : Info: ++[exec] returns noop Sending Access-Accept of id 150 to 192.168.6.211 port 1812 User-Name = "1234" MS-MPPE-Recv-Key = 0xb59a7655a33a5a5b6979a195b6277d8e7ac7a128b3eb78f2a941de634490be80 MS-MPPE-Send-Key = 0x47a29459f2ffd034955b9c980be7b66750706df94a0f24f279ca9999b3753da6 EAP-Message = 0x03080004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Feb 23 15:45:42 2016 : Info: Finished request 8. Tue Feb 23 15:45:42 2016 : Debug: Going to the next request Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds. Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 0 ID 142 with timestamp +8 Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 1 ID 143 with timestamp +8 Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 2 ID 144 with timestamp +8 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 3 ID 145 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 4 ID 146 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 5 ID 147 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 6 ID 148 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 7 ID 149 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 8 ID 150 with timestamp +9 Tue Feb 23 15:45:47 2016 : Info: Ready to process requests. Best regards Jonas

2 2

RE: FR Crash during ldap issues
by Franks Andy (IT Technical Architecture Manager) 23 Feb '16

23 Feb '16

Thanks Arran, I'll give that a test. Stupid AD servers have gone cross-eyed and just randomly time out, which is nice. Why stuff just can't work and stay working is beyond me. Cheers Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Arran Cudbard-Bell Sent: 22 February 2016 23:28 To: FreeRadius users mailing list Subject: Re: FR Crash during ldap issues > On 22 Feb 2016, at 12:20, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > > Hi all, > We've been having a few ldap timeouts and other weirdness. Unfortunately this has had the effect of stopping freeradius. The backtrace is below - any chance of someone taking a look and commenting? It's calling write on a socket that has already been closed. I pushed some changes which should show if we're closing the connection multiple times. Could you try with that? If it still crashes in the same way, then it's a libldap/gnutls issue. -Arran Arran Cudbard-Bell <a.cudbardb(a)freeradius.org> FreeRADIUS development team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2

1 0