radiusd debug understanding help needed (EAP session for state 0x... did not finish)

[Stefan Winter]

Hi,


> The size of that fragment, is pretty big, 1398 bytes. I think only fragments up to 1020 bytes are guaranteed to be handled by the authenticator.

Excellent analysis, just wondering about that sentence? The RADIUS side
of the authenticator has to be prepared to get 4k RADIUS packets (with
arbitrarily much of that being EAP-Message), and the EAPoL side of the
authenticator needs to support sending the local link's MTU minus EAPoL
headers as payload.

I don't recall any "grace" boundaries below that. Can you cite where
they would come from?

FWIW, our eduroam Monitoring intentionally sends 4k RADIUS to test for
proper fragmentation support. Not sure how much we stuff into the
EAP-Messages inside those big packets though.

Stefan

>
> 1435137443.632654: EAP: EAP entering state RECEIVED
> 1435137443.632657: EAP: Received EAP-Request id=154 method=13 vendor=0 vendorMethod=0
> 1435137443.632659: EAP: EAP entering state METHOD
> 1435137443.632660: SSL: Received packet(len=889) - Flags 0x80
> 1435137443.632661: SSL: TLS Message Length: 2867
> 1435137443.632685: SSL: (where=0x1001 ret=0x1)
> 1435137443.632686: SSL: SSL_connect:SSLv3 read server hello A
> 1435137443.632988: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=1 buf='/C=FR/ST=Radius/L=Somewhere/O=Example Inc./emailAddress=admin at example.com/CN=Example Certificat
> e Authority'
> 1435137443.632996: igb0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=FR/ST=Radius/L=Somewhere/O=Example Inc./emailAddress=admin at example.com/CN=Example Certificate Authority'
> 1435137443.632999: EAP: Status notification: remote certificate verification (param=success)
> 1435137443.633114: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=0 buf='/C=FR/ST=Radius/O=Example Inc./CN=Example Server Certificate/emailAddress=admin at example.com'
> 1435137443.633120: igb0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=FR/ST=Radius/O=Example Inc./CN=Example Server Certificate/emailAddress=admin at example.com'
> 1435137443.633297: EAP: Status notification: remote certificate verification (param=success)
> 1435137443.633307: SSL: (where=0x1001 ret=0x1)
> 1435137443.633309: SSL: SSL_connect:SSLv3 read server certificate A
> 1435137443.633421: SSL: (where=0x1001 ret=0x1)
> 1435137443.633423: SSL: SSL_connect:SSLv3 read server key exchange A
> 1435137443.633444: SSL: (where=0x1001 ret=0x1)
> 1435137443.633446: SSL: SSL_connect:SSLv3 read server certificate request A
> 1435137443.633447: SSL: (where=0x1001 ret=0x1)
> 1435137443.633449: SSL: SSL_connect:SSLv3 read server done A
> 1435137443.633541: SSL: (where=0x1001 ret=0x1)
> 1435137443.633544: SSL: SSL_connect:SSLv3 write client certificate A
> 1435137443.634368: SSL: (where=0x1001 ret=0x1)
> 1435137443.634372: SSL: SSL_connect:SSLv3 write client key exchange A
> 1435137443.636241: SSL: (where=0x1001 ret=0x1)
> 1435137443.636245: SSL: SSL_connect:SSLv3 write certificate verify A
> 1435137443.636315: SSL: (where=0x1001 ret=0x1)
> 1435137443.636317: SSL: SSL_connect:SSLv3 write change cipher spec A
> 1435137443.636336: SSL: (where=0x1001 ret=0x1)
> 1435137443.636338: SSL: SSL_connect:SSLv3 write finished A
> 1435137443.636345: SSL: (where=0x1001 ret=0x1)
> 1435137443.636346: SSL: SSL_connect:SSLv3 flush data
> 1435137443.636348: SSL: (where=0x1002 ret=0xffffffff)
> 1435137443.636349: SSL: SSL_connect:error in SSLv3 read finished A
> 1435137443.636351: SSL: SSL_connect - want more data
> 1435137443.636353: SSL: 2651 bytes pending from ssl_out
> 1435137443.636356: SSL: 2651 bytes left to be sent out (of total 2651 bytes)
> 1435137443.636358: SSL: sending 1398 bytes, more fragments will follow
> 1435137443.636360: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
> 1435137443.636362: EAP: EAP entering state SEND_RESPONSE
> 1435137443.636363: EAP: EAP entering state IDLE
> 1435137443.636364: EAPOL: SUPP_BE entering state RESPONSE
> 1435137443.636365: EAPOL: txSuppRsp
> 1435137443.636368: TX EAPOL: dst=01:80:c2:00:00:03
> 1435137443.636370: TX EAPOL - hexdump(len=1412): 01 00 05 80 02 9a 05 80 0d c0 00 00 0a 5b ...
>
> In request 6, we'd expect to see the server receiving that TLS fragment, but we don't. We instead see the supplicant restarting authentication. Looking at the timestamps, probably after timing out receiving a response from the server.
>
> So yes, this is definitely an MTU issue on the path from the Supplicant to the RADIUS server.
>
> I'm guessing as you have wpa_supplicant set to wired, you're doing wired 802.1X? So your switch is junk, and you either need to call the vendor and complain, or get a new switch.
>
> I've seen this exact same problem problem with Meraki access points. There's absolutely nothing you can do to fix it, because there's no MTU negotiation mechanism in EAP, and most supplicants do not expose an MTU control. So a vendor fix is the only option.
>
> The issue only shows up when doing EAP-TLS because all the packets sent supplicant to authenticator for PEAP and TTLS-PAP are relatively small. EAP-TLS however, requires the supplicant to send large chunks of certificate.
>
> Could you provide the make/model of the device (if it really is a switch), or the version if it's a software authenticator, just for my own edification.
>
> If it's software we might be able to submit a patch.
>
> -Arran
>
> Arran Cudbard-Bell <a.cudbardb at freeradius.org>
> FreeRADIUS development team
>
> FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
>
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20150625/dbf58973/attachment.sig>