Windows 8.1 Wi-Fi client handshake failure REVISITED

ChoongHotmail Kim concentric12 at hotmail.com
Sun Jan 22 10:05:20 CET 2017


Hello.

I've been having issues with my Windows 8.1 laptop as well as my Windows 
10 laptop when trying to connect to my FreeRADIUS server via EAP-TTLS. 
My FreeRADIUS server is running on an Asus RT-AC68U router and was 
installed and configured per the instructions on 
https://github.com/RMerl/asuswrt-merlin/wiki/Setting-up-FreeRadius2-through-Entware 
.  My problem is identical to the issue reported on 
http://lists.freeradius.org/pipermail/freeradius-users/2014-October/074177.html 
, and unfortunately, the thread ended without any resolution.  I was 
hoping to find any advice with regards to resolving this particular 
use-case as I started as Mr. Rowe has by setting the "cipher-list" 
attribute to "ALL" as well as checking the installed status of my 
certificates.  I am only having issues with the handshake when trying to 
connect with Windows 8.1 or Windows 10, but have none when connecting 
via Android.  For reference, I've a sanitized version of the output for 
radius -XX when successfully connecting via my Android device.  Thank you.

admin at ROUTER:/tmp/mnt/sda2/entware-ng.arm/etc/freeradius2# radiusd -XX
Sun Jan 22 08:39:20 2017 : Info: radiusd: FreeRADIUS Version 2.2.9, for 
host arm-openwrt-linux-gnu, built on Dec 26 2016 at 19:02:57
Sun Jan 22 08:39:20 2017 : Debug: Server was built with:
Sun Jan 22 08:39:20 2017 : Debug:   accounting
Sun Jan 22 08:39:20 2017 : Debug:   authentication
Sun Jan 22 08:39:20 2017 : Debug:  WITH_DHCP
Sun Jan 22 08:39:20 2017 : Debug:  WITH_VMPS
Sun Jan 22 08:39:20 2017 : Debug: Server core libs:
Sun Jan 22 08:39:20 2017 : Debug:   ssl: OpenSSL 1.0.2j  26 Sep 2016
Sun Jan 22 08:39:20 2017 : Info: Copyright (C) 1999-2015 The FreeRADIUS 
server project and contributors.
Sun Jan 22 08:39:20 2017 : Info: There is NO warranty; not even for 
MERCHANTABILITY or FITNESS FOR A
Sun Jan 22 08:39:20 2017 : Info: PARTICULAR PURPOSE.
Sun Jan 22 08:39:20 2017 : Info: You may redistribute copies of 
FreeRADIUS under the terms of the
Sun Jan 22 08:39:20 2017 : Info: GNU General Public License.
Sun Jan 22 08:39:20 2017 : Info: For more information about these 
matters, see the file named COPYRIGHT.
Sun Jan 22 08:39:20 2017 : Info: Starting - reading configuration files ...
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/radiusd.conf
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/clients.conf
Sun Jan 22 08:39:20 2017 : Debug: including files in directory 
/opt/etc/freeradius2/modules/
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/modules/ldap
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/modules/pap
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/modules/mschap
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/modules/files
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/eap.conf
Sun Jan 22 08:39:20 2017 : Debug: including files in directory 
/opt/etc/freeradius2/sites/
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:20 2017 : Debug: including configuration file 
/opt/etc/freeradius2/sites/inner-tunnel
Sun Jan 22 08:39:20 2017 : Debug: main {
Sun Jan 22 08:39:20 2017 : Debug:     allow_core_dumps = no
Sun Jan 22 08:39:20 2017 : Debug: }
Sun Jan 22 08:39:20 2017 : Debug: including dictionary file 
/opt/etc/freeradius2/dictionary
Sun Jan 22 08:39:20 2017 : Debug: main {
Sun Jan 22 08:39:20 2017 : Debug:     name = "radiusd"
Sun Jan 22 08:39:20 2017 : Debug:     prefix = "/opt"
Sun Jan 22 08:39:20 2017 : Debug:     localstatedir = "/opt/var"
Sun Jan 22 08:39:20 2017 : Debug:     sbindir = "/opt/sbin"
Sun Jan 22 08:39:20 2017 : Debug:     logdir = "/opt/var/log"
Sun Jan 22 08:39:20 2017 : Debug:     run_dir = "/opt/var/run/radius"
Sun Jan 22 08:39:20 2017 : Debug:     libdir = "/opt/lib/freeradius2"
Sun Jan 22 08:39:20 2017 : Debug:     radacctdir = "/opt/var/db/radacct"
Sun Jan 22 08:39:20 2017 : Debug:     hostname_lookups = no
Sun Jan 22 08:39:20 2017 : Debug:     max_request_time = 15
Sun Jan 22 08:39:20 2017 : Debug:     cleanup_delay = 7
Sun Jan 22 08:39:20 2017 : Debug:     max_requests = 512
Sun Jan 22 08:39:20 2017 : Debug:     pidfile = 
"/opt/var/run/radius/radiusd.pid"
Sun Jan 22 08:39:20 2017 : Debug:     checkrad = "/opt/sbin/checkrad"
Sun Jan 22 08:39:20 2017 : Debug:     debug_level = 0
Sun Jan 22 08:39:20 2017 : Debug:     proxy_requests = no
Sun Jan 22 08:39:20 2017 : Debug:  log {
Sun Jan 22 08:39:20 2017 : Debug:      stripped_names = no
Sun Jan 22 08:39:20 2017 : Debug:      auth = no
Sun Jan 22 08:39:20 2017 : Debug:      auth_badpass = no
Sun Jan 22 08:39:20 2017 : Debug:      auth_goodpass = no
Sun Jan 22 08:39:20 2017 : Debug:  }
Sun Jan 22 08:39:20 2017 : Debug:  security {
Sun Jan 22 08:39:20 2017 : Debug:      max_attributes = 200
Sun Jan 22 08:39:20 2017 : Debug:      reject_delay = 5
Sun Jan 22 08:39:20 2017 : Debug:      status_server = no
Sun Jan 22 08:39:20 2017 : Debug:  }
Sun Jan 22 08:39:20 2017 : Debug: }
Sun Jan 22 08:39:20 2017 : Debug: radiusd: #### Loading Realms and Home 
Servers ####
Sun Jan 22 08:39:20 2017 : Debug: radiusd: #### Loading Clients ####
Sun Jan 22 08:39:20 2017 : Debug:  client localhost {
Sun Jan 22 08:39:20 2017 : Debug:      ipaddr = 127.0.0.1
Sun Jan 22 08:39:20 2017 : Debug:      require_message_authenticator = yes
Sun Jan 22 08:39:20 2017 : Debug:      secret = "*removed1*"
Sun Jan 22 08:39:20 2017 : Debug:      nastype = "other"
Sun Jan 22 08:39:20 2017 : Debug:  }
Sun Jan 22 08:39:20 2017 : Debug: radiusd: #### Instantiating modules ####
Sun Jan 22 08:39:20 2017 : Debug: radiusd: #### Loading Virtual Servers ####
Sun Jan 22 08:39:20 2017 : Debug: server { # from file 
/opt/etc/freeradius2/radiusd.conf
Sun Jan 22 08:39:20 2017 : Debug:  modules {
Sun Jan 22 08:39:20 2017 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Sun Jan 22 08:39:20 2017 : Debug:     (Loaded rlm_eap, checking if it's 
valid)
Sun Jan 22 08:39:20 2017 : Debug:  Module: Linked to module rlm_eap
Sun Jan 22 08:39:20 2017 : Debug:  Module: Instantiating module "eap" 
from file /opt/etc/freeradius2/eap.conf
Sun Jan 22 08:39:20 2017 : Debug:   eap {
Sun Jan 22 08:39:20 2017 : Debug:       default_eap_type = "ttls"
Sun Jan 22 08:39:20 2017 : Debug:       timer_expire = 60
Sun Jan 22 08:39:20 2017 : Debug:       ignore_unknown_eap_types = no
Sun Jan 22 08:39:20 2017 : Debug:       cisco_accounting_username_bug = no
Sun Jan 22 08:39:20 2017 : Debug:       max_sessions = 4096
Sun Jan 22 08:39:20 2017 : Debug:   }
Sun Jan 22 08:39:20 2017 : Debug:  Module: Linked to sub-module rlm_eap_tls
Sun Jan 22 08:39:20 2017 : Debug:  Module: Instantiating eap-tls
Sun Jan 22 08:39:20 2017 : Debug:    tls {
Sun Jan 22 08:39:20 2017 : Debug:        rsa_key_exchange = no
Sun Jan 22 08:39:20 2017 : Debug:        dh_key_exchange = yes
Sun Jan 22 08:39:20 2017 : Debug:        rsa_key_length = 512
Sun Jan 22 08:39:20 2017 : Debug:        dh_key_length = 512
Sun Jan 22 08:39:20 2017 : Debug:        verify_depth = 0
Sun Jan 22 08:39:20 2017 : Debug:        pem_file_type = yes
Sun Jan 22 08:39:20 2017 : Debug:        private_key_file = 
"/opt/etc/freeradius2/certs/ec-server_key.pem"
Sun Jan 22 08:39:20 2017 : Debug:        certificate_file = 
"/opt/etc/freeradius2/certs/ec-server_cert.pem"
Sun Jan 22 08:39:20 2017 : Debug:        private_key_password = "*removed5*"
Sun Jan 22 08:39:20 2017 : Debug:        dh_file = 
"/opt/etc/freeradius2/certs/dh"
Sun Jan 22 08:39:20 2017 : Debug:        random_file = "/dev/urandom"
Sun Jan 22 08:39:20 2017 : Debug:        fragment_size = 1024
Sun Jan 22 08:39:20 2017 : Debug:        include_length = yes
Sun Jan 22 08:39:20 2017 : Debug:        check_crl = no
Sun Jan 22 08:39:20 2017 : Debug:        check_all_crl = no
Sun Jan 22 08:39:20 2017 : Debug:        cipher_list = "ALL"
Sun Jan 22 08:39:20 2017 : Debug:        check_cert_issuer = 
"/C=US/ST=NY/L=New York/O=Admin/OU=IT/CN=cert/emailAddress=admin at admin.com"
Sun Jan 22 08:39:20 2017 : Debug:        ecdh_curve = "secp521r1"
Sun Jan 22 08:39:20 2017 : Debug:    }
Sun Jan 22 08:39:21 2017 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Sun Jan 22 08:39:21 2017 : Debug:  Module: Instantiating eap-ttls
Sun Jan 22 08:39:21 2017 : Debug:    ttls {
Sun Jan 22 08:39:21 2017 : Debug:        default_eap_type = "md5"
Sun Jan 22 08:39:21 2017 : Debug:        copy_request_to_tunnel = no
Sun Jan 22 08:39:21 2017 : Debug:        use_tunneled_reply = yes
Sun Jan 22 08:39:21 2017 : Debug:        virtual_server = "inner-tunnel"
Sun Jan 22 08:39:21 2017 : Debug:        include_length = yes
Sun Jan 22 08:39:21 2017 : Debug:    }
Sun Jan 22 08:39:21 2017 : Debug:  Module: Checking authorize {...} for 
more modules to load
Sun Jan 22 08:39:21 2017 : Debug:  } # modules
Sun Jan 22 08:39:21 2017 : Debug: } # server
Sun Jan 22 08:39:21 2017 : Debug: server inner-tunnel { # from file 
/opt/etc/freeradius2/sites/inner-tunnel
Sun Jan 22 08:39:21 2017 : Debug:  modules {
Sun Jan 22 08:39:21 2017 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Sun Jan 22 08:39:21 2017 : Debug:     (Loaded rlm_pap, checking if it's 
valid)
Sun Jan 22 08:39:21 2017 : Debug:  Module: Linked to module rlm_pap
Sun Jan 22 08:39:21 2017 : Debug:  Module: Instantiating module "pap" 
from file /opt/etc/freeradius2/modules/pap
Sun Jan 22 08:39:21 2017 : Debug:   pap {
Sun Jan 22 08:39:21 2017 : Debug:       encryption_scheme = "auto"
Sun Jan 22 08:39:21 2017 : Debug:       auto_header = yes
Sun Jan 22 08:39:21 2017 : Debug:   }
Sun Jan 22 08:39:21 2017 : Debug:  Module: Checking authorize {...} for 
more modules to load
Sun Jan 22 08:39:21 2017 : Debug:     (Loaded rlm_files, checking if 
it's valid)
Sun Jan 22 08:39:21 2017 : Debug:  Module: Linked to module rlm_files
Sun Jan 22 08:39:21 2017 : Debug:  Module: Instantiating module "files" 
from file /opt/etc/freeradius2/modules/files
Sun Jan 22 08:39:21 2017 : Debug:   files {
Sun Jan 22 08:39:21 2017 : Debug:       usersfile = 
"/opt/etc/freeradius2/users"
Sun Jan 22 08:39:21 2017 : Debug:       compat = "no"
Sun Jan 22 08:39:21 2017 : Debug:   }
Sun Jan 22 08:39:21 2017 : Debug: reading pairlist file 
/opt/etc/freeradius2/users
Sun Jan 22 08:39:21 2017 : Debug:  } # modules
Sun Jan 22 08:39:21 2017 : Debug: } # server
Sun Jan 22 08:39:21 2017 : Debug: radiusd: #### Opening IP addresses and 
Ports ####
Sun Jan 22 08:39:21 2017 : Debug: listen {
Sun Jan 22 08:39:21 2017 : Debug:      type = "auth"
Sun Jan 22 08:39:21 2017 : Debug:      ipaddr = 127.0.0.1
Sun Jan 22 08:39:21 2017 : Debug:      port = 1812
Sun Jan 22 08:39:21 2017 : Debug: }
Sun Jan 22 08:39:21 2017 : Debug: listen {
Sun Jan 22 08:39:21 2017 : Debug:       type = "auth"
Sun Jan 22 08:39:21 2017 : Debug:       ipaddr = 127.0.0.1
Sun Jan 22 08:39:21 2017 : Debug:       port = 18120
Sun Jan 22 08:39:21 2017 : Debug: }
Sun Jan 22 08:39:21 2017 : Debug: Listening on authentication address 
127.0.0.1 port 1812
Sun Jan 22 08:39:21 2017 : Debug: Listening on authentication address 
127.0.0.1 port 18120 as server inner-tunnel
Sun Jan 22 08:39:21 2017 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 37394, id=0, 
length=131
     User-Name = "anonymous"
     NAS-IP-Address = 127.0.0.1
     Called-Station-Id = "*removed2*"
     Calling-Station-Id = "*removed3*"
     NAS-Identifier = "*removed4*"
     NAS-Port = 109
     Framed-MTU = 1400
     NAS-Port-Type = Wireless-802.11
     EAP-Message = 0x0200000e01616e6f6e796d6f7573
     Message-Authenticator = 0xdc4dde7c42159b142e2d300745db62e9
Sun Jan 22 08:39:35 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authorize {
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP packet type response id 0 
length 14
Sun Jan 22 08:39:35 2017 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = updated
Sun Jan 22 08:39:35 2017 : Info: +} # group authorize = updated
Sun Jan 22 08:39:35 2017 : Info: Found Auth-Type = EAP
Sun Jan 22 08:39:35 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authenticate {
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP Identity
Sun Jan 22 08:39:35 2017 : Info: [eap] processing type tls
Sun Jan 22 08:39:35 2017 : Info: [tls] Initiate
Sun Jan 22 08:39:35 2017 : Info: [tls] Start returned 1
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = handled
Sun Jan 22 08:39:35 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 37394
     EAP-Message = 0x010100061520
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0x33ba028433bb1704dfebfff672d73f51
Sun Jan 22 08:39:35 2017 : Info: Finished request 0.
Sun Jan 22 08:39:35 2017 : Debug: Going to the next request
Sun Jan 22 08:39:35 2017 : Debug: Waking up in 6.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 37394, id=0, 
length=339
Sun Jan 22 08:39:35 2017 : Info: Cleaning up request 0 ID 0 with 
timestamp +14
     User-Name = "anonymous"
     NAS-IP-Address = 127.0.0.1
     Called-Station-Id = "*removed11*"
     Calling-Station-Id = "*removed12*"
     NAS-Identifier = "*removed13*"
     NAS-Port = 109
     Framed-MTU = 1400
     State = 0x33ba028433bb1704dfebfff672d73f51
     NAS-Port-Type = Wireless-802.11
     EAP-Message = 
0x020100cc150016030100c1010000bd030158846fc7d8809f2085f98605d86439ecd041d6e190377d2be4e9a02cf3b2b980000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011
     Message-Authenticator = 0xc06c7e7bb5daec74806b049ab8bb7d0c
Sun Jan 22 08:39:35 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authorize {
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP packet type response id 1 
length 204
Sun Jan 22 08:39:35 2017 : Info: [eap] Continuing tunnel setup.
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = ok
Sun Jan 22 08:39:35 2017 : Info: +} # group authorize = ok
Sun Jan 22 08:39:35 2017 : Info: Found Auth-Type = EAP
Sun Jan 22 08:39:35 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authenticate {
Sun Jan 22 08:39:35 2017 : Info: [eap] Request found, released from the list
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP/ttls
Sun Jan 22 08:39:35 2017 : Info: [eap] processing type ttls
Sun Jan 22 08:39:35 2017 : Info: [ttls] Authenticate
Sun Jan 22 08:39:35 2017 : Info: [ttls] processing EAP-TLS
Sun Jan 22 08:39:35 2017 : Info: [ttls] eaptls_verify returned 7
Sun Jan 22 08:39:35 2017 : Info: [ttls] Done initial handshake
Sun Jan 22 08:39:35 2017 : Info: [ttls]     (other): before/accept 
initialization
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: before/accept 
initialization
Sun Jan 22 08:39:35 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:35 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 
00c1], ClientHello
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 
0039], ServerHello
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 
03f9], Certificate
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 
0119], ServerKeyExchange
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:35 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 
0004], ServerHelloDone
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: Need to read 
more data: unknown state
Sun Jan 22 08:39:35 2017 : Info: [ttls]     TLS_accept: Need to read 
more data: unknown state
Sun Jan 22 08:39:35 2017 : Debug: In SSL Handshake Phase
Sun Jan 22 08:39:35 2017 : Debug: In SSL Accept mode
Sun Jan 22 08:39:35 2017 : Info: [ttls] eaptls_process returned 13
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = handled
Sun Jan 22 08:39:35 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 37394
     EAP-Message = 
0x0102040015c000000563160301003902000035030191fab5ecc2a72a6100304fb55ecb4ab9487f48a79086bb74a18155747aacdcfc00c00a00000dff01000100000b00040300010216030103f90b0003f50003f20003ef308203eb3082034da003020102020101300a06082a8648ce3d04030430818b310b3009060355040613025553310b300906035504080c0243413114301206035504070c0b4c6f7320416e67656c657331123010060355040a0c0945766572677265656e310b3009060355040b0c024954310f300d06035504030c067175696c74793127302506092a864886f70d0109011618636f6e63656e74726963313240686f746d61696c
     EAP-Message = 
0x2e636f6d301e170d3136313130323035333532325a170d3236313033313035333532325a30818b310b3009060355040613025553310b300906035504080c0243413114301206035504070c0b4c6f7320416e67656c657331123010060355040a0c0945766572677265656e310b3009060355040b0c024954310f300d06035504030c067175696c74793127302506092a864886f70d0109011618636f6e63656e74726963313240686f746d61696c2e636f6d30819b301006072a8648ce3d020106052b81040023038186000400f07d650a69a067774af98c6e31536aaa2537f36512017e620d7e104f39b0f4a6046d2a375f1e316a74660eee1a7620e5
     EAP-Message = 
0x51e7b8b42411342af74b8946ba7723aa17017827f5dff7491d3d3cb8eadb6764a706c09164b601cde0acf797e686073fb6f651aa488356fa11a9ca62815eeee6f88cb1e3ebcadce6f8fd76c719c01b496edb17a382015b3082015730090603551d1304023000301106096086480186f8420101040403020640303306096086480186f842010d042616244f70656e53534c2047656e65726174656420536572766572204365727469666963617465301d0603551d0e04160414199f83c6183ee1343dd00a8cfedac804195db9f13081c00603551d230481b83081b58014956479ceb6825479147296a4672a7d22264c4b8da18191a4818e30818b310b30
     EAP-Message = 
0x09060355040613025553310b300906035504080c0243413114301206035504070c0b4c6f7320416e67656c657331123010060355040a0c0945766572677265656e310b3009060355040b0c024954310f300d06035504030c067175696c74793127302506092a864886f70d0109011618636f6e63656e74726963313240686f746d61696c2e636f6d820900883fa5aaf29fc76b30130603551d25040c300a06082b06010505070301300b0603551d0f0404030205a0300a06082a8648ce3d04030403818b00308187024101cf9236626271c7ae49d6a8c4dd59a719f3d6c9e1b3a9d8f85ef7386582084537f4f5d7a125b92e77aa2add03a2220b624d78
     EAP-Message = 0xeaa78fe101ded4031e55bc73
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0x33ba028432b81704dfebfff672d73f51
Sun Jan 22 08:39:35 2017 : Info: Finished request 1.
Sun Jan 22 08:39:35 2017 : Debug: Going to the next request
Sun Jan 22 08:39:35 2017 : Debug: Waking up in 6.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 37394, id=0, 
length=141
Sun Jan 22 08:39:35 2017 : Info: Cleaning up request 1 ID 0 with 
timestamp +14
     User-Name = "anonymous"
     NAS-IP-Address = 127.0.0.1
     Called-Station-Id = "*removed13*"
     Calling-Station-Id = "*removed14*"
     NAS-Identifier = "*removed15*"
     NAS-Port = 109
     Framed-MTU = 1400
     State = 0x33ba028432b81704dfebfff672d73f51
     NAS-Port-Type = Wireless-802.11
     EAP-Message = 0x020200061500
     Message-Authenticator = 0x134e376d22a73051434e5f01b9c6c362
Sun Jan 22 08:39:35 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authorize {
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP packet type response id 2 
length 6
Sun Jan 22 08:39:35 2017 : Info: [eap] Continuing tunnel setup.
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = ok
Sun Jan 22 08:39:35 2017 : Info: +} # group authorize = ok
Sun Jan 22 08:39:35 2017 : Info: Found Auth-Type = EAP
Sun Jan 22 08:39:35 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:35 2017 : Info: +group authenticate {
Sun Jan 22 08:39:35 2017 : Info: [eap] Request found, released from the list
Sun Jan 22 08:39:35 2017 : Info: [eap] EAP/ttls
Sun Jan 22 08:39:35 2017 : Info: [eap] processing type ttls
Sun Jan 22 08:39:35 2017 : Info: [ttls] Authenticate
Sun Jan 22 08:39:35 2017 : Info: [ttls] processing EAP-TLS
Sun Jan 22 08:39:35 2017 : Info: [ttls] Received TLS ACK
Sun Jan 22 08:39:35 2017 : Info: [ttls] ACK handshake fragment handler
Sun Jan 22 08:39:35 2017 : Info: [ttls] eaptls_verify returned 1
Sun Jan 22 08:39:35 2017 : Info: [ttls] eaptls_process returned 13
Sun Jan 22 08:39:35 2017 : Info: ++[eap] = handled
Sun Jan 22 08:39:35 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 37394
     EAP-Message = 
0x0103017715800000056330db0242013b408b3f1975bfcee706ab640ce0885b4c97fbe652592ab4fc3969a27771b8d8b536d9a1260f6aabc6bd4922054078488670864589f983cabfedd44c880e69745516030101190c000115030019850401b77f49bc6b1797ee770a5424a59e4f3170a6ff87ebc887b1448c0696a842a67f82d2770554c6a5629b79a257f435bf671c39d6ec651cf3ab227bbb8a240134f62700f034bbf09939e9dc8bf1838c523ec3c1c650bcc0b9fb171a97be015ae9770ccd62cff839c34a1b83cbfdc1960d6a5068816aa03b8aa9f52a0c0fc430c60500e2db008a308187024200801453769b7e29283c35b4a00ad31fa9e1f90b
     EAP-Message = 
0xc854ff2ea32d475dcab6ce05337b5886e52bc15349303acb7e905fa056f4e6c80afa7efbf8e53112a41fae0a92190241478c805797fc606c365d70e6c7a1f9f09826c325cfc93f387e1f4277741ff9a10df8f5122af7d4d8cf280f495406994e860930576409da5c5a6a0af976e46f400d16030100040e000000
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0x33ba028431b91704dfebfff672d73f51
Sun Jan 22 08:39:35 2017 : Info: Finished request 2.
Sun Jan 22 08:39:35 2017 : Debug: Going to the next request
Sun Jan 22 08:39:35 2017 : Debug: Waking up in 6.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 37394, id=0, 
length=343
Sun Jan 22 08:39:36 2017 : Info: Cleaning up request 2 ID 0 with 
timestamp +14
     User-Name = "anonymous"
     NAS-IP-Address = 127.0.0.1
     Called-Station-Id = "*removed6*"
     Calling-Station-Id = "*removed7*"
     NAS-Identifier = "*removed8*"
     NAS-Port = 109
     Framed-MTU = 1400
     State = 0x33ba028431b91704dfebfff672d73f51
     NAS-Port-Type = Wireless-802.11
     EAP-Message = 
0x020300d01500160301008a10000086850401f6a9402a58c058354414ef10493bb876a435d6ad1cd62954455bfe855111315a398f5c32d04070ee0942123275435dbf78c04683acf409a2bd1dd8580e5672a193018e8a832b15664fabe8e784b612dde5db6b8276b688111efc6efeafbbef1ec3a83e1e626d3be5a812826480b44e99b18f23cfff9172ff0be2e6a673139bb83389411403010001011603010030d8b1e1011f6b286e5ab9694d7117ba7df608ea60890450c8a8a171ee292fde0d3d19330ffbe9f7cf5ab6aab9b58600f7
     Message-Authenticator = 0x9330962a55c7b0a352d20bfbfbbc4d41
Sun Jan 22 08:39:36 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:36 2017 : Info: +group authorize {
Sun Jan 22 08:39:36 2017 : Info: [eap] EAP packet type response id 3 
length 208
Sun Jan 22 08:39:36 2017 : Info: [eap] Continuing tunnel setup.
Sun Jan 22 08:39:36 2017 : Info: ++[eap] = ok
Sun Jan 22 08:39:36 2017 : Info: +} # group authorize = ok
Sun Jan 22 08:39:36 2017 : Info: Found Auth-Type = EAP
Sun Jan 22 08:39:36 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:36 2017 : Info: +group authenticate {
Sun Jan 22 08:39:36 2017 : Info: [eap] Request found, released from the list
Sun Jan 22 08:39:36 2017 : Info: [eap] EAP/ttls
Sun Jan 22 08:39:36 2017 : Info: [eap] processing type ttls
Sun Jan 22 08:39:36 2017 : Info: [ttls] Authenticate
Sun Jan 22 08:39:36 2017 : Info: [ttls] processing EAP-TLS
Sun Jan 22 08:39:36 2017 : Info: [ttls] eaptls_verify returned 7
Sun Jan 22 08:39:36 2017 : Info: [ttls] Done initial handshake
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 
008a], ClientKeyExchange
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec 
[length 0001]
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< TLS 1.0 Handshake [length 
0010], Finished
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec 
[length 0001]
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls] >>> Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] >>> TLS 1.0 Handshake [length 
0010], Finished
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls]     TLS_accept: unknown state
Sun Jan 22 08:39:36 2017 : Info: [ttls]     (other): SSL negotiation 
finished successfully
Sun Jan 22 08:39:36 2017 : Debug: SSL Connection Established
Sun Jan 22 08:39:36 2017 : Info: [ttls] eaptls_process returned 13
Sun Jan 22 08:39:36 2017 : Info: ++[eap] = handled
Sun Jan 22 08:39:36 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 37394
     EAP-Message = 
0x0104004515800000003b14030100010116030100306c5718901210a53f7cb47324d4f06c38c95221bb1bb1a4fd190d8cac2800704128557b41fd3e9172fb584c444cd4b65e
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0x33ba028430be1704dfebfff672d73f51
Sun Jan 22 08:39:36 2017 : Info: Finished request 3.
Sun Jan 22 08:39:36 2017 : Debug: Going to the next request
Sun Jan 22 08:39:36 2017 : Debug: Waking up in 6.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 37394, id=0, 
length=247
Sun Jan 22 08:39:36 2017 : Info: Cleaning up request 3 ID 0 with 
timestamp +15
     User-Name = "anonymous"
     NAS-IP-Address = 127.0.0.1
     Called-Station-Id = "*removed9*"
     Calling-Station-Id = "*removed10*"
     NAS-Identifier = "*removed11*"
     NAS-Port = 109
     Framed-MTU = 1400
     State = 0x33ba028430be1704dfebfff672d73f51
     NAS-Port-Type = Wireless-802.11
     EAP-Message = 
0x020400701500170301002056e79f700170cf200b740f59f5d1130bcb65f93e1ba1add723b477774adfe37f17030100400b3dfe771e2a0348c26660fea52c503a2cf1cf9d6e93b269505e756453bd5f7156ce08993cf213bb2da11488871a65233f6ccb8154984c43433caec786540593
     Message-Authenticator = 0x8f418cc5f855ccc079daa09b41c9e087
Sun Jan 22 08:39:36 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:36 2017 : Info: +group authorize {
Sun Jan 22 08:39:36 2017 : Info: [eap] EAP packet type response id 4 
length 112
Sun Jan 22 08:39:36 2017 : Info: [eap] Continuing tunnel setup.
Sun Jan 22 08:39:36 2017 : Info: ++[eap] = ok
Sun Jan 22 08:39:36 2017 : Info: +} # group authorize = ok
Sun Jan 22 08:39:36 2017 : Info: Found Auth-Type = EAP
Sun Jan 22 08:39:36 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/default
Sun Jan 22 08:39:36 2017 : Info: +group authenticate {
Sun Jan 22 08:39:36 2017 : Info: [eap] Request found, released from the list
Sun Jan 22 08:39:36 2017 : Info: [eap] EAP/ttls
Sun Jan 22 08:39:36 2017 : Info: [eap] processing type ttls
Sun Jan 22 08:39:36 2017 : Info: [ttls] Authenticate
Sun Jan 22 08:39:36 2017 : Info: [ttls] processing EAP-TLS
Sun Jan 22 08:39:36 2017 : Info: [ttls] eaptls_verify returned 7
Sun Jan 22 08:39:36 2017 : Info: [ttls] Done initial handshake
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] <<< Unknown TLS version [length 
0005]
Sun Jan 22 08:39:36 2017 : Info: [ttls] eaptls_process returned 7
Sun Jan 22 08:39:36 2017 : Info: [ttls] Session established.  Proceeding 
to decode tunneled attributes.
Sun Jan 22 08:39:36 2017 : Info: [ttls] Got tunneled request
     User-Name = "user"
     User-Password = "pass"
     FreeRADIUS-Proxied-To = 127.0.0.1
Sun Jan 22 08:39:36 2017 : Info: [ttls] Sending tunneled request
     User-Name = "user"
     User-Password = "pass"
     FreeRADIUS-Proxied-To = 127.0.0.1
server inner-tunnel {
Sun Jan 22 08:39:36 2017 : Info: # Executing section authorize from file 
/opt/etc/freeradius2/sites/inner-tunnel
Sun Jan 22 08:39:36 2017 : Info: +group authorize {
Sun Jan 22 08:39:36 2017 : Info: [files] users: Matched entry user at line 7
Sun Jan 22 08:39:36 2017 : Info: ++[files] = ok
Sun Jan 22 08:39:36 2017 : Info: ++[pap] = updated
Sun Jan 22 08:39:36 2017 : Info: +} # group authorize = updated
Sun Jan 22 08:39:36 2017 : Info: Found Auth-Type = PAP
Sun Jan 22 08:39:36 2017 : Info: # Executing group from file 
/opt/etc/freeradius2/sites/inner-tunnel
Sun Jan 22 08:39:36 2017 : Info: +group PAP {
Sun Jan 22 08:39:36 2017 : Info: [pap] login attempt with password "pass"
Sun Jan 22 08:39:36 2017 : Info: [pap] Using clear text password "pass"
Sun Jan 22 08:39:36 2017 : Info: [pap] User authenticated successfully
Sun Jan 22 08:39:36 2017 : Info: ++[pap] = ok
Sun Jan 22 08:39:36 2017 : Info: +} # group PAP = ok
Sun Jan 22 08:39:36 2017 : Info:   WARNING: Empty post-auth section. 
Using default return values.
} # server inner-tunnel
Sun Jan 22 08:39:36 2017 : Info: [ttls] Got tunneled reply code 
Access-Accept
     Session-Timeout := 21600
Sun Jan 22 08:39:36 2017 : Info: [ttls] Got tunneled Access-Accept
Sun Jan 22 08:39:36 2017 : Info: [eap] Freeing handler
Sun Jan 22 08:39:36 2017 : Info: ++[eap] = ok
Sun Jan 22 08:39:36 2017 : Info: +} # group authenticate = ok
Sun Jan 22 08:39:36 2017 : Info:   WARNING: Empty post-auth section. 
Using default return values.
Sending Access-Accept of id 0 to 127.0.0.1 port 37394
     Session-Timeout := 21600
     MS-MPPE-Recv-Key = 
0xe98f09cadffcf56264b1e1cd574e373caad532adab6b9fadcfc2e521c15bb667
     MS-MPPE-Send-Key = 
0xe427cd87c5f09f746b2e214b668fceac6bf0f86245916ec6062e146ac433beea
     EAP-Message = 0x03040004
     Message-Authenticator = 0x00000000000000000000000000000000
     User-Name = "anonymous"
Sun Jan 22 08:39:36 2017 : Info: Finished request 4.
Sun Jan 22 08:39:36 2017 : Debug: Going to the next request
Sun Jan 22 08:39:36 2017 : Debug: Waking up in 6.9 seconds.
Sun Jan 22 08:39:43 2017 : Info: Cleaning up request 4 ID 0 with 
timestamp +15
Sun Jan 22 08:39:43 2017 : Info: Ready to process requests.



More information about the Freeradius-Users mailing list