TTLS authentication is not working on Ubuntu 16.04 Freeradius 2.2.8

6 Dec 2017

      Hello,

I have installed Freeradius (version 2.2.8) on Ubuntu 16.04 and user authentication is working for MD5, PEAPv0 and TLS authentications. However TTLS authentication is failing. I see from the logs that the group authentication is failing. Is there some configuration that I am missing? This is the client information for the Cisco Authenticator:

client 192.168.100.0/24 {
                require_message_authenticator = no
secret = "cisco"
shortname = "private-network-1"
}

This is the debug output from running "freeradius -xX":

root@ixia-Qa-Freeradius:/etc/freeradius# freeradius -xX
Fri Dec  1 16:21:44 2017 : Info: freeradius: FreeRADIUS Version 2.2.8, for host x86_64-pc-linux-gnu, built on Jul 26 2017 at 15:27:21
Fri Dec  1 16:21:44 2017 : Debug: Server was built with:
Fri Dec  1 16:21:44 2017 : Debug:   accounting
Fri Dec  1 16:21:44 2017 : Debug:   authentication
Fri Dec  1 16:21:44 2017 : Debug:  WITH_DHCP
Fri Dec  1 16:21:44 2017 : Debug:  WITH_VMPS
Fri Dec  1 16:21:44 2017 : Debug: Server core libs:
Fri Dec  1 16:21:44 2017 : Debug:   ssl: OpenSSL 1.0.2g  1 Mar 2016
Fri Dec  1 16:21:44 2017 : Info: Copyright (C) 1999-2015 The FreeRADIUS server project and contributors.
Fri Dec  1 16:21:44 2017 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Fri Dec  1 16:21:44 2017 : Info: PARTICULAR PURPOSE.
Fri Dec  1 16:21:44 2017 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Fri Dec  1 16:21:44 2017 : Info: GNU General Public License.
Fri Dec  1 16:21:44 2017 : Info: For more information about these matters, see the file named COPYRIGHT.
Fri Dec  1 16:21:44 2017 : Info: Starting - reading configuration files ...
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/radiusd.conf
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/proxy.conf
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/clients.conf
Fri Dec  1 16:21:44 2017 : Debug: including files in directory /etc/freeradius/modules/
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/exec
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/files
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/unix
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/ippool
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/sradutmp
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/radutmp
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/expiration
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/opendirectory
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/etc_group
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/rediswho
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/krb5
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/policy
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/soh
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/always
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/realm
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/cui
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/sql_log
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/checkval
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/smsotp
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/echo
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/dhcp_sqlippool
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/inner-eap
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/cache
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/radrelay
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/counter
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/preprocess
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/linelog
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/detail.log
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/pap
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/chap
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/pam
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/attr_filter
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/ldap
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/replicate
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/redis
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/smbpasswd
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/mac2ip
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/expr
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/mschap
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/detail
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/passwd
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/logintime
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/digest
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/perl
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/detail.example.com
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/mac2vlan
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/otp
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/wimax
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/modules/acct_unique
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/eap.conf
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/policy.conf
Fri Dec  1 16:21:44 2017 : Debug: including files in directory /etc/freeradius/sites-enabled/
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:21:44 2017 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Fri Dec  1 16:21:44 2017 : Debug: main {
Fri Dec  1 16:21:44 2017 : Debug:                user = "freerad"
Fri Dec  1 16:21:44 2017 : Debug:                group = "freerad"
Fri Dec  1 16:21:44 2017 : Debug:                allow_core_dumps = no
Fri Dec  1 16:21:44 2017 : Debug: }
Fri Dec  1 16:21:44 2017 : Debug: including dictionary file /etc/freeradius/dictionary
Fri Dec  1 16:21:44 2017 : Debug: main {
Fri Dec  1 16:21:44 2017 : Debug:                name = "freeradius"
Fri Dec  1 16:21:44 2017 : Debug:                prefix = "/usr"
Fri Dec  1 16:21:44 2017 : Debug:                localstatedir = "/var"
Fri Dec  1 16:21:44 2017 : Debug:                sbindir = "/usr/sbin"
Fri Dec  1 16:21:44 2017 : Debug:                logdir = "/var/log/freeradius"
Fri Dec  1 16:21:44 2017 : Debug:                run_dir = "/var/run/freeradius"
Fri Dec  1 16:21:44 2017 : Debug:                libdir = "/usr/lib/freeradius"
Fri Dec  1 16:21:44 2017 : Debug:                radacctdir = "/var/log/freeradius/radacct"
Fri Dec  1 16:21:44 2017 : Debug:                hostname_lookups = no
Fri Dec  1 16:21:44 2017 : Debug:                max_request_time = 30
Fri Dec  1 16:21:44 2017 : Debug:                cleanup_delay = 5
Fri Dec  1 16:21:44 2017 : Debug:                max_requests = 1024
Fri Dec  1 16:21:44 2017 : Debug:                pidfile = "/var/run/freeradius/freeradius.pid"
Fri Dec  1 16:21:44 2017 : Debug:                checkrad = "/usr/sbin/checkrad"
Fri Dec  1 16:21:44 2017 : Debug:                debug_level = 0
Fri Dec  1 16:21:44 2017 : Debug:                proxy_requests = yes
Fri Dec  1 16:21:44 2017 : Debug:  log {
Fri Dec  1 16:21:44 2017 : Debug:                stripped_names = no
Fri Dec  1 16:21:44 2017 : Debug:                auth = no
Fri Dec  1 16:21:44 2017 : Debug:                auth_badpass = no
Fri Dec  1 16:21:44 2017 : Debug:                auth_goodpass = no
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  security {
Fri Dec  1 16:21:44 2017 : Debug:                max_attributes = 200
Fri Dec  1 16:21:44 2017 : Debug:                reject_delay = 1
Fri Dec  1 16:21:44 2017 : Debug:                status_server = yes
Fri Dec  1 16:21:44 2017 : Debug:                allow_vulnerable_openssl = no
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug: }
Fri Dec  1 16:21:44 2017 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Dec  1 16:21:44 2017 : Debug:  proxy server {
Fri Dec  1 16:21:44 2017 : Debug:                retry_delay = 5
Fri Dec  1 16:21:44 2017 : Debug:                retry_count = 3
Fri Dec  1 16:21:44 2017 : Debug:                default_fallback = no
Fri Dec  1 16:21:44 2017 : Debug:                dead_time = 120
Fri Dec  1 16:21:44 2017 : Debug:                wake_all_if_all_dead = no
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  home_server localhost {
Fri Dec  1 16:21:44 2017 : Debug:                ipaddr = 127.0.0.1
Fri Dec  1 16:21:44 2017 : Debug:                port = 1812
Fri Dec  1 16:21:44 2017 : Debug:                type = "auth"
Fri Dec  1 16:21:44 2017 : Debug:                secret = "testing123"
Fri Dec  1 16:21:44 2017 : Debug:                response_window = 20
Fri Dec  1 16:21:44 2017 : Debug:                max_outstanding = 65536
Fri Dec  1 16:21:44 2017 : Debug:                require_message_authenticator = yes
Fri Dec  1 16:21:44 2017 : Debug:                zombie_period = 40
Fri Dec  1 16:21:44 2017 : Debug:                status_check = "status-server"
Fri Dec  1 16:21:44 2017 : Debug:                ping_interval = 30
Fri Dec  1 16:21:44 2017 : Debug:                check_interval = 30
Fri Dec  1 16:21:44 2017 : Debug:                num_answers_to_alive = 3
Fri Dec  1 16:21:44 2017 : Debug:                num_pings_to_alive = 3
Fri Dec  1 16:21:44 2017 : Debug:                revive_interval = 120
Fri Dec  1 16:21:44 2017 : Debug:                status_check_timeout = 4
Fri Dec  1 16:21:44 2017 : Debug:   coa {
Fri Dec  1 16:21:44 2017 : Debug:                irt = 2
Fri Dec  1 16:21:44 2017 : Debug:                mrt = 16
Fri Dec  1 16:21:44 2017 : Debug:                mrc = 5
Fri Dec  1 16:21:44 2017 : Debug:                mrd = 30
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  home_server_pool my_auth_failover {
Fri Dec  1 16:21:44 2017 : Debug:                type = fail-over
Fri Dec  1 16:21:44 2017 : Debug:                home_server = localhost
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  realm example.com {
Fri Dec  1 16:21:44 2017 : Debug:                auth_pool = my_auth_failover
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  realm LOCAL {
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug: radiusd: #### Loading Clients ####
Fri Dec  1 16:21:44 2017 : Debug:  client localhost {
Fri Dec  1 16:21:44 2017 : Debug:                ipaddr = 127.0.0.1
Fri Dec  1 16:21:44 2017 : Debug:                require_message_authenticator = no
Fri Dec  1 16:21:44 2017 : Debug:                secret = "testing123"
Fri Dec  1 16:21:44 2017 : Debug:                nastype = "cisco"
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug:  client 192.168.100.0/24 {
Fri Dec  1 16:21:44 2017 : Debug:                require_message_authenticator = no
Fri Dec  1 16:21:44 2017 : Debug:                secret = "cisco"
Fri Dec  1 16:21:44 2017 : Debug:                shortname = "private-network-1"
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug: radiusd: #### Instantiating modules ####
Fri Dec  1 16:21:44 2017 : Debug:  instantiate {
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_exec, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_exec
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "exec" from file /etc/freeradius/modules/exec
Fri Dec  1 16:21:44 2017 : Debug:   exec {
Fri Dec  1 16:21:44 2017 : Debug:                wait = no
Fri Dec  1 16:21:44 2017 : Debug:                input_pairs = "request"
Fri Dec  1 16:21:44 2017 : Debug:                shell_escape = yes
Fri Dec  1 16:21:44 2017 : Debug:                timeout = 10
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_expr, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_expr
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "expr" from file /etc/freeradius/modules/expr
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_expiration, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_expiration
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration
Fri Dec  1 16:21:44 2017 : Debug:   expiration {
Fri Dec  1 16:21:44 2017 : Debug:                reply-message = "Password Has Expired  "
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_logintime, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_logintime
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime
Fri Dec  1 16:21:44 2017 : Debug:   logintime {
Fri Dec  1 16:21:44 2017 : Debug:                reply-message = "You are calling outside your allowed timespan  "
Fri Dec  1 16:21:44 2017 : Debug:                minimum-timeout = 60
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:  }
Fri Dec  1 16:21:44 2017 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Dec  1 16:21:44 2017 : Debug: server { # from file /etc/freeradius/radiusd.conf
Fri Dec  1 16:21:44 2017 : Debug:  modules {
Fri Dec  1 16:21:44 2017 : Debug:   Module: Creating Auth-Type = digest
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_pap, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_pap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "pap" from file /etc/freeradius/modules/pap
Fri Dec  1 16:21:44 2017 : Debug:   pap {
Fri Dec  1 16:21:44 2017 : Debug:                encryption_scheme = "auto"
Fri Dec  1 16:21:44 2017 : Debug:                auto_header = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_chap, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_chap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "chap" from file /etc/freeradius/modules/chap
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_mschap, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_mschap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap
Fri Dec  1 16:21:44 2017 : Debug:   mschap {
Fri Dec  1 16:21:44 2017 : Debug:                use_mppe = yes
Fri Dec  1 16:21:44 2017 : Debug:                require_encryption = no
Fri Dec  1 16:21:44 2017 : Debug:                require_strong = no
Fri Dec  1 16:21:44 2017 : Debug:                with_ntdomain_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                allow_retry = yes
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_digest, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_digest
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "digest" from file /etc/freeradius/modules/digest
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_pam, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_pam
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "pam" from file /etc/freeradius/modules/pam
Fri Dec  1 16:21:44 2017 : Debug:   pam {
Fri Dec  1 16:21:44 2017 : Debug:                pam_auth = "radiusd"
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_unix, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_unix
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "unix" from file /etc/freeradius/modules/unix
Fri Dec  1 16:21:44 2017 : Debug:   unix {
Fri Dec  1 16:21:44 2017 : Debug:                radwtmp = "/var/log/freeradius/radwtmp"
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_eap, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_eap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "eap" from file /etc/freeradius/eap.conf
Fri Dec  1 16:21:44 2017 : Debug:   eap {
Fri Dec  1 16:21:44 2017 : Debug:                default_eap_type = "md5"
Fri Dec  1 16:21:44 2017 : Debug:                timer_expire = 60
Fri Dec  1 16:21:44 2017 : Debug:                ignore_unknown_eap_types = no
Fri Dec  1 16:21:44 2017 : Debug:                cisco_accounting_username_bug = no
Fri Dec  1 16:21:44 2017 : Debug:                max_sessions = 1024
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_md5
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-md5
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_leap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-leap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-gtc
Fri Dec  1 16:21:44 2017 : Debug:    gtc {
Fri Dec  1 16:21:44 2017 : Debug:                challenge = "Password: "
Fri Dec  1 16:21:44 2017 : Debug:                auth_type = "PAP"
Fri Dec  1 16:21:44 2017 : Debug:    }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_tls
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-tls
Fri Dec  1 16:21:44 2017 : Debug:    tls {
Fri Dec  1 16:21:44 2017 : Debug:                rsa_key_exchange = no
Fri Dec  1 16:21:44 2017 : Debug:                dh_key_exchange = yes
Fri Dec  1 16:21:44 2017 : Debug:                rsa_key_length = 512
Fri Dec  1 16:21:44 2017 : Debug:                dh_key_length = 512
Fri Dec  1 16:21:44 2017 : Debug:                verify_depth = 0
Fri Dec  1 16:21:44 2017 : Debug:                CA_path = "/etc/freeradius/certs"
Fri Dec  1 16:21:44 2017 : Debug:                pem_file_type = yes
Fri Dec  1 16:21:44 2017 : Debug:                private_key_file = "/etc/freeradius/certs/server_key.pem"
Fri Dec  1 16:21:44 2017 : Debug:                certificate_file = "/etc/freeradius/certs/server_cert.pem"
Fri Dec  1 16:21:44 2017 : Debug:                CA_file = "/etc/freeradius/certs/root.pem"
Fri Dec  1 16:21:44 2017 : Debug:                private_key_password = "whatever"
Fri Dec  1 16:21:44 2017 : Debug:                dh_file = "/etc/freeradius/certs/dh"
Fri Dec  1 16:21:44 2017 : Debug:                random_file = "/dev/urandom"
Fri Dec  1 16:21:44 2017 : Debug:                fragment_size = 1024
Fri Dec  1 16:21:44 2017 : Debug:                include_length = yes
Fri Dec  1 16:21:44 2017 : Debug:                check_crl = no
Fri Dec  1 16:21:44 2017 : Debug:                check_all_crl = no
Fri Dec  1 16:21:44 2017 : Debug:                cipher_list = "DEFAULT"
Fri Dec  1 16:21:44 2017 : Debug:                make_cert_command = "/etc/freeradius/certs/bootstrap"
Fri Dec  1 16:21:44 2017 : Debug:                ecdh_curve = "prime256v1"
Fri Dec  1 16:21:44 2017 : Debug:     cache {
Fri Dec  1 16:21:44 2017 : Debug:                enable = no
Fri Dec  1 16:21:44 2017 : Debug:                lifetime = 24
Fri Dec  1 16:21:44 2017 : Debug:                max_entries = 255
Fri Dec  1 16:21:44 2017 : Debug:     }
Fri Dec  1 16:21:44 2017 : Debug:     verify {
Fri Dec  1 16:21:44 2017 : Debug:     }
Fri Dec  1 16:21:44 2017 : Debug:     ocsp {
Fri Dec  1 16:21:44 2017 : Debug:                enable = no
Fri Dec  1 16:21:44 2017 : Debug:                override_cert_url = yes
Fri Dec  1 16:21:44 2017 : Debug:                url = "http://127.0.0.1/ocsp/"
Fri Dec  1 16:21:44 2017 : Debug:                use_nonce = yes
Fri Dec  1 16:21:44 2017 : Debug:                timeout = 0
Fri Dec  1 16:21:44 2017 : Debug:                softfail = no
Fri Dec  1 16:21:44 2017 : Debug:     }
Fri Dec  1 16:21:44 2017 : Debug:    }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-ttls
Fri Dec  1 16:21:44 2017 : Debug:    ttls {
Fri Dec  1 16:21:44 2017 : Debug:                default_eap_type = "md5"
Fri Dec  1 16:21:44 2017 : Debug:                copy_request_to_tunnel = no
Fri Dec  1 16:21:44 2017 : Debug:                use_tunneled_reply = yes
Fri Dec  1 16:21:44 2017 : Debug:                virtual_server = "inner-tunnel"
Fri Dec  1 16:21:44 2017 : Debug:                include_length = yes
Fri Dec  1 16:21:44 2017 : Debug:    }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_peap
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-peap
Fri Dec  1 16:21:44 2017 : Debug:    peap {
Fri Dec  1 16:21:44 2017 : Debug:                default_eap_type = "mschapv2"
Fri Dec  1 16:21:44 2017 : Debug:                copy_request_to_tunnel = no
Fri Dec  1 16:21:44 2017 : Debug:                use_tunneled_reply = no
Fri Dec  1 16:21:44 2017 : Debug:                proxy_tunneled_request_as_eap = yes
Fri Dec  1 16:21:44 2017 : Debug:                virtual_server = "inner-tunnel"
Fri Dec  1 16:21:44 2017 : Debug:                soh = no
Fri Dec  1 16:21:44 2017 : Debug:    }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to sub-module rlm_eap_mschapv2
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating eap-mschapv2
Fri Dec  1 16:21:44 2017 : Debug:    mschapv2 {
Fri Dec  1 16:21:44 2017 : Debug:                with_ntdomain_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                send_error = no
Fri Dec  1 16:21:44 2017 : Debug:    }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_preprocess, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_preprocess
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess
Fri Dec  1 16:21:44 2017 : Debug:   preprocess {
Fri Dec  1 16:21:44 2017 : Debug:                huntgroups = "/etc/freeradius/huntgroups"
Fri Dec  1 16:21:44 2017 : Debug:                hints = "/etc/freeradius/hints"
Fri Dec  1 16:21:44 2017 : Debug:                with_ascend_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                ascend_channels_per_line = 23
Fri Dec  1 16:21:44 2017 : Debug:                with_ntdomain_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                with_specialix_jetstream_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                with_cisco_vsa_hack = no
Fri Dec  1 16:21:44 2017 : Debug:                with_alvarion_vsa_hack = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/huntgroups
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/hints
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_realm, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_realm
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm
Fri Dec  1 16:21:44 2017 : Debug:   realm suffix {
Fri Dec  1 16:21:44 2017 : Debug:                format = "suffix"
Fri Dec  1 16:21:44 2017 : Debug:                delimiter = "@"
Fri Dec  1 16:21:44 2017 : Debug:                ignore_default = no
Fri Dec  1 16:21:44 2017 : Debug:                ignore_null = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_files, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_files
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "files" from file /etc/freeradius/modules/files
Fri Dec  1 16:21:44 2017 : Debug:   files {
Fri Dec  1 16:21:44 2017 : Debug:                usersfile = "/etc/freeradius/users"
Fri Dec  1 16:21:44 2017 : Debug:                acctusersfile = "/etc/freeradius/acct_users"
Fri Dec  1 16:21:44 2017 : Debug:                preproxy_usersfile = "/etc/freeradius/preproxy_users"
Fri Dec  1 16:21:44 2017 : Debug:                compat = "no"
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/users
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/acct_users
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/preproxy_users
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking preacct {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_acct_unique, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_acct_unique
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique
Fri Dec  1 16:21:44 2017 : Debug:   acct_unique {
Fri Dec  1 16:21:44 2017 : Debug:                key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking accounting {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_detail, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_detail
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "detail" from file /etc/freeradius/modules/detail
Fri Dec  1 16:21:44 2017 : Debug:   detail {
Fri Dec  1 16:21:44 2017 : Debug:                detailfile = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Fri Dec  1 16:21:44 2017 : Debug:                header = "%t"
Fri Dec  1 16:21:44 2017 : Debug:                detailperm = 384
Fri Dec  1 16:21:44 2017 : Debug:                dirperm = 493
Fri Dec  1 16:21:44 2017 : Debug:                locking = no
Fri Dec  1 16:21:44 2017 : Debug:                log_packet_header = no
Fri Dec  1 16:21:44 2017 : Debug:                escape_filenames = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_attr_filter, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_attr_filter
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter
Fri Dec  1 16:21:44 2017 : Debug:   attr_filter attr_filter.accounting_response {
Fri Dec  1 16:21:44 2017 : Debug:                attrsfile = "/etc/freeradius/attrs.accounting_response"
Fri Dec  1 16:21:44 2017 : Debug:                key = "%{User-Name}"
Fri Dec  1 16:21:44 2017 : Debug:                relaxed = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/attrs.accounting_response
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking session {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:     (Loaded rlm_radutmp, checking if it's valid)
Fri Dec  1 16:21:44 2017 : Debug:  Module: Linked to module rlm_radutmp
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp
Fri Dec  1 16:21:44 2017 : Debug:   radutmp {
Fri Dec  1 16:21:44 2017 : Debug:                filename = "/var/log/freeradius/radutmp"
Fri Dec  1 16:21:44 2017 : Debug:                username = "%{User-Name}"
Fri Dec  1 16:21:44 2017 : Debug:                case_sensitive = yes
Fri Dec  1 16:21:44 2017 : Debug:                check_with_nas = yes
Fri Dec  1 16:21:44 2017 : Debug:                perm = 384
Fri Dec  1 16:21:44 2017 : Debug:                callerid = yes
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Fri Dec  1 16:21:44 2017 : Debug:   attr_filter attr_filter.access_reject {
Fri Dec  1 16:21:44 2017 : Debug:                attrsfile = "/etc/freeradius/attrs.access_reject"
Fri Dec  1 16:21:44 2017 : Debug:                key = "%{User-Name}"
Fri Dec  1 16:21:44 2017 : Debug:                relaxed = no
Fri Dec  1 16:21:44 2017 : Debug:   }
Fri Dec  1 16:21:44 2017 : Debug: reading pairlist file /etc/freeradius/attrs.access_reject
Fri Dec  1 16:21:44 2017 : Debug:  } # modules
Fri Dec  1 16:21:44 2017 : Debug: } # server
Fri Dec  1 16:21:44 2017 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel
Fri Dec  1 16:21:44 2017 : Debug:  modules {
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking session {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Dec  1 16:21:44 2017 : Debug:  } # modules
Fri Dec  1 16:21:44 2017 : Debug: } # server
Fri Dec  1 16:21:44 2017 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Dec  1 16:21:44 2017 : Debug: listen {
Fri Dec  1 16:21:44 2017 : Debug:                type = "auth"
Fri Dec  1 16:21:44 2017 : Debug:                ipaddr = 192.168.100.1
Fri Dec  1 16:21:44 2017 : Debug:                port = 1645
Fri Dec  1 16:21:44 2017 : Debug: }
Fri Dec  1 16:21:44 2017 : Debug: listen {
Fri Dec  1 16:21:44 2017 : Debug:                type = "acct"
Fri Dec  1 16:21:44 2017 : Debug:                ipaddr = *
Fri Dec  1 16:21:44 2017 : Debug:                port = 0
Fri Dec  1 16:21:44 2017 : Debug: }
Fri Dec  1 16:21:44 2017 : Debug: listen {
Fri Dec  1 16:21:44 2017 : Debug:                type = "auth"
Fri Dec  1 16:21:44 2017 : Debug:                ipaddr = 127.0.0.1
Fri Dec  1 16:21:44 2017 : Debug:                port = 18120
Fri Dec  1 16:21:44 2017 : Debug: }
Fri Dec  1 16:21:44 2017 : Debug:  ... adding new socket proxy address * port 51592
Fri Dec  1 16:21:44 2017 : Debug: Listening on authentication interface ens192 address 192.168.100.1 port 1645
Fri Dec  1 16:21:44 2017 : Debug: Listening on accounting address * port 1813
Fri Dec  1 16:21:44 2017 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Fri Dec  1 16:21:44 2017 : Debug: Listening on proxy address 192.168.100.1 port 1647
Fri Dec  1 16:21:44 2017 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=158, length=152
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                EAP-Message = 0x0200000e01497869615573657233
                Message-Authenticator = 0x6684f9ff1c0cc8bd674f12581e828f21
Fri Dec  1 16:23:12 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authorize {
Fri Dec  1 16:23:12 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:12 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:12 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:12 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP packet type response id 0 length 14
Fri Dec  1 16:23:12 2017 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = updated
Fri Dec  1 16:23:12 2017 : Info: [files] users: Matched entry IxiaUser3 at line 92
Fri Dec  1 16:23:12 2017 : Info: ++[files] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[expiration] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[logintime] = noop
Fri Dec  1 16:23:12 2017 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Fri Dec  1 16:23:12 2017 : Info: ++[pap] = noop
Fri Dec  1 16:23:12 2017 : Info: +} # group authorize = updated
Fri Dec  1 16:23:12 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:12 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authenticate {
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP Identity
Fri Dec  1 16:23:12 2017 : Info: [eap] processing type md5
Fri Dec  1 16:23:12 2017 : Debug: rlm_eap_md5: Issuing Challenge
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:12 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 158 to 192.168.100.2 port 1645
                EAP-Message = 0x010100160410dd2045814f787682ebd8a34d7d8d7372
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff1b780881bf75674bfd214cc
Fri Dec  1 16:23:12 2017 : Info: Finished request 0.
Fri Dec  1 16:23:12 2017 : Debug: Going to the next request
Fri Dec  1 16:23:12 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=159, length=162
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff1b780881bf75674bfd214cc
                EAP-Message = 0x020100060315
                Message-Authenticator = 0x338cf6fb73f1b7a8010abf19b874e470
Fri Dec  1 16:23:12 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authorize {
Fri Dec  1 16:23:12 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:12 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:12 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:12 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP packet type response id 1 length 6
Fri Dec  1 16:23:12 2017 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = updated
Fri Dec  1 16:23:12 2017 : Info: [files] users: Matched entry IxiaUser3 at line 92
Fri Dec  1 16:23:12 2017 : Info: ++[files] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[expiration] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[logintime] = noop
Fri Dec  1 16:23:12 2017 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Fri Dec  1 16:23:12 2017 : Info: ++[pap] = noop
Fri Dec  1 16:23:12 2017 : Info: +} # group authorize = updated
Fri Dec  1 16:23:12 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:12 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authenticate {
Fri Dec  1 16:23:12 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP NAK
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP-NAK asked for EAP-Type/ttls
Fri Dec  1 16:23:12 2017 : Info: [eap] processing type tls
Fri Dec  1 16:23:12 2017 : Info: [tls] Initiate
Fri Dec  1 16:23:12 2017 : Info: [tls] Start returned 1
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:12 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 159 to 192.168.100.2 port 1645
                EAP-Message = 0x010200061520
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff0b491881bf75674bfd214cc
Fri Dec  1 16:23:12 2017 : Info: Finished request 1.
Fri Dec  1 16:23:12 2017 : Debug: Going to the next request
Fri Dec  1 16:23:12 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=160, length=260
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff0b491881bf75674bfd214cc
                EAP-Message = 0x0202006815800000005e16030100590100005503015a212fbc8e3eb147b08cbfa0d9e19720addd4ce3086ba9beb8ffb0c8a65929bf00002800390038003500160013000a00330032002f000700050004001500120009001400110008000600030100000400230000
                Message-Authenticator = 0x34befb6d2d79af57abfd6f57b7187fbe
Fri Dec  1 16:23:12 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authorize {
Fri Dec  1 16:23:12 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:12 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:12 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:12 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP packet type response id 2 length 104
Fri Dec  1 16:23:12 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:12 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:12 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:12 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authenticate {
Fri Dec  1 16:23:12 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:12 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:12 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:12 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:12 2017 : Debug:   TLS Length 94
Fri Dec  1 16:23:12 2017 : Info: [ttls] Length Included
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_verify returned 11
Fri Dec  1 16:23:12 2017 : Info: [ttls]     (other): before/accept initialization
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: before/accept initialization
Fri Dec  1 16:23:12 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:12 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 0059], ClientHello
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 05d9], Certificate
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:12 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: Need to read more data: unknown state
Fri Dec  1 16:23:12 2017 : Info: [ttls]     TLS_accept: Need to read more data: unknown state
Fri Dec  1 16:23:12 2017 : Debug: In SSL Handshake Phase
Fri Dec  1 16:23:12 2017 : Debug: In SSL Accept mode
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_process returned 13
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:12 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 160 to 192.168.100.2 port 1645
                EAP-Message = 0x0103040015c000000828160301002a0200002603011f860eddbeec439f6ea4e15cbed543b5cf476a6bdcc92d6a67cced012465f9fc0000390016030105d90b0005d50005d2000302308202fe30820267020101300d06092a864886f70d0101050500307c310b300906035504061302494e310c300a06035504080c0344454c310c300a06035504070c0344454c310d300b060355040a0c0449584941310c300a060355040b0c034250533110300e06035504030c07524f4f542d43413122302006092a864886f70d0109011613726f6f742d63614069786961636f6d2e636f6d301e170d3137303430363039353734315a170d32373034303430393537
                EAP-Message = 0x34315a30818e310b300906035504061302494e310b300906035504080c025742310c300a06035504070c034b4f4c310d300b060355040a0c0449584941310f300d060355040b0c0649584c4f41443124302206035504030c1b43412d5349474e45442d5253412d324b2d55554e53454355524544311e301c06092a864886f70d010901160f6162634069786961636f6d2e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100b077cde2fd98ef597ea7fecefe933ef103f4d01ee952886fbdd07a71f1305246276357b96ff058afa2495b8799a491464f3c71c3e2f74544957e334b9e45085a3aec3348a393cde6
                EAP-Message = 0x750cda5b85aff39feded3427d9da7fbda9463fb846791c79d6ae7cc39d5b9bbc690970ee0d882291c994d32dffae50c4dec1d9b2d87b3e64da8e2bee71615c17ff9fa4f2a6f825565feaea269f866b360cc269cc6fcc3b8ed2bad64f56ba0fb3b182f6103e566d292837337a0364be665117f55f34eef0268b0b8a7d1c1a1d9655e440674c2914f9bc4f3ac598b74662ae33ca279bc7472eadb5453b0aed21bab44809a2e570c1e1ae270f0784193ac3ddd0aa9035a143f10203010001300d06092a864886f70d0101050500038181007e59159785eab0cad7ae6aecae7b544055e426d8e27a6a8eb6e3df882acfd5c947cca2d8438d149df1d756aa78
                EAP-Message = 0xf25058cd2d2adca03a7596c06230dac143b3a106dfb8fa32851941940fa96ec4e452394f4053b98142083a429edd58ccd1979987276f74d394f83698930f1544a89dffd753e5724d09bee2ca58e3bc5e36c9690002ca308202c63082022fa003020102020900c922b862fc89e3dd300d06092a864886f70d0101050500307c310b300906035504061302494e310c300a06035504080c0344454c310c300a06035504070c0344454c310d300b060355040a0c0449584941310c300a060355040b0c034250533110300e06035504030c07524f4f542d43413122302006092a864886f70d0109011613726f6f742d63614069786961636f6d2e636f6d301e
                EAP-Message = 0x170d31373034303630393534
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff3b591881bf75674bfd214cc
Fri Dec  1 16:23:12 2017 : Info: Finished request 2.
Fri Dec  1 16:23:12 2017 : Debug: Going to the next request
Fri Dec  1 16:23:12 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=161, length=162
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff3b591881bf75674bfd214cc
                EAP-Message = 0x020300061500
                Message-Authenticator = 0x2c616da6552b60928e553257d66a78c8
Fri Dec  1 16:23:12 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authorize {
Fri Dec  1 16:23:12 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:12 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:12 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:12 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP packet type response id 3 length 6
Fri Dec  1 16:23:12 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:12 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:12 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:12 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authenticate {
Fri Dec  1 16:23:12 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:12 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:12 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:12 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:12 2017 : Info: [ttls] Received TLS ACK
Fri Dec  1 16:23:12 2017 : Info: [ttls] ACK handshake fragment handler
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_verify returned 1
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_process returned 13
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:12 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 161 to 192.168.100.2 port 1645
                EAP-Message = 0x0104040015c00000082832385a170d3237303430343039353432385a307c310b300906035504061302494e310c300a06035504080c0344454c310c300a06035504070c0344454c310d300b060355040a0c0449584941310c300a060355040b0c034250533110300e06035504030c07524f4f542d43413122302006092a864886f70d0109011613726f6f742d63614069786961636f6d2e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100c0295716be3ef8a96cd64394da8ad891666c738a2dcdff988053105204dc6b7b8e5a855cc0b7e7adf316118e5e3c4ef3c8e580738c92714831b05ecda326b42b76e343f60fa4
                EAP-Message = 0xaca9c9ddd74b43ec2eed013bb4e8452ff021d1f716baaa747ef4c5476701dff65ae07a427d598f8c2443ed1134963f7d7a069f7ba8579e34c5ab0203010001a350304e301d0603551d0e04160414ab7804d83f3ef207d8b56558471168fd991e3fc8301f0603551d23041830168014ab7804d83f3ef207d8b56558471168fd991e3fc8300c0603551d13040530030101ff300d06092a864886f70d010105050003818100919c10ff3faf93447b7b7faa384a5210539e5cce7eb1f387f27deaf1acf9677c7d7dd6b4de0daf00e741cfd2423b78c4f0c121ce99549e2b6cc6256115c7ba30c854877db2e64025e75df5f1e043400e10e4ea5cdf3cfc52db
                EAP-Message = 0xb26dcaa05b350787f705ee60634cdb280259508cfba7315ba658b09672b1cc7df5574beb7f6e86160301020d0c0002090080e987d2b6a373021a4e5359f8fff93f114a6c640d7a2d3da355b271449e073dd165d03bad6909d985e7073e9c4eea8508b5b99445b09fac2412452b0ab34acad5435d5c6d0800cbf6947f44820324e5e617cf0bfab1cdcaa37143bf296e7a19fb5402c830f5cba0af33e866a41dd8913bf07ee1cab3b3b544a2a703921b57fe4b00010200806ce84888bfa51384a4b42496a40029f85ee2c77a157681ab174f96bc6f46e6e1eca0f089f879cc16789b21d028fd30af4a9854b1e98d98589302095fed1eb94cb066855c2d84
                EAP-Message = 0x11bbd20328387287cd664b7693dfd25e79271c1eeb01ab72073a8f3a6a1ba26d8f49e41390cc845cf42e387ec8ea5f32834b41098293334ceac6010095c29f5fff4eeb8fcd0b5e3041ca62e9df4fc98312f0d6df5382a16e1a45bb37d461ed0d10966f5d3f956c753b5bdfc0ac1a3cb0b6693392ac02764b8d96845dbd754305990082a6a8e7063c78a8c8d07c537555fcd3966209b81f79f3cc2603192f8510ada3280975fc06dc9b0e545a49129e15d75345179e65752b153ea4d323fd262ada320cd22d3b131bc8fc49cbcaafb34d57c39d91590bc4847cb1d3bf693cf8ba46ee09b3b8ad50ae578ef5e866096cce4b83692c0aa1b7dd7a3cc62d91
                EAP-Message = 0x6d0dada9d43dc0327112afd7
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff2b291881bf75674bfd214cc
Fri Dec  1 16:23:12 2017 : Info: Finished request 3.
Fri Dec  1 16:23:12 2017 : Debug: Going to the next request
Fri Dec  1 16:23:12 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=162, length=162
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff2b291881bf75674bfd214cc
                EAP-Message = 0x020400061500
                Message-Authenticator = 0x5e228a19f56f356679f5ff250df22318
Fri Dec  1 16:23:12 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authorize {
Fri Dec  1 16:23:12 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:12 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:12 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:12 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:12 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:12 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP packet type response id 4 length 6
Fri Dec  1 16:23:12 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:12 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:12 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:12 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:12 2017 : Info: +group authenticate {
Fri Dec  1 16:23:12 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:12 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:12 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:12 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:12 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:12 2017 : Info: [ttls] Received TLS ACK
Fri Dec  1 16:23:12 2017 : Info: [ttls] ACK handshake fragment handler
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_verify returned 1
Fri Dec  1 16:23:12 2017 : Info: [ttls] eaptls_process returned 13
Fri Dec  1 16:23:12 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:12 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 162 to 192.168.100.2 port 1645
                EAP-Message = 0x01050046158000000828bafe736b94c5ee50100c15ef3cd0cb1d893df55df17f06b95810f5b69878b98abf524f7ab6dc0501d4b11b0311e2eb42412a7316030100040e000000
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff5b391881bf75674bfd214cc
Fri Dec  1 16:23:12 2017 : Info: Finished request 4.
Fri Dec  1 16:23:12 2017 : Debug: Going to the next request
Fri Dec  1 16:23:12 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=163, length=364
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff5b391881bf75674bfd214cc
                EAP-Message = 0x020500d01580000000c61603010086100000820080112e892bc29395e716668ae50d54cbc23d6bc0c99cdb3843e95e84ecfb607ec63d6b93e2cc76619c0236c83ba235bb0c606f6b544b7fc4a7cb3d720ee30b8b199baabe03229b263bcef5d8a7c6580cb56eaeeb83e8912f2ed165cd63819f3ab3580dbcdc833587045d36c52e5500a0fa197842e8a9123b6a6bac72c6e9df5d96140301000101160301003099a74e3fe02111c03f218c8ae535322b174fa1436b9cda0bca2db8b28d18c139bd0c744d5f3232d91b54b57d9c974199
                Message-Authenticator = 0xbcfcdeeb0f3d459054d61c477a5aa968
Fri Dec  1 16:23:13 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authorize {
Fri Dec  1 16:23:13 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:13 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:13 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:13 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:13 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP packet type response id 5 length 208
Fri Dec  1 16:23:13 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:13 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:13 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:13 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authenticate {
Fri Dec  1 16:23:13 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:13 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:13 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:13 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:13 2017 : Debug:   TLS Length 198
Fri Dec  1 16:23:13 2017 : Info: [ttls] Length Included
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_verify returned 11
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls]     TLS_accept: unknown state
Fri Dec  1 16:23:13 2017 : Info: [ttls]     (other): SSL negotiation finished successfully
Fri Dec  1 16:23:13 2017 : Debug: SSL Connection Established
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_process returned 13
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:13 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 163 to 192.168.100.2 port 1645
                EAP-Message = 0x0106004515800000003b1403010001011603010030312e304121a01ebc22ff4e21ef6f0e501606767c1c85aa6daf0dbdab818caa226318b09fac482933091e67cffa7d0988
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff4b091881bf75674bfd214cc
Fri Dec  1 16:23:13 2017 : Info: Finished request 5.
Fri Dec  1 16:23:13 2017 : Debug: Going to the next request
Fri Dec  1 16:23:13 2017 : Debug: Waking up in 4.3 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=164, length=348
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff4b091881bf75674bfd214cc
                EAP-Message = 0x020600c015001703010020841ae00c9f4fe67bdea8770668ffc3311394b948f6d9a7f88fedd20841aa15e5170301009099e4587fae0f7c948f1da6d1f269907ec82a3f5b6b642445d8680ce96052c61992345674ba0f0d3f3ead3498b9bc8b22735271b1197973b7ec584b08f578989fefc7ba2e150a5b989431c0116485b02ef9248610978741ee7a30c192aaabbbf4ab555e833f045d2e89a9a2cbc1d3ac72125922f90b7a9c45176a5b124e8729e8965d7430f3eb3c1bb0b2d5a92c81a944
                Message-Authenticator = 0x0f1151665c2472b2f0627e91f8ee74eb
Fri Dec  1 16:23:13 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authorize {
Fri Dec  1 16:23:13 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:13 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:13 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:13 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:13 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP packet type response id 6 length 192
Fri Dec  1 16:23:13 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:13 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:13 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:13 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authenticate {
Fri Dec  1 16:23:13 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:13 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:13 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:13 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_verify returned 7
Fri Dec  1 16:23:13 2017 : Info: [ttls] Done initial handshake
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] <<< Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_process returned 7
Fri Dec  1 16:23:13 2017 : Info: [ttls] Session established.  Proceeding to decode tunneled attributes.
  TTLS tunnel data in 0000: 00 00 00 01 40 00 00 11 49 78 69 61 55 73 65 72
  TTLS tunnel data in 0010: 33 00 00 00 00 00 00 0b c0 00 00 1c 00 00 01 37
  TTLS tunnel data in 0020: f3 0a 05 db a0 bb c4 8a c4 28 bd e5 ca e3 71 c8
  TTLS tunnel data in 0030: 00 00 00 19 c0 00 00 3e 00 00 01 37 f8 00 f3 0a
  TTLS tunnel data in 0040: 05 db a0 bb c4 8a c4 28 bd e5 ca e3 71 c8 00 00
  TTLS tunnel data in 0050: 00 00 00 00 00 00 70 f8 a8 10 a1 02 af 1a 13 2b
  TTLS tunnel data in 0060: 4b c5 1c 52 96 f2 d2 6f f1 e1 23 ed 75 30 f8 a8
Fri Dec  1 16:23:13 2017 : Info: [ttls] Got tunneled request
                User-Name = "IxiaUser3"
                MS-CHAP-Challenge = 0xf30a05dba0bbc48ac428bde5cae371c8
                MS-CHAP2-Response = 0xf800f30a05dba0bbc48ac428bde5cae371c8000000000000000070f8a810a102af1a132b4bc51c5296f2d26ff1e123ed7530
                FreeRADIUS-Proxied-To = 127.0.0.1
Fri Dec  1 16:23:13 2017 : Info: [ttls] Sending tunneled request
                User-Name = "IxiaUser3"
                MS-CHAP-Challenge = 0xf30a05dba0bbc48ac428bde5cae371c8
                MS-CHAP2-Response = 0xf800f30a05dba0bbc48ac428bde5cae371c8000000000000000070f8a810a102af1a132b4bc51c5296f2d26ff1e123ed7530
                FreeRADIUS-Proxied-To = 127.0.0.1
server inner-tunnel {
Fri Dec  1 16:23:13 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Fri Dec  1 16:23:13 2017 : Info: +group authorize {
Fri Dec  1 16:23:13 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:13 2017 : Info: [mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
Fri Dec  1 16:23:13 2017 : Info: ++[mschap] = ok
Fri Dec  1 16:23:13 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:13 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:13 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:13 2017 : Info: ++update control {
Fri Dec  1 16:23:13 2017 : Info: ++} # update control = noop
Fri Dec  1 16:23:13 2017 : Info: [eap] No EAP-Message, not doing EAP
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = noop
Fri Dec  1 16:23:13 2017 : Info: [files] users: Matched entry IxiaUser3 at line 92
Fri Dec  1 16:23:13 2017 : Info: ++[files] = ok
Fri Dec  1 16:23:13 2017 : Info: ++[expiration] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[logintime] = noop
Fri Dec  1 16:23:13 2017 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Fri Dec  1 16:23:13 2017 : Info: ++[pap] = noop
Fri Dec  1 16:23:13 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:13 2017 : Info: Found Auth-Type = MSCHAP
Fri Dec  1 16:23:13 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Fri Dec  1 16:23:13 2017 : Info: +group MS-CHAP {
Fri Dec  1 16:23:13 2017 : Info: [mschap] Creating challenge hash with username: IxiaUser3
Fri Dec  1 16:23:13 2017 : Info: [mschap] Client is using MS-CHAPv2 for IxiaUser3, we need NT-Password
Fri Dec  1 16:23:13 2017 : Info: [mschap] adding MS-CHAPv2 MPPE keys
Fri Dec  1 16:23:13 2017 : Info: ++[mschap] = ok
Fri Dec  1 16:23:13 2017 : Info: +} # group MS-CHAP = ok
Fri Dec  1 16:23:13 2017 : Info:   WARNING: Empty post-auth section.  Using default return values.
Fri Dec  1 16:23:13 2017 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel
} # server inner-tunnel
Fri Dec  1 16:23:13 2017 : Info: [ttls] Got tunneled reply code Access-Accept
                MS-CHAP2-Success = 0xf8533d39383035373142344434334232323341394244363144454137434537373232343431324436303335
                MS-MPPE-Recv-Key = 0xa9b88bb81e0b4518f84216b64a2674e3
                MS-MPPE-Send-Key = 0xf13a52dd26c6912ba4cd89838a0b51a2
                MS-MPPE-Encryption-Policy = 0x00000001
                MS-MPPE-Encryption-Types = 0x00000006
Fri Dec  1 16:23:13 2017 : Info: [ttls] Got tunneled Access-Accept
Fri Dec  1 16:23:13 2017 : Info: [ttls] Got MS-CHAP2-Success, tunneling it to the client in a challenge.
  TTLS tunnel data out 0000: 00 00 00 1a c0 00 00 37 00 00 01 37 f8 53 3d 39
  TTLS tunnel data out 0010: 38 30 35 37 31 42 34 44 34 33 42 32 32 33 41 39
  TTLS tunnel data out 0020: 42 44 36 31 44 45 41 37 43 45 37 37 32 32 34 34
  TTLS tunnel data out 0030: 31 32 44 36 30 33 35 00
Fri Dec  1 16:23:13 2017 : Info: [ttls] >>> Unknown TLS version [length 0005]
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = handled
Fri Dec  1 16:23:13 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 164 to 192.168.100.2 port 1645
                EAP-Message = 0x0107005f1580000000551703010050fbef1df34d40fe47f95efc844991e1871ba7bdfc136147c1f2669f8ca56eccf1f57f66dc9e20d605c84e1b30535a58666c269037cd61242f88f96f55abe3715dfef3e2bb56f0b1d18c61d4f31de0e8d8
                Message-Authenticator = 0x00000000000000000000000000000000
                State = 0xf1b684cff7b191881bf75674bfd214cc
Fri Dec  1 16:23:13 2017 : Info: Finished request 6.
Fri Dec  1 16:23:13 2017 : Debug: Going to the next request
Fri Dec  1 16:23:13 2017 : Debug: Waking up in 4.3 seconds.
rad_recv: Access-Request packet from host 192.168.100.2 port 1645, id=165, length=162
                NAS-IP-Address = 192.168.100.2
                NAS-Port = 4
                NAS-Port-Type = Ethernet
                User-Name = "IxiaUser3"
                Called-Station-Id = "00-0A-F3-30-77-0A"
                Calling-Station-Id = "46-1B-6D-CC-00-00"
                Service-Type = Framed-User
                Framed-MTU = 1500
                Calling-Station-Id = "34-36-2d-31-42-2d"
                State = 0xf1b684cff7b191881bf75674bfd214cc
                EAP-Message = 0x020700061500
                Message-Authenticator = 0x8781ec66fa8734c7aa63c177c1a09eed
Fri Dec  1 16:23:13 2017 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authorize {
Fri Dec  1 16:23:13 2017 : Info: ++[preprocess] = ok
Fri Dec  1 16:23:13 2017 : Info: ++[chap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[mschap] = noop
Fri Dec  1 16:23:13 2017 : Info: ++[digest] = noop
Fri Dec  1 16:23:13 2017 : Info: [suffix] No '@' in User-Name = "IxiaUser3", looking up realm NULL
Fri Dec  1 16:23:13 2017 : Info: [suffix] No such realm "NULL"
Fri Dec  1 16:23:13 2017 : Info: ++[suffix] = noop
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP packet type response id 7 length 6
Fri Dec  1 16:23:13 2017 : Info: [eap] Continuing tunnel setup.
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = ok
Fri Dec  1 16:23:13 2017 : Info: +} # group authorize = ok
Fri Dec  1 16:23:13 2017 : Info: Found Auth-Type = EAP
Fri Dec  1 16:23:13 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group authenticate {
Fri Dec  1 16:23:13 2017 : Info: [eap] Request found, released from the list
Fri Dec  1 16:23:13 2017 : Info: [eap] EAP/ttls
Fri Dec  1 16:23:13 2017 : Info: [eap] processing type ttls
Fri Dec  1 16:23:13 2017 : Info: [ttls] Authenticate
Fri Dec  1 16:23:13 2017 : Info: [ttls] processing EAP-TLS
Fri Dec  1 16:23:13 2017 : Info: [ttls] Received TLS ACK
Fri Dec  1 16:23:13 2017 : Info: [ttls] ACK default
Fri Dec  1 16:23:13 2017 : Error: [ttls] Invalid ACK received: 0
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_verify returned 4
Fri Dec  1 16:23:13 2017 : Info: [ttls] eaptls_process returned 4
Fri Dec  1 16:23:13 2017 : Info: [eap] Handler failed in EAP/ttls
Fri Dec  1 16:23:13 2017 : Info: [eap] Failed in EAP select
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = invalid
Fri Dec  1 16:23:13 2017 : Info: +} # group authenticate = invalid
Fri Dec  1 16:23:13 2017 : Info: Failed to authenticate the user.
Fri Dec  1 16:23:13 2017 : Info: Using Post-Auth-Type Reject
Fri Dec  1 16:23:13 2017 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Fri Dec  1 16:23:13 2017 : Info: +group REJECT {
Fri Dec  1 16:23:13 2017 : Info: [eap] Reply already contained an EAP-Message, not inserting EAP-Failure
Fri Dec  1 16:23:13 2017 : Info: ++[eap] = noop
Fri Dec  1 16:23:13 2017 : Info: [attr_filter.access_reject]                expand: %{User-Name} -> IxiaUser3
Fri Dec  1 16:23:13 2017 : Debug: attr_filter: Matched entry DEFAULT at line 11
Fri Dec  1 16:23:13 2017 : Info: ++[attr_filter.access_reject] = updated
Fri Dec  1 16:23:13 2017 : Info: +} # group REJECT = updated
Fri Dec  1 16:23:13 2017 : Info: Delaying reject of request 7 for 1 seconds
Fri Dec  1 16:23:13 2017 : Debug: Going to the next request
Fri Dec  1 16:23:13 2017 : Debug: Waking up in 0.9 seconds.
Fri Dec  1 16:23:14 2017 : Info: Sending delayed reject for request 7
Sending Access-Reject of id 165 to 192.168.100.2 port 1645
                EAP-Message = 0x04070004
                Message-Authenticator = 0x00000000000000000000000000000000
Fri Dec  1 16:23:14 2017 : Debug: Waking up in 3.3 seconds.
Fri Dec  1 16:23:17 2017 : Info: Cleaning up request 0 ID 158 with timestamp +88
Fri Dec  1 16:23:17 2017 : Info: Cleaning up request 1 ID 159 with timestamp +88
Fri Dec  1 16:23:17 2017 : Info: Cleaning up request 2 ID 160 with timestamp +88
Fri Dec  1 16:23:17 2017 : Info: Cleaning up request 3 ID 161 with timestamp +88
Fri Dec  1 16:23:17 2017 : Info: Cleaning up request 4 ID 162 with timestamp +88
Fri Dec  1 16:23:17 2017 : Debug: Waking up in 0.5 seconds.
Fri Dec  1 16:23:18 2017 : Info: Cleaning up request 5 ID 163 with timestamp +89
Fri Dec  1 16:23:18 2017 : Info: Cleaning up request 6 ID 164 with timestamp +89
Fri Dec  1 16:23:18 2017 : Debug: Waking up in 1.0 seconds.
Fri Dec  1 16:23:19 2017 : Info: Cleaning up request 7 ID 165 with timestamp +89
Fri Dec  1 16:23:19 2017 : Info: Ready to process requests.

With Regards,
Smita

TTLS authentication is not working on Ubuntu 16.04 Freeradius 2.2.8

Smita Selot