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

[Wang Nan]

(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.