TLS communication, EAP does not work

[Alan DeKok]

On Jul 13, 2017, at 4:50 PM, Edelberto Franco <esilva at midiacom.uff.br> wrote:
> 
> Hi
> 
> I'm working with Luciano on eduroam BR and trying to solve this.
> I attached our debug files.
> 4 files:
> 1) debug-eapol-from-ujfteste-to-rnpteste - the client eapol running an auth test
> 2) debug-ufjfteste-FR3 - FreeRadius @ inst1/ufjfteste.br
> 3) debug-rnpteste-FR3 - FreeRadius @ inst1/rnpteste.br
> 4) debug-radsecproxy-FLR - radsecproxy @ federation level

  You don't say which server is doing what, or why. Is (1) sending to (2) which is proxying to (3) and then (4)?

  Describing the system would be helpful.

> What caught my attention was this "error" on the local (institution) FreeRadius
> rlm_eap (EAP): No EAP session matching state 0xc6ab1049c7a90598

  There's some telling logs in mpteste:

(1) # Executing group from file /etc/freeradius/sites-enabled/default
(1) Sent Access-Challenge Id 1 from 0.0.0.0:2083 to 200.130.15.23:33001 length 0
(1)   EAP-Message = 0x010200061520
(1)   Message-Authenticator = 0x00000000000000000000000000000000
(1)   State = 0x161759b417154cb0f3b4952e04b41a4d
(1)   Proxy-State = 0x31
...
(2) Received Access-Request Id 2 from 200.130.15.23:33001 to 0.0.0.0:2083 length 464
(2)   User-Name = "eduroam at rnpteste.br"
...
(2)   EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(2)   State = 0x161759b417154cb0f3b4952e04b41a4d
...
(3) Received Access-Request Id 3 from 200.130.15.23:33001 to 0.0.0.0:2083 length 464
(3)   User-Name = "eduroam at rnpteste.br"
(3)   NAS-IP-Address = 127.0.0.1
(3)   Calling-Station-Id = "02-00-00-00-00-01"
(3)   Framed-MTU = 1400
(3)   NAS-Port-Type = Wireless-802.11
(3)   Service-Type = Framed-User
(3)   Connect-Info = "CONNECT 11Mbps 802.11b"
(3)   EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(3)   State = 0x161759b417154cb0f3b4952e04b41a4d
(3)   Message-Authenticator = 0x384c2741f7321ca2d8e8f78b9c0864b3


  The server is sending a reply to packet 2, and then packet 3 is a retransmit of packet 2.  That's wrong.  The client should go on to the next packet.

  This is confirmed from the eapol_test packet:

   Attribute 24 (State) length=18
      Value: 161759b417154cb0f3b4952e04b41a4d
   Attribute 80 (Message-Authenticator) length=18
      Value: 67ecbe0e885a25686f87da3397222a19
Next RADIUS client retransmit in 3 seconds
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: startWhen --> 0
STA 02:00:00:00:00:01: Resending RADIUS message (id=2)


 Packets are being lost somewhere.  I have no idea where.

  I suggest setting up a test system.  And don't use radsecproxy.  The debug output is entirely useless.  It doesn't show the packets going back and forth, so it is of *zero* help for debugging.

  Test the systems, and watch the packets going back and forth.  Then READ THE DEBUG OUTPUT.  If it's complaining that there's no EAP session for the State attribute... go back in the debug log looking for other references to that State.  See if the packets are being retransmitted.  See if the reply sent by the proxy is making it to the client.

  i.e. debug it.  Trace the packets step by step through the system.  It isn't hard.  It just takes some effort to read the debug output.

  Alan DeKok.