SCEP Certificate Deployment - Troubleshooting Reference

  • [アーティクル]

The below diagram is a pretty common Intune/SCCM hybrid configuration used to deploy certificates to clients (Win10/Windows Phone/Android/IOS) using the Simple Certificate Enrolment Protocol.  If your interested in setting it up - this is a pretty good blog series.

I have had to troubleshoot it a bit lately using different combinations of the logs described here. I've found that it's pretty handy to have a reference of what the logs/traces should look like when working so I know what to look for next time... Hence this post.

 

SCEP Architecture

Communications Flow – High Level

 1 MDM Synchronisation is triggered from the Client. The client receives policy settings from intune, including the public NDES URL.
 2 The Device generates a private key and marks it as non-exportable. The device contacts NDES and supplies the certificate request and challenge response.Note: WAP Server is configured in this scenario which means that the client will never talk directly to the NDES Server, WAP will terminate and re-establish sessions to the NDES Server. For troubleshooting, Just be aware that this is another moving part to troubleshoot and it may be necessary to capture a network trace here if things don’t look right on the client and NDES logs/traces.
 3 NDES receives the request and forwards to the NDES Policy Module. The policy module checks with the SCCM Certificate Registration Report (CRP)
 4 The SCCM CRP checks that the device is enrolled in Intune then sends a “TRUE” or “FALSE” validation response back to the NDES server.
 5 If the challenge was successful, NDES makes a request on behalf of the client and signs the request with the Enrolment Agent Certificate and sends to the Enterprise CA. The Enterprise CA issues the certificate and returns the certificate to NDES
 6 NDES then delivers the certificate to the mobile device

 

Communications Flow - Detailed

1CLIENT

Manually Trigger the sync for a good repro.

Automatic Synchronisations depends on the client platform:

 iOS -  Every 15 minutes for 6 hours and then every 6 hours

 Android -  Every 3 minutes for 15 minutes then every 15 minutes for 2 hours, and then every 8 hours

 Windows Phone -  Every 5 minutes for 15 minutes then every 15 minutes for 2 hours, and then every 8 hours

2CLIENT NetworkCapture

Client computer shows 3 separate TCP conversations with the WAP Server (Which it is passing through the Web traffic to the internal NDES Server)

Each TCP conversations shows a successful 3-way handshake, TLS Handshake, then some encrypted SSL traffic.
netcap1 netcap2 netcap3
2NDES SERVER IISlog

Check the IIS Log on the NDES Server to make sure each of the Requests made it to NDES. There is a few known issues with this conversation – due to the size of the request from the client. Read this for more details.

 #Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status time-taken
2016-06-10 02:44:06 [NDES-IP Address] GET /certsrv/mscep/mscep.dll/pkiclient.exe operation=GetCACert&message=MDM 443 - [WAP-IP Address]- - 200 0 0 0
2016-06-10 02:44:06 [NDES-IP Address] GET /certsrv/mscep/mscep.dll/pkiclient.exe operation=GetCACaps&message=MDM 443 - [WAP-IP Address]- - 200 0 0 31
2016-06-10 02:44:08 [NDES-IP Address] GET /certsrv/mscep/mscep.dll/pkiclient.exe operation=GetCACaps&message=default 443 - [WAP-IP Address]Mozilla/4.0+(compatible;+Win32;+WinHttp.WinHttpRequest.5) - 200 0 0 13
2016-06-10 02:44:08 [NDES-IP Address] GET /certsrv/mscep/mscep.dll/pkiclient.exe operation=GetCACert&message=default 443 - [WAP-IP Address]Mozilla/4.0+(compatible;+Win32;+WinHttp.WinHttpRequest.5) - 200 0 0 1
2016-06-10 02:44:12 [NDES-IP Address] GET /certsrv/mscep/mscep.dll/pkiclient.exe ... 443 - [WAP-IP Address]Mozilla/4.0+(compatible;+Win32;+WinHttp.WinHttpRequest.5) - 200 0 0 502

3NDES SERVER NDESlog

Check the NDES Log to ensure NDES is asking the CRP to do Validation:

 <![LOG[Calling VerifyRequest ...]LOG]!><time="02:44:11.789+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="2900" file="ndesplugin.cpp:646">
<![LOG[Sending request to certificate registration point.]LOG]!><time="02:44:11.789+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="2900" file="httprequest.cpp:114">
<![LOG[Verify challenge returns true]LOG]!><time="02:44:12.200+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="2900" file="ndesplugin.cpp:834">
<![LOG[Exiting VerifyRequest with 0x0]LOG]!><time="02:44:12.200+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="2900" file="ndesplugin.cpp:874">
<![LOG[Calling Notifyrequest ...]LOG]!><time="02:44:12.270+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="3088" file="ndesplugin.cpp:904">
<![LOG[Sending request to certificate registration point.]LOG]!><time="02:44:12.270+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="3088" file="httprequest.cpp:114">
<![LOG[Exiting Notify with 0x0]LOG]!><time="02:44:12.410+00" date="06-10-2016" component="NDESPlugin" context="" type="1" thread="3088" file="ndesplugin.cpp:1167">

4SCCM (CRP) SERVER IISlog

Check IIS Log on the SCCM/CRP Server to make sure it received the Verify Request Message

 2016-06-10 02:44:12 [SCCM-IP Address] POST /CMCertificateRegistration/Certificate/VerifyRequest - 443 - [NDES-IP Address] NDES_Plugin - 201 0 0 437 349
2016-06-10 02:44:12 [SCCM-IP Address] POST /CMCertificateRegistration/Certificate/Notify - 443 - [NDES-IP Address] NDES_Plugin - 204 0 0 357 102

crplog

Check the CRP Log on the SCCM/CRP Server to make sure the validation occurred:

 <![LOG[Reading Template Permission Check from registry.]LOG]!><time="02:44:11.8513964" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 1 started.]LOG]!><time="02:44:11.8513964" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 1 finised with status True.]LOG]!><time="02:44:12.0814310" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 2 started for device and user .]LOG]!><time="02:44:12.0814310" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 2 finished.]LOG]!><time="02:44:12.0824068" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 3 started for device 38fdb94d-db5c-468d-b8d6-37aff538e934 and user 4514c247-96e3-4c6e-9d60-806ac5fa7e2f.]LOG]!><time="02:44:12.0824068" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Get Challenge Parameters from DB using query: Execute CRP_VerifyRequestParameters @vchCertificateRequestID = 'ModelName=ScopeId_DEF1415D-2304-49FD-962C-92B560F126A4/ConfigurationPolicy_82ad9d8e-228e-4048-a598-d8a60c0ab996;Version=1;Hash=-1580759952', @vchDeviceID = '38fdb94d-db5c-468d-b8d6-37aff538e934', @vchUserID = '4514c247-96e3-4c6e-9d60-806ac5fa7e2f', @DeviceType = 1]LOG]!><time="02:44:12.0824068" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Validation Phase 3 finished with status True.]LOG]!><time="02:44:12.1504338" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[VerifyRequest Finished with status True]LOG]!><time="02:44:12.1514137" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="238" file="">
<![LOG[Notify Started.]LOG]!><time="02:44:12.3315169" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Beginning state message creation...]LOG]!><time="02:44:12.3315169" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Retrieveing the CRP certificate]LOG]!><time="02:44:12.3315169" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Retrieving the GWP or MP certificate.]LOG]!><time="02:44:12.3395154" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Sending Success state message]LOG]!><time="02:44:12.3714356" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[StateMessage C:\Program Files\Microsoft Configuration Manager\inboxes\auth\statesys.box\incoming\csq5f2dte2d.SMX is dropped.]LOG]!><time="02:44:12.3714915" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Successfully sent state message]LOG]!><time="02:44:12.3714915" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">
<![LOG[Notify Finished.]LOG]!><time="02:44:12.3714915" date="6-10-2016" component="CertificateRegistrationPoint" context="" type="1" thread="237" file="">

5CA SERVER

Check certsrv.msc on the Issuing CA making sure that a certificate has been issued by the NDES Service account (svc_NDES in the screenshot).
certsrv 6CLIENT

Check that the Certificate store on the device. (Certmgr.msc since this is a USER Certificate).
 certmgr

Log file Locations:

NetworkCaptureThere are a bunch of ways to capture a network trace (Network Monitor 3.4, Microsoft Message Analyzer or Wireshark). However, my favourite is capturing a trace without installing anything:

 netsh trace capture=yes tracefile=c:\trace.etl

NDESlog %systemdrive%\Program Files\Microsoft Configuration Manager\Logs\NDESPlugin.log

IISlog%systemdrive%\inetpub\logs\LogFiles\W3SVC1\u_exxxxxxx.log

crplog%systemdrive%\Program Files\SMS_CCM\CRP\Logs\CRP.log