Hi, I downloaded git master yesterday to test the new MS-CHAPv2 change password functionality. My setup is a Cisco router with "passwd-expiry" setup with Cisco VPN client for login, with FreeRadius to Windows AD through Winbind. MS-CHAPv2 authentication works fine. Winbind and AD setup is right. But testing the new passchange functionality by selecting "User must change password at next logon" in the Windows user, the New password windows popup in Cisco VPN client, but the change password process fails: ntlm_auth said: Password-Change: No Password-Change-Error: Wrong Password . . Winbind logs also shows: NT_STATUS_WRONG_PASSWORD Looking into code I suppose the problem is something with the old NT hash, but not an expert here. Any help would be apreciated. In these logs the user is "NIMASTELECOM\testpw". The current password is "y58R41ut8W" (expired). And the new password used was "H6eEWu7r65tw38ert1". Some radius logs: === # radiusd -X radiusd: FreeRADIUS Version 3.0.0, for host x86_64-unknown-linux-gnu, built on Nov 16 2012 at 01:46:19 Copyright (C) 1999-2012 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. For more information about these matters, see the file named COPYRIGHT. Starting - reading configuration files ... ...................................... Ready to process requests. rad_recv: Access-Request packet from host 10.112.14.2 port 1645, id=127, length=202 User-Name = "NIMASTELECOM\\testpw" Calling-Station-Id = "217.126.166.195" MS-CHAP-Challenge = 0xdd2a98d3c3c69fb959df2f561d50d025 MS-CHAP2-Response = 0x01007b0896de80c7098bac5566313c61d1b200000000000000003cc2724e1d2be6d1868df97bd0607859441dc99b5ef37af0 NAS-Port-Type = Virtual Cisco-NAS-Port = "85.112.6.36" NAS-Port = 0 NAS-Port-Id = "85.112.6.36" Service-Type = Login-User NAS-IP-Address = 10.112.14.2 Event-Timestamp = "Nov 16 2012 10:39:06 CET" (0) # Executing section authorize from file /etc/raddb/sites-enabled/vpn_nimas_tk (0) group authorize { (0) - entering group authorize {...} (0) mschap-vpn_nimas_tk : Found MS-CHAP attributes. Setting 'Auth-Type = mschap-vpn_nimas_tk' (0) [mschap-vpn_nimas_tk] = ok (0) ? if (!control:Auth-Type) (0) ? Evaluating !(control:Auth-Type) -> FALSE (0) ? if (!control:Auth-Type) -> FALSE (0) detail-vpn_nimas_tk-auth : expand: /var/log/radius/radacct/vpn_nimas_tk-auth-%Y%m%d -> /var/log/radius/radacct/vpn_nimas_tk-auth-20121116 (0) detail-vpn_nimas_tk-auth : /var/log/radius/radacct/vpn_nimas_tk-auth-%Y%m%d expands to /var/log/radius/radacct/vpn_nimas_tk-auth-20121116 (0) detail-vpn_nimas_tk-auth : expand: %t -> Fri Nov 16 10:39:06 2012 (0) [detail-vpn_nimas_tk-auth] = ok (0) Found Auth-Type = MSCHAP (0) # Executing group from file /etc/raddb/sites-enabled/vpn_nimas_tk (0) group MS-CHAP { (0) - entering group MS-CHAP {...} (0) mschap-vpn_nimas_tk : Creating challenge hash with username: testpw (0) mschap-vpn_nimas_tk : Client is using MS-CHAPv2 for testpw, we need NT-Password (0) mschap-vpn_nimas_tk : expand: --username=%{mschap-vpn_nimas_tk:User-Name} -> --username=testpw (0) mschap-vpn_nimas_tk : expand: --domain=%{mschap-vpn_nimas_tk:NT-Domain} -> --domain=NIMASTELECOM (0) mschap-vpn_nimas_tk : Creating challenge hash with username: testpw (0) mschap-vpn_nimas_tk : expand: --challenge=%{mschap-vpn_nimas_tk:Challenge:-00} -> --challenge=3550f7bf5746677f (0) mschap-vpn_nimas_tk : expand: --nt-response=%{mschap-vpn_nimas_tk:NT-Response:-00} -> --nt-response=3cc2724e1d2be6d1868df97bd0607859441dc99b5ef37af0 Exec-Program output: Must change password (0xc0000224) Exec-Program-Wait: plaintext: Must change password (0xc0000224) Exec-Program: returned: 1 (0) mschap-vpn_nimas_tk : ntlm_auth says Must change password (0xc0000224) (0) [mschap-vpn_nimas_tk] = reject (0) Failed to authenticate the user. (0) Login incorrect: [NIMASTELECOM\\testpw] (from client RMADTKNIMAS01 port 0 cli 217.126.166.195) (0) Using Post-Auth-Type Reject (0) WARNING: Unknown value specified for Post-Auth-Type. Cannot perform requested action. (0) Finished request 0. Waking up in 0.9 seconds. (0) Sending delayed reject Sending Access-Reject of id 127 from 85.112.8.156 port 1812 to 10.112.14.2 port 1645 MS-CHAP-Error = "\001E=648 R=0 C=47763c0a72e4fb2d546c9a413245f87b V=3 M=Password Expired" Waking up in 4.9 seconds. (0) Cleaning up request packet ID 127 with timestamp +14 Ready to process requests. rad_recv: Access-Request packet from host 10.112.14.2 port 1645, id=128, length=755 User-Name = "NIMASTELECOM\\testpw" MS-CHAP-Challenge = 0xf42a98d3c3c69fb959df2f561d50d025 MS-CHAP2-CPW = 0x070100000000000000000000000000000000b79a22699ae1dedc832935c8f5c5d7880000000000000000b0bfd263d6c0bbc0b2b28e085c072676857cf1f7c6f88a300000 MS-CHAP-NT-Enc-PW = 0x0601000176116065c54f9ef590a62a9e5d90a75e906e19b76954e1ff0deeb5f3a5212f64e16adf48e0f1e3bb2cd3c3889dac2d67b6584725b87c28d1612fdedf8268e3af3096a2c596ea8efb16697a10b5e726a86e457a84669c6ec82cfc67a301ff9d329b0ef45b96084d099823105412e0779971079efc9260b6ab1805df81b10f3fa65d4aa859beeaae01f0a2311f51bfc9c84f0168b595fa80273b6a08180e83ec63f03a6face5015ccb52114017 MS-CHAP-NT-Enc-PW = 0x060100025ddd392405df3b0952a11ad2158f1c26398cdd6f2eb4be40607ff1fe81fc1e4f335e9b1a8a8a4a081f4b6834fe8e8d024ae1c80da758057f9505f8dff2a0211dd68d67fea4cb6de33f582be526fb0698669878264cb7ab61883a4caa4e4bc60f5421496218319c3ad4c0210383edc4daf25f43a55002d8014c287659c32cdbc6a43e0dc01c2c2effc7aa43267a0cf5c2100b4d25de0408559dd012496716837562ff79032b2f1671cd85d582 MS-CHAP-NT-Enc-PW = 0x060100030c2cb9971bac6562e7e0615b9d89c703e7bbd4e0765af7c420590cd3b6d0149ab90d95b03f56e543759da80aea68ca44bf4b7514a1f2550fa2be6571c1639fd67738d2351a248f43f7ce4e1c552cf769416be4b6b78e7c1f49b32e5f2b7421acebab117a2009ccb87e0170cd30b31024a331920c5c2891a939ec22061af7fad85140a0bd99e89c3c6d56a3e9eb3a8025d5ef968ba7523c78f11bb43cd49936d2b28d289788d164b507a76fb6 NAS-Port-Type = Virtual Cisco-NAS-Port = "85.112.6.36" NAS-Port = 0 NAS-Port-Id = "85.112.6.36" Service-Type = Login-User NAS-IP-Address = 10.112.14.2 Event-Timestamp = "Nov 16 2012 10:39:20 CET" (1) # Executing section authorize from file /etc/raddb/sites-enabled/vpn_nimas_tk (1) group authorize { (1) - entering group authorize {...} (1) mschap-vpn_nimas_tk : Found MS-CHAP attributes. Setting 'Auth-Type = mschap-vpn_nimas_tk' (1) [mschap-vpn_nimas_tk] = ok (1) ? if (!control:Auth-Type) (1) ? Evaluating !(control:Auth-Type) -> FALSE (1) ? if (!control:Auth-Type) -> FALSE (1) detail-vpn_nimas_tk-auth : expand: /var/log/radius/radacct/vpn_nimas_tk-auth-%Y%m%d -> /var/log/radius/radacct/vpn_nimas_tk-auth-20121116 (1) detail-vpn_nimas_tk-auth : /var/log/radius/radacct/vpn_nimas_tk-auth-%Y%m%d expands to /var/log/radius/radacct/vpn_nimas_tk-auth-20121116 (1) detail-vpn_nimas_tk-auth : expand: %t -> Fri Nov 16 10:39:20 2012 (1) [detail-vpn_nimas_tk-auth] = ok (1) Found Auth-Type = MSCHAP (1) # Executing group from file /etc/raddb/sites-enabled/vpn_nimas_tk (1) group MS-CHAP { (1) - entering group MS-CHAP {...} (1) mschap-vpn_nimas_tk : MS-CHAPv2 password change request received (1) mschap-vpn_nimas_tk : Password change payload valid (1) mschap-vpn_nimas_tk : Doing MS-CHAPv2 password change via ntlm_auth helper (1) mschap-vpn_nimas_tk : expand: username: %{mschap-vpn_nimas_tk:User-Name} -> username: testpw (1) mschap-vpn_nimas_tk : expand: nt-domain: %{mschap-vpn_nimas_tk:NT-Domain} -> nt-domain: NIMASTELECOM (1) mschap-vpn_nimas_tk : ntlm_auth said: Password-Change: No Password-Change-Error: Wrong Password . . (1) mschap-vpn_nimas_tk : ntlm auth password change failed: Password-Change-Error: Wrong Password (1) mschap-vpn_nimas_tk : Password change failed (1) [mschap-vpn_nimas_tk] = reject (1) Failed to authenticate the user. (1) Login incorrect: [NIMASTELECOM\\testpw] (from client RMADTKNIMAS01 port 0) (1) Using Post-Auth-Type Reject (1) WARNING: Unknown value specified for Post-Auth-Type. Cannot perform requested action. (1) Finished request 1. Waking up in 0.2 seconds. Waking up in 0.7 seconds. (1) Sending delayed reject Sending Access-Reject of id 128 from 85.112.8.156 port 1812 to 10.112.14.2 port 1645 MS-CHAP-Error = "\001E=709 R=0 M=Password change failed" Waking up in 4.9 seconds. (1) Cleaning up request packet ID 128 with timestamp +28 Ready to process requests. === The mschap derived module is simple: === mschap mschap-vpn_nimas_tk { with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{mschap-vpn_nimas_tk:User-Name} --domain=%{mschap-vpn_nimas_tk:NT-Domain} --challenge=%{mschap-vpn_nimas_tk:Challenge:-00} --nt-response=%{mschap-vpn_nimas_tk:NT-Response:-00}" passchange { ntlm_auth = "/usr/bin/ntlm_auth -d 10 -l /var/log/samba --helper-protocol=ntlm-change-password-1" ntlm_auth_username = "username: %{mschap-vpn_nimas_tk:User-Name}" ntlm_auth_domain = "nt-domain: %{mschap-vpn_nimas_tk:NT-Domain}" retry_msg = "Re-enter (or reset) the password" } === Winbind logs: === [2012/11/16 10:39:06.810639, 6] winbindd/winbindd.c:794(new_connection) accepted socket 25 [2012/11/16 10:39:06.810793, 10] winbindd/winbindd.c:644(process_request) process_request: request fn INTERFACE_VERSION [2012/11/16 10:39:06.810841, 3] winbindd/winbindd_misc.c:384(winbindd_interface_version) [ 9918]: request interface version [2012/11/16 10:39:06.810906, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9918:INTERFACE_VERSION]: delivered response to client [2012/11/16 10:39:06.810964, 10] winbindd/winbindd.c:644(process_request) process_request: request fn WINBINDD_PRIV_PIPE_DIR [2012/11/16 10:39:06.811002, 3] winbindd/winbindd_misc.c:417(winbindd_priv_pipe_dir) [ 9918]: request location of privileged pipe [2012/11/16 10:39:06.811068, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9918:WINBINDD_PRIV_PIPE_DIR]: delivered response to client [2012/11/16 10:39:06.811117, 6] winbindd/winbindd.c:842(winbind_client_request_read) closing socket 25, client exited [2012/11/16 10:39:06.811171, 6] winbindd/winbindd.c:794(new_connection) accepted socket 25 [2012/11/16 10:39:06.811227, 10] winbindd/winbindd.c:617(process_request) process_request: Handling async request 9918:PAM_AUTH_CRAP [2012/11/16 10:39:06.811266, 3] winbindd/winbindd_pam_auth_crap.c:56(winbindd_pam_auth_crap_send) [ 9918]: pam auth crap domain: [NIMASTELECOM] user: testpw [2012/11/16 10:39:07.071142, 10] winbindd/winbindd.c:679(wb_request_done) wb_request_done[9918:PAM_AUTH_CRAP]: NT_STATUS_PASSWORD_MUST_CHANGE [2012/11/16 10:39:07.071243, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9918:PAM_AUTH_CRAP]: delivered response to client [2012/11/16 10:39:07.071320, 6] winbindd/winbindd.c:842(winbind_client_request_read) closing socket 25, client exited [2012/11/16 10:39:20.825567, 6] winbindd/winbindd.c:794(new_connection) accepted socket 25 [2012/11/16 10:39:20.825731, 10] winbindd/winbindd.c:644(process_request) process_request: request fn INTERFACE_VERSION [2012/11/16 10:39:20.825780, 3] winbindd/winbindd_misc.c:384(winbindd_interface_version) [ 9957]: request interface version [2012/11/16 10:39:20.825851, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9957:INTERFACE_VERSION]: delivered response to client [2012/11/16 10:39:20.825916, 10] winbindd/winbindd.c:644(process_request) process_request: request fn WINBINDD_PRIV_PIPE_DIR [2012/11/16 10:39:20.825960, 3] winbindd/winbindd_misc.c:417(winbindd_priv_pipe_dir) [ 9957]: request location of privileged pipe [2012/11/16 10:39:20.826035, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9957:WINBINDD_PRIV_PIPE_DIR]: delivered response to client [2012/11/16 10:39:20.826106, 6] winbindd/winbindd.c:842(winbind_client_request_read) closing socket 25, client exited [2012/11/16 10:39:20.826169, 6] winbindd/winbindd.c:794(new_connection) accepted socket 25 [2012/11/16 10:39:20.826235, 10] winbindd/winbindd.c:644(process_request) process_request: request fn DOMAIN_NAME [2012/11/16 10:39:20.826279, 3] winbindd/winbindd_misc.c:394(winbindd_domain_name) [ 9957]: request domain name [2012/11/16 10:39:20.826341, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9957:DOMAIN_NAME]: delivered response to client [2012/11/16 10:39:20.826497, 10] winbindd/winbindd.c:617(process_request) process_request: Handling async request 9957:PAM_CHNG_PSWD_AUTH_CRAP [2012/11/16 10:39:20.826544, 3] winbindd/winbindd_pam_chng_pswd_auth_crap.c:57(winbindd_pam_chng_pswd_auth_crap_send) [ 9957]: pam change pswd auth crap domain: NIMASTELECOM user: testpw [2012/11/16 10:39:20.856407, 10] winbindd/winbindd.c:679(wb_request_done) wb_request_done[9957:PAM_CHNG_PSWD_AUTH_CRAP]: NT_STATUS_WRONG_PASSWORD [2012/11/16 10:39:20.856498, 10] winbindd/winbindd.c:740(winbind_client_response_written) winbind_client_response_written[9957:PAM_CHNG_PSWD_AUTH_CRAP]: delivered response to client [2012/11/16 10:39:20.856674, 6] winbindd/winbindd.c:842(winbind_client_request_read) closing socket 25, client exited === Regards, Carlos Velasco