Wired Ethernet EAP-TLS

[Darren Maden]

 >
 > 1) If the RADIUS server isn't receiving packets, blame the NAS
 > 2) If the NAS isn't sending packets, it's because no one is logging in
 > 3) If someone is trying to log in, and nothing happens, blame the NAS
 >

I decided to blame the NAS...so I reset it to factory, ie no VLANs or 
anything like that and I've now got a step further towards it working. 
I suppose it was a bit adventurous to try this first time with VLANs and 
everything, although I could actually connect with authentication 
disabled and ping through to the server from the client but still, seems 
something in there was messing it up, I'll worry about all those fancy 
extras on the switch later and concentrate on getting it authenticating 
first.

So now, the client's request is reaching the RADIUS server but it 
doesn't seem to be working, I'm quite new to RADIUS but...this setup is 
working properly with EAP-TLS over wireless.  Any ideas what is going 
wrong here?...


What the server sees......


rad_recv: Access-Request packet from host 10.1.0.7:7160, id=42, length=170
         User-Name = "es6.evosys.co.uk"
         NAS-IP-Address = 10.1.0.7
         NAS-Port = 22
         NAS-Identifier = "ES7_SWITCH"
         Service-Type = Framed-User
         Framed-Protocol = PPP
         Called-Station-Id = "00-0:-17-00-18-B4"
         Framed-MTU = 1400
         NAS-Port-Type = Ethernet
         Connect-Info = "CONNECT Ethernet 802.3"
         EAP-Message = 0x028a0015016573362e65766f7379732e636f2e756b
         Message-Authenticator = 0x9c4dd90736ab44c24180b404675396f3
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 23
   modcall[authorize]: module "preprocess" returns ok for request 23
   modcall[authorize]: module "mschap" returns noop for request 23
     rlm_realm: No '@' in User-Name = "es6.evosys.co.uk", looking up 
realm NULL
     rlm_realm: No such realm "NULL"
   modcall[authorize]: module "suffix" returns noop for request 23
   rlm_eap: EAP packet type response id 138 length 21
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 23
radius_xlat:  'es6.evosys.co.uk'
rlm_sql (sql): sql_set_user escaped user --> 'es6.evosys.co.uk'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM 
radcheck           WHERE Username = 'es6.evosys.co.uk'           ORDER 
BY id'
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): User es6.evosys.co.uk not found in radcheck
radius_xlat:  'SELECT 
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op 
  FROM radgroupcheck,usergroup WHERE usergroup.Username = 
'es6.evosys.co.uk' AND usergroup.GroupName = radgroupcheck.GroupName 
ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT 
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op 
  FROM radgroupreply,usergroup WHERE usergroup.Username = 
'es6.evosys.co.uk' AND usergroup.GroupName = radgroupreply.GroupName 
ORDER BY radgroupreply.id'
rlm_sql (sql): User es6.evosys.co.uk not found in radgroupcheck
rlm_sql (sql): Released sql socket id: 0
rlm_sql (sql): User not found
   modcall[authorize]: module "sql" returns notfound for request 23
modcall: leaving group authorize (returns updated) for request 23
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 23
   rlm_eap: EAP Identity
   rlm_eap: processing type tls
  rlm_eap_tls: Requiring client certificate
   rlm_eap_tls: Initiate
   rlm_eap_tls: Start returned 1
   modcall[authenticate]: module "eap" returns handled for request 23
modcall: leaving group authenticate (returns handled) for request 23
Sending Access-Challenge of id 42 to 10.1.0.7 port 7160
         EAP-Message = 0x018b00060d20
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0x7edcdc092933bf1c0eaeb691bfaf641d
Finished request 23
Going to the next request



What the client sees.....


es6:~ # wpa_supplicant -Dwired -ieth1 -c/etc/wpa_supplicant.conf -d
Initializing interface 'eth1' conf '/etc/wpa_supplicant.conf' driver 
'wired' ctrl_interface 'N/A'
Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant.conf'
ctrl_interface='/var/run/wpa_supplicant'
ctrl_interface_group=10 (from group name 'wheel')
ap_scan=0
Priority group 0
    id=0 ssid=''
Initializing interface (2) 'eth1'
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
wpa_driver_wired_init: Added multicast membership with packet socket
Own MAC address: 00:50:ba:eb:a3:19
Setting scan request: 0 sec 100000 usec
Added interface eth1
EAPOL: External notification - portControl=Auto
Already associated with a configured network - generating associated event
Association info event
State: DISCONNECTED -> ASSOCIATED
Associated to a new BSS: BSSID=01:80:c2:00:00:03
No keys have been configured - skip key clearing
Network configuration found for the current AP
WPA: clearing AP WPA IE
WPA: clearing AP RSN IE
WPA: clearing own WPA/RSN IE
EAPOL: External notification - portControl=Auto
Associated with 01:80:c2:00:00:03
WPA: Association event - clear replay counter
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
EAPOL: startWhen --> 0
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: txStart
RX EAPOL from 00:0a:17:00:18:b4
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_PAE entering state RESTART
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=1 id=225
EAP: EAP entering state IDENTITY
CTRL-EVENT-EAP-STARTED EAP authentication started
EAP: EAP-Request Identity data - hexdump_ascii(len=0):
EAP: using real identity - hexdump_ascii(len=16):
      65 73 36 2e 65 76 6f 73 79 73 2e 63 6f 2e 75 6b   es6.evosys.co.uk
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0a:17:00:18:b4
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=13 id=226
EAP: EAP entering state GET_METHOD
EAP: Initialize selected EAP method (13, TLS)
TLS: Trusted root certificate(s) loaded
OpenSSL: tls_connection_client_cert - SSL_use_certificate_file (DER) 
failed error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag
OpenSSL: pending error: error:0D07803A:asn1 encoding 
routines:ASN1_ITEM_EX_D2I:nested asn1 error
OpenSSL: pending error: error:140C800D:SSL 
routines:SSL_use_certificate_file:ASN1 lib
OpenSSL: SSL_use_certificate_file (PEM) --> OK
OpenSSL: tls_connection_private_key - SSL_use_PrivateKey_File (DER) 
failed error:0D094068:asn1 encoding routines:d2i_ASN1_SET:bad tag
OpenSSL: pending error: error:0D0680A8:asn1 encoding 
routines:ASN1_CHECK_TLEN:wrong tag
OpenSSL: pending error: error:0D07803A:asn1 encoding 
routines:ASN1_ITEM_EX_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding 
routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CB00D:SSL 
routines:SSL_use_PrivateKey_file:ASN1 lib
OpenSSL: SSL_use_PrivateKey_File (PEM) --> OK
SSL: Private key loaded successfully
CTRL-EVENT-EAP-METHOD EAP method 13 (TLS) selected
EAP: EAP entering state METHOD
SSL: Received packet(len=6) - Flags 0x20
EAP-TLS: Start
SSL: (where=0x10 ret=0x1)
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:before/connect initialization
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client hello A
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read server hello A
SSL: SSL_connect - want more data
SSL: 99 bytes pending from ssl_out
SSL: 99 bytes left to be sent out (of total 99 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
CTRL-EVENT-TERMINATING - signal 2 received
Removing interface eth1
State: ASSOCIATED -> DISCONNECTED
No keys have been configured - skip key clearing
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portValid=0
No keys have been configured - skip key clearing
EAP: deinitialize previously used EAP method (13, TLS) at EAP deinit