Email Router Demystified – Tools for Troubleshooting - WCF Tracing

Author note: As you’ll notice with most of my blog posts, they tend to have a lot of information and are a bit long.  Instead of sacrificing content, I’ll break up the posts into a series for posts.  This way people don’t get overwhelmed with the amount of content but for those that want the deep technical details, they get that as well.

This article covers WCF Tracing and is the fourth article within the Email Router Demystified – Tools for Troubleshooting blog series.  To get to a list of the other tools, go HERE.

One of the alternates to Fiddler and Message Analyzer is to be able to use WCF tracing.  WCF tracing allows us to see the WCF traffic in clear text between the router and the email service.  The reason you would use WCF tracing rather than Fiddler is that Fiddler will not show you HTTP, non SSL, traffic.  WCF encrypts the message and Fiddler is not able to decrypt the WCF encryption.  So WCF tracing is the only way you are going to be able to see HTTP traffic and the result from the Email Router.  However, we can see the POP3 and SMTP traffic as well within this trace.

Configuration

To enable WCF tracing, it requires a file to be created and placed within the Service folder (C:\Program Files\Microsoft CRM Email\Service).  You need to create Microsoft.Crm.Tools.EmailAgent.exe.config.  You can use Notepad or some other simple text editor or using Visual Studio if you want to get the rich XML experience.  The config file must contain the following:

<configuration>
<system.diagnostics>
  <sources>
      <source name="System.Net" tracemode="includehex" maxdatasize="1024">
        <listeners>
          <add name="System.Net"/>
        </listeners>
      </source>
      <source name="System.Net.Sockets">
        <listeners>
          <add name="System.Net"/>
        </listeners>
      </source>
      <source name="System.Net.Cache">
        <listeners>
          <add name="System.Net"/>
        </listeners>
      </source>
    </sources>
    <switches>
         <add name="System.Net" value="Verbose"/>
      <add name="System.Net.Sockets" value="Verbose"/>
      <add name="System.Net.Cache" value="Verbose"/>
    </switches>
   <sharedListeners>
      <add name="System.Net" type="System.Diagnostics.TextWriterTraceListener" initializeData="c:\EmailRouterWCFLog\network.log"/>
    </sharedListeners>
    <trace autoflush="true"/>
  </system.diagnostics>
</configuration>

NOTE: The trace directory (c:\EmailRouterWCFLog) needs to be created prior to setting this up otherwise the log will not be created.

Once you have created the config file and defined the details above, then you need to restart the Microsoft CRM Email Router service:

Log

After enabling WCF logging and restarting the service, we can review the log file that was created in the directory defined with the config file.  The details in the log file are hard to read to the eye and to correlate. 

There are a couple of things you can do to help you parse through the log file

1. The trace file is broken up into class (System.Net, System.NET.Sockets, etc)
2. Additionally, it has a thread ID associated to it.   In the screenshot above, you can see there are three of them [1476], [1612], [13880]

Reviewing the log file, let’s say I want to review the traffic incoming traffic for Tamera Lawson.  I know that Tamera has an email address of tamera@contoso.local.  I need to try and find something to search on in the trace files.  You can see in the file details above, we have a lot of line breaks and we are seeing a bunch of hex data.  To the right of the hex data, we can see clear text but it’s possible that my search conditions are going to be broken up into multiple lines. 

Searching for tamera@contoso.local returns nothing.  However, if I search for tamera, I get a hit:

Looking at the screenshot above, I can see that there are two different threads here (1476, 13880) and the data is sort of all over the place.  So what can we do to help extract the pertinent details to the thread ID that is important to us, 13880.

BareGrep

The best thing I have found to parse through these files is a free text searching tool called BareGrep.  When using BareGrep, I define the folder where my file is at, in this case C:\EmailRouterWCFLog, and I can leave the wildcard *.* for the file (will search every file in that directory) or I can define a specific file, network.log.  Now the crux of this is the search criteria that you set in the Text field.  Here I put in [13880], note I unchecked “Regex Syntax” and hit search.

The data, again, is not easy to read but I can do a couple of things:

1. If you understand how to use Regular Expression, you can define a more detailed search criteria and check the “Regex Syntax”.  However, I know my limitations and I’m not RegEx expert.  I’m willing to learn if someone is patient to teach me.
2. What I tend to do is export the results to a text file and then use BareGrep again to refine data.  You do this within BareGrep by clicking on File > Export.  Then I simply export the Text column “To File”:
   
3. Now I can use BareGrep to do additional searching.  In this case, I searched on StatusCode and found a response that is concerning (StatusCode=500):
   
4. Next I go to that specific Line number, 1718, (if you open the file in Notepad, you can use CNTRL+G and enter the line number) and look at the response I am getting back:
   

You can see the message I get back is similar to what we would see in Fiddler.  Again, this is not an option I use a lot.  However, it is something I have used when I am in a bind and a customer is communicating over HTTP.