ttls with mschapV2 authentication problem
Could someone please take a look at the attached log file and give me a hint about how to solve the problem. Please ignore the lines beggining with ***********;I used them to debug something else previously. Thank you. Cristian Starting FreeRADIUS:FreeRADIUS Version 2.0.0, for host i686-pc-linux-gnu, built on Apr 7 2008 at 15:56:51 Copyright (C) 1999-2008 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License. Starting - reading configuration files ... including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/radiusd.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/proxy.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/clients.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/snmp.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/eap.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/sql.conf including configuration file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/sql/mysql/dialup.conf including dictionary file /udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/dictionary main { prefix = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/" localstatedir = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var" logdir = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius" libdir = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//lib" radacctdir = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 allow_core_dumps = no pidfile = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/run/radiusd/radiusd.pid" checkrad = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//sbin/checkrad" debug_level = 0 proxy_requests = yes security { max_attributes = 200 reject_delay = 1 status_server = no } log_auth = yes log_auth_badpass = yes log_auth_goodpass = yes log_stripped_names = no log_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius/radius.log" } client 127.0.0.1 { require_message_authenticator = no secret = "testing123" shortname = "localhost" nastype = "other" } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = yes dead_time = 120 wake_all_if_all_dead = no } realm asb.com { authhost = LOCAL accthost = LOCAL } realm LOCAL { authhost = LOCAL accthost = LOCAL } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = yes input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating expr } radiusd: #### Loading Virtual Servers #### server { modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating pap pap { encryption_scheme = "crypt" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating chap Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no } Module: Linked to module rlm_unix Module: Instantiating unix unix { radwtmp = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating eap eap { default_eap_type = "ttls" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 pem_file_type = yes private_key_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//etc/raddb/certs/NEW/server-key.pem" certificate_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//etc/raddb/certs/NEW/server.pem" CA_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//etc/raddb/certs/NEW/ca-cert.pem" private_key_password = "asb#1234" dh_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//etc/raddb/certs/NEW/dh" random_file = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//etc/raddb/certs/NEW/random" fragment_size = 1024 include_length = yes check_crl = yes } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = yes } Module: Linked to sub-module rlm_eap_sim Module: Instantiating eap-sim Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating preprocess preprocess { huntgroups = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/huntgroups" hints = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } Module: Linked to module rlm_realm Module: Instantiating suffix realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating files files { usersfile = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/users" acctusersfile = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/acct_users" preproxy_usersfile = "/udir/novac/FREERADIUS_WIMAX_INSTALLED/etc/raddb/preproxy_users" compat = "no" } ************************************** cp after=000000100104a501 *********************subattr_name=PacketDataFlowID *********************subattr_value=0083 ************************************* da->attr=1 *********************subattr_name=ServiceDataFlowID *********************subattr_value=0083 ************************************* da->attr=2 *********************subattr_name=Direction *********************subattr_value=03 ************************************* da->attr=4 *********************subattr_name=ActivationTrigger *********************subattr_value=04 ************************************* da->attr=5 *********************subattr_name=TransportType *********************subattr_value=01 ************************************* da->attr=6 *********************subattr_name=UplinkQosID *********************subattr_value=83 ************************************* da->attr=7 *********************subattr_name=DownlinkQoSID *********************subattr_value=84 ************************************* da->attr=8 ************************************** cp after=000104008302040083040303050304060301070383080384 *********************subattr_name=QoSID *********************subattr_value=83 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=02 ************************************* da->attr=4 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=000F4000 ************************************* da->attr=6 *********************subattr_name=MediaFlowType *********************subattr_value=02 ************************************* da->attr=12 ************************************** cp after=800103830403020606000F40000c0302 *********************subattr_name=QoSID *********************subattr_value=84 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=02 ************************************* da->attr=4 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=001F4000 ************************************* da->attr=6 *********************subattr_name=MediaFlowType *********************subattr_value=02 ************************************* da->attr=12 ************************************** cp after=000103840403020606001F40000c0302 ************************************** cp after=0001041111040303050304060301070311 ************************************** cp after=000103110403060706000fa0000906000000140a06000000140c03010d040014 ************************************** cp after=0001041111040303050304060301070312 ************************************** cp after=000103120403060706002ee3e80906000000140a06000000140c03010d040014 ************************************** cp after=800104008302040083040303050304060301070383080384 ************************************** cp after=0001041111040303050304060301070312 ************************************** cp after=800103830403020606000F40000c0302 ************************************** cp after=800103840403020606001F40000c0302 ************************************** cp after=000103120403060706002ee3e80906000000140a06000000140c03010d040014 ************************************** cp after=0001041112040303050304060301070313080314 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 ************************************** cp after=000103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 *********************subattr_name=PacketDataFlowID *********************subattr_value=1112 ************************************* da->attr=1 *********************subattr_name=Direction *********************subattr_value=03 ************************************* da->attr=4 *********************subattr_name=ActivationTrigger *********************subattr_value=04 ************************************* da->attr=5 *********************subattr_name=TransportType *********************subattr_value=01 ************************************* da->attr=6 *********************subattr_name=UplinkQosID *********************subattr_value=13 ************************************* da->attr=7 *********************subattr_name=DownlinkQoSID *********************subattr_value=14 ************************************* da->attr=8 ************************************** cp after=8001041112040303050304060301070313080314 *********************subattr_name=PacketDataFlowID *********************subattr_value=0083 ************************************* da->attr=1 *********************subattr_name=ServiceDataFlowID *********************subattr_value=0083 ************************************* da->attr=2 *********************subattr_name=Direction *********************subattr_value=03 ************************************* da->attr=4 *********************subattr_name=ActivationTrigger *********************subattr_value=04 ************************************* da->attr=5 *********************subattr_name=TransportType *********************subattr_value=01 ************************************* da->attr=6 *********************subattr_name=UplinkQosID *********************subattr_value=83 ************************************* da->attr=7 *********************subattr_name=DownlinkQoSID *********************subattr_value=84 ************************************* da->attr=8 ************************************** cp after=000104008302040083040303050304060301070383080384 *********************subattr_name=QoSID *********************subattr_value=13 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=05 ************************************* da->attr=4 *********************subattr_name=TrafficPriority *********************subattr_value=03 ************************************* da->attr=5 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=000fa000 ************************************* da->attr=6 *********************subattr_name=MinimumReservedTrafficRate *********************subattr_value=0007d000 ************************************* da->attr=7 *********************subattr_name=ToleratedJitter *********************subattr_value=0000000a ************************************* da->attr=9 *********************subattr_name=MaximumLatency *********************subattr_value=00000014 ************************************* da->attr=10 *********************subattr_name=MediaFlowType *********************subattr_value=80 ************************************* da->attr=12 *********************subattr_name=UnsolicitedGrantInterval *********************subattr_value=0014 ************************************* da->attr=13 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 *********************subattr_name=QoSID *********************subattr_value=14 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=05 ************************************* da->attr=4 *********************subattr_name=TrafficPriority *********************subattr_value=03 ************************************* da->attr=5 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=002ee3e8 ************************************* da->attr=6 *********************subattr_name=MinimumReservedTrafficRate *********************subattr_value=000fa000 ************************************* da->attr=7 *********************subattr_name=ToleratedJitter *********************subattr_value=0000000a ************************************* da->attr=9 *********************subattr_name=MaximumLatency *********************subattr_value=00000014 ************************************* da->attr=10 *********************subattr_name=MediaFlowType *********************subattr_value=80 ************************************* da->attr=12 ************************************** cp after=800103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 *********************subattr_name=QoSID *********************subattr_value=83 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=02 ************************************* da->attr=4 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=000F4000 ************************************* da->attr=6 *********************subattr_name=MediaFlowType *********************subattr_value=02 ************************************* da->attr=12 ************************************** cp after=800103830403020606000F40000c0302 *********************subattr_name=QoSID *********************subattr_value=84 ************************************* da->attr=1 *********************subattr_name=ScheduleType *********************subattr_value=02 ************************************* da->attr=4 *********************subattr_name=MaximumSustainedTrafficRate *********************subattr_value=001F4000 ************************************* da->attr=6 *********************subattr_name=MediaFlowType *********************subattr_value=02 ************************************* da->attr=12 ************************************** cp after=000103840403020606001F40000c0302 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070312 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 ************************************** cp after=800103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 ************************************** cp after=000103120403060706002ee3e80906000000140a06000000140c03010d040014 ************************************** cp after=8001041111040303050304060301070312 ************************************** cp after=0001041112040303050304060301070313080314 ************************************** cp after=800103120403060706000fa0000906000000140a06000000140c03010d040014 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 ************************************** cp after=000103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070312 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 ************************************** cp after=800103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 ************************************** cp after=000103120403060706002ee3e80906000000140a06000000140c03010d040014 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070311 ************************************** cp after=800103130403050503030606000fa00007060007d00009060000000a0a06000000140c03800d040014 ************************************** cp after=800103140403050503030606002ee3e80706000fa00009060000000a0a06000000140c0380 ************************************** cp after=000103110403060706000fa0000906000000140a06000000140c03010d040014 ************************************** cp after=0001041112040303050304060301070313080314 ************************************** cp after=8001031304030305030107060003e8000c0382 ************************************** cp after=0001031404030305030107060007d0000c0382 ************************************** cp after=0001041112040303050304060301070313080314 ************************************** cp after=8001031304030305030106060007d00007060007d0000c0382 ***************** Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating detail detail { detailfile = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_radutmp Module: Instantiating radutmp radutmp { filename = "/udir/novac/FREERADIUS_WIMAX_INSTALLED//var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load } } radiusd: #### Opening IP addresses and Ports #### bind_address = * WARNING: The directive 'bind_adress' is deprecated, and will be removed in future versions of FreeRADIUS. Please edit the configuration files to use the directive 'listen'. Listening on authentication address * port 1812 Listening on accounting address * port 1813 Ready to process requests. ********************* cp after=000103140403030503010606000fa0000706000fa0000c0382 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070312 ************************************** cp after=8001031304030305030106060007d00007060007d0000c0382 ************************************** cp after=800103140403030503010606000fa0000706000fa0000c0382 ************************************** cp after=000103120403060706002ee3e80906000000140a06000000140c03010d040014 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=000104008302040083040303050304060301070383080384 ************************************** cp after=8001031304030305030106060007d00007060007d0000c0382 ************************************** cp after=800103140403030503010606000fa0000706000fa0000c0382 ************************************** cp after=800103830403020606000F40000c0302 ************************************** cp after=000103840403020606001F40000c0302 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070311 ************************************** cp after=8001031304030305030106060007d00007060007d0000c0382 ************************************** cp after=800103140403030503010606000fa0000706000fa0000c0382 ************************************** cp after=000103110403060706000fa0000906000000140a06000000140c03010d040014 ************************************** cp after=0001041112040303050304060301070313080314 ************************************** cp after=800103130403040503020606000FA00007060007d0000a06000000640c03810f040032 ************************************** cp after=000103140403040503020606001f40000706000fa0000a06000000640c0381 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=000104008302040083040303050304060301070383080384 ************************************** cp after=800103130403040503020606000FA00007060007d0000a06000000640c03810f040032 ************************************** cp after=800103140403040503020606001f40000706000fa0000a06000000640c0381 ************************************** cp after=800103830403020606000F40000c0302 ************************************** cp after=000103840403020606001F40000c0302 ************************************** cp after=8001041112040303050304060301070313080314 ************************************** cp after=0001041111040303050304060301070311 ************************************** cp after=800103130403040503020606000FA00007060007d0000a06000000640c03810f040032 ************************************** cp after=800103140403040503020606001f40000706000fa0000a06000000640c0381 ************************************** cp after=800103140403030503010606000fa0000706000fa0000c0382 ************************************** cp after=000103110403060706000fa0000906000000140a06000000140c03010d040014 rad_recv: Access-Request packet from host 127.0.0.1 port 32776, id=24, length=166 QoSID = 0x616e6f6e796d6f7573406173622e636f6d ScheduleType = 0x7f000001 TrafficPriority = 0x00000000 Called-Station-Id = "00-00-00-00-00-00:" Calling-Station-Id = "00-13-49-C3-C5-30" MediaFlowType = 0x00000578 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 0Mbps 802.11" EAP-Message = 0x0206001601616e6f6e796d6f7573406173622e636f6d Message-Authenticator = 0xf3763cb9e2245f701f5e645477aabcaf +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "anonymous" rlm_realm: Proxying request from user anonymous to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: EAP packet type response id 6 length 22 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated users: Matched entry DEFAULT at line 367 ++[files] returns ok rad_check_password: Found Auth-Type EAP auth: type "EAP" +- entering group authenticate rlm_eap: EAP Identity rlm_eap: processing type tls rlm_eap_tls: Initiate rlm_eap_tls: Start returned 1 ************************************** cp after=00 ++[eap] returns handled Sending Access-Challenge of id 24 to 127.0.0.1 port 32776 EAP-Message = 0x010700061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd99b9956d99c8c9338d70856535d0709 Finished request 0. Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 32776, id=25, length=270 QoSID = 0x616e6f6e796d6f7573406173622e636f6d ScheduleType = 0x7f000001 TrafficPriority = 0x00000000 Called-Station-Id = "00-00-00-00-00-00:" Calling-Station-Id = "00-13-49-C3-C5-30" MediaFlowType = 0x00000578 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 0Mbps 802.11" EAP-Message = 0x0207006c150016030100610100005d030147fe1bbab68ca66dcea8ffe3050798e1c791305d5ae8f844fdbc6e511d8f397b00003600390038003500160013000a00330032002f0007006600050004006300620061001500120009006500640060001400110008000600030100 State = 0xd99b9956d99c8c9338d70856535d0709 Message-Authenticator = 0x5bb8fdd1fbfce657f4bbe925da19f5d8 +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "anonymous" rlm_realm: Proxying request from user anonymous to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: EAP packet type response id 7 length 108 rlm_eap: Continuing tunnel setup. ++[eap] returns ok users: Matched entry DEFAULT at line 367 ++[files] returns ok rad_check_password: Found Auth-Type EAP auth: type "EAP" +- entering group authenticate 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 eaptls_verify returned 7 rlm_eap_tls: Done initial handshake (other): before/accept initialization TLS_accept: before/accept initialization rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], 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 0438], Certificate TLS_accept: SSLv3 write certificate A rlm_eap_tls: >>> TLS 1.0 Handshake [length 010d], ServerKeyExchange TLS_accept: SSLv3 write key exchange 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 ************************************** cp after=00 ++[eap] returns handled Sending Access-Challenge of id 25 to 127.0.0.1 port 32776 EAP-Message = 0x0108040015c0000005a7160301004a02000046030147fe2bba6ed4e4b07672c2d9e9a788f26f123361e05d0d848f15f9717cf8f9a1208d6a2ccc9a237ba766409902c3ae2355bbcec3fee2c7aadb84db3a289bf564b600390016030104380b000434000431000218308202143082017d020105300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d3037313131393038303533305a170d3038313131383038303533305a3055310b3009060355 EAP-Message = 0x040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b13037264723110300e060355040313076173622e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100b0634f379d38220d960a6f7c80abd51a2b7a9cac830613ec665fae7c1ca6215b60ea222142e7c6832c6d344dae7bc5cc3385db768824fbc63c93bfe9c79af932248380799e7f7bbb1ad953ac64adf590f2af0d02a5440e7a67769c92fcb74b4e20cb6776513eb13297599961c1be81ec0c6633ef709da026e96feebe5d0ab5e70203010001300d06092a864886f70d010104 EAP-Message = 0x05000381810069e6b80739a38b06b15a28ace28510b0fc9a26d291c4b9ab9102bc349827197bce7bf4d3bca49e5a5bc61da2b1d9f96e504a469deaf4cf1d915b844f8506ccdd9e995654aafca0e93598b19ab21667ecb40617b4a0e80816a89e3924aeb0c53d93dad0a14e8c678197708ad92f1769673a4499d5ec811a090253bf18df6dd5b50002133082020f30820178020100300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d30373131 EAP-Message = 0x31393038303433315a170d3038313131383038303433315a3050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b300906035504031302636130819f300d06092a864886f70d010101050003818d0030818902818100dc70ad4fc5351431abb49e7f58f1d25e90634ea6dcb7f5f440ac2059ccb4d5b47a0c6c1c62014d96c48cb295344fa36bea1dfeb171dab4aa2238087937ac41e513c49af623af2ab3170628cb1d954fdc4587171caae000e325620f5d35aee55712d8f28af71e1be41bed4970bc00c4320a3208bae176 EAP-Message = 0x2d816730040ada827c0d0203 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd99b9956d8938c9338d70856535d0709 Finished request 1. Going to the next request Waking up in 0.4 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 32776, id=26, length=168 QoSID = 0x616e6f6e796d6f7573406173622e636f6d ScheduleType = 0x7f000001 TrafficPriority = 0x00000000 Called-Station-Id = "00-00-00-00-00-00:" Calling-Station-Id = "00-13-49-C3-C5-30" MediaFlowType = 0x00000578 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 0Mbps 802.11" EAP-Message = 0x020800061500 State = 0xd99b9956d8938c9338d70856535d0709 Message-Authenticator = 0xc4dcb0d4e3790f0746b2ec8c71a5e87b +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "anonymous" rlm_realm: Proxying request from user anonymous to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: EAP packet type response id 8 length 6 rlm_eap: Continuing tunnel setup. ++[eap] returns ok users: Matched entry DEFAULT at line 367 ++[files] returns ok rad_check_password: Found Auth-Type EAP auth: type "EAP" +- entering group authenticate 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: Received EAP-TLS ACK message rlm_eap_tls: ack handshake fragment handler eaptls_verify returned 1 eaptls_process returned 13 ************************************** cp after=00 ++[eap] returns handled Sending Access-Challenge of id 26 to 127.0.0.1 port 32776 EAP-Message = 0x010901bb1580000005a7010001300d06092a864886f70d010104050003818100321f6dace1aa2f6e55d16f64eb6363393119b3da5c41a7127c7b46e0931d115b6ecb9f52a33868ab8e969dc418740767936cb9f9da02837b868ba824fcad2df8fe3a2fe5cff8dac483603ce312e0218bb93681b208d15fe55ac185416d56696c75d5dd0d8981f3b49962b3b23608fd7010e0ccd32501a7240ec82973066c7332160301010d0c0001090040ea491ab5e523f0f500b96463241287517f2ef085934a4977d6d7484bdfd4dadf7eb552b0e7e3154925eea5c6ad362d72e39a694dfaf9a0bc58dc18aa0e638f0b0001020040426ffc359de2c9fb9cda60c1a0 EAP-Message = 0x1e0f0118e8484519c0c5217adc8de0ad1c4a20370cbb0bb1cc0244dd354d745a6f396a0c9393cdb00a94538430cc727025f0c6008049828458e7b9472e0ab564e98b260c10dfe4e722b7825489fbd0502af8c05938ebe39d9cb1d351806ee994e83bb0e32b2992e4ace4770094caab3902c27b6a46a4d635919a384ac3623f83d24d33744fd760579d2eea4b3a413daacc60fde5514c671391956bc15e901cb0e39d12aa23ab2c7036ba7ca1f3ab7be97edcb0787916030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd99b9956db928c9338d70856535d0709 Finished request 2. Going to the next request Waking up in 0.5 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 32776, id=27, length=302 QoSID = 0x616e6f6e796d6f7573406173622e636f6d ScheduleType = 0x7f000001 TrafficPriority = 0x00000000 Called-Station-Id = "00-00-00-00-00-00:" Calling-Station-Id = "00-13-49-C3-C5-30" MediaFlowType = 0x00000578 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 0Mbps 802.11" EAP-Message = 0x0209008c1500160301004610000042004055b5552282f3e2b403cb95ebafe1775d9745c1e28caffe410d0c9ddcb53215c48fb9fe4089571488886d206d0b6d1477f96e41f60ce4c571db632263859d5ac21403010001011603010030d9d62590005656c6a68b85a81bf3372ce074b399ad3cd901e6c01c8843cad950a8331ac521da18d1a058cab3db826059 State = 0xd99b9956db928c9338d70856535d0709 Message-Authenticator = 0xe8bb979b6e4487cddab43e461cd5c3f1 +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "anonymous" rlm_realm: Proxying request from user anonymous to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: EAP packet type response id 9 length 140 rlm_eap: Continuing tunnel setup. ++[eap] returns ok users: Matched entry DEFAULT at line 367 ++[files] returns ok rad_check_password: Found Auth-Type EAP auth: type "EAP" +- entering group authenticate 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 eaptls_verify returned 7 rlm_eap_tls: Done initial handshake rlm_eap_tls: <<< TLS 1.0 Handshake [length 0046], 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 ************************************** cp after=00 ++[eap] returns handled Sending Access-Challenge of id 27 to 127.0.0.1 port 32776 EAP-Message = 0x010a004515800000003b1403010001011603010030ceb5957b02c100e31eafcd91a62160c6e280c309e3a1801a96b773674452e84573dbd2282b5a76864615e85fded34ad8 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd99b9956da918c9338d70856535d0709 Finished request 3. Going to the next request Waking up in 0.2 seconds. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 32776, id=28, length=354 QoSID = 0x616e6f6e796d6f7573406173622e636f6d ScheduleType = 0x7f000001 TrafficPriority = 0x00000000 Called-Station-Id = "00-00-00-00-00-00:" Calling-Station-Id = "00-13-49-C3-C5-30" MediaFlowType = 0x00000578 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 0Mbps 802.11" EAP-Message = 0x020a00c01500170301002075b9ecb64bd478294e53d8974b9ab6b2aba82994aba94cca4813de38d98024551703010090a547448c7e85c24c6646e4267961917e069b4bda8568ea3889ba39dd3d44c68c3f60d9f216eb82411fe73d0285efbf28f250ee44c8ad9234f044ef3bbaecf04b813f66919dac8330989a6ced5fcfaac5f64958daf0cae184eef6a8574ac94d92b974e64f7448d93536ec41cb47520c7570bcd4958c9307fff13264755078051c890d65009dbf1c3c53306ec07db630b6 State = 0xd99b9956da918c9338d70856535d0709 Message-Authenticator = 0x6c4cd222e98a1db76a3b564e93301450 +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "anonymous" rlm_realm: Proxying request from user anonymous to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: EAP packet type response id 10 length 192 rlm_eap: Continuing tunnel setup. ++[eap] returns ok users: Matched entry DEFAULT at line 367 ++[files] returns ok rad_check_password: Found Auth-Type EAP auth: type "EAP" +- entering group authenticate 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 eaptls_verify returned 7 rlm_eap_tls: Done initial handshake eaptls_process returned 7 rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes. +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop rlm_mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok rlm_realm: Looking up realm "asb.com" for User-Name = "ERTVR_BE@asb.com" rlm_realm: Found realm "asb.com" rlm_realm: Adding Stripped-User-Name = "ERTVR_BE" rlm_realm: Proxying request from user ERTVR_BE to realm asb.com rlm_realm: Adding Realm = "asb.com" rlm_realm: Authentication realm is LOCAL. ++[suffix] returns noop rlm_eap: No EAP-Message, not doing EAP ++[eap] returns noop WARNING: Found User-Password == "...". WARNING: Are you sure you don't mean Cleartext-Password? WARNING: See "man rlm_pap" for more information. users: Matched entry ERTVR_BE at line 146 ++[files] returns ok rad_check_password: Found Auth-Type mschap auth: type "MSCHAP" +- entering group MS-CHAP rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password. rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password. rlm_mschap: Told to do MS-CHAPv2 for ERTVR_BE@asb.com with NT-Password rlm_mschap: FAILED: No NT/LM-Password. Cannot perform authentication. rlm_mschap: FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject auth: Failed to validate the user. Login incorrect: [ERTVR_BE@asb.com/<via Auth-Type = mschap>] (from client localhost port 0 cli 00-13-49-C3-C5-30) TTLS: Got tunneled Access-Reject rlm_eap: Handler failed in EAP/ttls rlm_eap: Failed in EAP select ++[eap] returns invalid auth: Failed to validate the user. Login incorrect: [anonymous@asb.com/<via Auth-Type = EAP>] (from client localhost port 0 cli 00-13-49-C3-C5-30) Delaying reject of request 4 for 1 seconds Going to the next request Waking up in 0.2 seconds. Waking up in 0.3 seconds. Waking up in 0.3 seconds. Sending delayed reject for request 4 Sending Access-Reject of id 28 to 127.0.0.1 port 32776 EAP-Message = 0x040a0004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 2.3 seconds. Cleaning up request 0 ID 24 with timestamp +6 Waking up in 0.5 seconds. Cleaning up request 1 ID 25 with timestamp +6 Waking up in 0.3 seconds. Cleaning up request 2 ID 26 with timestamp +6 Waking up in 0.3 seconds. Cleaning up request 3 ID 27 with timestamp +7 Waking up in 1.3 seconds. Cleaning up request 4 ID 28 with timestamp +7 Ready to process requests.
Could someone please take a look at the attached log file and give me a hint about how to solve the problem. Please ignore the lines beggining with ***********;I used them to debug something else previously.
Thank you. Cristian
WARNING: Found User-Password == "...". WARNING: Are you sure you don't mean Cleartext-Password? WARNING: See "man rlm_pap" for more information. users: Matched entry ERTVR_BE at line 146 ++[files] returns ok .. rad_check_password: Found Auth-Type mschap auth: type "MSCHAP" +- entering group MS-CHAP rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password. rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password. rlm_mschap: Told to do MS-CHAPv2 for ERTVR_BE@asb.com with NT-Password rlm_mschap: FAILED: No NT/LM-Password. Cannot perform authentication. rlm_mschap: FAILED: MS-CHAP2-Response is incorrect Debug is quite clear about what's wrong. You are using a wrong password attribute. Ivan Kalik Kalik Informatika ISP
Cristian Novac wrote:
Could someone please take a look at the attached log file and give me a hint about how to solve the problem.
The log file tells you how to solve the problem: WARNING: Found User-Password == "...". WARNING: Are you sure you don't mean Cleartext-Password? WARNING: See "man rlm_pap" for more information. users: Matched entry ERTVR_BE at line 146 ++[files] returns ok rad_check_password: Found Auth-Type mschap auth: type "MSCHAP" +- entering group MS-CHAP rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password. rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password. rlm_mschap: Told to do MS-CHAPv2 for ERTVR_BE@asb.com with NT-Password rlm_mschap: FAILED: No NT/LM-Password. Cannot perform authentication. rlm_mschap: FAILED: MS-CHAP2-Response is incorrect What are the "users" entries at lines 146 and 367? Fix the correct one to set Cleartext-Password with := e.g. username Cleartext-Password := "password"
Thanks for your advices! It works fine now. I was using an older version(1.0.1) of radius before and ttls with mschapV2 authentication seemed to go fine, even if I was using "==" operator instead of ":=" Anyway, it is ok now. Thanks again Phil Mayers wrote:
Cristian Novac wrote:
Could someone please take a look at the attached log file and give me a hint about how to solve the problem.
The log file tells you how to solve the problem:
WARNING: Found User-Password == "...". WARNING: Are you sure you don't mean Cleartext-Password? WARNING: See "man rlm_pap" for more information. users: Matched entry ERTVR_BE at line 146 ++[files] returns ok rad_check_password: Found Auth-Type mschap auth: type "MSCHAP" +- entering group MS-CHAP rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password. rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password. rlm_mschap: Told to do MS-CHAPv2 for ERTVR_BE@asb.com with NT-Password rlm_mschap: FAILED: No NT/LM-Password. Cannot perform authentication. rlm_mschap: FAILED: MS-CHAP2-Response is incorrect
What are the "users" entries at lines 146 and 367? Fix the correct one to set Cleartext-Password with := e.g.
username Cleartext-Password := "password" - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (3)
-
Cristian Novac -
Ivan Kalik -
Phil Mayers