When troubleshooting a Dynamics CRM installation, there are a number of different logs that can be useful to users. Today I want to talk about what these logs are, and what sort of information they contain. This information applies to an on-premise installation of Dynamics CRM and should be applicable to CRM 2011, CRM 2013, CRM 2015, and CRM 2016.
Windows Application log
The first log I want to talk about is the Windows Application log, which is available through the Event Viewer application on the server running Dynamics CRM. Many errors that occur in the application pool managed by this server are logged here, showing up with either the severity of “Warning” or “Error.” If possible, when I discover that CRM is behaving unusually, I experiment to isolate the smallest number of steps that will reproduce the error. After I do this, I will reproduce the error several times.
Repeatedly reproducing the error has two advantages. First, I will learn exactly what causes the error. Did I see an error when I was opening a contact record? If so, does it happen for every contact? If not, what do the contacts that it does happen for have in common? The information I learn from finding the smallest set of steps that reproduces the error is very helpful. The second benefit of this step is that it will make the log messages I care about easier to find, because each instance of the error will be logged. Now it’s time to look at the IIS log.
Typically, the log entry that I’m looking for has severity level “warning” and appears in the event viewer as an IIS application pool exception. The detailed view of this error will have a stack trace, which is enough information for me to figure out what code was running when the error occurred. If the stack trace contains code that looks like it belongs to a particular CRM solution publisher, you can investigate further the data used by that solution, and perhaps contact that solution publisher for support. If the stack trace contains only methods that are internal to Dynamics CRM, there is a good chance that the data or customizations around the particular records affected by the error message are malformed in some way. For example, it could be that solution changes caused a record to have an invalid status reason. Another piece of information to check while you’re looking at the Windows Application logs is when the earliest instance of the error occurred. Did it start last week? Did it start right after someone changed the SMTP settings? This information can be very helpful.
CRM trace log
The next type of log is CRM’s trace log. This can be turned on through deployment manager, but it should almost always be off; leaving CRM trace logging on will degrade performance significantly. When I need to use this log, I make sure I know exactly what I need to test, then I set a timer for five minutes, so that I’ll remember to turn off the log again, and then turn the log on to record five minutes of activity. After I stop the recording, I’ll copy the log files to my local computer and begin searching through them for the information I need. For example, I once worked with a client whose CRM instance was experiencing heavy amounts of traffic from an unknown source. I hypothesized that a plugin this client had installed was creating too much data in CRM. One step in testing this hypothesis was looking through CRM’s trace logs for queries that I knew were executed by this plugin.
The information in CRM’s trace logging is very verbose. It logs every query or update made through CRM. That’s one reason for recording only five minutes of activity; a week of CRM trace logs would be too much information to reasonably interpret. Also, before looking at trace logs, you should have an idea of what you are looking for. For example, when I was investigating the performance drag from a third party plugin, I had some idea, from looking at relative table sizes in SQL server, of which plugin to investigate. I was looking to confirm or reject a particular hypothesis; otherwise I would have been reading trace logs for a very long time.
Business process errors
The last type of log I’d like to discuss is business process errors. Sometimes when working with CRM, I will save a record and see a dialog box that says “Business Process Error. Download Log File?” What should we do with those files?
First off, you should always download this log file, even if you don’t know how to interpret it; if you need to contact any IT personnel about the error, they will want to see the log file. In here you’ll find a stack trace. One thing to do with a stack trace is to look through it for names you recognize. For example, I just triggered a business process error on one of our dev servers. Here’s the start of the log:
Unhandled Exception: System.ServiceModel.FaultException`1[[Microsoft.Xrm.Sdk.OrganizationServiceFault, Microsoft.Xrm.Sdk, Version=126.96.36.199, Culture=neutral, PublicKeyToken=31bf3856ad364e35]]: System.ApplicationException: Exception executing Event Handler type: Cobalt.SomeNamespace.SomePluginClass, method: Execute…
I edited this a little. We don’t actually have a class in our source code called “SomePluginClass.” But the highlighted part of the stack trace will often contain the name of the plugin publisher whose code encountered the error.
Part of CRM’s plugin execution model is to wrap basically any plugin exception in a “Microsoft.Xrm.Sdk.OrganizationServiceFault.” In other words, you should read “Microsoft.Xrm.Sdk.OrganizationServiceFault” as “Some plugin error! See below,” because the phrase itself doesn’t tell you much about what went wrong.
It might be that the developers thought to put a human readable error message somewhere in this stack trace. For example, you might see something like, “ArgumentNullException: Update contact when username is null.” If you’re able to find something like that, it might help you interpret the error. If there isn’t a helpful error message, your best bet is to try to get at least the name of the solution that is experiencing the error and contact its publisher.