The Plugin Trace Log

The Plugin Trace Log is basically an entity in CRM. One trace log record contains details about one plugin execution. The entity has a number of fields that describes some “hard facts” about the execution, such as start time, duration, entity and message that triggered the execution and other details from the execution pipeline. It also contains a field called Message Block, and this is where your own custom logging information ends up. This is where you tailor your style of logging, this is where it gets interesting. Finally if the plugin caused or threw an exception, the Exception field contains information about the exception that was thrown, as well as anything written to the Message Block. This field contains the same information as that you get from the CRM UI when an error message has been shown and you click the Download log file button. The Plugin Trace Log can be found in CRM if you go to Settings – Customization – Plugin Trace Log.

CRM UX

Investigating the Plugin Trace Log in CRM is unfortunately quite discouraging. The default view is missing some painfully obvious columns, such as which Entity that triggered the plugin writing the record and the Execution duration. But you do see the column Is system generated, which should be quite obvious. (When would you manually create Plugin Trace Log records? Why?) If you open Advanced Find to make the view work a little better for you, you realize that some things just cannot be done. You cannot filter the view by triggering entity. You cannot see in which stage it executed. You cannot filter to only display logs with exceptions or duration to identify long running plugins. When you look at the form, you see four fields that show you guids. We are human beings looking at this form, and we are not made for looking at guids! The four fields are Persistence Key, Plugin Step Id, Correlation Id and Request Id. These really tell you nothing, especially since they are only visible on the form, if you stretch it some of these guids might be useful when looking for patterns over multiple trace log records (an example of this will be given in the next article where we use the Correlation Id to track chains of events).

Considerations

When using the Plugin Trace Log, there are some parameters to consider.

Always on
The performance impact of having the trace activated is small from a user perspective as the trace log records are written asynchronously. But it does affect the database size.
Recurring delete job
Make sure there is a recurring bulk delete job that removes older trace log records. CRM provides a default job that deletes records older than one day, once a day. This can of course be adjusted to fit your needs, but make sure you have thought this through.
Logging verbosity
How much should your plugins write to the message block? More detail helps you better, but there is also a 10k limit to this field, where the text is truncated from the top when it exceeds 10k. You can vote on this CRM Idea to make this limit configurable.
Sandboxing
Currently only sandboxed plugins write to the Plugin Trace Log. Plugins in isolation have tighter limits for execution time and trust level. SDK documentation still claims it should work for both partial and full trust plugins. Vote for this CRM Idea to make that true.

Demo 1 – OOTB features

During the first demo I showed how features around the Plugin Trace Log in the CRM UI.
How to activate the log, the default view, what possibilities you have to create your own views within CRM, and the standard form for the entity. Unfortunately there really is nothing from the demo on out of the box Plugin Trace Log investigation worth more space on this blog than the image to the right. Instead I will dedicate the next article in this series to the Plugin Trace Viewer in XrmToolBox.