PEAP/MS-CHAPv2 issue: mschap verified successful, but peap got no responses.

(others keywords: ActiveDirectory, Active Directory, AD, winbind, samba, eap.conf, peap, mschap) Hi FreeRARIUS gurus, I was implementing FreeRADIUS solution integrated with AD environment by using Samba/Winbind. EAP/TLS works, but not PEAP/MSCHAPv2, in that peap module is waiting for something after ntlm_auth returns success. I tested kinit/wbinfo/ntlm_auth individually, and they all works. I they tried all the ways (modifying around in /etc/raddb) came into my mind before I decided to ask help from freeradius mailling-list. I also tried with incorrect domain credentials, and the freeradius successfully rejected, whereas the correct could not successfully pass. I don't know if I misunderstand anything about freeradius configuration, so I post the log here. It would be appreciated if somebody here could give me a hand. Many Thanks, Eric Version: FreeRADIUS 2.1.6 AD box: MS Windows 2003 Radius box: OpenSUSE 11.2 Switch: Cisco 2950 Test Clients: WinXP(SP3) The following messages are copied from /var/log/radius.log: group = radiusd user = radiusd including dictionary file /etc/raddb/dictionary main { prefix = "/usr" localstatedir = "/var" logdir = "/var/log/radius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 allow_core_dumps = no pidfile = "/var/run/radiusd/radiusd.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no log { stripped_names = no auth = yes auth_badpass = yes auth_goodpass = yes } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = "testing123" response_window = 20 max_outstanding = 65536 require_message_authenticator = no zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 num_answers_to_alive = 3 num_pings_to_alive = 3 revive_interval = 120 status_check_timeout = 4 irt = 2 mrt = 16 mrc = 5 mrd = 30 } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client 10.6.10.4 { require_message_authenticator = no secret = "test" shortname = "10.6.10.4" nastype = "cisco" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating expr Module: Linked to module rlm_expiration Module: Instantiating expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server inner-tunnel { modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --domain=%{mschap:NT-Domain} --username=%{mschap:User-Name} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}" } Module: Linked to module rlm_eap Module: Instantiating eap eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 2048 } 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 = "/etc/raddb/certs/MyCerts/server.key" certificate_file = "/etc/raddb/certs/MyCerts/server.pem" CA_file = "/etc/raddb/certs/MyCerts/ca.pem" private_key_password = "testing123" dh_file = "/etc/raddb/certs/MyCerts/dh" random_file = "/dev/urandom" fragment_size = 1024 include_length = yes check_crl = no make_cert_command = "/etc/raddb/certs/MyCerts/bootstrap" cache { enable = no lifetime = 24 max_entries = 255 } } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes } 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: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating radutmp radutmp { filename = "/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_attr_filter Module: Instantiating attr_filter.access_reject attr_filter attr_filter.access_reject { attrsfile = "/etc/raddb/attrs.access_reject" key = "%{User-Name}" } } # modules } # server server { modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating preprocess preprocess { huntgroups = "/etc/raddb/huntgroups" hints = "/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: 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 = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Instantiating attr_filter.accounting_response attr_filter attr_filter.accounting_response { attrsfile = "/etc/raddb/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server thread pool { start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 0 cleanup_delay = 5 max_queue_size = 65536 } Thread spawned new child 1. Total threads in pool: 1 Thread 1 waiting to be assigned a request Thread spawned new child 2. Total threads in pool: 2 Thread 2 waiting to be assigned a request Thread spawned new child 3. Total threads in pool: 3 Thread 3 waiting to be assigned a request Thread spawned new child 4. Total threads in pool: 4 Thread 4 waiting to be assigned a request Thread spawned new child 5. Total threads in pool: 5 Thread 5 waiting to be assigned a request Thread pool initialized radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 0 Failed binding to socket: Address already in use /etc/raddb/radiusd.conf[240]: Error binding to port for 0.0.0.0 port 1812 Waking up in 0.9 seconds. Thread 1 got semaphore Thread 1 handling request 8, (2 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 0 length 18 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Finished request 8. Going to the next request Thread 1 waiting to be assigned a request Waking up in 0.9 seconds. Thread 5 got semaphore Thread 5 handling request 9, (2 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 1 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 70 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 0041], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 0a8f], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Finished request 9. Going to the next request Thread 5 waiting to be assigned a request Waking up in 0.9 seconds. Thread 4 got semaphore Thread 4 handling request 10, (3 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 2 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Finished request 10. Going to the next request Thread 4 waiting to be assigned a request Waking up in 0.9 seconds. Thread 3 got semaphore Thread 3 handling request 11, (3 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 3 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Finished request 11. Going to the next request Thread 3 waiting to be assigned a request Waking up in 0.9 seconds. Thread 2 got semaphore Thread 2 handling request 12, (3 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 4 length 192 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 182 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Finished request 12. Going to the next request Thread 2 waiting to be assigned a request Waking up in 0.9 seconds. Thread 1 got semaphore Thread 1 handling request 13, (3 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS ++[eap] returns handled Finished request 13. Going to the next request Thread 1 waiting to be assigned a request Waking up in 0.8 seconds. Thread 5 got semaphore Thread 5 handling request 14, (3 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 6 length 41 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Identity - MYDOMAIN\user2 PEAP: Got tunneled identity of MYDOMAIN\user2 PEAP: Setting default EAP type for tunneled EAP session. PEAP: Setting User-Name to MYDOMAIN\user2 +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 6 length 18 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled [peap] Got tunneled Access-Challenge ++[eap] returns handled Finished request 14. Going to the next request Thread 5 waiting to be assigned a request Waking up in 0.8 seconds. Thread 4 got semaphore Thread 4 handling request 15, (4 handled so far) +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 7 length 95 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] EAP type mschapv2 PEAP: Setting User-Name to MYDOMAIN\user2 +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 7 length 72 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Told to do MS-CHAPv2 for user2 with NT-Password [mschap] expand: --domain=%{mschap:NT-Domain} -> --domain=MYDOMAIN [mschap] expand: --username=%{mschap:User-Name} -> --username=user2 [mschap] mschap2: ab [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=482dd107d4b6071b [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=7cb8be62e4bf7ef40c1d0e858acf3c321d869149d0be4215 Exec-Program output: NT_KEY: 99EC5F817A0D1BC302A389EA28204422 Exec-Program-Wait: plaintext: NT_KEY: 99EC5F817A0D1BC302A389EA28204422 Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled [peap] Got tunneled Access-Challenge ++[eap] returns handled Finished request 15. Going to the next request Thread 4 waiting to be assigned a request Waking up in 3.8 seconds. Cleaning up request 8 ID 218 with timestamp +93 Cleaning up request 9 ID 219 with timestamp +93 Cleaning up request 10 ID 220 with timestamp +93 Cleaning up request 11 ID 221 with timestamp +93 Cleaning up request 12 ID 222 with timestamp +93 Cleaning up request 13 ID 223 with timestamp +93 Cleaning up request 14 ID 224 with timestamp +93 Waking up in 0.1 seconds. Cleaning up request 15 ID 225 with timestamp +93 Ready to process requests. Ready to process requests. Exiting normally.