radiusd debug understanding help needed (EAP session for state 0x... did not finish)
Zeus Panchenko
zeus at ibs.dn.ua
Mon Jun 22 18:59:07 CEST 2015
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
hi,
please, help me to be sure I understand `radiusd -X' output right way ...
some period of time, FR with EAP-TLS + LDAP was working in "test mode" ... now it is not
and I'm trying to understand why
FR: server is v.2.2.6 on FreeBSD 10.1R
WS: wpa_supplicant client on FreeBSD 10.1R
network (LAN) topology: FR <-> 100Mb Switch <-> WS
FR configured with EAP + LDAP and EAP/md5 for MAC auth works fine.
but EAP/tls spawns:
WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
WARNING: !! EAP session for state 0x8c1a57f7885a5afa did not finish!
WARNING: !! Please read http://wiki.freeradius.org/guide/Certificate_Compatibility
WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
on this wiki page for this case it is told:
- - - Follow the instructions given above.
it is what I have folowed
- - - Consider to decreasing the tunnel MTU
there is no tunnel, but decreasing MTU on NIC didn't help
last time I faced this very problem on my VPN and MTU decreasing to 1250
helped well, but now it is not ...
in `radiusd -X' I see this:
- - ---[ quotation start ]-------------------------------------------
...
[files] expand: %{User-Name}, you have came from %{NAS-IP-Address} copper port %{NAS-Port}. -> jdoe-eap, you have came from 192.168.0.1 copper port 14.
++[files] = ok
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
[ldap] performing user authorization for jdoe-eap
[ldap] expand: %{Stripped-User-Name} ->
[ldap] ... expanding second conditional
[ldap] expand: %{User-Name} -> jdoe-eap
[ldap] expand: (&(cn=%{%{Stripped-User-Name}:-%{User-Name}})(|(authorizedService=802.1x-mac at xyz)(authorizedService=802.1x-eap at xyz)(authorizedService=802.1x at xyz))) -> (&(cn=jdoe-eap)(|(autho
rizedService=802.1x-mac at xyz)(authorizedService=802.1x-eap at xyz)(authorizedService=802.1x at xyz)))
[ldap] expand: ou=People,dc=xyz -> ou=People,dc=xyz
[ldap] ldap_get_conn: Checking Id: 0
[ldap] ldap_get_conn: Got Id: 0
[ldap] performing search in ou=People,dc=xyz, with filter (&(cn=jdoe-eap)(|(authorizedService=802.1x-mac at xyz)(authorizedService=802.1x-eap at xyz)(authorizedService=802.1x at xyz)))
[ldap] performing search in cn=ethernet,ou=rad-profiles,dc=xyz, with filter (objectclass=radiusprofile)
[ldap] radiusTunnelMediumType -> Tunnel-Medium-Type:0 = IEEE-802
[ldap] radiusTunnelType -> Tunnel-Type:0 = VLAN
[ldap] radiusSessionTimeout -> Session-Timeout = 900
[ldap] looking for check items in directory...
[ldap] userPassword -> Cleartext-Password == "jdoe-eap"
[ldap] userPassword -> Password-With-Header == "jdoe-eap"
[ldap] looking for reply items in directory...
[ldap] radiusTunnelPrivateGroupId -> Tunnel-Private-Group-Id:0 = "3495"
[ldap] radiusTunnelMediumType -> Tunnel-Medium-Type:0 = IEEE-802
[ldap] radiusTunnelType -> Tunnel-Type:0 = VLAN
[ldap] radiusServiceType -> Service-Type = Framed-User
[ldap] ldap_release_conn: Release Id: 0
++[ldap] = ok
- - ---[ quotation end ]-------------------------------------------
so, am I correct? here it is written that LDAP auth performed successfully
further:
- - ---[ quotation start ]-------------------------------------------
++? if (notfound)
? Evaluating (notfound) -> FALSE
++? if (notfound) -> FALSE
++? if (reject)
? Evaluating (reject) -> FALSE
++? if (reject) -> FALSE
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] Received TLS ACK
[tls] ACK handshake fragment handler
[tls] eaptls_verify returned 1
[tls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
...
- - ---[ quotation end ]-------------------------------------------
what does these rows mean?
- - ---[ quotation start ]-------------------------------------------
[tls] eaptls_verify returned 1
[tls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
- - ---[ quotation end ]-------------------------------------------
wpa_supplicant debug shows this:
- - ---[ quotation start ]-------------------------------------------
...
1434988426.933490: SSL: (where=0x1001 ret=0x1)
1434988426.933492: SSL: SSL_connect:SSLv3 read server hello A
1434988426.933731: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=1 buf='/C=AU/ST=SDN/L=Sidney/O=RADIUS/OU=RADIUS/CN=changeme/emailAddress=security at xyz'
1434988426.933736: igb0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=AU/ST=SDN/L=Sidney/O=RADIUS/OU=RADIUS/CN=xyz-ca/emailAddress=security at xyz'
1434988426.933738: EAP: Status notification: remote certificate verification (param=success)
1434988426.933814: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=0 buf='/C=AU/ST=SDN/L=Sidney/O=RADIUS/OU=RADIUS/CN=office1.xyz/emailAddress=security at xyz'
1434988426.933818: igb0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=AU/ST=SDN/L=Sidney/O=RADIUS/OU=RADIUS/CN=office1.xyz/emailAddress=security at xyz'
1434988426.934102: EAP: Status notification: remote certificate verification (param=success)
1434988426.934106: SSL: (where=0x1001 ret=0x1)
1434988457.029252: SSL: SSL_connect:SSLv3 write finished A
1434988457.029254: SSL: (where=0x1001 ret=0x1)
1434988457.029255: SSL: SSL_connect:SSLv3 flush data
1434988457.029257: SSL: (where=0x1002 ret=0xffffffff)
1434988457.029258: SSL: SSL_connect:error in SSLv3 read finished A
1434988457.029260: SSL: SSL_connect - want more data
1434988457.029262: SSL: 2750 bytes pending from ssl_out
1434988457.029264: SSL: 2750 bytes left to be sent out (of total 2750 bytes)
1434988457.029266: SSL: sending 1398 bytes, more fragments will follow
1434988457.029268: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
1434988457.029270: EAP: EAP entering state SEND_RESPONSE
1434988457.029272: EAP: EAP entering state IDLE
1434988457.029273: EAPOL: SUPP_BE entering state RESPONSE
1434988457.029274: EAPOL: txSuppRsp
1434988457.029276: TX EAPOL: dst=01:80:c2:00:00:03
1434988457.029278: TX EAPOL - hexdump(len=1412): 01 00 ...
...
1 09 01 16 0c 73 65 63 75 72 69 74 79 40 69 62 73 30 1e 17 0d 31 34 30 33 31 30 31
1434988457.030267: EAPOL: SUPP_BE entering state RECEIVE
...
1434989781.980570: igb0: RX EAPOL from 34:db:fd:81:43:2b
1434989781.980571: RX EAPOL - hexdump(len=46): 01 00 00 04 04 cf 00 04 00 00 ...
1434989781.980579: EAPOL: Received EAP-Packet frame
1434989781.980580: EAPOL: SUPP_BE entering state REQUEST
1434989781.980581: EAPOL: getSuppRsp
1434989781.980582: EAP: EAP entering state RECEIVED
1434989781.980584: EAP: Received EAP-Failure
1434989781.980585: EAP: Status notification: completion (param=failure)
1434989781.980587: EAP: EAP entering state FAILURE
1434989781.980589: igb0: CTRL-EVENT-EAP-FAILURE EAP authentication failed
1434989781.980590: EAPOL: SUPP_PAE entering state HELD
1434989781.980591: EAPOL: Supplicant port status: Unauthorized
1434989781.980593: EAPOL: SUPP_BE entering state RECEIVE
1434989781.980594: EAPOL: SUPP_BE entering state FAIL
1434989781.980595: EAPOL: SUPP_BE entering state IDLE
1434989781.980596: EAPOL authentication completed unsuccessfully
...
- - ---[ quotation end ]-------------------------------------------
looks like OpenSSL related something, is it?
so, may somebody advise where to look at? how to know who is guilty?
- --
Zeus V. Panchenko jid:zeus at im.ibs.dn.ua
IT Dpt., I.B.S. LLC GMT+2 (EET)
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
iEYEARECAAYFAlWIPtsACgkQr3jpPg/3oyoZIwCg5AcO12uDdmpWBPvLskHTp4ct
X3IAn0QOx/e0dLm+6erzEMKeTW6LB5Z2
=DtVP
-----END PGP SIGNATURE-----
More information about the Freeradius-Users
mailing list