Hello- I have done lots of searching and through some archived messages from this list made some good progress. Reading these messages I have determined that since I have md5 hashed passwords in my openldap database I need to use PAP + TTLS. I have read and performed the radtests at the top of the inner-tunnel config file with successful auths. Specifically, I ran the following successfully: radtest -t pap USER PASSWORD 127.0.0.1:18120 0 testing123 My problem comes when I try to authenticate a wireless device against the network. I enter the username and password in the dialog (cisco WLC and Mac OSX Client) and get the following from the freeradius debug output. I think its trying to do a form of authentication that I do not want hence why I am getting "No Authenticate method found for request". Any guidance would be greatly appreciated. If you need me to supply config files I can do that. Thank you ahead of time for taking the time to read this: rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=209, length=223 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0201001001616c6578677265676f7279 Message-Authenticator = 0x85c12dd9ab3c4960d2889e61daedc0c6 Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[digest] returns noop Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] EAP packet type response id 1 length 16 Tue Aug 12 00:41:59 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns updated Tue Aug 12 00:41:59 2014 : Info: ++[files] returns noop Tue Aug 12 00:41:59 2014 : Info: [ldap] performing user authorization for alexgregory Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: %{Stripped-User-Name} -> Tue Aug 12 00:41:59 2014 : Info: [ldap] ... expanding second conditional Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: %{User-Name} -> alexgregory Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=alexgregory) Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_get_conn: Got Id: 0 Tue Aug 12 00:41:59 2014 : Debug: [ldap] attempting LDAP reconnection Tue Aug 12 00:41:59 2014 : Debug: [ldap] (re)connect to localhost:389, authentication 0 Tue Aug 12 00:41:59 2014 : Debug: [ldap] bind as cn=admin,dc=team,dc=company,dc=com/653776d05374 to localhost:389 Tue Aug 12 00:41:59 2014 : Debug: [ldap] waiting for bind result ... Tue Aug 12 00:41:59 2014 : Debug: [ldap] Bind was successful Tue Aug 12 00:41:59 2014 : Debug: [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=alexgregory) Tue Aug 12 00:41:59 2014 : Info: [ldap] No default NMAS login sequence Tue Aug 12 00:41:59 2014 : Info: [ldap] looking for check items in directory... Tue Aug 12 00:41:59 2014 : Debug: [ldap] userPassword -> Password-With-Header == "{MD5}replacedpasswordhash" Tue Aug 12 00:41:59 2014 : Info: [ldap] looking for reply items in directory... Tue Aug 12 00:41:59 2014 : Info: [ldap] user alexgregory authorized to use remote access Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_release_conn: Release Id: 0 Tue Aug 12 00:41:59 2014 : Info: ++[ldap] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[expiration] returns noop Tue Aug 12 00:41:59 2014 : Info: ++[logintime] returns noop Tue Aug 12 00:41:59 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Aug 12 00:41:59 2014 : Info: ++[pap] returns noop Tue Aug 12 00:41:59 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:41:59 2014 : Info: [eap] EAP Identity Tue Aug 12 00:41:59 2014 : Info: [eap] processing type tls Tue Aug 12 00:41:59 2014 : Info: [tls] Initiate Tue Aug 12 00:41:59 2014 : Info: [tls] Start returned 1 Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 209 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x010200061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x136652b6136447253c8241792e3864a7 Tue Aug 12 00:41:59 2014 : Info: Finished request 0. Tue Aug 12 00:41:59 2014 : Debug: Going to the next request Tue Aug 12 00:41:59 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=210, length=377 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0202009815800000008e160301008901000085030153e962d614f15c225bbed04d947e74771b76339e7fede2cc3e100ed6c5e8e02a00004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100 State = 0x136652b6136447253c8241792e3864a7 Message-Authenticator = 0x385c18e1699b11f23b5ccdadb073dcf2 Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[digest] returns noop Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] EAP packet type response id 2 length 152 Tue Aug 12 00:41:59 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns ok Tue Aug 12 00:41:59 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:41:59 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:41:59 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:41:59 2014 : Info: [eap] processing type ttls Tue Aug 12 00:41:59 2014 : Info: [ttls] Authenticate Tue Aug 12 00:41:59 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:41:59 2014 : Debug: TLS Length 142 Tue Aug 12 00:41:59 2014 : Info: [ttls] Length Included Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:41:59 2014 : Info: [ttls] (other): before/accept initialization Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: before/accept initialization Tue Aug 12 00:41:59 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0089], ClientHello Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 read client hello A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0039], ServerHello Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write server hello A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 02c4], Certificate Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write certificate A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write key exchange A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write server done A Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Aug 12 00:41:59 2014 : Debug: In SSL Handshake Phase Tue Aug 12 00:41:59 2014 : Debug: In SSL Accept mode Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 210 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x0103040015c000000460160301003902000035030153e962d744d1a41d7796e73a84a55e3ecd6f143df28b861f8a5d93d8bc80a60700c01400000dff01000100000b00040300010216030102c40b0002c00002bd0002ba308202b63082019ea003020102020900b507e231935d6b3f300d06092a864886f70d010105050030133111300f060355040313086f70656e6c646170301e170d3134303830373232333035385a170d3234303830343232333035385a30133111300f060355040313086f70656e6c64617030820122300d06092a864886f70d01010105000382010f003082010a0282010100bae7e24798efa862ea1659a17ac74864a297d09a EAP-Message = 0x249d8e467e1a40a3fc4fdcf36e73ac43cc11e5df4978020ae6af6c12d0a98f7c90d0352eae9c5b9c8364cffe115b833c52bfbcb43c292c303ee0f8cca82a3732ed53bcdba3905a9f030c9bf242e7482f28c0a30e5210afbf064e6129cef1358e30942581621b927da448fcea0fcca181c7ea6ac7385946513bd092e7ccf41df13f7a4f498533947d1f0451659c20977cfddeb5ffadef948b8f876a1bbba0f2a574e05daf8fe696a828973f21674abc246ca73279dcd5fe1720f1140b3f351427fc5be4a4158fb31d2b46643e0bbef9297b892cea88babfcb26e53bcc981bec71b84d0fb21760176f5d12adc90203010001a30d300b30090603551d1304 EAP-Message = 0x023000300d06092a864886f70d010105050003820101009a35e4dddb99265dfbe96dbd2dd5efcec97ebbb6111d42b313a0d7b6f29a4a4cc378c154afc028a986a118ddf1e611aa3fda9ed59c9f745663fcfd2655891584047b99042c2f7d3757ff92e86d008a55dac7e1e2a8f7e67711fec590812461e9de753eacf30285e44c3c7ecc31671d4ccbfdc6de65536e8b780cbf05ca5e0442748ccc7356f315baac1cc9bb528198bba1526d18213171b26e3676162be28056600762ed21df47ca64f29fb8b9853b8e84731708c7e7c5b0862c3d61aa07b37b89eb915e0fb7f5867a9eb9346574bfc112aa4ea45ae9bae8fdf44b9cedbd3ba5082046a7de23 EAP-Message = 0xc8fefa2502dad1e8da8bf54443bc2b061a301dd93689ce6867d9160301014b0c0001470300174104c833e1540e097f1e67c5b07600aed83309c6e30ee8881705b60b847eddc532f31791039547ef4bfcbb6ac6a8f8002f68a21ae8fd516ba969ae79829cc3c53cc601006e2e6fc775a6528b025bfc7605cbb2448d3571cf62293a8ba90c69daa86dc8f090e869362ee4a57fc0300dccc93f970fb0402632f4977a2346e4ee2947a180866e2b6fb7873c6f6ded0a810a1fb9c49952c918e416f516b34855d0371e9066eae748d1d467035a333c4d05e11222879454b7a492d187edb65306dff65955fecad26bfd1a79301dd5568dfd5a236f93420cd068 EAP-Message = 0x051d4c1e3e1ec8536a166083 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x136652b6126547253c8241792e3864a7 Tue Aug 12 00:41:59 2014 : Info: Finished request 1. Tue Aug 12 00:41:59 2014 : Debug: Going to the next request Tue Aug 12 00:41:59 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=211, length=231 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300061500 State = 0x136652b6126547253c8241792e3864a7 Message-Authenticator = 0xcec26d420e8446eca2daa7c678f31edf Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[digest] returns noop Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] EAP packet type response id 3 length 6 Tue Aug 12 00:41:59 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns ok Tue Aug 12 00:41:59 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:41:59 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:41:59 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:41:59 2014 : Info: [eap] processing type ttls Tue Aug 12 00:41:59 2014 : Info: [ttls] Authenticate Tue Aug 12 00:41:59 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:41:59 2014 : Info: [ttls] Received TLS ACK Tue Aug 12 00:41:59 2014 : Info: [ttls] ACK handshake fragment handler Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_verify returned 1 Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 211 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x01040074158000000460e16f53b8c421f13b800a406a4af847fe03bd96ecadc78ba923d1e7aaed4324dfc7daaee76106d734751755494bfa126d7ce78d28cd6e999d9a4dcd7cabbe6378c66afc86e1eac9de94fb58ec01b03fdb99c58c58336ecdaf8d5840b49a2ab4a00916030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x136652b6116247253c8241792e3864a7 Tue Aug 12 00:41:59 2014 : Info: Finished request 2. Tue Aug 12 00:41:59 2014 : Debug: Going to the next request Tue Aug 12 00:41:59 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=212, length=369 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0204009015800000008616030100461000004241047e1f049d3dd9710b6b47b7c6531e6881e765adb63d231e128e5c1656f58c2d396607a6af675607c91011a766f6697aab0b3052de7ff8e3786f13065b851af468140301000101160301003050d9c71f246c4d8eb945d9df442f7282a41eede22f07169c4896feae772897c6ce3235500f7508721ad8f19d3aff5267 State = 0x136652b6116247253c8241792e3864a7 Message-Authenticator = 0x02fc5bba2b69377c63112ef27fc30f03 Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[digest] returns noop Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] EAP packet type response id 4 length 144 Tue Aug 12 00:41:59 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns ok Tue Aug 12 00:41:59 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:41:59 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:41:59 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:41:59 2014 : Info: [eap] processing type ttls Tue Aug 12 00:41:59 2014 : Info: [ttls] Authenticate Tue Aug 12 00:41:59 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:41:59 2014 : Debug: TLS Length 134 Tue Aug 12 00:41:59 2014 : Info: [ttls] Length Included Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:41:59 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 read client key exchange A Tue Aug 12 00:41:59 2014 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue Aug 12 00:41:59 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 read finished A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write change cipher spec A Tue Aug 12 00:41:59 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 write finished A Tue Aug 12 00:41:59 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Aug 12 00:41:59 2014 : Info: [ttls] (other): SSL negotiation finished successfully Tue Aug 12 00:41:59 2014 : Debug: SSL Connection Established Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 212 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x0105004515800000003b1403010001011603010030dc83519bd0a54a2ba41dd3dd74692893c115160b7e71146f182ca186255317fc818e1681328d26a42aa495432bc5c248 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x136652b6106347253c8241792e3864a7 Tue Aug 12 00:41:59 2014 : Info: Finished request 3. Tue Aug 12 00:41:59 2014 : Debug: Going to the next request Tue Aug 12 00:41:59 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=213, length=384 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0205009f15800000009517030100906e9af3e38e1981dff6e7302b8416c4225a69e79159da41f80b94714d999f8f6db4f68627a60ab33836980ce199aaca80f2dc87f04621632ab15a338b87cbc7c6fbb1fa04c0cf0fe5098807810e55c05457de3d0b774145bc3d7fc2643f135c544702649a03598f45fbf3d1c74bc0c5523d9d808b2a6ecfdb74bf15464ea1fcb6679f332682b1b30ec13ac0ab460f2a43 State = 0x136652b6106347253c8241792e3864a7 Message-Authenticator = 0xe56cd52f822858761a85b03a3891a935 Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[digest] returns noop Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] EAP packet type response id 5 length 159 Tue Aug 12 00:41:59 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns ok Tue Aug 12 00:41:59 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:41:59 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:41:59 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:41:59 2014 : Info: [eap] processing type ttls Tue Aug 12 00:41:59 2014 : Info: [ttls] Authenticate Tue Aug 12 00:41:59 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:41:59 2014 : Debug: TLS Length 149 Tue Aug 12 00:41:59 2014 : Info: [ttls] Length Included Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:41:59 2014 : Info: [ttls] eaptls_process returned 7 Tue Aug 12 00:41:59 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. TTLS tunnel data in 0000: 00 00 00 01 00 00 00 13 61 6c 65 78 67 72 65 67 TTLS tunnel data in 0010: 6f 72 79 00 00 00 00 0b 80 00 00 1c 00 00 01 37 TTLS tunnel data in 0020: 77 cb 2f 7d e8 c3 de e8 10 e3 b5 0d 16 23 8e 37 TTLS tunnel data in 0030: 00 00 00 19 80 00 00 3e 00 00 01 37 97 00 d8 6e TTLS tunnel data in 0040: 34 f0 8e e9 d8 24 d9 d7 93 55 6d cf 6b 51 00 00 TTLS tunnel data in 0050: 00 00 00 00 00 00 b6 3d 56 f4 29 90 0e 14 16 da TTLS tunnel data in 0060: dc 4a fd f6 50 15 09 5e 57 92 f5 03 d9 d9 00 00 Tue Aug 12 00:41:59 2014 : Info: [ttls] Got tunneled request User-Name = "alexgregory" MS-CHAP-Challenge = 0x77cb2f7de8c3dee810e3b50d16238e37 MS-CHAP2-Response = 0x9700d86e34f08ee9d824d9d793556dcf6b510000000000000000b63d56f429900e1416dadc4afdf65015095e5792f503d9d9 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Aug 12 00:41:59 2014 : Info: [ttls] Sending tunneled request User-Name = "alexgregory" MS-CHAP-Challenge = 0x77cb2f7de8c3dee810e3b50d16238e37 MS-CHAP2-Response = 0x9700d86e34f08ee9d824d9d793556dcf6b510000000000000000b63d56f429900e1416dadc4afdf65015095e5792f503d9d9 FreeRADIUS-Proxied-To = 127.0.0.1 Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 server inner-tunnel { Tue Aug 12 00:41:59 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Tue Aug 12 00:41:59 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:41:59 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:41:59 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:41:59 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:41:59 2014 : Info: ++[control] returns noop Tue Aug 12 00:41:59 2014 : Info: [eap] No EAP-Message, not doing EAP Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns noop Tue Aug 12 00:41:59 2014 : Info: ++[files] returns noop Tue Aug 12 00:41:59 2014 : Info: [ldap] performing user authorization for alexgregory Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: %{Stripped-User-Name} -> Tue Aug 12 00:41:59 2014 : Info: [ldap] ... expanding second conditional Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: %{User-Name} -> alexgregory Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=alexgregory) Tue Aug 12 00:41:59 2014 : Info: [ldap] expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_get_conn: Got Id: 0 Tue Aug 12 00:41:59 2014 : Debug: [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=alexgregory) Tue Aug 12 00:41:59 2014 : Info: [ldap] No default NMAS login sequence Tue Aug 12 00:41:59 2014 : Info: [ldap] looking for check items in directory... Tue Aug 12 00:41:59 2014 : Debug: [ldap] userPassword -> Password-With-Header == "{MD5}replacedpasswordhash" Tue Aug 12 00:41:59 2014 : Info: [ldap] looking for reply items in directory... Tue Aug 12 00:41:59 2014 : Info: [ldap] user alexgregory authorized to use remote access Tue Aug 12 00:41:59 2014 : Debug: [ldap] ldap_release_conn: Release Id: 0 Tue Aug 12 00:41:59 2014 : Info: ++[ldap] returns ok Tue Aug 12 00:41:59 2014 : Info: ++[expiration] returns noop Tue Aug 12 00:41:59 2014 : Info: ++[logintime] returns noop Tue Aug 12 00:41:59 2014 : Info: [pap] No clear-text password in the request. Not performing PAP. Tue Aug 12 00:41:59 2014 : Info: ++[pap] returns noop Tue Aug 12 00:41:59 2014 : Info: ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Tue Aug 12 00:41:59 2014 : Info: Failed to authenticate the user. } # server inner-tunnel Tue Aug 12 00:41:59 2014 : Info: [ttls] Got tunneled reply code 3 Tue Aug 12 00:41:59 2014 : Info: [ttls] Got tunneled Access-Reject Tue Aug 12 00:41:59 2014 : Info: [eap] Handler failed in EAP/ttls Tue Aug 12 00:41:59 2014 : Info: [eap] Failed in EAP select Tue Aug 12 00:41:59 2014 : Info: ++[eap] returns invalid Tue Aug 12 00:41:59 2014 : Info: Failed to authenticate the user. Tue Aug 12 00:41:59 2014 : Info: Using Post-Auth-Type Reject Tue Aug 12 00:41:59 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:41:59 2014 : Info: +- entering group REJECT {...} Tue Aug 12 00:41:59 2014 : Info: [attr_filter.access_reject] expand: %{User-Name} -> alexgregory Tue Aug 12 00:41:59 2014 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Aug 12 00:41:59 2014 : Info: ++[attr_filter.access_reject] returns updated Tue Aug 12 00:41:59 2014 : Info: Delaying reject of request 4 for 1 seconds Tue Aug 12 00:41:59 2014 : Debug: Going to the next request Tue Aug 12 00:41:59 2014 : Debug: Waking up in 0.9 seconds. Tue Aug 12 00:42:00 2014 : Info: Sending delayed reject for request 4 Sending Access-Reject of id 213 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x04050004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Aug 12 00:42:00 2014 : Debug: Waking up in 3.8 seconds. Tue Aug 12 00:42:04 2014 : Info: Cleaning up request 0 ID 209 with timestamp +23 Tue Aug 12 00:42:04 2014 : Info: Cleaning up request 1 ID 210 with timestamp +23 Tue Aug 12 00:42:04 2014 : Info: Cleaning up request 2 ID 211 with timestamp +23 Tue Aug 12 00:42:04 2014 : Info: Cleaning up request 3 ID 212 with timestamp +23 Tue Aug 12 00:42:04 2014 : Debug: Waking up in 1.0 seconds. Tue Aug 12 00:42:05 2014 : Info: Cleaning up request 4 ID 213 with timestamp +23 Tue Aug 12 00:42:05 2014 : Info: Ready to process requests. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=214, length=223 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0201001001616c6578677265676f7279 Message-Authenticator = 0x89bf1ff14e1e789bcabf7f8b1e6e4cb0 Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[digest] returns noop Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] EAP packet type response id 1 length 16 Tue Aug 12 00:42:07 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns updated Tue Aug 12 00:42:07 2014 : Info: ++[files] returns noop Tue Aug 12 00:42:07 2014 : Info: [ldap] performing user authorization for alexgregory Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: %{Stripped-User-Name} -> Tue Aug 12 00:42:07 2014 : Info: [ldap] ... expanding second conditional Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: %{User-Name} -> alexgregory Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=alexgregory) Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_get_conn: Got Id: 0 Tue Aug 12 00:42:07 2014 : Debug: [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=alexgregory) Tue Aug 12 00:42:07 2014 : Info: [ldap] No default NMAS login sequence Tue Aug 12 00:42:07 2014 : Info: [ldap] looking for check items in directory... Tue Aug 12 00:42:07 2014 : Debug: [ldap] userPassword -> Password-With-Header == "{MD5}replacedpasswordhash" Tue Aug 12 00:42:07 2014 : Info: [ldap] looking for reply items in directory... Tue Aug 12 00:42:07 2014 : Info: [ldap] user alexgregory authorized to use remote access Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_release_conn: Release Id: 0 Tue Aug 12 00:42:07 2014 : Info: ++[ldap] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[expiration] returns noop Tue Aug 12 00:42:07 2014 : Info: ++[logintime] returns noop Tue Aug 12 00:42:07 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Aug 12 00:42:07 2014 : Info: ++[pap] returns noop Tue Aug 12 00:42:07 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:42:07 2014 : Info: [eap] EAP Identity Tue Aug 12 00:42:07 2014 : Info: [eap] processing type tls Tue Aug 12 00:42:07 2014 : Info: [tls] Initiate Tue Aug 12 00:42:07 2014 : Info: [tls] Start returned 1 Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 214 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x010200061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf4659c56f467891adaf6263d5bd06672 Tue Aug 12 00:42:07 2014 : Info: Finished request 5. Tue Aug 12 00:42:07 2014 : Debug: Going to the next request Tue Aug 12 00:42:07 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=215, length=377 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0202009815800000008e160301008901000085030153e962de481721e9ec93cd96a6d507b8c83a2e8ff85bef8f992ef6e991eb252a00004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100 State = 0xf4659c56f467891adaf6263d5bd06672 Message-Authenticator = 0x6f742b54c937a23a2edc3e0f9dd35c37 Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[digest] returns noop Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] EAP packet type response id 2 length 152 Tue Aug 12 00:42:07 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns ok Tue Aug 12 00:42:07 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:42:07 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:42:07 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:42:07 2014 : Info: [eap] processing type ttls Tue Aug 12 00:42:07 2014 : Info: [ttls] Authenticate Tue Aug 12 00:42:07 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:42:07 2014 : Debug: TLS Length 142 Tue Aug 12 00:42:07 2014 : Info: [ttls] Length Included Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:42:07 2014 : Info: [ttls] (other): before/accept initialization Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: before/accept initialization Tue Aug 12 00:42:07 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0089], ClientHello Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 read client hello A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0039], ServerHello Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write server hello A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 02c4], Certificate Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write certificate A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write key exchange A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write server done A Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Aug 12 00:42:07 2014 : Debug: In SSL Handshake Phase Tue Aug 12 00:42:07 2014 : Debug: In SSL Accept mode Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 215 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x0103040015c000000460160301003902000035030153e962df37a9d56ac3e6810cf50a27b3f859e545ec4588903fa92db2b6e7a76500c01400000dff01000100000b00040300010216030102c40b0002c00002bd0002ba308202b63082019ea003020102020900b507e231935d6b3f300d06092a864886f70d010105050030133111300f060355040313086f70656e6c646170301e170d3134303830373232333035385a170d3234303830343232333035385a30133111300f060355040313086f70656e6c64617030820122300d06092a864886f70d01010105000382010f003082010a0282010100bae7e24798efa862ea1659a17ac74864a297d09a EAP-Message = 0x249d8e467e1a40a3fc4fdcf36e73ac43cc11e5df4978020ae6af6c12d0a98f7c90d0352eae9c5b9c8364cffe115b833c52bfbcb43c292c303ee0f8cca82a3732ed53bcdba3905a9f030c9bf242e7482f28c0a30e5210afbf064e6129cef1358e30942581621b927da448fcea0fcca181c7ea6ac7385946513bd092e7ccf41df13f7a4f498533947d1f0451659c20977cfddeb5ffadef948b8f876a1bbba0f2a574e05daf8fe696a828973f21674abc246ca73279dcd5fe1720f1140b3f351427fc5be4a4158fb31d2b46643e0bbef9297b892cea88babfcb26e53bcc981bec71b84d0fb21760176f5d12adc90203010001a30d300b30090603551d1304 EAP-Message = 0x023000300d06092a864886f70d010105050003820101009a35e4dddb99265dfbe96dbd2dd5efcec97ebbb6111d42b313a0d7b6f29a4a4cc378c154afc028a986a118ddf1e611aa3fda9ed59c9f745663fcfd2655891584047b99042c2f7d3757ff92e86d008a55dac7e1e2a8f7e67711fec590812461e9de753eacf30285e44c3c7ecc31671d4ccbfdc6de65536e8b780cbf05ca5e0442748ccc7356f315baac1cc9bb528198bba1526d18213171b26e3676162be28056600762ed21df47ca64f29fb8b9853b8e84731708c7e7c5b0862c3d61aa07b37b89eb915e0fb7f5867a9eb9346574bfc112aa4ea45ae9bae8fdf44b9cedbd3ba5082046a7de23 EAP-Message = 0xc8fefa2502dad1e8da8bf54443bc2b061a301dd93689ce6867d9160301014b0c000147030017410421f95124ae7f38f71bf732b2781f1a6bc15dc261d0da4beb19f6ded2ff693eb8dd6e07996bdb8a54b76f694a9d1ba3a929fab8b30ce26243d194a97ec262c0b00100485c8393ff37ca0476fc9b5368dfb6222fe8c5c491e5c202deaf9a65186760861a551fa6ede92df57bc62b9eed3113ddcbc3553ae4c5cfeea1c773903780d4e2205b5e8dd1fbcdf39abc08c836b5db984e8df7718e769ef13c68d92b00085e89a331bee6762dfa3251912ccb415a1457707443c3bb856020e45760d9c5060bab2a883998a936e71147470f60748f563ffffa80 EAP-Message = 0xce2b6f452704e0ae5a4d1808 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf4659c56f566891adaf6263d5bd06672 Tue Aug 12 00:42:07 2014 : Info: Finished request 6. Tue Aug 12 00:42:07 2014 : Debug: Going to the next request Tue Aug 12 00:42:07 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=216, length=231 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300061500 State = 0xf4659c56f566891adaf6263d5bd06672 Message-Authenticator = 0x83131792813c3848c6a17efe5d93c5da Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[digest] returns noop Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] EAP packet type response id 3 length 6 Tue Aug 12 00:42:07 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns ok Tue Aug 12 00:42:07 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:42:07 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:42:07 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:42:07 2014 : Info: [eap] processing type ttls Tue Aug 12 00:42:07 2014 : Info: [ttls] Authenticate Tue Aug 12 00:42:07 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:42:07 2014 : Info: [ttls] Received TLS ACK Tue Aug 12 00:42:07 2014 : Info: [ttls] ACK handshake fragment handler Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_verify returned 1 Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 216 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x010400741580000004603041fb2046d9e58d258f4cdd4e20c9249dc902d21713370b300975e8e8d63b7902a267e342faf9de6c4bb93d97b9ac18c8cd79e8ce50c058536884496fc0644fdfe96026bf7e1e79df0fff526f4a1cc029a47926a7ab9f3a3b4fc8160e5d499be616030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf4659c56f661891adaf6263d5bd06672 Tue Aug 12 00:42:07 2014 : Info: Finished request 7. Tue Aug 12 00:42:07 2014 : Debug: Going to the next request Tue Aug 12 00:42:07 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=217, length=369 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02040090158000000086160301004610000042410410609b20fa3db38744d052fa32b9d99534c8e0aad10ebe39f5ad4ea1360b6bd7367a59faf71c6b95eae90ced4a0bfe0809d24c5ff21851f7faefc016d41924141403010001011603010030f347f9e61c61c903fcb9199137cb8b1cecf39deb7f3d418c0b82f3b06b583c76b2eafad1e9a766192f0fe28a16809ae2 State = 0xf4659c56f661891adaf6263d5bd06672 Message-Authenticator = 0x0a403539bd800196113b1aa9a87d78b3 Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[digest] returns noop Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] EAP packet type response id 4 length 144 Tue Aug 12 00:42:07 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns ok Tue Aug 12 00:42:07 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:42:07 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:42:07 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:42:07 2014 : Info: [eap] processing type ttls Tue Aug 12 00:42:07 2014 : Info: [ttls] Authenticate Tue Aug 12 00:42:07 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:42:07 2014 : Debug: TLS Length 134 Tue Aug 12 00:42:07 2014 : Info: [ttls] Length Included Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:42:07 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 read client key exchange A Tue Aug 12 00:42:07 2014 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue Aug 12 00:42:07 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 read finished A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write change cipher spec A Tue Aug 12 00:42:07 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 write finished A Tue Aug 12 00:42:07 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Aug 12 00:42:07 2014 : Info: [ttls] (other): SSL negotiation finished successfully Tue Aug 12 00:42:07 2014 : Debug: SSL Connection Established Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_process returned 13 Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 217 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x0105004515800000003b1403010001011603010030d8f2c43771ec025853ef49cc006b67b868a494442d6037ee42ec86ed631480ba9a17c9d3a760732b9f07d446f1f5a839 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf4659c56f760891adaf6263d5bd06672 Tue Aug 12 00:42:07 2014 : Info: Finished request 8. Tue Aug 12 00:42:07 2014 : Debug: Going to the next request Tue Aug 12 00:42:07 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX port 32768, id=218, length=384 User-Name = "alexgregory" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0205009f15800000009517030100907bc646b5cd2459705f364e4ba30bd248154985b82c9961aae42e39904a74c2dd39af755c6bb342dd1bd9e21d6d965b1751e44d16f9ebbadf648adc439e136e2c2c62a8ec6010b6b3a1683b9f2d03500d3bc33728c7789e5be81a9f20f318cc6c5eac3b959c3e0eb7d60e31b4e15a9eaad9d0e3b9c649ea3a2dc326e6cf1491dd356d7b4fab2d581abe522b9990e0afef State = 0xf4659c56f760891adaf6263d5bd06672 Message-Authenticator = 0xccc7cc64a106a3fcbe39b45ee77bb381 Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: ++[preprocess] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[digest] returns noop Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] EAP packet type response id 5 length 159 Tue Aug 12 00:42:07 2014 : Info: [eap] Continuing tunnel setup. Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns ok Tue Aug 12 00:42:07 2014 : Info: Found Auth-Type = EAP Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group authenticate {...} Tue Aug 12 00:42:07 2014 : Info: [eap] Request found, released from the list Tue Aug 12 00:42:07 2014 : Info: [eap] EAP/ttls Tue Aug 12 00:42:07 2014 : Info: [eap] processing type ttls Tue Aug 12 00:42:07 2014 : Info: [ttls] Authenticate Tue Aug 12 00:42:07 2014 : Info: [ttls] processing EAP-TLS Tue Aug 12 00:42:07 2014 : Debug: TLS Length 149 Tue Aug 12 00:42:07 2014 : Info: [ttls] Length Included Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_verify returned 11 Tue Aug 12 00:42:07 2014 : Info: [ttls] eaptls_process returned 7 Tue Aug 12 00:42:07 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. TTLS tunnel data in 0000: 00 00 00 01 00 00 00 13 61 6c 65 78 67 72 65 67 TTLS tunnel data in 0010: 6f 72 79 00 00 00 00 0b 80 00 00 1c 00 00 01 37 TTLS tunnel data in 0020: 63 61 7d 3c 0b 66 a7 d4 4f c7 f6 2a f6 1c ce b2 TTLS tunnel data in 0030: 00 00 00 19 80 00 00 3e 00 00 01 37 1c 00 2e b8 TTLS tunnel data in 0040: 7c 02 be de 7f 09 34 cd a0 f7 76 5c fa ac 00 00 TTLS tunnel data in 0050: 00 00 00 00 00 00 c2 ab 1c 93 9d c6 10 de f7 ac TTLS tunnel data in 0060: bd c9 79 e0 3d 9a d5 81 c5 05 61 8b f9 9f 00 00 Tue Aug 12 00:42:07 2014 : Info: [ttls] Got tunneled request User-Name = "alexgregory" MS-CHAP-Challenge = 0x63617d3c0b66a7d44fc7f62af61cceb2 MS-CHAP2-Response = 0x1c002eb87c02bede7f0934cda0f7765cfaac0000000000000000c2ab1c939dc610def7acbdc979e03d9ad581c505618bf99f FreeRADIUS-Proxied-To = 127.0.0.1 Tue Aug 12 00:42:07 2014 : Info: [ttls] Sending tunneled request User-Name = "alexgregory" MS-CHAP-Challenge = 0x63617d3c0b66a7d44fc7f62af61cceb2 MS-CHAP2-Response = 0x1c002eb87c02bede7f0934cda0f7765cfaac0000000000000000c2ab1c939dc610def7acbdc979e03d9ad581c505618bf99f FreeRADIUS-Proxied-To = 127.0.0.1 Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "78-31-c1-be-89-a8" Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test" NAS-Port = 4 Cisco-AVPair = "audit-session-id=0a2100820000057653e962bb" NAS-IP-Address = 10.33.0.130 NAS-Identifier = "inWebo" Airespace-Wlan-Id = 6 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 server inner-tunnel { Tue Aug 12 00:42:07 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Tue Aug 12 00:42:07 2014 : Info: +- entering group authorize {...} Tue Aug 12 00:42:07 2014 : Info: [suffix] No '@' in User-Name = "alexgregory", looking up realm NULL Tue Aug 12 00:42:07 2014 : Info: [suffix] No such realm "NULL" Tue Aug 12 00:42:07 2014 : Info: ++[suffix] returns noop Tue Aug 12 00:42:07 2014 : Info: ++[control] returns noop Tue Aug 12 00:42:07 2014 : Info: [eap] No EAP-Message, not doing EAP Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns noop Tue Aug 12 00:42:07 2014 : Info: ++[files] returns noop Tue Aug 12 00:42:07 2014 : Info: [ldap] performing user authorization for alexgregory Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: %{Stripped-User-Name} -> Tue Aug 12 00:42:07 2014 : Info: [ldap] ... expanding second conditional Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: %{User-Name} -> alexgregory Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=alexgregory) Tue Aug 12 00:42:07 2014 : Info: [ldap] expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_get_conn: Got Id: 0 Tue Aug 12 00:42:07 2014 : Debug: [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=alexgregory) Tue Aug 12 00:42:07 2014 : Info: [ldap] No default NMAS login sequence Tue Aug 12 00:42:07 2014 : Info: [ldap] looking for check items in directory... Tue Aug 12 00:42:07 2014 : Debug: [ldap] userPassword -> Password-With-Header == "{MD5}replacedpasswordhash" Tue Aug 12 00:42:07 2014 : Info: [ldap] looking for reply items in directory... Tue Aug 12 00:42:07 2014 : Info: [ldap] user alexgregory authorized to use remote access Tue Aug 12 00:42:07 2014 : Debug: [ldap] ldap_release_conn: Release Id: 0 Tue Aug 12 00:42:07 2014 : Info: ++[ldap] returns ok Tue Aug 12 00:42:07 2014 : Info: ++[expiration] returns noop Tue Aug 12 00:42:07 2014 : Info: ++[logintime] returns noop Tue Aug 12 00:42:07 2014 : Info: [pap] No clear-text password in the request. Not performing PAP. Tue Aug 12 00:42:07 2014 : Info: ++[pap] returns noop Tue Aug 12 00:42:07 2014 : Info: ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Tue Aug 12 00:42:07 2014 : Info: Failed to authenticate the user. } # server inner-tunnel Tue Aug 12 00:42:07 2014 : Info: [ttls] Got tunneled reply code 3 Tue Aug 12 00:42:07 2014 : Info: [ttls] Got tunneled Access-Reject Tue Aug 12 00:42:07 2014 : Info: [eap] Handler failed in EAP/ttls Tue Aug 12 00:42:07 2014 : Info: [eap] Failed in EAP select Tue Aug 12 00:42:07 2014 : Info: ++[eap] returns invalid Tue Aug 12 00:42:07 2014 : Info: Failed to authenticate the user. Tue Aug 12 00:42:07 2014 : Info: Using Post-Auth-Type Reject Tue Aug 12 00:42:07 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Tue Aug 12 00:42:07 2014 : Info: +- entering group REJECT {...} Tue Aug 12 00:42:07 2014 : Info: [attr_filter.access_reject] expand: %{User-Name} -> alexgregory Tue Aug 12 00:42:07 2014 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Aug 12 00:42:07 2014 : Info: ++[attr_filter.access_reject] returns updated Tue Aug 12 00:42:07 2014 : Info: Delaying reject of request 9 for 1 seconds Tue Aug 12 00:42:07 2014 : Debug: Going to the next request Tue Aug 12 00:42:07 2014 : Debug: Waking up in 0.9 seconds. Tue Aug 12 00:42:08 2014 : Info: Sending delayed reject for request 9 Sending Access-Reject of id 218 to XXX.XXX.XXX.XXX port 32768 EAP-Message = 0x04050004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Aug 12 00:42:08 2014 : Debug: Waking up in 3.9 seconds. Tue Aug 12 00:42:12 2014 : Info: Cleaning up request 5 ID 214 with timestamp +31 Tue Aug 12 00:42:12 2014 : Info: Cleaning up request 6 ID 215 with timestamp +31 Tue Aug 12 00:42:12 2014 : Info: Cleaning up request 7 ID 216 with timestamp +31 Tue Aug 12 00:42:12 2014 : Info: Cleaning up request 8 ID 217 with timestamp +31 Tue Aug 12 00:42:12 2014 : Debug: Waking up in 1.0 seconds. Tue Aug 12 00:42:13 2014 : Info: Cleaning up request 9 ID 218 with timestamp +31 Tue Aug 12 00:42:13 2014 : Info: Ready to process requests.