A few days ago, I was working on LightReader, trying to nail down some features before the West Michigan Day of .NET.  I ended up spending a few hours chasing down a WCF issue and wanted to write about it in hopes it will help others.

The error I was seeing was:

“An exception of type ‘System.ServiceModel.ProtocolException’ occurred in System.ServiceModel.dll but was not handled in user code

Additional information: The remote server returned an unexpected response: (404) Not Found.”

Not very helpful is it?

The particular functionality I was working on involved importing an OPML file.  This turned out to be one of those classic examples of having passing unit tests, but a big failure when running the application (or integration tests).  The method I was working on has this signature:

List ImportOPML(string opmlContents);

BTW, the application is being developed using TDD, so let’s review that process: write a test that fails, add just enough code to get that test to pass, refactor.  Red, Green, Refactor!

After selecting the OPML file to import, I pull the contents into a string variable and then call LightReaderService.ImportOPML to save the feeds to the database.  The ImportOPML method uses a 3rd party library – the Argotic Syndication Framework – to parse the OPML so once the data is loaded, I simply iterate through the “outlines”, persist and then return the imported feeds in List.

   1:  private void importOPMLButton_Click(object sender, RoutedEventArgs e)

   2:  {

   3:      OpenFileDialog dlg = new OpenFileDialog();

   4:      dlg.Filter = "OPML Files (*.opml)|*.opml";

   5:      if (dlg.ShowDialog() == DialogResult.OK)

   6:      {

   7:          using (StreamReader reader = dlg.SelectedFile.OpenText())

   8:          {

   9:              string opmlContents = reader.ReadToEnd();

  10:              if (opmlContents.Length > 0)

  11:              {

  12:                  _lightReaderServiceProxy.ImportOPMLAsync(opmlContents);

  13:              }

  14:          }

  15:      }

  16:  }

Easy enough, right?

It worked in the context of my unit test, but as soon as I fired up LightReader and selected a “real” OPML file, things went straight to hell and I started receiving the error I described at the top of this post.  Being a relative noob to WCF, I ended up googling for more information on that error.  I quickly found out that I would need to turn on logging for WCF since it is turned off by default for WCF.  Bummer.  Luckily I found a blog post that helped me configure things so I could get more detail about what was happening.  Of course that post talked about using the “Service Trace Viewer” (SvcTraceViewer.exe), but didn’t say where to get it.  After some searching, I found that it’s in the Windows SDK along with the service configuration utility.  Thank God I had the SDK installed because otherwise it’s a 1+ GB download (iso).

After modifying my config file to include the sections for logging, I fired up LightReader, opened my OPML file and watched the exception pop up.  Opening the log filen that was generated gave me this extended error:

“The formatter threw an exception while trying to deserialize the message: There was an error while trying to deserialize parameter http://tempuri.org/:opmlContents. The InnerException message was ‘There was an error deserializing the object of type System.String. The maximum string content length quota (8192) has been exceeded while reading XML data. This quota may be increased by changing the MaxStringContentLength property on the XmlDictionaryReaderQuotas object used when creating the XML reader. Line 57, position 166.’.  Please see InnerException for more details.”

Huh?  I had already set the readerQuotas in my config file because of another issue I had early on in the development.  I originally modified these values because I was unable to return the contents of a full feed back to my client.  In this case, the error above was being caused because I was trying to send the opmlContents string to the service, but it was larger than 8192 bytes.

Anyway, here is what the config section looked like:

<readerQuotas maxDepth="32"
    maxStringContentLength="2147483647"
    maxArrayLength="2147483647"
    maxBytesPerRead="4096"
    maxNameTableCharCount="4096" />

I also had the following code in the client portion of my app:

   1:  BasicHttpBinding binding = new BasicHttpBinding(BasicHttpSecurityMode.None);            

   2:  binding.MaxBufferSize = Int32.MaxValue;

   3:  binding.MaxReceivedMessageSize = Int32.MaxValue;            

   4:   

   5:  EndpointAddress address = new EndpointAddress(http:///LightReaderService.svc);

Note: As I continue in the development of LightReader, I’ll probably tweak those “max” values to something more reasonable than Int32.MaxValue.  The same goes for the values in my config file.

Because I knew I had already changed those values in my config file (AND in code), I became fixated on the “XMLDictionaryReaderQuotas” and spent at least an hour surfing, trying to figure out how in the hell to set the value.  None of the solutions I found seemed to apply to my situation so I kept looking.  I even posted on twitter at one point.  As luck would have it, the “XMLDictionaryReaderQuotas” had nothing to do with it because the error was related to the configuration.

Here is my complete (before I fixed it) system.ServiceModel section from my config file.  Can ya spot the problem? 

   1:    <system.serviceModel>

   2:      <diagnostics>

   3:        <messageLogging logEntireMessage="true" logMalformedMessages="true"

   4:          logMessagesAtServiceLevel="true" logMessagesAtTransportLevel="true"

   5:          maxMessagesToLog="3000" maxSizeOfMessageToLog="2000" />

   6:      diagnostics>    

   7:      <services>

   8:        <service behaviorConfiguration="LightReaderServiceBehavior" name="LightReader.Business.Services.LightReaderService">

   9:          <endpoint address="" binding="basicHttpBinding" contract="LightReader.Business.Services.Contracts.ILightReaderService">

  10:            <identity>

  11:              <dns value="localhost" />

  12:            identity>

  13:          endpoint>

  14:          <endpoint address="mex" binding="mexHttpBinding" contract="IMetadataExchange" />

  15:        service>

  16:        <service behaviorConfiguration="UserServiceBehavior" name="LightReader.Business.Services.UserService">

  17:          <endpoint address="" binding="basicHttpBinding" contract="LightReader.Business.Services.Contracts.IUserService">

  18:            <identity>

  19:              <dns value="localhost" />

  20:            identity>

  21:          endpoint>

  22:          <endpoint address="mex" binding="mexHttpBinding" contract="IMetadataExchange" />

  23:        service>

  24:      services>

  25:      <behaviors>

  26:        <serviceBehaviors>

  27:          <behavior name="LightReaderServiceBehavior">

  28:            <serviceMetadata httpGetEnabled="true" />

  29:            <serviceDebug includeExceptionDetailInFaults="false" />

  30:          behavior>

  31:          <behavior name="UserServiceBehavior">

  32:            <serviceMetadata httpGetEnabled="true" />

  33:            <serviceDebug includeExceptionDetailInFaults="false" />

  34:          behavior>        

  35:        serviceBehaviors>

  36:      behaviors>

  37:   

  38:      <bindings>      

  39:        <basicHttpBinding>        

  40:          <binding name="basicHttpBinding" closeTimeout="00:10:00" openTimeout="00:10:00"

  41:            receiveTimeout="00:10:00" sendTimeout="00:10:00" bypassProxyOnLocal="false"

  42:            hostNameComparisonMode="StrongWildcard" maxBufferSize="2147483647"

  43:            maxBufferPoolSize="524288" maxReceivedMessageSize="2147483647"

  44:            messageEncoding="Text" textEncoding="utf-8" transferMode="Buffered"

  45:            useDefaultWebProxy="true">

  46:            <readerQuotas maxDepth="32"

  47:           maxStringContentLength="2147483647"

  48:           maxArrayLength="2147483647"

  49:           maxBytesPerRead="4096"

  50:           maxNameTableCharCount="4096" />

  51:          binding>

  52:        basicHttpBinding>

  53:      bindings>    

  54:    system.serviceModel>  

Did you find the problem?  I made the same error that the guy who posted the last reply in this forum thread.  It took a long time before I realized what I was missing and that was only after I stared at that forum post for way too long.  In my opinion, this was angle brackets for the loss. 

Line 9 should look like this:

<endpoint bindingConfiguration="basicHttpBinding" address="" binding="basicHttpBinding" contract="LightReader.Business.Services.Contracts.ILightReaderService">

Ugh.  Several hours wasted because I didn’t specify the bindingConfiguration!  Honestly, I kinda thought that by specifying the binding that it’d pick up all the configuration information that was needed.  I ASSUMEd incorrectly.   Like I said, I’m a WCF noob, but it would have been nice if the error had said, oh I don’t know, something like “missing configuration information” or “bindingConfiguration not set”.

I should mention that within a minute or so of me figuring out the issue, Joe Wirtley came through with a link related to my issue.   BTW, I twittered my victory.