EAP Taking Too Long to Authenticate
Syed Rais Ahmad NON DRI
SAhmad at darden.com
Fri Nov 6 23:25:39 CET 2015
Folks,
Here is the debug.
Thanks.
Fri Nov 6 17:12:35 2015 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Fri Nov 6 17:12:35 2015 : Debug: Listening on proxy address * port 1814
Fri Nov 6 17:12:35 2015 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=70, length=211
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0xbba9666d164b7ce837156221640f5393
EAP-Message = 0x0202001e01686f73742f4c4f414e45523735312e64617264656e2e636f6d
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:40 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:40 2015 : Info: +group authorize {
Fri Nov 6 17:12:40 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:40 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:40 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:40 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:40 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:40 2015 : Info: [eap] EAP packet type response id 2 length 30
Fri Nov 6 17:12:40 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:40 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:40 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:40 2015 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Fri Nov 6 17:12:40 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:40 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:40 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:40 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:40 2015 : Info: +group authenticate {
Fri Nov 6 17:12:40 2015 : Info: [eap] EAP Identity
Fri Nov 6 17:12:40 2015 : Info: [eap] processing type md5
Fri Nov 6 17:12:40 2015 : Debug: rlm_eap_md5: Issuing Challenge
Fri Nov 6 17:12:40 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:40 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 70 to 10.238.250.50 port 1645
EAP-Message = 0x010300160410a6596026f130cc961331daae2ef5f4f3
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x139712c8139416e01bcd15fe5a12236f
Fri Nov 6 17:12:40 2015 : Info: Finished request 0.
Fri Nov 6 17:12:40 2015 : Debug: Going to the next request
Fri Nov 6 17:12:40 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=71, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0xda8d567be65507a40f686b7895d75be1
EAP-Message = 0x02030006030d
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x139712c8139416e01bcd15fe5a12236f
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:40 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:40 2015 : Info: +group authorize {
Fri Nov 6 17:12:40 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:40 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:40 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:40 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:40 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:40 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:40 2015 : Info: [eap] EAP packet type response id 3 length 6
Fri Nov 6 17:12:40 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:40 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:40 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:40 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:40 2015 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Fri Nov 6 17:12:40 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:40 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:40 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:40 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:40 2015 : Info: +group authenticate {
Fri Nov 6 17:12:40 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:40 2015 : Info: [eap] EAP NAK
Fri Nov 6 17:12:40 2015 : Info: [eap] EAP-NAK asked for EAP-Type/tls
Fri Nov 6 17:12:40 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:40 2015 : Info: [tls] Requiring client certificate
Fri Nov 6 17:12:40 2015 : Info: [tls] Initiate
Fri Nov 6 17:12:40 2015 : Info: [tls] Start returned 1
Fri Nov 6 17:12:40 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:40 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 71 to 10.238.250.50 port 1645
EAP-Message = 0x010400060d20
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x139712c812931fe01bcd15fe5a12236f
Fri Nov 6 17:12:40 2015 : Info: Finished request 1.
Fri Nov 6 17:12:40 2015 : Debug: Going to the next request
Fri Nov 6 17:12:40 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=72, length=336
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x66d5f3fc51531333adc3bfe256c26630
EAP-Message = 0x020400890d800000007f160301007a010000760301563d25d83e430aab0e7740e341e31ef3bd6ca2b18bb7b2108f2accd4ba5c7e0020774fda81dd8e756f3af283185f9e38011457bf0fba7fe6cac82d6ebfbc29a4630018002f00350005000ac013c014c009c00a003200380013000401000015ff01000100000a0006000400170018000b00020100
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x139712c812931fe01bcd15fe5a12236f
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:41 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authorize {
Fri Nov 6 17:12:41 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:41 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:41 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:41 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:41 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP packet type response id 4 length 137
Fri Nov 6 17:12:41 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:41 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:41 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:41 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:41 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authenticate {
Fri Nov 6 17:12:41 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:41 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:41 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:41 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:41 2015 : Debug: TLS Length 127
Fri Nov 6 17:12:41 2015 : Info: [tls] Length Included
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_verify returned 11
Fri Nov 6 17:12:41 2015 : Info: [tls] (other): before/accept initialization
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: before/accept initialization
Fri Nov 6 17:12:41 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 007a], ClientHello
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: SSLv3 read client hello A
Fri Nov 6 17:12:41 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0031], ServerHello
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: SSLv3 write server hello A
Fri Nov 6 17:12:41 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 060d], Certificate
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: SSLv3 write certificate A
Fri Nov 6 17:12:41 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0027], CertificateRequest
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: SSLv3 write certificate request A
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: SSLv3 flush data
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Nov 6 17:12:41 2015 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Nov 6 17:12:41 2015 : Debug: In SSL Handshake Phase
Fri Nov 6 17:12:41 2015 : Debug: In SSL Accept mode
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:41 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 72 to 10.238.250.50 port 1645
EAP-Message = 0x010504000dc00000067416030100310200002d0301563d25d969a9aed366db266f2b224291eb05e014015fb8856d23cc3903be242300002f000005ff01000100160301060d0b000609000606000603308205ff308204e7a003020102020a3254f09e00020002d0a6300d06092a864886f70d0101050500304231133011060a0992268993f22c6401191603636f6d31163014060a0992268993f22c640119160664617264656e311330110603550403130a52534343525450523032301e170d3135313031353139313632375a170d3138303832343231303632375a3072310b30090603550406130255533110300e06035504081307466c6f7269646131
EAP-Message = 0x10300e060355040713074f726c616e646f310f300d060355040a130644617264656e31163014060355040b130d44617461205365637572697479311630140603550403130d61746c7261646975736472303130820122300d06092a864886f70d01010105000382010f003082010a02820101009dee408f93ad85f91e024534c3924cd135e2ba43aa0a7391df14d03c779b55f145bff10c55a8901f3c73290a7b43b4a1a982a89f6eb2903d77a15f55ad6dcca44615c937a658aa3be79385b95996180b0780ebdd5404dc876032108d2d3f1e05a2f011c692fb1506b585d22481b3442834217d66896322d9f6e7b5c495ffe58f9fbe4bb018f8ea4fdc7e
EAP-Message = 0xd80e40e016fdb56f018be773143dfacfa4c645b27d40a9599a2a5b3268ae3b34b78881cc43cea1ce672e39e71cc30d4f9c051246859ac860fc9310b7bb0b726d5a9419d6ff80c3ee9f4abdd33a5b39da233619b7b5c8365d85e3e94fff82b9457a10047b4aa56ca0883b43892e1e3def4533b47025910203010001a38202c5308202c1300b0603551d0f0404030204b0303d06092b06010401823715070430302e06262b060104018237150881f0962881a8985e8289931584a9f42186d6a875178396b00c83c3ae0602016402010c301d0603551d0e0416041413f6e9e13094aa39d83ce70447add33fcd37bc343081f00603551d1f0481e83081e530
EAP-Message = 0x81e2a081dfa081dc8624687474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e63726c8681b36c6461703a2f2f2f434e3d525343435254505230322c434e3d727363637274707230322c434e3d4344502c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f63657274696669636174655265766f636174696f6e4c6973743f626173653f6f626a656374436c6173733d63524c446973747269627574696f6e506f696e743082011706082b060105050701010482010930820105303006
EAP-Message = 0x082b06010505073002862468
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x139712c811921fe01bcd15fe5a12236f
Fri Nov 6 17:12:41 2015 : Info: Finished request 2.
Fri Nov 6 17:12:41 2015 : Debug: Going to the next request
Fri Nov 6 17:12:41 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=73, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x2cd5606514f284d9b8e035387d0bae00
EAP-Message = 0x020500060d00
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x139712c811921fe01bcd15fe5a12236f
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:41 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authorize {
Fri Nov 6 17:12:41 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:41 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:41 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:41 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:41 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP packet type response id 5 length 6
Fri Nov 6 17:12:41 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:41 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:41 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:41 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:41 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authenticate {
Fri Nov 6 17:12:41 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:41 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:41 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:41 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:41 2015 : Info: [tls] Received TLS ACK
Fri Nov 6 17:12:41 2015 : Info: [tls] ACK handshake fragment handler
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_verify returned 1
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:41 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 73 to 10.238.250.50 port 1645
EAP-Message = 0x010602880d80000006747474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e6372743081a806082b0601050507300286819b6c6461703a2f2f2f434e3d525343435254505230322c434e3d4149412c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f634143657274696669636174653f626173653f6f626a656374436c6173733d63657274696669636174696f6e417574686f72697479302606082b06010505073001861a687474703a2f2f706b692e64617264656e2e636f6d2f6f
EAP-Message = 0x637370301d0603551d250416301406082b0601050507030106082b06010505070302302706092b060104018237150a041a3018300a06082b06010505070301300a06082b06010505070302300d06092a864886f70d010105050003820101007634c4282ac4c4187cfcfd41e6eff3c1984655d2e3d99b8b0342c956fd7d718ec2b6ae75413fd18d9586c26d14722d54a42b42cc3171b5e641a4cee1e4a3b5348bde8b541299c9dd34f2ccd8af91f3761f12b5badbdc89fac1f3a990490d1f5435a0605ed0e7d4d3b0ea34466d190ffe1e4d34d495cae322eb95790f1bdca453dbebd58882cefe4a7ce55e3a08d843e7e5ed5fee7496f27ba34f451b8589
EAP-Message = 0xb658e0acdaf96afb18f4b73e063987082a384acd3bfc799b566d559c19b6fcf6ff72eef9ca0b4e919e0dada70251f476eb62367a4d78052b1fca7aed10733b0c65dfe445492403d491d8de1ea7cb263808b21182bd82356f305beae9c3e68023b3d616030100270d00001f03010240001900173015311330110603550403130a525343435254505230310e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x139712c810911fe01bcd15fe5a12236f
Fri Nov 6 17:12:41 2015 : Info: Finished request 3.
Fri Nov 6 17:12:41 2015 : Debug: Going to the next request
Fri Nov 6 17:12:41 2015 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=74, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0xa836f6d54c6455f67f4e9635398d35e9
EAP-Message = 0x020600060d00
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x139712c810911fe01bcd15fe5a12236f
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:41 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authorize {
Fri Nov 6 17:12:41 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:41 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:41 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:41 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:41 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:41 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP packet type response id 6 length 6
Fri Nov 6 17:12:41 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:41 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:41 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:41 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:41 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:41 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:41 2015 : Info: +group authenticate {
Fri Nov 6 17:12:41 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:41 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:41 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:41 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:41 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:41 2015 : Info: [tls] Received TLS ACK
Fri Nov 6 17:12:41 2015 : Info: [tls] ACK handshake fragment handler
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_verify returned 1
Fri Nov 6 17:12:41 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:41 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:41 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 74 to 10.238.250.50 port 1645
EAP-Message = 0x0107000a0d8000000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x139712c817901fe01bcd15fe5a12236f
Fri Nov 6 17:12:41 2015 : Info: Finished request 4.
Fri Nov 6 17:12:41 2015 : Debug: Going to the next request
Fri Nov 6 17:12:41 2015 : Debug: Waking up in 4.8 seconds.
Fri Nov 6 17:12:45 2015 : Info: Cleaning up request 0 ID 70 with timestamp +5
Fri Nov 6 17:12:45 2015 : Info: Cleaning up request 1 ID 71 with timestamp +5
Fri Nov 6 17:12:46 2015 : Info: Cleaning up request 2 ID 72 with timestamp +6
Fri Nov 6 17:12:46 2015 : Info: Cleaning up request 3 ID 73 with timestamp +6
Fri Nov 6 17:12:46 2015 : Info: Cleaning up request 4 ID 74 with timestamp +6
Fri Nov 6 17:12:46 2015 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Fri Nov 6 17:12:46 2015 : Debug: WARNING: !! EAP session for state 0x139712c817901fe0 did not finish!
Fri Nov 6 17:12:46 2015 : Debug: WARNING: !! Please read http://wiki.freeradius.org/guide/Certificate_Compatibility
Fri Nov 6 17:12:46 2015 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Fri Nov 6 17:12:46 2015 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=75, length=166
User-Name = "wlse06 at darden"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "00c0.9f79.88a1"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x96bcc3ac097fac4a4e9b9eed9d976d4d
EAP-Message = 0x0202001201776c736530364064617264656e
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2610"
NAS-Port = 2610
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:51 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authorize {
Fri Nov 6 17:12:51 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:51 2015 : Info: [suffix] Looking up realm "darden" for User-Name = "wlse06 at darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Found realm "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Stripped-User-Name = "wlse06"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Realm = "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:51 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP packet type response id 2 length 18
Fri Nov 6 17:12:51 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:51 2015 : Info: [files] users: Matched entry wlse06 at line 1
Fri Nov 6 17:12:51 2015 : Info: ++[files] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:51 2015 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Fri Nov 6 17:12:51 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:51 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:51 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:51 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authenticate {
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP Identity
Fri Nov 6 17:12:51 2015 : Info: [eap] processing type md5
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_md5: Issuing Challenge
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:51 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 75 to 10.238.250.50 port 1645
EAP-Message = 0x0103001604107e459cff976e3bf2bc182144f6cd077a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbfeb8995bfe88d6d0f85629a73d23b83
Fri Nov 6 17:12:51 2015 : Info: Finished request 5.
Fri Nov 6 17:12:51 2015 : Debug: Going to the next request
Fri Nov 6 17:12:51 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=76, length=172
User-Name = "wlse06 at darden"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "00c0.9f79.88a1"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0xe3c7a4b9306602fdd37ec7363fcfc6a5
EAP-Message = 0x020300060311
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2610"
NAS-Port = 2610
State = 0xbfeb8995bfe88d6d0f85629a73d23b83
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:51 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authorize {
Fri Nov 6 17:12:51 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:51 2015 : Info: [suffix] Looking up realm "darden" for User-Name = "wlse06 at darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Found realm "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Stripped-User-Name = "wlse06"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Realm = "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:51 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP packet type response id 3 length 6
Fri Nov 6 17:12:51 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:51 2015 : Info: [files] users: Matched entry wlse06 at line 1
Fri Nov 6 17:12:51 2015 : Info: ++[files] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:51 2015 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Fri Nov 6 17:12:51 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:51 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:51 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:51 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authenticate {
Fri Nov 6 17:12:51 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP NAK
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP-NAK asked for EAP-Type/leap
Fri Nov 6 17:12:51 2015 : Info: [eap] processing type leap
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_leap: Stage 2
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_leap: Issuing AP Challenge
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_leap: Successfully initiated
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:51 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 76 to 10.238.250.50 port 1645
EAP-Message = 0x0104001611010008684b572fbce7e4b2776c73653036
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbfeb8995beef986d0f85629a73d23b83
Fri Nov 6 17:12:51 2015 : Info: Finished request 6.
Fri Nov 6 17:12:51 2015 : Debug: Going to the next request
Fri Nov 6 17:12:51 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=77, length=204
User-Name = "wlse06 at darden"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "00c0.9f79.88a1"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x7f0d380bd93e793fa61b88b273c2ca56
EAP-Message = 0x0204002611010018d3207e696990b35e1d6b315ec156e9d9bc01c3d1b77da1b7776c73653036
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2610"
NAS-Port = 2610
State = 0xbfeb8995beef986d0f85629a73d23b83
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:51 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authorize {
Fri Nov 6 17:12:51 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:51 2015 : Info: [suffix] Looking up realm "darden" for User-Name = "wlse06 at darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Found realm "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Stripped-User-Name = "wlse06"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Adding Realm = "darden"
Fri Nov 6 17:12:51 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:51 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP packet type response id 4 length 38
Fri Nov 6 17:12:51 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:51 2015 : Info: [files] users: Matched entry wlse06 at line 1
Fri Nov 6 17:12:51 2015 : Info: ++[files] = ok
Fri Nov 6 17:12:51 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:51 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:51 2015 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Fri Nov 6 17:12:51 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:51 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:51 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:51 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:51 2015 : Info: +group authenticate {
Fri Nov 6 17:12:51 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:51 2015 : Info: [eap] EAP/leap
Fri Nov 6 17:12:51 2015 : Info: [eap] processing type leap
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_leap: Stage 4
Fri Nov 6 17:12:51 2015 : Debug: rlm_eap_leap: NtChallengeResponse from AP is valid
Fri Nov 6 17:12:51 2015 : Info: [eap] Underlying EAP-Type set EAP ID to 5
Fri Nov 6 17:12:51 2015 : Info: ++[eap] = ok
Fri Nov 6 17:12:51 2015 : Info: +} # group authenticate = ok
Sending Access-Challenge of id 77 to 10.238.250.50 port 1645
EAP-Message = 0x03050004
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbfeb8995bdee986d0f85629a73d23b83
Fri Nov 6 17:12:51 2015 : Info: Finished request 7.
Fri Nov 6 17:12:51 2015 : Debug: Going to the next request
Fri Nov 6 17:12:51 2015 : Debug: Waking up in 4.9 seconds.
Fri Nov 6 17:12:56 2015 : Info: Cleaning up request 5 ID 75 with timestamp +16
Fri Nov 6 17:12:56 2015 : Info: Cleaning up request 6 ID 76 with timestamp +16
Fri Nov 6 17:12:56 2015 : Info: Cleaning up request 7 ID 77 with timestamp +16
Fri Nov 6 17:12:56 2015 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=78, length=211
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x8394c64eaffc2378e02c15f3749f96fc
EAP-Message = 0x0208001e01686f73742f4c4f414e45523735312e64617264656e2e636f6d
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 8 length 30
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP Identity
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type md5
Fri Nov 6 17:12:59 2015 : Debug: rlm_eap_md5: Issuing Challenge
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 78 to 10.238.250.50 port 1645
EAP-Message = 0x0109001604100f46486ab8d7782d205adb7ce5726b0e
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586e23e62aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 8.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=79, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x50b8da48b4727d3ebf55da9a4bb0db07
EAP-Message = 0x02090006030d
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586e23e62aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 9 length 6
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP NAK
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP-NAK asked for EAP-Type/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Requiring client certificate
Fri Nov 6 17:12:59 2015 : Info: [tls] Initiate
Fri Nov 6 17:12:59 2015 : Info: [tls] Start returned 1
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 79 to 10.238.250.50 port 1645
EAP-Message = 0x010a00060d20
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586f20ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 9.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=80, length=304
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x6c3705e8255a474c29b3cd7ab5ebf1f4
EAP-Message = 0x020a00690d800000005f160301005a010000560301563d25eb2e0e860574cd818ce2fd31988b89f3374efd56fa4720233a6b17535c000018002f00350005000ac013c014c009c00a003200380013000401000015ff01000100000a0006000400170018000b00020100
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586f20ef2aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 10 length 105
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:59 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:59 2015 : Debug: TLS Length 95
Fri Nov 6 17:12:59 2015 : Info: [tls] Length Included
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_verify returned 11
Fri Nov 6 17:12:59 2015 : Info: [tls] (other): before/accept initialization
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: before/accept initialization
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 005a], ClientHello
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 read client hello A
Fri Nov 6 17:12:59 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0031], ServerHello
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 write server hello A
Fri Nov 6 17:12:59 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 060d], Certificate
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 write certificate A
Fri Nov 6 17:12:59 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0027], CertificateRequest
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 write certificate request A
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 flush data
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Nov 6 17:12:59 2015 : Debug: In SSL Handshake Phase
Fri Nov 6 17:12:59 2015 : Debug: In SSL Accept mode
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 80 to 10.238.250.50 port 1645
EAP-Message = 0x010b04000dc00000067416030100310200002d0301563d25ebf86d09290f06e3392743dd20ed31a510aca7d18a5a51ff2b2bfa069100002f000005ff01000100160301060d0b000609000606000603308205ff308204e7a003020102020a3254f09e00020002d0a6300d06092a864886f70d0101050500304231133011060a0992268993f22c6401191603636f6d31163014060a0992268993f22c640119160664617264656e311330110603550403130a52534343525450523032301e170d3135313031353139313632375a170d3138303832343231303632375a3072310b30090603550406130255533110300e06035504081307466c6f7269646131
EAP-Message = 0x10300e060355040713074f726c616e646f310f300d060355040a130644617264656e31163014060355040b130d44617461205365637572697479311630140603550403130d61746c7261646975736472303130820122300d06092a864886f70d01010105000382010f003082010a02820101009dee408f93ad85f91e024534c3924cd135e2ba43aa0a7391df14d03c779b55f145bff10c55a8901f3c73290a7b43b4a1a982a89f6eb2903d77a15f55ad6dcca44615c937a658aa3be79385b95996180b0780ebdd5404dc876032108d2d3f1e05a2f011c692fb1506b585d22481b3442834217d66896322d9f6e7b5c495ffe58f9fbe4bb018f8ea4fdc7e
EAP-Message = 0xd80e40e016fdb56f018be773143dfacfa4c645b27d40a9599a2a5b3268ae3b34b78881cc43cea1ce672e39e71cc30d4f9c051246859ac860fc9310b7bb0b726d5a9419d6ff80c3ee9f4abdd33a5b39da233619b7b5c8365d85e3e94fff82b9457a10047b4aa56ca0883b43892e1e3def4533b47025910203010001a38202c5308202c1300b0603551d0f0404030204b0303d06092b06010401823715070430302e06262b060104018237150881f0962881a8985e8289931584a9f42186d6a875178396b00c83c3ae0602016402010c301d0603551d0e0416041413f6e9e13094aa39d83ce70447add33fcd37bc343081f00603551d1f0481e83081e530
EAP-Message = 0x81e2a081dfa081dc8624687474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e63726c8681b36c6461703a2f2f2f434e3d525343435254505230322c434e3d727363637274707230322c434e3d4344502c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f63657274696669636174655265766f636174696f6e4c6973743f626173653f6f626a656374436c6173733d63524c446973747269627574696f6e506f696e743082011706082b060105050701010482010930820105303006
EAP-Message = 0x082b06010505073002862468
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586c21ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 10.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=81, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x773d4f27852005263ea01081b56ac936
EAP-Message = 0x020b00060d00
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586c21ef2aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 11 length 6
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:59 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:59 2015 : Info: [tls] Received TLS ACK
Fri Nov 6 17:12:59 2015 : Info: [tls] ACK handshake fragment handler
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_verify returned 1
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 81 to 10.238.250.50 port 1645
EAP-Message = 0x010c02880d80000006747474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e6372743081a806082b0601050507300286819b6c6461703a2f2f2f434e3d525343435254505230322c434e3d4149412c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f634143657274696669636174653f626173653f6f626a656374436c6173733d63657274696669636174696f6e417574686f72697479302606082b06010505073001861a687474703a2f2f706b692e64617264656e2e636f6d2f6f
EAP-Message = 0x637370301d0603551d250416301406082b0601050507030106082b06010505070302302706092b060104018237150a041a3018300a06082b06010505070301300a06082b06010505070302300d06092a864886f70d010105050003820101007634c4282ac4c4187cfcfd41e6eff3c1984655d2e3d99b8b0342c956fd7d718ec2b6ae75413fd18d9586c26d14722d54a42b42cc3171b5e641a4cee1e4a3b5348bde8b541299c9dd34f2ccd8af91f3761f12b5badbdc89fac1f3a990490d1f5435a0605ed0e7d4d3b0ea34466d190ffe1e4d34d495cae322eb95790f1bdca453dbebd58882cefe4a7ce55e3a08d843e7e5ed5fee7496f27ba34f451b8589
EAP-Message = 0xb658e0acdaf96afb18f4b73e063987082a384acd3bfc799b566d559c19b6fcf6ff72eef9ca0b4e919e0dada70251f476eb62367a4d78052b1fca7aed10733b0c65dfe445492403d491d8de1ea7cb263808b21182bd82356f305beae9c3e68023b3d616030100270d00001f03010240001900173015311330110603550403130a525343435254505230310e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586d26ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 11.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=82, length=1701
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x53faf7046d54aa9718682ab99123a929
EAP-Message = 0x020c05d40dc000000eb91603010e790b000c69000c660005d1308205cd308204b5a003020102020a14b4ddae000200026319300d06092a864886f70d0101050500304231133011060a0992268993f22c6401191603636f6d31163014060a0992268993f22c640119160664617264656e311330110603550403130a52534343525450523032301e170d3134303530373135333535325a170d3138303832343231303632375a301f311d301b060355040313144c4f414e45523735312e64617264656e2e636f6d30820122300d06092a864886f70d01010105000382010f003082010a02820101008d968dbd88c00e6440f3d8cdccfbcf3d85d91f006466
EAP-Message = 0xfe781223287d151568506231c76b8fc21845d09b2a9dfa06ca062247332d2e5b971cda6215f7983ada2c63fc3fccb9e69285e7ef5b3913d2456528c73f9f4dada6f7bc0c90cf87c9768723e7d32e0f4c9d2c133fa9585a46dfbdb509837a675494b92404636b5a6c5443cc0acf0d9d1870c98342e6f62b23a3973a841a5237ff2f69eaf6279f46d938b3d5997bd7caa0cf08905ca67c37642ad0f2c11883ec97a12ccc57efa0f0222cac8f7f01220673c3aea995add1b316f150a39346bdbf4fda3d6dbb8b32332b22259b3a0bacd586c8c71955f7adb4659e5e31eab5d76b3510facb89e73e31dc0f450203010001a38202e6308202e2303d06092b06
EAP-Message = 0x010401823715070430302e06262b060104018237150881f0962881a8985e8289931584a9f42186d6a87517828cd61b85b4982b02016402010e301d0603551d250416301406082b0601050507030106082b06010505070302300b0603551d0f0404030205a0302706092b060104018237150a041a3018300a06082b06010505070301300a06082b06010505070302301d0603551d0e04160414fff88f06b35abf9ffefad4e788400202dd783c0a3081f00603551d1f0481e83081e53081e2a081dfa081dc8624687474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e63726c8681b36c6461703a2f2f2f434e3d5253434352
EAP-Message = 0x54505230322c434e3d727363637274707230322c434e3d4344502c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f63657274696669636174655265766f636174696f6e4c6973743f626173653f6f626a656374436c6173733d63524c446973747269627574696f6e506f696e743082011706082b060105050701010482010930820105303006082b060105050730028624687474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230322e6372743081a806082b0601050507300286819b6c64
EAP-Message = 0x61703a2f2f2f434e3d525343435254505230322c434e3d4149412c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f634143657274696669636174653f626173653f6f626a656374436c6173733d63657274696669636174696f6e417574686f72697479302606082b06010505073001861a687474703a2f2f706b692e64617264656e2e636f6d2f6f637370301f0603551d110418301682144c4f414e45523735312e64617264656e2e636f6d300d06092a864886f70d0101050500038201010082337a6dd17bef
EAP-Message = 0x0ad5f397074eb72372d5efa2efb86cd7d20799b3a51c954c6e666b9c1c2103fcab4ffd0bd41df4a47176c18ee12e6b61e6757a9bfb9faca12b850d295f24f3e678ff2ddf019798e74707a6730292cfb325d3d9de7487492e31b37177b1db709e399626c516faeb6afe36cccdbe5dbbca4f0a4698d9735d771480bccb0a36592e3ecb5a3b634162db503f36173e6351e9bea39df5668f27f4f58e16e295927f6157151a5a14bf24d2682ea48e931d1f20a32cbc87f46a23033b919bd89418c87ab9cd9b62f7cae9684b0c5d4a8cd4a61efeec97ae285d6e7d902b11c671bab37f5f69f4
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586d26ef2aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 12 length 253
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:59 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:59 2015 : Debug: TLS Length 3769
Fri Nov 6 17:12:59 2015 : Info: [tls] Received EAP-TLS First Fragment of the message
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_verify returned 9
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 82 to 10.238.250.50 port 1645
EAP-Message = 0x010d00060d00
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586a27ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 12.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=83, length=1701
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x4c7c36f1b64301ef4d78e92759b4d065
EAP-Message = 0x020d05d40d40033bc27bdf114ab87c2e646a7e9726449db15e3af87400068f3082068b30820473a003020102021318000000082c1827ba531916a3000100000008300d06092a864886f70d01010505003015311330110603550403130a52534343525450523031301e170d3133303832343230353632375a170d3138303832343231303632375a304231133011060a0992268993f22c6401191603636f6d31163014060a0992268993f22c640119160664617264656e311330110603550403130a5253434352545052303230820122300d06092a864886f70d01010105000382010f003082010a0282010100dd01d3500f91126f6410fa793110ac5552
EAP-Message = 0x931cda6303ee0f3bce534d7e15a8e9ff80a3c143707dc16526be971e97ef1f9e15cc28d87cc4fa1c4602ef34ca3aaa8a5b912659b505226308e2f26b95a382ea320aac65ec4af7a658e7a7f9a11fb67f0b66d2fc67dc8dad7693cc67c2cda1834110a90aaf5b56f40f4de704d0b65dbcab16031349f5262d560c1a51c381d00413b51e8a42b01aa056181a6aed099e608392ff9df7a6f259c87b57082e695e8dc5015be084daa383e93d97a1c54079fb3bda207101bc15d77642323f82062934175bc969143d24bd6ccbf695e9af77c9956d3dee14bbba45f1693d7dbbc22abe4dd838c8f2a4f1a54b390c49b4640f0203010001a38202a5308202a130
EAP-Message = 0x0f0603551d130101ff040530030101ff301d0603551d0e041604141c2b7745e7b2aefe4e77569e3b631af9f1a5cc60300b0603551d0f040403020186301006092b06010401823715010403020102302306092b060104018237150204160414576772d0b5e1bb3739c465648b3e733d040fe18b301906092b0601040182371402040c1e0a00530075006200430041301f0603551d23041830168014d2fae6fd64dc95818329153bb7fe1345d31fa6fd3081f00603551d1f0481e83081e53081e2a081dfa081dc8624687474703a2f2f706b692e64617264656e2e636f6d2f525343435254505230312e63726c8681b36c6461703a2f2f2f434e3d525343
EAP-Message = 0x435254505230312c434e3d727363637274707230312c434e3d4344502c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d636f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f63657274696669636174655265766f636174696f6e4c6973743f626173653f6f626a656374436c6173733d63524c446973747269627574696f6e506f696e743081fb06082b060105050701010481ee3081eb303e06082b060105050730018632687474703a2f2f706b692e64617264656e2e636f6d2f727363637274707230315f525343435254505230312831292e6372743081a80608
EAP-Message = 0x2b0601050507300286819b6c6461703a2f2f2f434e3d525343435254505230312c434e3d4149412c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d636f6e66696775726174696f6e2c44433d64617264656e2c44433d636f6d3f634143657274696669636174653f626173653f6f626a656374436c6173733d63657274696669636174696f6e417574686f72697479300d06092a864886f70d0101050500038202010075efac378701de9e43d6c4d39544db118c412e04ae980657f38f30c93dcfc217a518869098a2e50221e52fe1065903e88fa3ce9e9066b37767c689bf5282e9d16680af
EAP-Message = 0xd55c4ec659a19bf3d48e5cca8814c7b86fce09b36403ac5efce0421718472b5f84c2d716a96c3fe335281ed0792e16b246062f11b3882f6d3c448ad0c5f5780667230419b6886b69bff731896eb46d6ae0a7499def08c30a70400e3e92051ca25d1ee4285180d5e00d79aabd6fa7d52702547040efd0bd93bcd03f2ea86eaa36bb537c007b0e356c0771959c049fce87f97590b02fd9b49461258d6afbe08dd2ccd701e0db451aea153070d55bc1cff2d4e4503c73a326be8cd6244f3b7603d6b03cab64f8f0113ed024401369ff60d5bbeab4aa890270de7bd84154d601aaf2b0cda2
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586a27ef2aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 13 length 253
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:59 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:59 2015 : Info: [tls] More fragments to follow
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_verify returned 10
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 83 to 10.238.250.50 port 1645
EAP-Message = 0x010e00060d00
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586b24ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 13.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=84, length=1012
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0xf9d6606d176bf5dcc82c28c834ecba4f
EAP-Message = 0x020e03270d00a7ed0e3eda2fdb6b6c49d3dcc5fcb161ac96a4a0bf6c5970b924e06758116839d1959275ca23d2eb7afd9e3c88dd09800186a18835bacf804434c17df62fa80c807b230d37755a12afb5b57bea504a9f16f0466041ff848d8f9ee1c969feb7334305f32ff640c4212f909e0672795787bb1f1a29d4deb1f74a44f52b9aabdff6405560885610f6d0af3ab3fa125847b13f5a0dd4874ca274744539be88a3dc9ccedae82404d226bca0f6d4c49a1d808d74887eb663248203219610bb09fbff87416d7fc81d7b45d79b3ecbe80f3fbf7efb20f05ca5542d4f562110000102010096e1ad42aa82999649459d8f52a6adf81b2e09f1aca5cd
EAP-Message = 0x5b7783485266cf2270f9954ad8f444c82f9b2255f4c03ccea2510efefc64ed341cbb57c594789ad259a2e1611a1c107dd0d3f1af230f50a0ee1e2bbcedf19f2e144b69d081a54fd4442c9dacdac51bb6a68e199c9a740075bede54ecfdc55589ae01825e3027bcf4297acc7748e660152b9de0e8099e33e768e900e0ebe94997b4144aafd7c9d7ab79b9973edfd6bddfdf7d2a6955eb11ac0cd767af8f33fc110ffe40020adf3603a198c5ec9954b89daa66dcbecc3a371705e74948ff98aa3e830e1354818e9f441e0c0ba09a2ab03cc4c7cbd79d4042e605443440359f290c52f878e997b76dabcb0f00010201001696d41c626b99313ae3da86cbaf
EAP-Message = 0x376f64d9f5aeb131057065a6e114357eb28d78a0032b93e1925dea93c816fc036eeb314a592c7fbd7a28e28644150aacd24cb659a7427de2f3aee8b288f93f46f9457624a38a9f3ddfee85549bc624f7ade8fb6cecb24618674e7db5a84cb42d0e85ed1bbf5a47dbdb582d7c0ab3a735e21a74a71c4a47abac4bac7d4a725b09c54ad3611888f828aee40de4bf6848c92c321a23f8e00718492d32dddf70c07791af5629725631b1563dcb7f9d75d4961c90051364998a2d5a2651c590d5f2099c9e397313715e444a0bbf39e483063168e45e6dc68ea3156bb54c0e811b3100249644241469959b2353edf027725db10e781403010001011603010030
EAP-Message = 0xd0caaed32c2f7f3cd9cfacd6d40c1be5b153b5e4c0b6a13c6975b9b348e17b47abb2a9110c72ff41e3802d1c675507af
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586b24ef2aa91c87a2ceb35d37
NAS-IP-Address = 10.238.250.50
Fri Nov 6 17:12:59 2015 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authorize {
Fri Nov 6 17:12:59 2015 : Info: ++[preprocess] = ok
Fri Nov 6 17:12:59 2015 : Info: ++[chap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[mschap] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[digest] = noop
Fri Nov 6 17:12:59 2015 : Info: [suffix] No '@' in User-Name = "host/LOANER751.darden.com", looking up realm NULL
Fri Nov 6 17:12:59 2015 : Info: [suffix] Found realm "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Stripped-User-Name = "host/LOANER751.darden.com"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Adding Realm = "NULL"
Fri Nov 6 17:12:59 2015 : Info: [suffix] Authentication realm is LOCAL.
Fri Nov 6 17:12:59 2015 : Info: ++[suffix] = ok
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP packet type response id 14 length 253
Fri Nov 6 17:12:59 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = updated
Fri Nov 6 17:12:59 2015 : Info: ++[files] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[expiration] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[logintime] = noop
Fri Nov 6 17:12:59 2015 : Info: ++[pap] = noop
Fri Nov 6 17:12:59 2015 : Info: +} # group authorize = updated
Fri Nov 6 17:12:59 2015 : Info: Found Auth-Type = EAP
Fri Nov 6 17:12:59 2015 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Fri Nov 6 17:12:59 2015 : Info: +group authenticate {
Fri Nov 6 17:12:59 2015 : Info: [eap] Request found, released from the list
Fri Nov 6 17:12:59 2015 : Info: [eap] EAP/tls
Fri Nov 6 17:12:59 2015 : Info: [eap] processing type tls
Fri Nov 6 17:12:59 2015 : Info: [tls] Authenticate
Fri Nov 6 17:12:59 2015 : Info: [tls] processing EAP-TLS
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_verify returned 7
Fri Nov 6 17:12:59 2015 : Info: [tls] Done initial handshake
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0c6d], Certificate
Fri Nov 6 17:12:59 2015 : Info: [tls] chain-depth=2,
Fri Nov 6 17:12:59 2015 : Info: [tls] error=0
Fri Nov 6 17:12:59 2015 : Info: [tls] --> User-Name = host/LOANER751.darden.com
Fri Nov 6 17:12:59 2015 : Info: [tls] --> BUF-Name = RSCCRTPR01
Fri Nov 6 17:12:59 2015 : Info: [tls] --> subject = /CN=RSCCRTPR01
Fri Nov 6 17:12:59 2015 : Info: [tls] --> issuer = /CN=RSCCRTPR01
Fri Nov 6 17:12:59 2015 : Info: [tls] --> verify return:1
Fri Nov 6 17:12:59 2015 : Info: [tls] chain-depth=1,
Fri Nov 6 17:12:59 2015 : Info: [tls] error=0
Fri Nov 6 17:12:59 2015 : Info: [tls] --> User-Name = host/LOANER751.darden.com
Fri Nov 6 17:12:59 2015 : Info: [tls] --> BUF-Name = RSCCRTPR02
Fri Nov 6 17:12:59 2015 : Info: [tls] --> subject = /DC=com/DC=darden/CN=RSCCRTPR02
Fri Nov 6 17:12:59 2015 : Info: [tls] --> issuer = /CN=RSCCRTPR01
Fri Nov 6 17:12:59 2015 : Info: [tls] --> verify return:1
TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Server Authentication, TLS Web Client Authentication"
TLS-Client-Cert-X509v3-Subject-Key-Identifier += "FF:F8:8F:06:B3:5A:BF:9F:FE:FA:D4:E7:88:40:02:02:DD:78:3C:0A"
Fri Nov 6 17:12:59 2015 : Info: [tls] chain-depth=0,
Fri Nov 6 17:12:59 2015 : Info: [tls] error=0
Fri Nov 6 17:12:59 2015 : Info: [tls] --> User-Name = host/LOANER751.darden.com
Fri Nov 6 17:12:59 2015 : Info: [tls] --> BUF-Name = LOANER751.darden.com
Fri Nov 6 17:12:59 2015 : Info: [tls] --> subject = /CN=LOANER751.darden.com
Fri Nov 6 17:12:59 2015 : Info: [tls] --> issuer = /DC=com/DC=darden/CN=RSCCRTPR02
Fri Nov 6 17:12:59 2015 : Info: [tls] --> verify return:1
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 read client certificate A
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 read client key exchange A
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0106], CertificateVerify
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 read certificate verify A
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Fri Nov 6 17:12:59 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 read finished A
Fri Nov 6 17:12:59 2015 : Info: [tls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 write change cipher spec A
Fri Nov 6 17:12:59 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0010], Finished
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 write finished A
Fri Nov 6 17:12:59 2015 : Info: [tls] TLS_accept: SSLv3 flush data
Fri Nov 6 17:12:59 2015 : Info: [tls] (other): SSL negotiation finished successfully
Fri Nov 6 17:12:59 2015 : Debug: SSL Connection Established
Fri Nov 6 17:12:59 2015 : Info: [tls] eaptls_process returned 13
Fri Nov 6 17:12:59 2015 : Info: ++[eap] = handled
Fri Nov 6 17:12:59 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 84 to 10.238.250.50 port 1645
EAP-Message = 0x010f00450d800000003b14030100010116030100303392b593360cebdcadf4644937d15e2ff4c84e79e8fb592b51ba174675e57032ef269cbf5abf69d1ef1761d808aab6d6
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6e2ae2586825ef2aa91c87a2ceb35d37
Fri Nov 6 17:12:59 2015 : Info: Finished request 14.
Fri Nov 6 17:12:59 2015 : Debug: Going to the next request
Fri Nov 6 17:12:59 2015 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.238.250.50 port 1645, id=85, length=205
User-Name = "host/LOANER751.darden.com"
Framed-MTU = 1400
Called-Station-Id = "0019.aaab.5af5"
Calling-Station-Id = "100b.a988.b5a0"
Cisco-AVPair = "ssid=DRI_test"
WISPr-Location-Name = "4441-NC-AP1"
Service-Type = Login-User
Message-Authenticator = 0x2ec46a57c51bcacfd071dbe36746a2fb
EAP-Message = 0x020f00060d00
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "2609"
NAS-Port = 2609
State = 0x6e2ae2586825ef2aa91c87a2ceb35d37
-----Original Message-----
From: Freeradius-Users [mailto:freeradius-users-bounces+sahmad=darden.com at lists.freeradius.org] On Behalf Of Alan DeKok
Sent: Monday, November 02, 2015 4:07 PM
To: FreeRadius users mailing list
Subject: Re: EAP Taking Too Long to Authenticate
On Nov 2, 2015, at 4:00 PM, Syed Rais Ahmad NON DRI <SAhmad at darden.com> wrote:
>
> I am using NTLM for login-prompt based devices and EAP for laptops. Our laptops have certificates signed by our own Root CA. Radius already has root, ca and its own certificates installed. It’s not that it doesn’t authenticate, it authenticates but takes too much time.
You've said that. We've told you how to track down the problem.
You don't seem to be listening.
> On one of the wireless controllers, the call flow between Radius and itself is as follows:
Which is a complete and total waste of everyone's time.
DO NOT post that kind of nonsense to the list. It's irrelevant and useless.
DO go read the debug output yourself. There is NO EXCUSE for failing to do that.
If you're not going to follow instructions, you should not be asking questions on this list.
Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
This e-mail message is for the sole use of the intended recipient and may contain information that is confidential, proprietary or privileged. Any unauthorized review, use, distribution, copying or disclosure is strictly prohibited. If you are not the intended recipient, or the employee or agent responsible for delivering it to the intended recipient, please notify sender of the delivery error by replying to this message and then delete it from your system. Receipt by anyone other than the intended recipient is not a waiver of confidentiality or privilege.
More information about the Freeradius-Users
mailing list