FIM CM Troubleshooting: Portal sporadically fails updating smart card
ISSUE: Occasionally updating smart cards in the portal fails. The portal throws an error. The error condition may clear itself up. Sometimes rebooting CM server and CA offers relief. There really did not seem to be a pattern.
TROUBLESHOOTING: The event logs on the CM server offered no insight. Looking into the CA event logs gave us some clues. The first event (ID 53) didn’t help much. However in the second event (ID 0), way down in the “2) Exception Information” section we hit pay dirt. An RPC issue.
Log Name: Application
Source: Microsoft-Windows-CertificationAuthority
Date: 8/29/2012 10:44:45 AM
Event ID: 53
Task Category: None
Level: Warning
Keywords: Classic
User: SYSTEM
Computer: CA02.contoso.com
Description:
Active Directory Certificate Services denied request 12345 because An unknown error occurred while processing the certificate. 0x80090327 (-2146893017). The request was for CONTOSO\user. Additional information: Denied by Policy ModuleLog Name: FIM Certificate Management
Source: FIM CM CA Modules
Date: 8/29/2012 10:44:45 AM
Event ID: 0
Task Category: None
Level: Error
Keywords: Classic
User: N/A
Computer: CA02.contoso.com
Description:
"2012-08-29 10:44:45.90 -05" "Microsoft.Clm.PolicyModulePlugins.Subject.SubjectModule" "Microsoft.Clm.Common.PolicyModule.ErrorLevel Process(Microsoft.Clm.Common.PolicyModule.CertificateRequestData, Microsoft.Clm.Shared.CertificateServer.EnrollmentAttributes, Microsoft.Clm.Common.PolicyModule.PolicyModuleContext)" "" "NT AUTHORITY\SYSTEM" 0x0000050C 0x0000000DGeneral Information
*********************************************
Additional Info:
Failed to customize the certificate subject.1) Exception Information
*********************************************
Exception Type: System.ApplicationException
Message: Parsing exception
Data: System.Collections.ListDictionaryInternal
TargetSite: System.String ParseUserAttributes(System.String, System.String)
HelpLink: NULL
Source: Microsoft.Clm.PolicyModulePluginsStackTrace Information
*********************************************
at Microsoft.Clm.PolicyModulePlugins.Parser.ParseUserAttributes(String userName, String template)
at Microsoft.Clm.PolicyModulePlugins.Subject.SubjectModule.Process(CertificateRequestData certRequest, EnrollmentAttributes data, PolicyModuleContext context)2) Exception Information
*********************************************
Exception Type: System.Runtime.InteropServices.COMException
ErrorCode: -2147023169
Message: The remote procedure call failed and did not execute. (Exception from HRESULT: 0x800706BF)
Data: System.Collections.ListDictionaryInternal
TargetSite: Void InitEx(Int32, System.String, System.String, System.String, System.String)
HelpLink: NULL
Source: Microsoft.Clm.Interop.activedsStackTrace Information
*********************************************
at Microsoft.Clm.Interop.activeds.NameTranslateClass.InitEx(Int32 lnSetType, String bstrADsPath, String bstrUserID, String bstrDomain, String bstrPassword)
at Microsoft.Clm.DS.NameTranslator..ctor()
at Microsoft.Clm.DS.NameTranslator.Convert(String name, NameType from, NameType to)
at Microsoft.Clm.PolicyModulePlugins.Parser.ParseUserAttributes(String userName, String template)
DIGGING DEEPER: Installed Microsoft Network Monitor 3.4 on the CA. Then a network capture was gathered while reproducing the issue.
Filtering on just “protocol.MSRPC” I looked at all the traffic from the certsrv.exe process (thanks, netmon). At first it is the expected RPC traffic that leads to DCOM communication. There is a bit of certificate request DCOM interaction between the FIM CM server and the CA. Next is some RPC traffic between the CA and a DC. Then back to the FIM CM and CA traffic. (Screenshot 1)
A closer inspection of the CA/DC traffic shows a bit of problem. At this point I back out of the RPC filter and look at all the traffic in this process.
What we find is that the CA binds to the endpoint mapper (port 135) on the DC. The DC responds and the CA asks for endpoint information for the DRSR service. The endpoint mapper provided the information. The CA then attempts to bind to the DRSR service (twice). No response is received so the CA gives up. (Screenshot 2)
After the last attempt the CA goes back the the FIM CM server, reports the response (or lack thereof), and the session is torn down.
CAUSE: The DC apparently had a firewall setting blocking off the DRSR port. The endpoint mapper port, 135, was open, but the other port was not. Hence the CA found a DC, the DC responded, but when the DRSR service was contacted nothing happened.
This also explains the sporadic nature of the error. Sometime the CA would use a different domain controller. The other DCs were not blocking the necessary ports so those transactions completed successfully.
RESOLUTION: Adjusting the DC firewall to allow the DRSR traffic or removing it from the site alleviated the issue.
Screenshot 1