EAP-TTLS/PAP tunneling issue

Edwin van Zyl edwinvanzyl at conor.co.za
Tue Feb 12 14:29:44 CET 2008


Hi Alan,

This is the debug trace

rad_recv: Access-Request packet from host 127.0.0.1:49483, id=24,  
length=69
	User-Name = "edwinvanzyl"
	EAP-Message = 0x0200001001656477696e76616e7a796c
	Message-Authenticator = 0xed79f4cc7febfa2e6a5b68d140ee542b
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
   rlm_eap: EAP packet type response id 0 length 16
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 4
     users: Matched entry edwinvanzyl at line 80
   modcall[authorize]: module "files" returns ok for request 4
modcall: leaving group authorize (returns updated) for request 4
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 4
   rlm_eap: EAP Identity
   rlm_eap: processing type tls
   rlm_eap_tls: Initiate
   rlm_eap_tls: Start returned 1
   modcall[authenticate]: module "eap" returns handled for request 4
modcall: leaving group authenticate (returns handled) for request 4
Sending Access-Challenge of id 24 to 127.0.0.1 port 49483
	EAP-Message = 0x010100061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x59994c8086dcf4cfeabfc31438dbba9d
Finished request 4
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:49483, id=25,  
length=135
	User-Name = "edwinvanzyl"
	State = 0x59994c8086dcf4cfeabfc31438dbba9d
	EAP-Message =  
0x0201004015800000003a16030100310100002d030147b19e11c55051203e70a3b34b02f2af7f42fa8345639d44c65c8f5773ba94aa000006002f003300320100
	Message-Authenticator = 0x073d25f7a7bfc79e5cfe9044951bf879
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
   rlm_eap: EAP packet type response id 1 length 64
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 5
     users: Matched entry edwinvanzyl at line 80
   modcall[authorize]: module "files" returns ok for request 5
modcall: leaving group authorize (returns updated) for request 5
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 5
   rlm_eap: Request found, released from the list
   rlm_eap: EAP/ttls
   rlm_eap: processing type ttls
   rlm_eap_ttls: Authenticate
   rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
   eaptls_verify returned 11
     (other): before/accept initialization
     TLS_accept: before/accept initialization
   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0031], ClientHello
     TLS_accept: SSLv3 read client hello A
   rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
     TLS_accept: SSLv3 write server hello A
   rlm_eap_tls: >>> TLS 1.0 Handshake [length 024f], Certificate
     TLS_accept: SSLv3 write certificate A
   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
     TLS_accept: SSLv3 write server done A
     TLS_accept: SSLv3 flush data
     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
   eaptls_process returned 13
   modcall[authenticate]: module "eap" returns handled for request 5
modcall: leaving group authenticate (returns handled) for request 5
Sending Access-Challenge of id 25 to 127.0.0.1 port 49483
	EAP-Message =  
0x010202b21500160301004a02000046030147b19e119f75aea0f1e09e68fba01f980f72263176ebf126951ca3453fd32e9f207f7fffa1bc92784cdb75d44eeec70d263fbc8e6578b680cff8e74e7d9f58737c002f00160301024f0b00024b00024800024530820241308201aa0203100001300d06092a864886f70d0101040500307431173015060355040a130e616c636174656c2d6c7563656e74310e300c060355040b130557694d4158310c300a06035504071303465344310f300d0603550408130670756e6a6162310b300906035504061302706b311d301b060355040313146161617365727665722e616c636174656c2e706b301e170d303730
	EAP-Message =  
0x3531343131353334365a170d3038303531333131353334365a305c310b300906035504061302706b310f300d0603550408130670756e6a616231173015060355040a130e616c636174656c2d6c7563656e74310e300c060355040b130557694d4158311330110603550403130a7a7978656c2e7573657230819f300d06092a864886f70d010101050003818d0030818902818100baaf122e60946da7ee1dc1101854e1836e848c0f3d5372be31e29eef2566a673f138809b9a118846e6846280408d822960c6345a6ce922155463fe3a267bc8d047aa8a435f506d9df7670e9d5dcc381f48d99662943546c4acca0db93665023181924fa574b52fb8ec
	EAP-Message =  
0x7a05a85edf77fc408350e82f41536fb4584afe6671fd5f0203010001300d06092a864886f70d01010405000381810065c020869992c43b685a15a53ffee8ea31743ac9fe71a741b5265dbc1caa2d01e614820b4d05d2f5bd5bf04804259abfdad4d492877574946c10afba0c07a04304876701ac9e29a8297b2a9f1d6bb5e080d2fc5b633d63433f63e4be896dc4bd9db1606e80af636c2a1eabba9e0c3d73059bfc66efc9d06b8af35a8d2862971416030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdb9212a8b9011cdfcdf439d379d5f3fd
Finished request 5
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:49483, id=26,  
length=279
	User-Name = "edwinvanzyl"
	State = 0xdb9212a8b9011cdfcdf439d379d5f3fd
	EAP-Message =  
0x020200d01580000000ca1603010086100000820080851b83bc1ef0bf9191a86fbaea6ccfc1125f3bb6a921e98c9e4d88a1027f97b7becbfcf93b4680ce3c633d59accde21e782450f8ddc0643fe4940ca0f69bc5685c7c4ad87f6dd48d9071c298444a2aa4c7e00974111f73bed623482b62cafcdd64f80a86c04764eb60cf915817bbfeeeea66c383283f80e9af8f65cba652ea0f1403010001011603010030cbd3122559d1fc2a6ff191e8bdea363db4e5759dcd863977b38556689a77b9711f38db5cace0453b0e1275bb1e6ccd73
	Message-Authenticator = 0x6be9cce642516930e4ff0790e2040d11
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
   rlm_eap: EAP packet type response id 2 length 208
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 6
     users: Matched entry edwinvanzyl at line 80
   modcall[authorize]: module "files" returns ok for request 6
modcall: leaving group authorize (returns updated) for request 6
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 6
   rlm_eap: Request found, released from the list
   rlm_eap: EAP/ttls
   rlm_eap: processing type ttls
   rlm_eap_ttls: Authenticate
   rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
   eaptls_verify returned 11
   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
     TLS_accept: SSLv3 read client key exchange A
   rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
     TLS_accept: SSLv3 read finished A
   rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
     TLS_accept: SSLv3 write change cipher spec A
   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
     TLS_accept: SSLv3 write finished A
     TLS_accept: SSLv3 flush data
     (other): SSL negotiation finished successfully
SSL Connection Established
   eaptls_process returned 13
   modcall[authenticate]: module "eap" returns handled for request 6
modcall: leaving group authenticate (returns handled) for request 6
Sending Access-Challenge of id 26 to 127.0.0.1 port 49483
	EAP-Message =  
0x01030041150014030100010116030100303e4590682263ecfae1df520a9e735fc24dc0b9dadc289c73d44c68e892db13489f2a9d4413f92d0ae4225bdea6d680cd
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x57145bf98bdf07a373ce7da47d5414ff
Finished request 6
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:49483, id=27,  
length=134
	User-Name = "edwinvanzyl"
	State = 0x57145bf98bdf07a373ce7da47d5414ff
	EAP-Message =  
0x0203003f1580000000391703010030d6fe3b607f24657f497e2f40481ba0002aaab90f6a005f62004eb7f6a1ccdbf1a8c3a93780e2e9402f537bd7b080a283
	Message-Authenticator = 0x49352d2e77eb31e74b65c2cdc1059f73
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
   rlm_eap: EAP packet type response id 3 length 63
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 7
     users: Matched entry edwinvanzyl at line 80
   modcall[authorize]: module "files" returns ok for request 7
modcall: leaving group authorize (returns updated) for request 7
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
   rlm_eap: Request found, released from the list
   rlm_eap: EAP/ttls
   rlm_eap: processing type ttls
   rlm_eap_ttls: Authenticate
   rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
   eaptls_verify returned 11
   eaptls_process returned 7
   rlm_eap_ttls: Session established.  Proceeding to decode tunneled  
attributes.
   rlm_eap_ttls:  Non-RADIUS attribute in tunneled authentication is  
not supported
  rlm_eap: Handler failed in EAP/ttls
   rlm_eap: Failed in EAP select
   modcall[authenticate]: module "eap" returns invalid for request 7
modcall: leaving group authenticate (returns invalid) for request 7
auth: Failed to validate the user.
Delaying request 7 for 1 seconds
Finished request 7
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 4 ID 24 with timestamp 47b19e11
Cleaning up request 5 ID 25 with timestamp 47b19e11
Cleaning up request 6 ID 26 with timestamp 47b19e11
Sending Access-Reject of id 27 to 127.0.0.1 port 49483
	EAP-Message = 0x04030004
	Message-Authenticator = 0x00000000000000000000000000000000
Cleaning up request 7 ID 27 with timestamp 47b19e11
Nothing to do.  Sleeping until we see a request.

Thx
Edwin
On 12 Feb 2008, at 2:47 PM, Alan DeKok wrote:

> Edwin van Zyl wrote:
>> I'm looking for some help with regards to setting up EAP-TTLS. I've
>> managed to make some progress, but can't get past the following  
>> problem
>> which gets printed in the debug logs:
>>
>> "rlm_eap_ttls:  Non-RADIUS attribute in tunneled authentication is  
>> not
>> supported"
>>
>> The message gets generated when attribute length > 255, but none of  
>> the
>> attributes I send through are that large.
>
>  Then (a) the code in FreeRADIUS is buggy, or (b) the code in jradius
> is buggy, or (c) you actually are sending attributes that are that  
> large.
>
>> I'm using JRadius to simulate Radius traffic over EAP-TTLS/PAP and  
>> are
>> sending through the following when receiving the message.
>
>  Is jradius sending this?  Because that message *only* gets printed  
> out
> for data inside of the TTLS tunnel.  And the sample packet you show
> does not contain enough data to form anything inside of the TTLS  
> tunnel.
>
>  And... most importantly... if the server was built with debugging
> symbols (like it usually is), then running in debugging mode would  
> show
> you the raw data inside of the TLS tunnel, which would give you (and  
> me)
> enough information to decide definitively what's going on.
>
>> Can anyone please assist?
>
>  Can you post the debug log, as suggested in the FAQ, README, INSTALL,
> and daily on this list?
>
>  Honestly... I'm still amazed at the number of people who careful post
> what the client is sending... and then ask "Why does the server not do
> what I expect?"  If your car is broken, it is totally pointless to go
> examine the road.
>
>  Alan DeKok.
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html




More information about the Freeradius-Users mailing list