You *cannot* make this work using MSCHAP and AD.It is working. Look at this: Mon Nov 12 11:04:40 2018 : Debug: (0) Received Access-Request Id 8 from 192.168.2.100:58006 to 192.168.1.100:1812 length 170 Mon Nov 12 11:04:40 2018 : Debug: (0) User-Name = "johndoe:123456" Mon Nov 12 11:04:40 2018 : Debug: (0) NAS-Port-Type = Virtual Mon Nov 12 11:04:40 2018 : Debug: (0) Service-Type = Framed-User Mon Nov 12 11:04:40 2018 : Debug: (0) NAS-Port = 5 Mon Nov 12 11:04:40 2018 : Debug: (0) NAS-Port-Id = "con2" Mon Nov 12 11:04:40 2018 : Debug: (0) NAS-IP-Address = 188.188.188.188 Mon Nov 12 11:04:40 2018 : Debug: (0) Called-Station-Id = "188.188.188.188[4500]" Mon Nov 12 11:04:40 2018 : Debug: (0) Calling-Station-Id = "66.66.66.66[4500]" Mon Nov 12 11:04:40 2018 : Debug: (0) EAP-Message = 0x02000019016d61726b75732e6d61757265723a313131313131 Mon Nov 12 11:04:40 2018 : Debug: (0) NAS-Identifier = "strongSwan" Mon Nov 12 11:04:40 2018 : Debug: (0) Message-Authenticator = 0xc990005408b55db605a48c5ba965d7da Mon Nov 12 11:04:40 2018 : Debug: (0) session-state: No State attribute Mon Nov 12 11:04:40 2018 : Debug: (0) # Executing section authorize from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (0) authorize { Mon Nov 12 11:04:40 2018 : Debug: (0) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: No matches Mon Nov 12 11:04:40 2018 : Debug: Adding 3 matches Mon Nov 12 11:04:40 2018 : Debug: (0) if ( &User-Name =~ /^(.*):([0-9]{6})$/) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (0) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: (0) update request { Mon Nov 12 11:04:40 2018 : Debug: (0) 1/3 Found: johndoe (14) Mon Nov 12 11:04:40 2018 : Debug: (0) EXPAND %{1} Mon Nov 12 11:04:40 2018 : Debug: (0) --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (0) Stripped-User-Name := johndoe Mon Nov 12 11:04:40 2018 : Debug: (0) 2/3 Found: 123456 (7) Mon Nov 12 11:04:40 2018 : Debug: (0) EXPAND %{2} Mon Nov 12 11:04:40 2018 : Debug: (0) --> 123456 Mon Nov 12 11:04:40 2018 : Debug: (0) User-OTP := 123456 Mon Nov 12 11:04:40 2018 : Debug: (0) } # update request = noop Mon Nov 12 11:04:40 2018 : Debug: (0) } # if ( &User-Name =~ /^(.*):([0-9]{6})$/) = noop Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (0) [preprocess] = ok Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: calling files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: XLAT-IF { Mon Nov 12 11:04:40 2018 : Debug: attribute --> Stripped-User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: XLAT-ELSE { Mon Nov 12 11:04:40 2018 : Debug: attribute --> User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: (0) files: EXPAND %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: (0) files: --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (0) files: users: Matched entry johndoe at line 4 Mon Nov 12 11:04:40 2018 : Debug: (0) files: ::: FROM 0 TO 0 MAX 0 Mon Nov 12 11:04:40 2018 : Debug: (0) files: ::: TO in 0 out 0 Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: returned from files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: (0) [files] = ok Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: calling expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: returned from expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (0) [expiration] = noop Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: calling logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: returned from logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (0) [logintime] = noop Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authorize]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (0) [pap] = updated Mon Nov 12 11:04:40 2018 : Debug: (0) } # authorize = updated Mon Nov 12 11:04:40 2018 : Debug: (0) Found Auth-Type = PAP Mon Nov 12 11:04:40 2018 : Debug: (0) # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (0) Auth-Type PAP { Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authenticate]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (0) pap: Login attempt with password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (0) pap: Comparing with "known good" Cleartext-Password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (0) pap: User authenticated successfully Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authenticate]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (0) [pap] = ok Mon Nov 12 11:04:40 2018 : Debug: (0) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (0) if (ok) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (0) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (0) eap: Peer sent packet with method EAP Identity (1) Mon Nov 12 11:04:40 2018 : Debug: (0) eap: Calling submodule eap_mschapv2 to process data Mon Nov 12 11:04:40 2018 : Debug: (0) eap_mschapv2: Issuing Challenge Mon Nov 12 11:04:40 2018 : Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 43 Mon Nov 12 11:04:40 2018 : Debug: (0) eap: EAP session adding &reply:State = 0xfb6bfe4bfb6ae43b Mon Nov 12 11:04:40 2018 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (0) [eap] = handled Mon Nov 12 11:04:40 2018 : Debug: (0) } # if (ok) = handled Mon Nov 12 11:04:40 2018 : Debug: (0) } # Auth-Type PAP = handled Mon Nov 12 11:04:40 2018 : Debug: (0) Using Post-Auth-Type Challenge Mon Nov 12 11:04:40 2018 : Debug: (0) # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (0) Challenge { ... } # empty sub-section is ignored Mon Nov 12 11:04:40 2018 : Debug: (0) session-state: Nothing to cache Mon Nov 12 11:04:40 2018 : Debug: (0) Sent Access-Challenge Id 8 from 192.168.1.100:1812 to 192.168.2.100:58006 length 0 Mon Nov 12 11:04:40 2018 : Debug: (0) EAP-Message = 0x0101002b1a010100261030e3952e2c9124e7da1b5349c01cd33d667265657261646975732d332e302e3133 Mon Nov 12 11:04:40 2018 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000 Mon Nov 12 11:04:40 2018 : Debug: (0) State = 0xfb6bfe4bfb6ae43b45f5a1d5430de6d2 Mon Nov 12 11:04:40 2018 : Debug: (0) Finished request Mon Nov 12 11:04:40 2018 : Debug: Waking up in 4.9 seconds. Mon Nov 12 11:04:40 2018 : Debug: (1) Received Access-Request Id 9 from 192.168.2.100:58006 to 192.168.1.100:1812 length 242 Mon Nov 12 11:04:40 2018 : Debug: (1) User-Name = "johndoe:123456" Mon Nov 12 11:04:40 2018 : Debug: (1) NAS-Port-Type = Virtual Mon Nov 12 11:04:40 2018 : Debug: (1) Service-Type = Framed-User Mon Nov 12 11:04:40 2018 : Debug: (1) NAS-Port = 5 Mon Nov 12 11:04:40 2018 : Debug: (1) NAS-Port-Id = "con2" Mon Nov 12 11:04:40 2018 : Debug: (1) NAS-IP-Address = 188.188.188.188 Mon Nov 12 11:04:40 2018 : Debug: (1) Called-Station-Id = "188.188.188.188[4500]" Mon Nov 12 11:04:40 2018 : Debug: (1) Calling-Station-Id = "66.66.66.66[4500]" Mon Nov 12 11:04:40 2018 : Debug: (1) EAP-Message = 0x0201004f1a0201004a3145c827eec3e80f01d82457f43e2e188100000000000000004caa9abd0548379b7e274a01c7faf807a7be4b3f16980725006d61726b75732e6d61757265723a313131313131 Mon Nov 12 11:04:40 2018 : Debug: (1) NAS-Identifier = "strongSwan" Mon Nov 12 11:04:40 2018 : Debug: (1) State = 0xfb6bfe4bfb6ae43b45f5a1d5430de6d2 Mon Nov 12 11:04:40 2018 : Debug: (1) Message-Authenticator = 0x502608d30fe0da78dfab8667b1a66496 Mon Nov 12 11:04:40 2018 : Debug: (1) session-state: No cached attributes Mon Nov 12 11:04:40 2018 : Debug: (1) # Executing section authorize from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (1) authorize { Mon Nov 12 11:04:40 2018 : Debug: (1) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: No matches Mon Nov 12 11:04:40 2018 : Debug: Adding 3 matches Mon Nov 12 11:04:40 2018 : Debug: (1) if ( &User-Name =~ /^(.*):([0-9]{6})$/) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (1) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: (1) update request { Mon Nov 12 11:04:40 2018 : Debug: (1) 1/3 Found: johndoe (14) Mon Nov 12 11:04:40 2018 : Debug: (1) EXPAND %{1} Mon Nov 12 11:04:40 2018 : Debug: (1) --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (1) Stripped-User-Name := johndoe Mon Nov 12 11:04:40 2018 : Debug: (1) 2/3 Found: 123456 (7) Mon Nov 12 11:04:40 2018 : Debug: (1) EXPAND %{2} Mon Nov 12 11:04:40 2018 : Debug: (1) --> 123456 Mon Nov 12 11:04:40 2018 : Debug: (1) User-OTP := 123456 Mon Nov 12 11:04:40 2018 : Debug: (1) } # update request = noop Mon Nov 12 11:04:40 2018 : Debug: (1) } # if ( &User-Name =~ /^(.*):([0-9]{6})$/) = noop Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (1) [preprocess] = ok Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: calling files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: XLAT-IF { Mon Nov 12 11:04:40 2018 : Debug: attribute --> Stripped-User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: XLAT-ELSE { Mon Nov 12 11:04:40 2018 : Debug: attribute --> User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: (1) files: EXPAND %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: (1) files: --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (1) files: users: Matched entry johndoe at line 4 Mon Nov 12 11:04:40 2018 : Debug: (1) files: ::: FROM 0 TO 0 MAX 0 Mon Nov 12 11:04:40 2018 : Debug: (1) files: ::: TO in 0 out 0 Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: returned from files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: (1) [files] = ok Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: calling expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: returned from expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (1) [expiration] = noop Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: calling logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: returned from logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (1) [logintime] = noop Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (1) [pap] = updated Mon Nov 12 11:04:40 2018 : Debug: (1) } # authorize = updated Mon Nov 12 11:04:40 2018 : Debug: (1) Found Auth-Type = PAP Mon Nov 12 11:04:40 2018 : Debug: (1) # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (1) Auth-Type PAP { Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authenticate]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (1) pap: Login attempt with password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (1) pap: Comparing with "known good" Cleartext-Password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (1) pap: User authenticated successfully Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authenticate]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (1) [pap] = ok Mon Nov 12 11:04:40 2018 : Debug: (1) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (1) if (ok) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (1) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Expiring EAP session with state 0xfb6bfe4bfb6ae43b Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Finished EAP session with state 0xfb6bfe4bfb6ae43b Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Previous EAP request found for state 0xfb6bfe4bfb6ae43b, released from the list Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Peer sent packet with method EAP MSCHAPv2 (26) Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Calling submodule eap_mschapv2 to process data Mon Nov 12 11:04:40 2018 : Debug: (1) eap_mschapv2: # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (1) eap_mschapv2: authenticate { Mon Nov 12 11:04:40 2018 : Debug: (1) eap_mschapv2: modsingle[authenticate]: calling mschap (rlm_mschap) Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Found Cleartext-Password, hashing to create NT-Password Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Found Cleartext-Password, hashing to create LM-Password Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Creating challenge hash with username: johndoe:123456 Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Client is using MS-CHAPv2 Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Executing: /usr/bin/ntlm_auth --request-nt-key --username=%{Stripped-User-Name} --domain=%{%{mschap:NT-Domain}:-EXAMPLEDOM} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}: Mon Nov 12 11:04:40 2018 : Debug: --username=%{Stripped-User-Name} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: literal --> --username= Mon Nov 12 11:04:40 2018 : Debug: attribute --> Stripped-User-Name Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: EXPAND --username=%{Stripped-User-Name} Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: --> --username=johndoe Mon Nov 12 11:04:40 2018 : Debug: --domain=%{%{mschap:NT-Domain}:-EXAMPLEDOM} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: literal --> --domain= Mon Nov 12 11:04:40 2018 : Debug: XLAT-IF { Mon Nov 12 11:04:40 2018 : Debug: xlat --> mschap Mon Nov 12 11:04:40 2018 : Debug: { Mon Nov 12 11:04:40 2018 : Debug: literal --> NT-Domain Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: XLAT-ELSE { Mon Nov 12 11:04:40 2018 : Debug: literal --> EXAMPLEDOM Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : ERROR: (1) mschap: No NT-Domain was found in the User-Name Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: EXPAND --domain=%{%{mschap:NT-Domain}:-EXAMPLEDOM} Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: --> --domain=EXAMPLEDOM Mon Nov 12 11:04:40 2018 : Debug: --challenge=%{mschap:Challenge:-00} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: literal --> --challenge= Mon Nov 12 11:04:40 2018 : Debug: xlat --> mschap Mon Nov 12 11:04:40 2018 : Debug: { Mon Nov 12 11:04:40 2018 : Debug: literal --> Challenge:-00 Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Creating challenge hash with username: johndoe:123456 Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: EXPAND --challenge=%{mschap:Challenge:-00} Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: --> --challenge=d64fcfdbedcc33ee Mon Nov 12 11:04:40 2018 : Debug: --nt-response=%{mschap:NT-Response:-00} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: literal --> --nt-response= Mon Nov 12 11:04:40 2018 : Debug: xlat --> mschap Mon Nov 12 11:04:40 2018 : Debug: { Mon Nov 12 11:04:40 2018 : Debug: literal --> NT-Response:-00 Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: EXPAND --nt-response=%{mschap:NT-Response:-00} Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: --> --nt-response=4caa9abd0548379b7e274a01c7faf807a7be4b3f16980725 Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Program returned code (0) and output 'NT_KEY: B18DE605DA0547E15B2F27CEBA5CEBB1' Mon Nov 12 11:04:40 2018 : Debug: (1) mschap: Adding MS-CHAPv2 MPPE keys Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authenticate]: returned from mschap (rlm_mschap) Mon Nov 12 11:04:40 2018 : Debug: (1) [mschap] = ok Mon Nov 12 11:04:40 2018 : Debug: (1) } # authenticate = ok Mon Nov 12 11:04:40 2018 : Debug: (1) MSCHAP Success Mon Nov 12 11:04:40 2018 : Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 51 Mon Nov 12 11:04:40 2018 : Debug: (1) eap: EAP session adding &reply:State = 0xfb6bfe4bfa69e43b Mon Nov 12 11:04:40 2018 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (1) [eap] = handled Mon Nov 12 11:04:40 2018 : Debug: (1) } # if (ok) = handled Mon Nov 12 11:04:40 2018 : Debug: (1) } # Auth-Type PAP = handled Mon Nov 12 11:04:40 2018 : Debug: (1) Using Post-Auth-Type Challenge Mon Nov 12 11:04:40 2018 : Debug: (1) # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (1) Challenge { ... } # empty sub-section is ignored Mon Nov 12 11:04:40 2018 : Debug: (1) session-state: Nothing to cache Mon Nov 12 11:04:40 2018 : Debug: (1) Sent Access-Challenge Id 9 from 192.168.1.100:1812 to 192.168.2.100:58006 length 0 Mon Nov 12 11:04:40 2018 : Debug: (1) EAP-Message = 0x010200331a0301002e533d31454643303335343134334238423145433843363138443039453534433946453631373032333434 Mon Nov 12 11:04:40 2018 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000 Mon Nov 12 11:04:40 2018 : Debug: (1) State = 0xfb6bfe4bfa69e43b45f5a1d5430de6d2 Mon Nov 12 11:04:40 2018 : Debug: (1) Finished request Mon Nov 12 11:04:40 2018 : Debug: Waking up in 4.9 seconds. Mon Nov 12 11:04:40 2018 : Debug: (2) Received Access-Request Id 10 from 192.168.2.100:58006 to 192.168.1.100:1812 length 169 Mon Nov 12 11:04:40 2018 : Debug: (2) User-Name = "johndoe:123456" Mon Nov 12 11:04:40 2018 : Debug: (2) NAS-Port-Type = Virtual Mon Nov 12 11:04:40 2018 : Debug: (2) Service-Type = Framed-User Mon Nov 12 11:04:40 2018 : Debug: (2) NAS-Port = 5 Mon Nov 12 11:04:40 2018 : Debug: (2) NAS-Port-Id = "con2" Mon Nov 12 11:04:40 2018 : Debug: (2) NAS-IP-Address = 188.188.188.188 Mon Nov 12 11:04:40 2018 : Debug: (2) Called-Station-Id = "188.188.188.188[4500]" Mon Nov 12 11:04:40 2018 : Debug: (2) Calling-Station-Id = "66.66.66.66[4500]" Mon Nov 12 11:04:40 2018 : Debug: (2) EAP-Message = 0x020200061a03 Mon Nov 12 11:04:40 2018 : Debug: (2) NAS-Identifier = "strongSwan" Mon Nov 12 11:04:40 2018 : Debug: (2) State = 0xfb6bfe4bfa69e43b45f5a1d5430de6d2 Mon Nov 12 11:04:40 2018 : Debug: (2) Message-Authenticator = 0x654b4205c000cb7eab5e5262156d5ca8 Mon Nov 12 11:04:40 2018 : Debug: (2) session-state: No cached attributes Mon Nov 12 11:04:40 2018 : Debug: (2) # Executing section authorize from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (2) authorize { Mon Nov 12 11:04:40 2018 : Debug: (2) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: No matches Mon Nov 12 11:04:40 2018 : Debug: Adding 3 matches Mon Nov 12 11:04:40 2018 : Debug: (2) if ( &User-Name =~ /^(.*):([0-9]{6})$/) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (2) if ( &User-Name =~ /^(.*):([0-9]{6})$/) { Mon Nov 12 11:04:40 2018 : Debug: (2) update request { Mon Nov 12 11:04:40 2018 : Debug: (2) 1/3 Found: johndoe (14) Mon Nov 12 11:04:40 2018 : Debug: (2) EXPAND %{1} Mon Nov 12 11:04:40 2018 : Debug: (2) --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (2) Stripped-User-Name := johndoe Mon Nov 12 11:04:40 2018 : Debug: (2) 2/3 Found: 123456 (7) Mon Nov 12 11:04:40 2018 : Debug: (2) EXPAND %{2} Mon Nov 12 11:04:40 2018 : Debug: (2) --> 123456 Mon Nov 12 11:04:40 2018 : Debug: (2) User-OTP := 123456 Mon Nov 12 11:04:40 2018 : Debug: (2) } # update request = noop Mon Nov 12 11:04:40 2018 : Debug: (2) } # if ( &User-Name =~ /^(.*):([0-9]{6})$/) = noop Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) Mon Nov 12 11:04:40 2018 : Debug: (2) [preprocess] = ok Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: calling files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: Parsed xlat tree: Mon Nov 12 11:04:40 2018 : Debug: XLAT-IF { Mon Nov 12 11:04:40 2018 : Debug: attribute --> Stripped-User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: XLAT-ELSE { Mon Nov 12 11:04:40 2018 : Debug: attribute --> User-Name Mon Nov 12 11:04:40 2018 : Debug: } Mon Nov 12 11:04:40 2018 : Debug: (2) files: EXPAND %{%{Stripped-User-Name}:-%{User-Name}} Mon Nov 12 11:04:40 2018 : Debug: (2) files: --> johndoe Mon Nov 12 11:04:40 2018 : Debug: (2) files: users: Matched entry johndoe at line 4 Mon Nov 12 11:04:40 2018 : Debug: (2) files: ::: FROM 0 TO 0 MAX 0 Mon Nov 12 11:04:40 2018 : Debug: (2) files: ::: TO in 0 out 0 Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: returned from files (rlm_files) Mon Nov 12 11:04:40 2018 : Debug: (2) [files] = ok Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: calling expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: returned from expiration (rlm_expiration) Mon Nov 12 11:04:40 2018 : Debug: (2) [expiration] = noop Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: calling logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: returned from logintime (rlm_logintime) Mon Nov 12 11:04:40 2018 : Debug: (2) [logintime] = noop Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authorize]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (2) [pap] = updated Mon Nov 12 11:04:40 2018 : Debug: (2) } # authorize = updated Mon Nov 12 11:04:40 2018 : Debug: (2) Found Auth-Type = PAP Mon Nov 12 11:04:40 2018 : Debug: (2) # Executing group from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (2) Auth-Type PAP { Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authenticate]: calling pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (2) pap: Login attempt with password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (2) pap: Comparing with "known good" Cleartext-Password "123456" (6) Mon Nov 12 11:04:40 2018 : Debug: (2) pap: User authenticated successfully Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authenticate]: returned from pap (rlm_pap) Mon Nov 12 11:04:40 2018 : Debug: (2) [pap] = ok Mon Nov 12 11:04:40 2018 : Debug: (2) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (2) if (ok) -> TRUE Mon Nov 12 11:04:40 2018 : Debug: (2) if (ok) { Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Expiring EAP session with state 0xfb6bfe4bfa69e43b Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Finished EAP session with state 0xfb6bfe4bfa69e43b Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Previous EAP request found for state 0xfb6bfe4bfa69e43b, released from the list Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Peer sent packet with method EAP MSCHAPv2 (26) Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Calling submodule eap_mschapv2 to process data Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Sending EAP Success (code 3) ID 2 length 4 Mon Nov 12 11:04:40 2018 : Debug: (2) eap: Freeing handler Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) Mon Nov 12 11:04:40 2018 : Debug: (2) [eap] = ok Mon Nov 12 11:04:40 2018 : Debug: (2) } # if (ok) = ok Mon Nov 12 11:04:40 2018 : Debug: (2) } # Auth-Type PAP = ok Mon Nov 12 11:04:40 2018 : Debug: (2) # Executing section post-auth from file /etc/raddb/sites-enabled/default Mon Nov 12 11:04:40 2018 : Debug: (2) post-auth { Mon Nov 12 11:04:40 2018 : Debug: (2) update { Mon Nov 12 11:04:40 2018 : Debug: (2) No attributes updated Mon Nov 12 11:04:40 2018 : Debug: (2) } # update = noop Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[post-auth]: calling exec (rlm_exec) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[post-auth]: returned from exec (rlm_exec) Mon Nov 12 11:04:40 2018 : Debug: (2) [exec] = noop Mon Nov 12 11:04:40 2018 : Debug: (2) policy remove_reply_message_if_eap { Mon Nov 12 11:04:40 2018 : Debug: (2) if (&reply:EAP-Message && &reply:Reply-Message) { Mon Nov 12 11:04:40 2018 : Debug: (2) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Mon Nov 12 11:04:40 2018 : Debug: (2) else { Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[post-auth]: calling noop (rlm_always) Mon Nov 12 11:04:40 2018 : Debug: (2) modsingle[post-auth]: returned from noop (rlm_always) Mon Nov 12 11:04:40 2018 : Debug: (2) [noop] = noop Mon Nov 12 11:04:40 2018 : Debug: (2) } # else = noop Mon Nov 12 11:04:40 2018 : Debug: (2) } # policy remove_reply_message_if_eap = noop Mon Nov 12 11:04:40 2018 : Debug: (2) } # post-auth = noop Mon Nov 12 11:04:40 2018 : Debug: (2) Sent Access-Accept Id 10 from 192.168.1.100:1812 to 192.168.2.100:58006 length 0 Mon Nov 12 11:04:40 2018 : Debug: (2) MS-MPPE-Encryption-Policy = Encryption-Required Mon Nov 12 11:04:40 2018 : Debug: (2) MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed Mon Nov 12 11:04:40 2018 : Debug: (2) MS-MPPE-Send-Key = 0xcbf551f76a44f29550c2e6bccd4e256c Mon Nov 12 11:04:40 2018 : Debug: (2) MS-MPPE-Recv-Key = 0xd85d1854dee9755637e77e927291eec4 Mon Nov 12 11:04:40 2018 : Debug: (2) EAP-Message = 0x03020004 Mon Nov 12 11:04:40 2018 : Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000 Mon Nov 12 11:04:40 2018 : Debug: (2) Finished request Mon Nov 12 11:04:40 2018 : Debug: Waking up in 4.9 seconds. Am Montag, November 12, 2018 10:27 CET, Adam Bishop <Adam.Bishop@jisc.ac.uk> schrieb: On 11 Nov 2018, at 20:56, Markus Maurer <lists@v-net.tk> wrote:
Hmm... Meanwhile I think that you didn‘t understand the problem. You’re just talking around the problem, not about the problem neither trying to help solving it...
I'm reasonably sure the maintainer of the server has a better idea of how it works than yourself.
The nt hash is calculated from the password, not from the username
That's 100% correct, but unfortunately 100% unrelated. MSCHAP uses the username to create the *challenge hash* not the *NT hash*. If you change the username, the authentication process fails because you've changed the challenge hash. You *cannot* make this work using MSCHAP and AD. If you want to use OTP you have to change EAP method, or as Alan told you several messages ago, store clear text passwords. Adam Bishop gpg: E75B 1F92 6407 DFDF 9F1C BF10 C993 2504 6609 D460 jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc’s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800. Jisc Services Limited is a wholly owned Jisc subsidiary and a company limited by guarantee which is registered in England under company number 2881024, VAT number GB 197 0632 86. The registered office is: One Castle Park, Tower Hill, Bristol BS2 0JA. T 0203 697 5800. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html -- This email was Malware checked by UTM 9. http://www.sophos.com