Dynamics CRM, Outlook, Troubleshooting

Tracing Network Traffic Between the Outlook Plugin and Dynamics CRM

Recently we had an issue where appointments deleted in CRM via the web application were not being deleted from certain users Outlook calendars.

Now, I enjoy a fruitless game of email ping pong with MS tech support as much as any man but this time I thought I’d take a look at how syncing works directly. I have to confess – the sync process has always been a bit of a black box to me so I was curious to see how it worked.

One of the key areas of interest is going to be what information is getting sent from CRM to the Outlook add in when a sync operation takes place. This would at least give us a fighting chance of understanding whether we are dealing with a server side issue or something in the way the client add in processes the change instruction.

Given that we know we want to take a look the web service calls between the client and the CRM Organization.svc endpoint my first port of call was the awesomeness that is Fiddler: http://www.telerik.com/download/fiddler

The problem we immediately face is that although we can see the back and forth easily enough – the message payload is encrypted, even in the absence of HTTPS:

Image
I don’t fancy our chances of decrypting that any time soon…

Unlike HTTPS encryption, which we could circumvent using a fiddler proxy, we have to take a different approach to the payload based encryption employed here.

In this instance we are going to rely on enabling WCF tracing within the Outlook add in to output our traffic in the clear. To achieve this, do the following:

1. Create a new folder for the resulting WCF trace files e.g. C:\WCF Trace\

2. Navigate to the install folder of the CRM Outlook Client – in my case C:\Program Files\Microsoft Dynamics CRM\Client

3. Locate the configuration file named CrmClient<GUID>.config. Add the following section of code to the file, just within the <configuration> element:


  <system.diagnostics>
    <sources>
      <source name ="System.ServiceModel.MessageLogging"
              switchValue="Verbose, ActivityTracing">
        <listeners>
          <add name="xml" />
        </listeners>
      </source>
    </sources>
    <sharedListeners>
      <add name="xml" type="System.Diagnostics.XmlWriterTraceListener"
           traceOutputOptions="LogicalOperationStack"
           initializeData="C:\WCF Trace\CRMTrace.svclog" />
    </sharedListeners>
    <trace autoflush="true" />
  </system.diagnostics>

  <system.serviceModel>
    <diagnostics>
      <messageLogging
           logEntireMessage="true"
           logMalformedMessages="false"
           logMessagesAtServiceLevel="true"
           logMessagesAtTransportLevel="false"/>
    </diagnostics>
  </system.serviceModel>

In my case this leaves the overall file looking like:


<configuration>
<system.net>
	<defaultProxy useDefaultCredentials="true" />
	<settings>
		<servicePointManager expect100Continue="false" />
	</settings>
</system.net>

  <system.diagnostics>
    <sources>
      <source name ="System.ServiceModel.MessageLogging"
              switchValue="Verbose, ActivityTracing">
        <listeners>
          <add name="xml" />
        </listeners>
      </source>
    </sources>
    <sharedListeners>
      <add name="xml" type="System.Diagnostics.XmlWriterTraceListener"
           traceOutputOptions="LogicalOperationStack"
           initializeData="C:\WCF Trace\CRMTrace.svclog" />
    </sharedListeners>
    <trace autoflush="true" />
  </system.diagnostics>

  <system.serviceModel>
    <diagnostics>
      <messageLogging
           logEntireMessage="true"
           logMalformedMessages="false"
           logMessagesAtServiceLevel="true"
           logMessagesAtTransportLevel="false"/>
    </diagnostics>
  </system.serviceModel>

</configuration>

At this point I would use the CRM Diagnostics tool to disable automatic synchronisation by the add in for the simple reason that the WCF traces can fill up fast and can become pretty difficult to decipher even with minimal traffic.

Either way, when you start Outlook and a sync is started you should see a file appear in your designated trace folder. Make sure you have initiated at least one (and ideally only one) sync operation with CRM and then close Outlook.

Once we have our WCF trace we need a tool to read it. I’ve been using the WCF Service Trace Viewer that comes as part of the Windows SDK

Once the viewer is installed open the trace file. Move to the Message tab and you should get a view similar to the following:

WCF Tracing between Outlook and CRM
WCF Tracing between Outlook and CRM

Now – I am not going to describe the full intricacies of the Outlook CRM Sync process – Microsoft have already done a pretty good job of that in whitepapers published on MSDN. However I am going to give you a couple of pointers about how to use the trace viewer tool as it can be a little tricky finding what we actually want.

In the above screenshot, notice the various entries ending /Execute and /ExecuteResponse. These pairs detail the outgoing request from the client and the subsequent response from the server shortly after. The messages that don’t end in /Execute or /ExecuteResponse can usually be ignored.

One of the first tips I have for you is to use a Filter to eliminate the junk rows as shown below:

Filtering the WCF Trace
Filtering the WCF Trace

This will give a much clearer view of the back and forth involved in doing a sync.

The next step is to find the method calls that we are actually interested in. The easiest way I have found to do this is to just jump through the messages in sequence whilst keeping an eye on the Parameters section shown below:

Spotting the write message in the trace
Spotting the right message in the trace

In the example above we can see that a request is going out to the Execute method and it is being passed “IsPrimaryClientSubscriptionClients” as the RequestName parameter and my Outlook client’s id as the ClientID parameter. Shortly afterwards the ExecuteResponse will come back with the server’s response.

Once you have focused in on the Execute/ExecuteResponse pair that you are interested in, you will then switch over to the XML tab to get the full details of the exchange:

WCF Tracing XML

WCF Tracing XML

And that’s it! Once you’ve managed to focus in on the messages of interest you at least stand a fighting chance of being able to figure out what’s going on!

One last note is that once you have done your tracing you should be sure to switch your config file back or comment out the section we added earlier. Your users won’t thank you for the performance or disk space hit you get from leaving Outlook spewing trace data 😉

Happy bug hunting!

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s