EAP-TTLS with mschapv2 inner authentication issue

matteo at crs4.it matteo at crs4.it
Tue Aug 31 11:23:49 CEST 2010


Hello all,
I'm trying to use Freeradius 21.1.9 EAP-TTLS with MSCHAPv2 as inner  
authentication against an OpenLDAP server with crypt password  
encryption scheme.
the following is my eap.conf relevant part

eap {
                        default_eap_type = ttls

                    ttls {

                         default_eap_type = mschapv2

                         copy_request_to_tunnel = yes

                         use_tunneled_reply = yes
                     }


}


rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=3, length=161
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x02010013016d617474656f40637273342e6974
	Message-Authenticator = 0x310153774fd7a4c1fdc46eaf761b9d12
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 1 length 19
Tue Aug 31 11:12:04 2010 : Info: [eap] No EAP Start, assuming it's an  
on-going EAP conversation
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns updated
Tue Aug 31 11:12:04 2010 : Info: ++[unix] returns notfound
Tue Aug 31 11:12:04 2010 : Info: ++[files] returns noop
Tue Aug 31 11:12:04 2010 : Info: [ldap] performing user authorization  
for matteo
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand: %{Stripped-User-Name}  
-> matteo
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand:  
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=matteo)
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand: ou=people,dc=crs4 ->  
ou=people,dc=crs4
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] attempting LDAP reconnection
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] (re)connect to  
opmanager.crs4.it:389, authentication 0
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] setting TLS CACert File to  
/etc/raddb/certs/ca.crt
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] setting TLS CACert  
Directory to /etc/raddb/certs
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] setting TLS Cert File to  
/etc/raddb/certs/cheope.crs4.it.crt
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] setting TLS Key File to  
/etc/raddb/certs/cheope.crs4.it.key
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] setting TLS Key File to  
/etc/raddb/certs/random
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] bind as / to opmanager.crs4.it:389
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] waiting for bind result ...
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] Bind was successful
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] performing search in  
ou=people,dc=crs4, with filter (uid=matteo)
Tue Aug 31 11:12:04 2010 : Info: [ldap] checking if remote access for  
matteo is allowed by uid
Tue Aug 31 11:12:04 2010 : Info: [ldap] looking for check items in  
directory...
Tue Aug 31 11:12:04 2010 : Info: [ldap] looking for reply items in  
directory...
Tue Aug 31 11:12:04 2010 : Debug: WARNING: No "known good" password  
was found in LDAP.  Are you sure that the user is configured correctly?
Tue Aug 31 11:12:04 2010 : Info: [ldap] user matteo authorized to use  
remote access
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 31 11:12:04 2010 : Info: ++[ldap] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[expiration] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[logintime] returns noop
Tue Aug 31 11:12:04 2010 : Info: [pap] WARNING! No "known good"  
password found for the user.  Authentication may fail because of this.
Tue Aug 31 11:12:04 2010 : Info: ++[pap] returns noop
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP Identity
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type tls
Tue Aug 31 11:12:04 2010 : Info: [tls] Initiate
Tue Aug 31 11:12:04 2010 : Info: [tls] Start returned 1
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 3 to 156.148.67.1 port 2051
	EAP-Message = 0x010200061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf7433873f7412de76bc05ae5c5ee9be3
Tue Aug 31 11:12:04 2010 : Info: Finished request 0.
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=4, length=472
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message =  
0x020201361500160301012b0100012703014c7cc72991e0f662002866a71c28c820e0de34a9e3f5d4cdd13261ab80f40b55208298e10f7d136b8f7040f0eaaf1022bebec5ce851488d142188422a15669cc22003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff010000a4002300a06a3964ec740269814b2ef1451d08078ab642deed9ed76c8fcd99571221446e26ee799830d7c693d0d6ca12ed94f11cd993fe30d0f00a5cf3f9fcbec1311bd587cdb9f5562778d8775df0cc8d9a1407571de33118d559b7d5054dec66bc7cd9813f7d659743b857
	EAP-Message =  
0x5d4fa13722451fdadd0fe7726729751bd3fb33e6f9804924d63a5015b9e24f600db85992ec2ee81fd2be461b7d63f3afbe9954c132c68c8c70
	State = 0xf7433873f7412de76bc05ae5c5ee9be3
	Message-Authenticator = 0xc42ebb371107e22f74212604dfdfef72
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 2  
length 253
Tue Aug 31 11:12:04 2010 : Info: [eap] Continuing tunnel setup.
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns ok
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] Request found, released from the list
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type ttls
Tue Aug 31 11:12:04 2010 : Info: [ttls] Authenticate
Tue Aug 31 11:12:04 2010 : Info: [ttls] processing EAP-TLS
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_verify returned 7
Tue Aug 31 11:12:04 2010 : Info: [ttls] Done initial handshake
Tue Aug 31 11:12:04 2010 : Info: [ttls]     (other): before/accept  
initialization
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: before/accept  
initialization
Tue Aug 31 11:12:04 2010 : Info: [ttls] <<< TLS 1.0 Handshake [length  
012b], ClientHello
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 read  
client hello A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length  
0035], ServerHello
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
server hello A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length  
085e], Certificate
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
certificate A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length  
020d], ServerKeyExchange
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
key exchange A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length  
0004], ServerHelloDone
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
server done A
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 flush data
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: Need to read  
more data: SSLv3 read client certificate A
Tue Aug 31 11:12:04 2010 : Debug: In SSL Handshake Phase
Tue Aug 31 11:12:04 2010 : Debug: In SSL Accept mode
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_process returned 13
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 4 to 156.148.67.1 port 2051
	EAP-Message =  
0x0103040015c000000ab816030100350200003103014c7cc764ee8967ea86227d977c0209ae026833b7c3f9a6ba01a475086c0750e5000039000009ff0100010000230000160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c652043657274696669636174
	EAP-Message =  
0x6520417574686f72697479301e170d3130303833303134323634315a170d3130313032393134323634315a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100e64d2b1c06ad321d18c37a6f2bb3468e00c78591d30b43d5e9401db1ceef05649c8aec520724c31dd478ac33e3d71e6b2e8c4a
	EAP-Message =  
0xa324cf3e8c43351b557b1663c4dc7e43ad45d61117ef2e1ff4e21a7c6527d26ad57ed37b46c66552551ae79f7478bfe0d71bb213877401717bc83fd61f2d1bc04c0e7df8c608e0f5d568dca460bdcbcfbeca0341c39497d70c53084d06266575817ffb327c7139dd4ecc855bb5a7f5d2e3961f4fb4eb593711f5caf7332d5060edeb3cf5b371e4be6411bb846465d8d084631b6056647245113d877199b15632c4407c63c85410c46e0fe2e15eb169c6c220e1308ba0699f3bba60801a5a932efd513091546caaea3a4f883b1f0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101050500038201
	EAP-Message =  
0x01002073766ca83a1ba10142d0f92f36da3449108d16e0469be3882cfc78201cdd1e454889d1a7f0e65adf7588b39cd0211570886bc9059f5560f48b6c3a279fb1d98f49d78fe632a28ea29d311dc574be98bf3eb0c4ce868b30a38eac7cbfbb069e1d4b45296f923c8d8f3a04da7b49c5104b7dd871e42bb035095cee01a744920b2efc8e5c7a52b710833072981cbd36c045a0196458aa2c00925fe3daf5b3b4295bab38dd4295534af663c1fc091a04cf085bb361fcd6a17da4c462aee22403d424f549ec228aee321406fbda0531ac81027a3d1f9b400777235b4f55e79134c514cc6f677494ba37e47c9e7438b9e89eac3af712f740ac78849013
	EAP-Message = 0xdf7baaeb7f0004ab308204a7
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf7433873f6402de76bc05ae5c5ee9be3
Tue Aug 31 11:12:04 2010 : Info: Finished request 1.
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=5, length=166
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x020300061500
	State = 0xf7433873f6402de76bc05ae5c5ee9be3
	Message-Authenticator = 0xf74084774c3b55e0435dc7d30cfeb1b5
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 3 length 6
Tue Aug 31 11:12:04 2010 : Info: [eap] Continuing tunnel setup.
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns ok
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] Request found, released from the list
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type ttls
Tue Aug 31 11:12:04 2010 : Info: [ttls] Authenticate
Tue Aug 31 11:12:04 2010 : Info: [ttls] processing EAP-TLS
Tue Aug 31 11:12:04 2010 : Info: [ttls] Received TLS ACK
Tue Aug 31 11:12:04 2010 : Info: [ttls] ACK handshake fragment handler
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_verify returned 1
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_process returned 13
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 5 to 156.148.67.1 port 2051
	EAP-Message =  
0x0104040015c000000ab83082038fa003020102020900d829c8370b2af3f0300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3130303833303134323634315a170d3130313032393134323634315a308193310b3009060355040613024652310f300d060355040813
	EAP-Message =  
0x065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100e4d4978618cd2cefb02d44dca989a98bf2bd5a9334875c18b3e0142cbc9b93cd7085bdc5737790ff6499d42ecc802f45f45ea948dd85f00fb1577659c6ad42df27300226b96639e7590da3e888ccbc562ab2f53cea477d074f6d5ab05b037803
	EAP-Message =  
0xaeab93ae0507dc3939bb85fe311d8d46c63fe46423862df36a702f07b12fd7778f952c6cc0b9386aed7f908bd2cc1bb271a41da34b753797433db1a4914721ca3a30ea4b926ae71b06d9bdc2ea40911d36c80430cf82fbc023a0af28b66a7eec239ace82f69f8c8ef463a101f3be268aabff86f1ce327fd449f6ab00c9ac3cab923d8c9fc98c53d556e111f58c875a78c1a8fe5285558e622adf3b43267027630203010001a381fb3081f8301d0603551d0e04160414d31721def8d660b5959afd3fd3d8fc7afd08b6773081c80603551d230481c03081bd8014d31721def8d660b5959afd3fd3d8fc7afd08b677a18199a48196308193310b30090603
	EAP-Message =  
0x55040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900d829c8370b2af3f0300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100491e9d2ae9b0866a9c12d4794e1d0cda8c1d8f7916d978ec0cc7a20d44d6b8f675dba42bfb5711cd3ac966e0f6e157a6a2bfadbdad765d943ce0caaf6e9333dd907264
	EAP-Message = 0x665c8a1f4f7350d8576c568d
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf7433873f5472de76bc05ae5c5ee9be3
Tue Aug 31 11:12:04 2010 : Info: Finished request 2.
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=6, length=166
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x020400061500
	State = 0xf7433873f5472de76bc05ae5c5ee9be3
	Message-Authenticator = 0xd3d142cd579704f7568415bebcabf209
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 4 length 6
Tue Aug 31 11:12:04 2010 : Info: [eap] Continuing tunnel setup.
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns ok
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] Request found, released from the list
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type ttls
Tue Aug 31 11:12:04 2010 : Info: [ttls] Authenticate
Tue Aug 31 11:12:04 2010 : Info: [ttls] processing EAP-TLS
Tue Aug 31 11:12:04 2010 : Info: [ttls] Received TLS ACK
Tue Aug 31 11:12:04 2010 : Info: [ttls] ACK handshake fragment handler
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_verify returned 1
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_process returned 13
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 6 to 156.148.67.1 port 2051
	EAP-Message =  
0x010502d6158000000ab822ed15fed4dc8a20c592978393c7f39286c9051b45b6c8d2d6b49fcee87929d2f89ac7b939bc578cf80ed3aec354a796ff7d8f940dceca5d9ef5c93e973c19b17a99e2dd61b4fe64f0ef16130f818a9332da132bcea3f481a838e5c671bcc0785f238c115588c49bc2c947da6a0fe0f2432ba405bb22e812643db915e311e906ff18c8ad04488f2ca4d7364bf933f37b658cbe1e3ba2d396f85c2ad1ca82e02937203e5b0d2dac6afbaddf577d89b8b84f160301020d0c0002090080c7e15d5614adc42a0a86db0c582d372039c504a066f598ddfeb9023b952c5faabe6cce07e7162721670f859f763e7d8cbb755f807462df
	EAP-Message =  
0x7a3fa50c3034739706a0bd4a068a8158d00d585b4523818910c22e93ef09f25d8e3a3e141afb28eb7ff78227a5a598c64d65f180c59734aa046f1b6a8f388a40dd9305b4d8e05575ab0001020080afcee5c8c7066e3b2a53baa2539070f1d858bb006af30b640314e9afc2a6111a5497aa6c2a68abc17da6da5914c829bb3eebd1b899dbee7d9f08bb9a7244b4236677ae915e08178bdc568d39d9835edfad0efdee06842b1493181e54cfda5880a6265fb6c8accbb4dc25393476445fb3e83c5902304b3f5c49d3a299a42e67210100c2a94598594cacb671b3a6db93c139a8217c567c2113f7f74d2655ad959276f149ca7f2707c55a8a0bc98a4ecb
	EAP-Message =  
0x8523bcec647e13d1998485bfd1acffa12a50b03ba658dbaf971a3b71d3a70a03afcdeeecdb51e029417efd641fdc5129ab5635dc90e5bc9d8c7184e9c376ee6bdf37c190b9c2224d02390016e6c8386de8ab526235929d4c59a46f6f1e30ce8341255800100921b2ea574f3b45a0468e108c58811bb90aa9cc00790fe7bec2e06ec5a22dbce7eb09b9d20bf1d017bcf7b4669732fc71ebc8611a88b8ed7af43a07ede45c34eabb62dedcab923066ed7d0fb3da005dcb8309043e184aece0e4bdeb3c3a54bf4e10c9f144859cdd52a780e9c7d316030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf7433873f4462de76bc05ae5c5ee9be3
Tue Aug 31 11:12:04 2010 : Info: Finished request 3.
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=7, length=364
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message =  
0x020500cc1500160301008610000082008004cfeafd3b9b8260735f24f8f8b16d93856be3943ef7858eda6d09495c3af1f5da3b379c9cfcbee26d4702d5c6aef2ac6428e650b81037554daff815963bd86f8c7cfaed3bc63f147a539f70b81bc06974e1a39d370480723e34719ec1bb012e28507af95e0ba513f108af491b16379c1212bced3ae2f23a38d4553eb8bcb898140301000101160301003052029573f3da8bbf3a1e11ac72261ba74fda0cb0458739ed1cd86b09d4fe594955090b007e7241772c3c8bdb46c43975
	State = 0xf7433873f4462de76bc05ae5c5ee9be3
	Message-Authenticator = 0x3e9223979b8ab301e8c2db09504480d3
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 5  
length 204
Tue Aug 31 11:12:04 2010 : Info: [eap] Continuing tunnel setup.
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns ok
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] Request found, released from the list
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type ttls
Tue Aug 31 11:12:04 2010 : Info: [ttls] Authenticate
Tue Aug 31 11:12:04 2010 : Info: [ttls] processing EAP-TLS
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_verify returned 7
Tue Aug 31 11:12:04 2010 : Info: [ttls] Done initial handshake
Tue Aug 31 11:12:04 2010 : Info: [ttls] <<< TLS 1.0 Handshake [length  
0086], ClientKeyExchange
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 read  
client key exchange A
Tue Aug 31 11:12:04 2010 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec  
[length 0001]
Tue Aug 31 11:12:04 2010 : Info: [ttls] <<< TLS 1.0 Handshake [length  
0010], Finished
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 read finished A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length 00aa]???
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
session ticket A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec  
[length 0001]
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write  
change cipher spec A
Tue Aug 31 11:12:04 2010 : Info: [ttls] >>> TLS 1.0 Handshake [length  
0010], Finished
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 write finished A
Tue Aug 31 11:12:04 2010 : Info: [ttls]     TLS_accept: SSLv3 flush data
Tue Aug 31 11:12:04 2010 : Info: [ttls]     (other): SSL negotiation  
finished successfully
Tue Aug 31 11:12:04 2010 : Debug: SSL Connection Established
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_process returned 13
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 7 to 156.148.67.1 port 2051
	EAP-Message =  
0x010600f41580000000ea16030100aa040000a60000000000a0ddf880d70a4d942659aed5d739a410fa7cc22e51d7ecbcd25da3be52d86e924f78be9f8b54d3619c241849a7eace6818e47701a8e0e6ac61470e49e4bcf25eb00bf99957c19671b01accf016dc7198027c523e9aa4f79e8e85791e55d61b7a7ef26bce66475f59ba12c0795c36e7363564864f3b3b19ecc856b66e755e4c6e7e1824d1c1359bfdf4d6fc54a83a6e90d82cd1fed1ebda89daed0103d4c2176c3a1403010001011603010030bf32bca6f008708a21cf9e219b030bfc9b6c044cd73d6590a2478269a1793d7f473390bdd65005ce265992cd80e4c632
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf7433873f3452de76bc05ae5c5ee9be3
Tue Aug 31 11:12:04 2010 : Info: Finished request 4.
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 156.148.67.1 port 2051,  
id=8, length=352
	User-Name = "matteo at crs4.it"
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message =  
0x020600c0150017030100209ce0298de2f2f794027d59c49acb8cf212c5c5732f8df1a162b3fbf3cccea7831703010090df90c0a4f21cf3ed38d6bda8efd9b20bac73b45981160a7ebebd29545e0fb888d85512f9df7ec9c3b1b74632b423ec1112571f73a5013621d97f4646e1d895fa9e62e1843be9b4f726e572cba518d5b6489929324f0f2555c025bd04b6b28adc712cfdcd41117175c23f073c972fabdf63f56075ab5de57e89c6b89d3273bf8280d31ba460122c6c94e57d866bc28bcf
	State = 0xf7433873f3452de76bc05ae5c5ee9be3
	Message-Authenticator = 0xbbf5e2e64b3139a15cd7578fcdab8314
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[preprocess] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP packet type response id 6  
length 192
Tue Aug 31 11:12:04 2010 : Info: [eap] Continuing tunnel setup.
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns ok
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = EAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group authenticate {...}
Tue Aug 31 11:12:04 2010 : Info: [eap] Request found, released from the list
Tue Aug 31 11:12:04 2010 : Info: [eap] EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] processing type ttls
Tue Aug 31 11:12:04 2010 : Info: [ttls] Authenticate
Tue Aug 31 11:12:04 2010 : Info: [ttls] processing EAP-TLS
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_verify returned 7
Tue Aug 31 11:12:04 2010 : Info: [ttls] Done initial handshake
Tue Aug 31 11:12:04 2010 : Info: [ttls] eaptls_process returned 7
Tue Aug 31 11:12:04 2010 : Info: [ttls] Session established.   
Proceeding to decode tunneled attributes.
Tue Aug 31 11:12:04 2010 : Info: [ttls] Got tunneled request
	User-Name = "matteo at crs4.it"
	MS-CHAP-Challenge = 0x16e7dbe472e6a50d286f1f628a30ecca
	MS-CHAP2-Response =  
0x3f00000000d1000000308193310b300906030000000000000000a271d84cdf0a461a8ad483eeb04d8f8e2fe59853bece1446
	FreeRADIUS-Proxied-To = 127.0.0.1
Tue Aug 31 11:12:04 2010 : Info: [ttls] Sending tunneled request
	User-Name = "matteo at crs4.it"
	MS-CHAP-Challenge = 0x16e7dbe472e6a50d286f1f628a30ecca
	MS-CHAP2-Response =  
0x3f00000000d1000000308193310b300906030000000000000000a271d84cdf0a461a8ad483eeb04d8f8e2fe59853bece1446
	FreeRADIUS-Proxied-To = 127.0.0.1
	NAS-IP-Address = 156.148.67.1
	NAS-Port = 0
	Called-Station-Id = "00-1E-E5-28-99-F8"
	Calling-Station-Id = "00-13-CE-3C-7E-17"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
server inner-tunnel {
Tue Aug 31 11:12:04 2010 : Info: +- entering group authorize {...}
Tue Aug 31 11:12:04 2010 : Info: ++[chap] returns noop
Tue Aug 31 11:12:04 2010 : Info: [mschap] Found MS-CHAP attributes.   
Setting 'Auth-Type  = mschap'
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[unix] returns notfound
Tue Aug 31 11:12:04 2010 : Info: [suffix] Looking up realm "crs4.it"  
for User-Name = "matteo at crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Found realm "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Stripped-User-Name = "matteo"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Adding Realm = "crs4.it"
Tue Aug 31 11:12:04 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Aug 31 11:12:04 2010 : Info: ++[suffix] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[control] returns ok
Tue Aug 31 11:12:04 2010 : Info: [eap] No EAP-Message, not doing EAP
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[files] returns noop
Tue Aug 31 11:12:04 2010 : Info: [ldap] performing user authorization  
for matteo
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand: %{Stripped-User-Name}  
-> matteo
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand:  
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=matteo)
Tue Aug 31 11:12:04 2010 : Info: [ldap] 	expand: ou=people,dc=crs4 ->  
ou=people,dc=crs4
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] performing search in  
ou=people,dc=crs4, with filter (uid=matteo)
Tue Aug 31 11:12:04 2010 : Info: [ldap] checking if remote access for  
matteo is allowed by uid
Tue Aug 31 11:12:04 2010 : Info: [ldap] looking for check items in  
directory...
Tue Aug 31 11:12:04 2010 : Info: [ldap] looking for reply items in  
directory...
Tue Aug 31 11:12:04 2010 : Debug: WARNING: No "known good" password  
was found in LDAP.  Are you sure that the user is configured correctly?
Tue Aug 31 11:12:04 2010 : Info: [ldap] user matteo authorized to use  
remote access
Tue Aug 31 11:12:04 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 31 11:12:04 2010 : Info: ++[ldap] returns ok
Tue Aug 31 11:12:04 2010 : Info: ++[expiration] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[logintime] returns noop
Tue Aug 31 11:12:04 2010 : Info: ++[pap] returns noop
Tue Aug 31 11:12:04 2010 : Info: Found Auth-Type = MSCHAP
Tue Aug 31 11:12:04 2010 : Info: +- entering group MS-CHAP {...}
Tue Aug 31 11:12:04 2010 : Info: [mschap] No Cleartext-Password  
configured.  Cannot create LM-Password.
Tue Aug 31 11:12:04 2010 : Info: [mschap] No Cleartext-Password  
configured.  Cannot create NT-Password.
Tue Aug 31 11:12:04 2010 : Info: [mschap] Told to do MS-CHAPv2 for  
matteo at crs4.it with NT-Password
Tue Aug 31 11:12:04 2010 : Info: [mschap] FAILED: No NT/LM-Password.   
Cannot perform authentication.
Tue Aug 31 11:12:04 2010 : Info: [mschap] FAILED: MS-CHAP2-Response is  
incorrect
Tue Aug 31 11:12:04 2010 : Info: ++[mschap] returns reject
Tue Aug 31 11:12:04 2010 : Info: Failed to authenticate the user.
} # server inner-tunnel
Tue Aug 31 11:12:04 2010 : Info: [ttls] Got tunneled reply code 3
	MS-CHAP-Error = "?E=691 R=1"
Tue Aug 31 11:12:04 2010 : Info: [ttls] Got tunneled Access-Reject
Tue Aug 31 11:12:04 2010 : Info: [eap] Handler failed in EAP/ttls
Tue Aug 31 11:12:04 2010 : Info: [eap] Failed in EAP select
Tue Aug 31 11:12:04 2010 : Info: ++[eap] returns invalid
Tue Aug 31 11:12:04 2010 : Info: Failed to authenticate the user.
Tue Aug 31 11:12:04 2010 : Info: Using Post-Auth-Type Reject
Tue Aug 31 11:12:04 2010 : Info: +- entering group REJECT {...}
Tue Aug 31 11:12:04 2010 : Info: [attr_filter.access_reject] 	expand:  
%{User-Name} -> matteo at crs4.it
Tue Aug 31 11:12:04 2010 : Debug:  attr_filter: Matched entry DEFAULT  
at line 11
Tue Aug 31 11:12:04 2010 : Info: ++[attr_filter.access_reject] returns updated
Tue Aug 31 11:12:04 2010 : Info: Delaying reject of request 5 for 1 seconds
Tue Aug 31 11:12:04 2010 : Debug: Going to the next request
Tue Aug 31 11:12:04 2010 : Debug: Waking up in 0.9 seconds.
Tue Aug 31 11:12:05 2010 : Info: Sending delayed reject for request 5
Sending Access-Reject of id 8 to 156.148.67.1 port 2051
	EAP-Message = 0x04060004
	Message-Authenticator = 0x00000000000000000000000000000000
Tue Aug 31 11:12:05 2010 : Debug: Waking up in 3.8 seconds.


file /etc/raddb/modules/mschap

mschap {
         #
         #  If you are using /etc/smbpasswd, see the 'passwd'
         #  module for an example of how to use /etc/smbpasswd

         # if use_mppe is not set to no mschap will
         # add MS-CHAP-MPPE-Keys for MS-CHAPv1 and
         # MS-MPPE-Recv-Key/MS-MPPE-Send-Key for MS-CHAPv2
         #
         #################use_mppe = no
         use_mppe = yes

         # if mppe is enabled require_encryption makes
         # encryption moderate
         #
         #require_encryption = yes

         # require_strong always requires 128 bit key
         # encryption
         #
         #require_strong = yes
         require_strong = yes

         # Windows sends us a username in the form of
         # DOMAIN\user, but sends the challenge response
         # based on only the user portion.  This hack
         # corrects for that incorrect behavior.
         #
         ############################with_ntdomain_hack = no
         with_ntdomain_hack = no
# The module can perform authentication itself, OR
         # use a Windows Domain Controller.  This configuration
         # directive tells the module to call the ntlm_auth
         # program, which will do the authentication, and return
         # the NT-Key.  Note that you MUST have "winbindd" and
         # "nmbd" running on the local machine for ntlm_auth
         # to work.  See the ntlm_auth program documentation
         # for details.
         #
         # If ntlm_auth is configured below, then the mschap
         # module will call ntlm_auth for every MS-CHAP
         # authentication request.  If there is a cleartext
         # or NT hashed password available, you can set
         # "MS-CHAP-Use-NTLM-Auth := No" in the control items,
         # and the mschap module will do the authentication itself,
         # without calling ntlm_auth.
         #
         # Be VERY careful when editing the following line!
         #
         # You can also try setting the user name as:
         #
         #       ... --username=%{mschap:User-Name} ...
         #
         # In that case, the mschap module will look at the User-Name
         # attribute, and do prefix/suffix checks in order to obtain
         # the "best" user name for the request.
         #
         #ntlm_auth = "/path/to/ntlm_auth --request-nt-key  
--username=%{%{Stripped-User-Name}:-%{User-Name:-None}}  
--challenge=%{mschap:Challenge:-00}  
--nt-response=%{mschap:NT-Response:-00}"


Any idea about it?
Thanks








----------------------------------------------------------------
This message was sent using IMP, the Internet Messaging Program.





More information about the Freeradius-Users mailing list