EAP-TTLS with mschapv2 inner authentication issue

Tue, 31 Aug 2010 02:27:44 -0700 

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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 = "mat...@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 mat...@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} -> mat...@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.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

Reply via email to