EAP-TTLS authentication
Isaac Konikoff
konikofi
Tue Aug 11 14:04:13 PDT 2015
Here is my hostapd log showing a failure when HS2.0 in enabled and a
success when HS2.0 is disabled. EAP-TTLS used in both cases,
wpa_supplicant configs also included below.
Is the failure due to an incorrect EAP method or TLS tunnel fail in phase 1?
hostapd_log
1439324295.015798: RADIUS SRV: Creating a new session
1439324295.015838: RADIUS SRV: Matching user entry found
1439324295.015861: RADIUS SRV: [0x2c 127.0.0.1] New session created
1439324295.015874: EAP: Server state machine created
1439324295.015881: RADIUS SRV: New session 0x2c initialized
1439324295.015889: EAP: EAP entering state INITIALIZE
1439324295.015900: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=202
respMethod=1 respVendor=0 respVendorMethod=0
1439324295.015910: eth1: CTRL-EVENT-EAP-STARTED 00:00:00:00:00:00
1439324295.015915: EAP: EAP entering state PICK_UP_METHOD
1439324295.015921: eth1: CTRL-EVENT-EAP-PROPOSED-METHOD method=1
1439324295.015925: EAP: EAP entering state METHOD_RESPONSE
1439324295.015930: EAP-Identity: Peer identity - hexdump_ascii(len=20):
61 6e 6f 6e 79 6d 6f 75 73 40 6d 79 74 65 73 74 anonymous at mytest
2e 63 6f 6d .com
1439324295.015947: RADIUS SRV: [0x2c 127.0.0.1] EAP:
EAP-Response/Identity 'anonymous at mytest.com'
1439324295.015952: EAP: EAP entering state SELECT_ACTION
1439324295.015957: EAP: getDecision: no more methods available -> FAILURE
1439324295.015961: EAP: EAP entering state FAILURE
1439324295.015965: EAP: Building EAP-Failure (id=202)
1439324295.015971: eth1: CTRL-EVENT-EAP-FAILURE 00:00:00:00:00:00
1439324295.015976: RADIUS SRV: [0x2c 127.0.0.1] EAP authentication failed
1439324295.015987: RADIUS SRV: Reply to 127.0.0.1:16114
1439324295.015993: RADIUS SRV: [0x2c 127.0.0.1] Sending Access-Reject
1439324295.016017: RADIUS SRV: Removing completed session 0x2c after timeout
1439324295.675875: RADIUS SRV: Removing completed session 0x2a
1439324295.675923: EAP: Server state machine removed
1439324300.854864: RADIUS SRV: Removing completed session 0x2b
1439324300.854908: EAP: Server state machine removed
1439324301.373902: RADIUS SRV: Received 259 bytes from 127.0.0.1:16114
1439324301.373959: RADIUS SRV: Creating a new session
1439324301.373985: RADIUS SRV: Matching user entry found
1439324301.374011: RADIUS SRV: [0x2d 127.0.0.1] New session created
1439324301.374027: EAP: Server state machine created
1439324301.374038: RADIUS SRV: New session 0x2d initialized
1439324301.374050: EAP: EAP entering state INITIALIZE
1439324301.374058: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=203
respMethod=1 respVendor=0 respVendorMethod=0
1439324301.374071: eth1: CTRL-EVENT-EAP-STARTED 00:00:00:00:00:00
1439324301.374080: EAP: EAP entering state PICK_UP_METHOD
1439324301.374089: eth1: CTRL-EVENT-EAP-PROPOSED-METHOD method=1
1439324301.374097: EAP: EAP entering state METHOD_RESPONSE
1439324301.374104: EAP-Identity: Peer identity - hexdump_ascii(len=20):
61 6e 6f 6e 79 6d 6f 75 73 40 6d 79 74 65 73 74 anonymous at mytest
2e 63 6f 6d .com
1439324301.374134: RADIUS SRV: [0x2d 127.0.0.1] EAP:
EAP-Response/Identity 'anonymous at mytest.com'
1439324301.374140: EAP: EAP entering state SELECT_ACTION
1439324301.374147: EAP: getDecision: no more methods available -> FAILURE
1439324301.374151: EAP: EAP entering state FAILURE
1439324301.374156: EAP: Building EAP-Failure (id=203)
1439324301.374166: eth1: CTRL-EVENT-EAP-FAILURE 00:00:00:00:00:00
1439324301.374172: RADIUS SRV: [0x2d 127.0.0.1] EAP authentication failed
1439324301.374184: RADIUS SRV: Reply to 127.0.0.1:16114
1439324301.374191: RADIUS SRV: [0x2d 127.0.0.1] Sending Access-Reject
1439324301.374217: RADIUS SRV: Removing completed session 0x2d after timeout
1439324353.450529: RADIUS SRV: Creating a new session
1439324353.450556: RADIUS SRV: Matching user entry found
1439324353.450569: RADIUS SRV: [0x2f 127.0.0.1] New session created
1439324353.450583: EAP: Server state machine created
1439324353.450720: RADIUS SRV: New session 0x2f initialized
1439324353.450733: EAP: EAP entering state INITIALIZE
1439324353.450740: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=30
respMethod=1 respVendor=0 respVendorMethod=0
1439324353.450751: eth1: CTRL-EVENT-EAP-STARTED 00:00:00:00:00:00
1439324353.450758: EAP: EAP entering state PICK_UP_METHOD
1439324353.450765: eth1: CTRL-EVENT-EAP-PROPOSED-METHOD method=1
1439324353.450772: EAP: EAP entering state METHOD_RESPONSE
1439324353.450780: EAP-Identity: Peer identity - hexdump_ascii(len=13):
6c 61 6e 66 6f 72 67 65 2e 74 74 6c 73 lanforge.ttls
1439324353.450794: RADIUS SRV: [0x2f 127.0.0.1] EAP:
EAP-Response/Identity 'lanforge.ttls'
1439324353.450799: EAP: EAP entering state SELECT_ACTION
1439324353.450805: EAP: getDecision: another method available -> CONTINUE
1439324353.450809: EAP: EAP entering state PROPOSE_METHOD
1439324353.450813: EAP: getNextMethod: vendor 0 type 13
1439324353.450838: eth1: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13
1439324353.450844: RADIUS SRV: [0x2f 127.0.0.1] EAP: Propose EAP method
vendor=0 method=13
1439324353.450849: EAP: EAP entering state METHOD_REQUEST
1439324353.450853: EAP: building EAP-Request: Identifier 31
1439324353.450858: EAP-TLS: START -> CONTINUE
1439324353.450863: EAP: EAP entering state SEND_REQUEST
1439324353.450868: EAP: EAP entering state IDLE
1439324353.450872: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.450884: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.452467: RADIUS SRV: Received 228 bytes from 127.0.0.1:16114
1439324353.452521: RADIUS SRV: Request for session 0x2f
1439324353.452543: EAP: EAP entering state RECEIVED
1439324353.452560: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=31
respMethod=3 respVendor=0 respVendorMethod=0
1439324353.452576: EAP: EAP entering state NAK
1439324353.452601: EAP: EAP entering state SELECT_ACTION
1439324353.452617: EAP: getDecision: another method available -> CONTINUE
1439324353.452622: EAP: EAP entering state PROPOSE_METHOD
1439324353.452626: EAP: getNextMethod: vendor 0 type 21
1439324353.452639: eth1: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21
1439324353.452646: RADIUS SRV: [0x2f 127.0.0.1] EAP: Propose EAP method
vendor=0 method=21
1439324353.452653: EAP: EAP entering state METHOD_REQUEST
1439324353.452659: EAP: building EAP-Request: Identifier 32
1439324353.452665: EAP-TTLS: START -> PHASE1
1439324353.452669: EAP: EAP entering state SEND_REQUEST
1439324353.452674: EAP: EAP entering state IDLE
1439324353.452681: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.452693: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.454554: RADIUS SRV: Received 473 bytes from 127.0.0.1:16114
1439324353.454579: RADIUS SRV: Request for session 0x2f
1439324353.454588: EAP: EAP entering state RECEIVED
1439324353.454600: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=32
respMethod=21 respVendor=0 respVendorMethod=0
1439324353.454611: EAP: EAP entering state INTEGRITY_CHECK
1439324353.454621: EAP: EAP entering state METHOD_RESPONSE
1439324353.454626: SSL: Received packet(len=251) - Flags 0x00
1439324353.454631: SSL: Received packet: Flags 0x0 Message Length 0
1439324353.454648: SSL: (where=0x10 ret=0x1)
1439324353.454665: SSL: (where=0x2001 ret=0x1)
1439324353.454672: SSL: SSL_accept:before/accept initialization
1439324353.454696: OpenSSL: RX ver=0x303 content_type=22
1439324353.454745: SSL: (where=0x2001 ret=0x1)
1439324353.454755: SSL: SSL_accept:SSLv3 read client hello A
1439324353.454764: OpenSSL: TX ver=0x303 content_type=22
1439324353.454769: SSL: (where=0x2001 ret=0x1)
1439324353.454774: SSL: SSL_accept:SSLv3 write server hello A
1439324353.454829: OpenSSL: TX ver=0x303 content_type=22
1439324353.454841: SSL: (where=0x2001 ret=0x1)
1439324353.454846: SSL: SSL_accept:SSLv3 write certificate A
1439324353.454852: OpenSSL: TX ver=0x303 content_type=22
1439324353.454860: SSL: (where=0x2001 ret=0x1)
1439324353.454866: SSL: SSL_accept:SSLv3 write server done A
1439324353.454877: SSL: (where=0x2001 ret=0x1)
1439324353.454890: SSL: SSL_accept:SSLv3 flush data
1439324353.454896: SSL: (where=0x2002 ret=0xffffffff)
1439324353.454900: SSL: SSL_accept:error in SSLv3 read client certificate A
1439324353.454905: SSL: (where=0x2002 ret=0xffffffff)
1439324353.454909: SSL: SSL_accept:error in SSLv3 read client certificate A
1439324353.454920: SSL: SSL_connect - want more data
1439324353.454926: SSL: 2434 bytes pending from ssl_out
1439324353.454935: EAP: EAP entering state METHOD_REQUEST
1439324353.454939: EAP: building EAP-Request: Identifier 33
1439324353.454944: SSL: Generating Request
1439324353.454950: SSL: Sending out 1393 bytes (1041 more to send)
1439324353.454955: EAP: EAP entering state SEND_REQUEST
1439324353.454959: EAP: EAP entering state IDLE
1439324353.454964: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.454982: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.458261: RADIUS SRV: Received 228 bytes from 127.0.0.1:16114
1439324353.458284: RADIUS SRV: Request for session 0x2f
1439324353.458293: EAP: EAP entering state RECEIVED
1439324353.458304: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=33
respMethod=21 respVendor=0 respVendorMethod=0
1439324353.458315: EAP: EAP entering state INTEGRITY_CHECK
1439324353.458333: EAP: EAP entering state METHOD_RESPONSE
1439324353.458339: SSL: Received packet(len=6) - Flags 0x00
1439324353.458344: SSL: Received packet: Flags 0x0 Message Length 0
1439324353.458348: SSL: Fragment acknowledged
1439324353.458353: EAP: EAP entering state METHOD_REQUEST
1439324353.458357: EAP: building EAP-Request: Identifier 34
1439324353.458361: SSL: Generating Request
1439324353.458367: SSL: Sending out 1041 bytes (message sent completely)
1439324353.458371: EAP: EAP entering state SEND_REQUEST
1439324353.458380: EAP: EAP entering state IDLE
1439324353.458385: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.458413: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.462932: RADIUS SRV: Received 548 bytes from 127.0.0.1:16114
1439324353.462956: RADIUS SRV: Request for session 0x2f
1439324353.462970: EAP: EAP entering state RECEIVED
1439324353.462980: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=34
respMethod=21 respVendor=0 respVendorMethod=0
1439324353.462994: EAP: EAP entering state INTEGRITY_CHECK
1439324353.462999: EAP: EAP entering state METHOD_RESPONSE
1439324353.463003: SSL: Received packet(len=324) - Flags 0x00
1439324353.463007: SSL: Received packet: Flags 0x0 Message Length 0
1439324353.463020: OpenSSL: RX ver=0x303 content_type=22
1439324353.465410: SSL: (where=0x2001 ret=0x1)
1439324353.465424: SSL: SSL_accept:SSLv3 read client key exchange A
1439324353.465432: OpenSSL: RX ver=0x303 content_type=20
1439324353.465502: OpenSSL: RX ver=0x303 content_type=22
1439324353.465511: SSL: (where=0x2001 ret=0x1)
1439324353.465516: SSL: SSL_accept:SSLv3 read finished A
1439324353.465522: OpenSSL: TX ver=0x303 content_type=20
1439324353.465531: SSL: (where=0x2001 ret=0x1)
1439324353.465538: SSL: SSL_accept:SSLv3 write change cipher spec A
1439324353.465563: OpenSSL: TX ver=0x303 content_type=22
1439324353.465570: SSL: (where=0x2001 ret=0x1)
1439324353.465575: SSL: SSL_accept:SSLv3 write finished A
1439324353.465580: SSL: (where=0x2001 ret=0x1)
1439324353.465585: SSL: SSL_accept:SSLv3 flush data
1439324353.465593: SSL: (where=0x20 ret=0x1)
1439324353.465597: SSL: (where=0x2002 ret=0x1)
1439324353.465602: SSL: 51 bytes pending from ssl_out
1439324353.465608: EAP: EAP entering state METHOD_REQUEST
1439324353.465612: EAP: building EAP-Request: Identifier 35
1439324353.465617: EAP-TTLS: Phase1 done, starting Phase2
1439324353.465621: EAP-TTLS: PHASE1 -> PHASE2_START
1439324353.465625: SSL: Generating Request
1439324353.465630: SSL: Sending out 51 bytes (message sent completely)
1439324353.465637: EAP: EAP entering state SEND_REQUEST
1439324353.465642: EAP: EAP entering state IDLE
1439324353.465646: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.465660: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.467464: RADIUS SRV: Received 285 bytes from 127.0.0.1:16114
1439324353.467488: RADIUS SRV: Request for session 0x2f
1439324353.467497: EAP: EAP entering state RECEIVED
1439324353.467509: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=35
respMethod=21 respVendor=0 respVendorMethod=0
1439324353.467520: EAP: EAP entering state INTEGRITY_CHECK
1439324353.467531: EAP: EAP entering state METHOD_RESPONSE
1439324353.467535: SSL: Received packet(len=63) - Flags 0x00
1439324353.467540: SSL: Received packet: Flags 0x0 Message Length 0
1439324353.467544: EAP-TTLS: received 57 bytes encrypted data for Phase 2
1439324353.467555: EAP-TTLS: Decrypted Phase 2 EAP - hexdump(len=28):
[REMOVED]
1439324353.467563: EAP-TTLS: AVP: code=79 flags=0x40 length=26
1439324353.467569: EAP-TTLS: AVP data - hexdump(len=18): 02 00 00 12 01
6c 61 6e 66 6f 72 67 65 2e 74 74 6c 73
1439324353.467575: EAP-TTLS: AVP - EAP Message
1439324353.467580: EAP-TTLS/EAP: initializing Phase 2
1439324353.467585: EAP-TTLS/EAP: received Phase 2 EAP: code=2
identifier=0 length=18
1439324353.467590: EAP-Identity: Peer identity - hexdump_ascii(len=13):
6c 61 6e 66 6f 72 67 65 2e 74 74 6c 73 lanforge.ttls
1439324353.467602: RADIUS SRV: [0x2f 127.0.0.1] EAP:
EAP-Response/Identity 'lanforge.ttls'
1439324353.467609: EAP-TTLS: PHASE2_START -> PHASE2_METHOD
1439324353.467614: EAP-TTLS: try EAP type 4
1439324353.467619: EAP: EAP entering state METHOD_REQUEST
1439324353.467624: EAP: building EAP-Request: Identifier 36
1439324353.467961: EAP-TTLS/EAP: Encapsulate Phase 2 data -
hexdump(len=22): [REMOVED]
1439324353.467973: EAP-TTLS/EAP: Encrypt encapsulated Phase 2 data -
hexdump(len=32): [REMOVED]
1439324353.467983: SSL: Generating Request
1439324353.467988: SSL: Sending out 61 bytes (message sent completely)
1439324353.467993: EAP: EAP entering state SEND_REQUEST
1439324353.467997: EAP: EAP entering state IDLE
1439324353.468001: EAP: retransmit timeout 3 seconds (from dynamic back
off; retransCount=0)
1439324353.468019: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.469607: RADIUS SRV: Received 289 bytes from 127.0.0.1:16114
1439324353.469631: RADIUS SRV: Request for session 0x2f
1439324353.469640: EAP: EAP entering state RECEIVED
1439324353.469652: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=36
respMethod=21 respVendor=0 respVendorMethod=0
1439324353.469663: EAP: EAP entering state INTEGRITY_CHECK
1439324353.469673: EAP: EAP entering state METHOD_RESPONSE
1439324353.469678: SSL: Received packet(len=67) - Flags 0x00
1439324353.469682: SSL: Received packet: Flags 0x0 Message Length 0
1439324353.469686: EAP-TTLS: received 61 bytes encrypted data for Phase 2
1439324353.469696: EAP-TTLS: Decrypted Phase 2 EAP - hexdump(len=32):
[REMOVED]
1439324353.469704: EAP-TTLS: AVP: code=79 flags=0x40 length=30
1439324353.469710: EAP-TTLS: AVP data - hexdump(len=22): 02 24 00 16 04
10 57 17 84 f7 74 2f db 0b 87 1d 25 66 46 30 fd 77
1439324353.469717: EAP-TTLS: AVP - EAP Message
1439324353.469721: EAP-TTLS/EAP: received Phase 2 EAP: code=2
identifier=36 length=22
1439324353.469727: EAP-MD5: Done - Success
1439324353.469732: EAP-TTLS: PHASE2_METHOD -> SUCCESS
1439324353.469766: OpenSSL: Using internal PRF
1439324353.469775: EAP-TTLS: Derived key - hexdump(len=64): [REMOVED]
1439324353.469781: EAP: Session-Id - hexdump(len=65): 15 55 ca 58 c1 8f
ec 2f 42 93 1a 70 35 ac a0 32 eb 17 b3 91 83 7f 91 4d 1e 2e bd 13 52 e2
9d 77 e6 55 ca 58 c1 48 8c e8 88 51 f5 81 05 69 cf 5a a3 5f 35 c9 e4 a5
8c f4 6f f9 f3 87 75 80 79 cf 32
1439324353.469793: EAP: EAP entering state SELECT_ACTION
1439324353.469797: EAP: getDecision: method succeeded -> SUCCESS
1439324353.469801: EAP: EAP entering state SUCCESS
1439324353.469806: EAP: Building EAP-Success (id=36)
1439324353.469813: eth1: CTRL-EVENT-EAP-SUCCESS 00:00:00:00:00:00
1439324353.469818: RADIUS SRV: [0x2f 127.0.0.1] EAP authentication succeeded
1439324353.469835: RADIUS SRV: Reply to 127.0.0.1:16114
1439324353.469845: RADIUS SRV: [0x2f 127.0.0.1] Sending Access-Accept
1439324353.469865: RADIUS SRV: Removing completed session 0x2f after timeout
hs20-sta4.conf
ctrl_interface=/var/run/wpa_supplicant
fast_reauth=1
concurrent_assoc_ok=1
accept_external_scan_results=1
scan_cur_freq=1
min_scan_gap=5
p2p_disabled=1
# 802.11u / Interworking configuration.
interworking=1
hessid=00:00:00:00:00:33
auto_interworking=1
access_network_type=0
# HotSpot 2.0 configuration
hs20=1
osu_dir=/home/lanforge/wifi/osu_sta4
bss_max_count=2000
network={
interworking_defaults=1
disable_ht=0
disable_vht=0
ieee80211w=0
disable_ht40=0
disable_sgi=0
ht_mcs=""
disable_max_amsdu=-1
ampdu_factor=-1
ampdu_density=-1
}
cred={
username="lanforge.ttls"
password="!!ttls123"
realm="mytest.com"
domain="mytest.com"
eap=TTLS
phase2="autheap=MD5"
}
no-hs20-sta4.conf
ctrl_interface=/var/run/wpa_supplicant
fast_reauth=1
concurrent_assoc_ok=1
accept_external_scan_results=1
scan_cur_freq=1
min_scan_gap=5
p2p_disabled=1
# 802.11u / Interworking configuration.
interworking=1
hessid=00:00:00:00:00:33
auto_interworking=1
access_network_type=0
bss_max_count=2000
network={
ssid="ABCD-1234"
disable_ht=0
disable_vht=0
ieee80211w=0
disable_ht40=0
disable_sgi=0
ht_mcs=""
disable_max_amsdu=-1
ampdu_factor=-1
ampdu_density=-1
proto=RSN
key_mgmt=WPA-EAP
eap=TTLS
ocsp=0
pairwise=TKIP CCMP
group=TKIP CCMP
identity="lanforge.ttls"
password="!!ttls123"
phase2="autheap=MD5"
proactive_key_caching=0
}
cred={
username="lanforge.ttls"
password="!!ttls123"
realm="mytest.com"
domain="mytest.com"
eap=TTLS
phase2="autheap=MD5"
}
On 08/05/2015 03:02 AM, Jouni Malinen wrote:
> On Tue, Aug 04, 2015 at 02:00:14PM -0700, Isaac Konikoff wrote:
>> I'm testing HS2.0 and EAP-TTLS with hostapd-radius but I get this failure:
>>
>> 1438714591.511626: sta4: SME: Trying to authenticate with
>> 00:0e:8e:c3:19:79 (SSID='ABCD-1234' freq=5765 MHz)
>> 1438714591.519533: sta4: Trying to associate with 00:0e:8e:c3:19:79
>> (SSID='ABCD-1234' freq=5765 MHz)
>> 1438714591.522218: sta4: Associated with 00:0e:8e:c3:19:79
>> 1438714591.523228: sta4: CTRL-EVENT-EAP-STARTED EAP authentication started
>> 1438714591.525898: sta4: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE
>> type=COUNTRY alpha2=US
>> 1438714621.527055: sta4: CTRL-EVENT-EAP-STARTED EAP authentication started
>> 1438714651.624031: sta4: CTRL-EVENT-DISCONNECTED
>
> It looks like the authentication server does not select an EAP method
> and actual authentication does not start. The debug log from hostapd
> should show why that is the case.
>
More information about the Hostap
mailing list