CRM 2015 – Understanding the plugin profiler and a puzzling error

I am a big fan of debugging my plugins using the plugin profiler, it’s easy, quick and you can do it on your own computer without adversely affecting any fellow developers

The alternative for debugging plugins is to debug on the server, I usually don’t like doing this because if the plugin is not in the sandbox is can stop the whole server and I have personally found remote debugging doesn’t always work with the debugger dropping off after 30 seconds.

Puzzling problem with the plugin profiler

Recently a CRM developer was debugging using the plugin profiler and he had a puzzling problem

He was creating a plugin which fired on post event of creating  which when a new entity was created, it created a Task, which referenced the newly created entity.

Here is a brief description of what the code was doing

• created a new task
• update the description on the task
• set the Regarding to be an entity reference to the newly created Entity

The code was erroring, the CRM developer was puzzled.

This problem is what I would call a CRM riddle and to get to the answer you need to do a bit of thinking.

When you are investigating a bug you need to reject your prejudices and biases.  You probably have an idea of the cause of the problem and it’s fine to check this first but if it isn’t the cause you need to make sure you are systematic and logical in your investigating.

I have written a blog post recently where I have investigated a bug, you need to investigate bugs like Sherlock holmes looking for clues – Sherlock Hosk and the case of the annoying bug

When debugging, eliminate what isn’t causing the problem and whatever code or customization is left must be the culprit. – Sherlock Hosk 

When testing your code I alway feel it’s just as valuable to find out what isn’t causing the problem because you are narrowing down the list of potential causes for the bug.

This highlights the process you should use, methodological, changing one variable at a time.

In the article Why all developers should be friends with a cardboard developer,  I suggest, you get the cardboard developer to stand next to you.

• You have stepped back from the problem, you have stopped to think
• Go through step by step
• Explain what you want to happen
• Explain what is happening

For debugging I would add these points

• change one variable
• Test to see if problem is resolved
• repeat

A mistake a lot of CRM developers make when testing for a bug is changing lots of variables and then not knowing what change has resolved the problem. If you do this you are now in a pickle because it means you have to change all the variables again or get the customer to change all of the variables to resolve the problem.  The other choice is you test again, changing one variable at a time.

Understanding the plugin profiler

To understand the problem you need to understand how the plugin profiler works.

Here is a good step by step guide

Debugging online plugin in CRM 2013

When you turn on profiling the profiler works by capturing all the data being sent and serializing it all into a file and then throwing an error.

This is why you see the error message

#exception (Recommended)

When the profiled component is triggered, an exception will be thrown with the compressed profile in the error message

Below is a picture from the step by step guide above

This is really like adding some code at the end of your plugin throws a InvalidPlugInExecutionException, which would roll back the transaction and not save those changes to the CRM database.  (I’m not sure it does throw an InvalidPluginExecutionException but I am saying it acts as if it does)

This allows you to keep running the test without the plugin creating/updating any records in CRM.  It means you can trigger the plugin multiple times.

Back to the Problem

We know when using the Plugin profiler to debug records don’t get updated or created.

This plugin was being triggered on the create message of a record. Let’s say it was the contact record.

The user put in the contact details, pressed save to create the contact record. This action was captured by the plugin profiler and saved to a serialized file with the InvalidPlugInExecutionException so the record was not being created.

The CRM developer was stepping through the code using the plugin profiler.  The plugin was creating a task, the next step tried to set the regarding to the newly created record.

The problem was being caused by the plugin profiler.  The CRM Developer was running the code in the plugin profiler the on the create of the contact record, the code was creating a new task record and attempting to set the regarding on the task to the newly created contact record but it was throwing an error because the contact record didn’t exist.

When the CRM developer turned off the plugin profiler the code worked fine but this left him confused for a while.

Understanding the how CRM works is important

I am often saying in blog posts

Always start with the CRM SDK

When I say this I mean CRM Developers should first look in the CRM SDK to see if they can understand how this part of the system is working, try to understand the underlying logic of CRM.

Most developers find example code by taking the easy option and searching the internet, finding a code example which someone has written, copying and modifying and using it.

The problem with this is you don’t learn how or why the code works and the CRM developer will not understand the process behind the code.

When you try to create the code yourself, you will experience lots of small errors but overcome them.

CRM Developers first find out how things don’t work to understand how CRM customizations do work – Hosk

In my blog post CRM 2013 – How to get guid of initiating record in CustomWorkflow

I couldn’t work out how to get guid of the initiating record of a custom workflow.  The reason for this was the plugin context passes in a target field and this has the initiating entity.

Custom workflows do not have a target instead they have PrimaryEntityId.

I found out this information by looking in the CRM SDK and thinking about the problem.

The puzzling plugin profiler problem puzzled the CRM developer enough to ask me what was going on, why did it work when the CRM developer stopped using the plugin profiler?

It’s important to understand how CRM works because when things go wrong and errors start popping up, this is when understanding how CRM customizations work will help you work out what the problem is but if you haven’t stopped to learn how things work then they will continue to be a mystery and resolving the errors will be very difficult.

What does the CRM SDK say

if you search the CRM SDK for plugin profiler you will probably get to this page

Analyze plug-in performance

This is a great page with lots of information, below is an excellent description of how the plugin profiler replay works

Replaying plug-in execution does not require a connection to a Microsoft Dynamics CRM server and organization. The advantage of this method is that you can obtain the plug-in execution profile from a customer and debug the plug-in remotely. A restriction of the replay feature is that you cannot change the sequence of calls your plug-in code makes in the debugger while you are debugging.

The replay feature provides the plug-in with a snapshot of the call data and event execution context from the Microsoft Dynamics CRM server. You are getting the same events, GUIDs, and so on from calls to the Organization service but no data is being modified on the server as you debug the plug-in. During the debugging procedure in the previous section, the plug-in actually connects to the server and makes calls in real time.

Whenever I read the CRM SDK I always learn something new, here is what I learned from the paragraphs above

• The plugin profiler doesn’t need a CRM connection to work
• You can profile on a customer production system and debug remotely
• You get a snapshot of the data -same events and same guids
• No data is being modified