Threading issues in WCF-Adapter Body Path

by | Jan 14, 2015 | BizTalk Community Blogs via Syndication | 0 comments

(I originally wrote this the 5th of May 2014 but did not publish it. I only sent it as internal feedback at the time. I am now choosing to publish it anyway since there has now been ample time for Microsoft to fix the problem)

The scenario

I am using the BizTalk Server WCF adapters in a solicit-response send port and I am getting the response using the Body Path configuration option.

The problem

Main issues that using the WCF Adapter – Messages tab – Inbound BizTalk message body – Path, configured with an XPath and String Node Encoding configuration options produces under load:

  • Deserialization fails producing random and irregular errors seemingly caused by the stream position jumping to an erroneous location.
  • The adapter returns the wrong mismatched response (!!!) back to the pipeline

For the first issue, the following is the error message (or an example of):

System.Xml.XmlException: Start element 'To s:mustUndersta' does not match end element 'sendMessageResult'. Line 1, position 951.

If you catch it and look at the XmlExceptions call stack, you will find this:

at System.Xml.XmlExceptionHelper.ThrowXmlException(XmlDictionaryReader reader, String res, String arg1, String arg2, String arg3)
at System.Xml.XmlUTF8TextReader.ReadEndElement()
at System.Xml.XmlUTF8TextReader.Read()
at System.Xml.XmlSubtreeReader.Read()
at Microsoft.BizTalk.Adapter.Wcf.Runtime.BinaryReaderStream.ReadContentAsString(Byte[] buffer, Int32 offset, Int32 count)
(call stack continues with custom code)

For the second issue, you will NOT find anything wrong in BizTalk. It will simply associate the wrong response with the wrong request and return the wrong message! This is far worse than the first exception in my opinion since it effectively, successfully and quietly sends back someone else's response to a caller. When examining it closer it does not appear to swap responses, it just hands one response back to more then one caller, and the other responses simply disappear and are never used. BizTalk will not discover this (at least not in my case where I am always getting the same response MessageType back from the port), only whatever application logic that are either built into BizTalk by you or the system or application calling BizTalk or human intervention might discover what has happened. Perhaps when getting the wrong data back.

Guide to reproduce

Steps (that I took) to build up and test a solution to reproduce the error:

  1. Download the Windows Communication Foundation (WCF) and Windows Workflow Foundation (WF) Samples for .NET Framework 4, http://www.microsoft.com/en-us/download/details.aspx?id=21459 (this is not required, though it gives us a simple starting point.
  2. Use the Self-Host sample found at \WCF\Basic\Services\Hosting\SelfHost\CS and described at http://msdn.microsoft.com/en-us/library/vstudio/ms733765%28v=vs.100%29.aspx. Basically this is the Calculator sample hosted in a Console app (this is not required for repro, it is just for simplicity).
  3. Test it to make sure it’s working.
  4. Extend the Client somewhat to get a bit more simultaneous and multi-threaded. I will show this later but essentially I am using the Calculator Add method and from several threads to create some load.
  5. Test it again and see there are no errors.
  6. Create a receive port and receive location, as well as a send port in BizTalk and route the message through so that BizTalk is between the client and the service.
  7. Test it and make sure it’s working (at this point I still have no issues).
  8. Now consume the Calculator service metadata in a BizTalk project to create the schema for the Add, Subtract, etc methods and their responses. Create a simple BizTalk flat file schema (we need something to store the XPath string we extract), create a pipeline with the Flat File Disassembler configured with that schema (we need to disassemble the string we receive from the adapter into that schema), and then a Map mapping from that schema to the original Calculator service schema and the AddResponse message (we want the client to get the correct response back).
  9. Compile, Deploy and wire everything up inside Biztalk (ie re-configure the ports created to use the receive pipeline we created, and the map we created.
  10. Also configure the send ports WCF Adapter – Messages tab – Inbound BizTalk message body – Path,  with an XPath and String Node Encoding.
  11. Run a single message through to make sure everything works. In fact, run it non-multi-threaded with several messages and make sure it works (which for me it did).
  12. Now run multiple threads to create a load on the system.
  13. Watch as the previously described errors appear. At first it works fine, then I begin getting responses I did not expect (2+2 = 8?) and then I run into the ’Start element ’’ does not match end element ’’ exception.

An in-depth look

The service

There is nothing to see here really. It’s your most basic WCF service, same as it comes with the sample (slightly abbreviated in the sample below).

Code

namespace Microsoft.ServiceModel.Samples
{
    // Define a service contract.
    [ServiceContract(Namespace="http://Microsoft.ServiceModel.Samples")]
    public interface ICalculator
    {
        [OperationContract]
        double Add(double n1, double n2);
       ...
    }

    // Service class which implements the service contract.
    // Added code to write output to the console window
    public class CalculatorService : ICalculator
    {
        public double Add(double n1, double n2)
        {
            double result = n1 + n2;
            Console.WriteLine("Received Add({0},{1})", n1, n2);
            Console.WriteLine("Return: {0}", result);
            return result;
        }
        ...

        // Host the service within this EXE console application.
        public static void Main()
        {
            // Create a ServiceHost for the CalculatorService type.
            using (ServiceHost serviceHost = new ServiceHost(typeof(CalculatorService)))
            {
                // Open the ServiceHost to create listeners and start listening for messages.
                serviceHost.Open();

                // The service can now be accessed.
                Console.WriteLine("The service is ready.");
                Console.WriteLine("Press <ENTER> to terminate service.");
                Console.WriteLine();
                Console.ReadLine();

            }
        }

    }

}

Config

This is basically the same as the sample, the only exception is that I removed security (simply because that’s what the scenario I was testing had).

    <bindings>
      <wsHttpBinding>
        <binding name="wsConfig">
          <security mode="None" />
        </binding>
      </wsHttpBinding>
    </bindings>
    
    <services>
      <service name="Microsoft.ServiceModel.Samples.CalculatorService" behaviorConfiguration="CalculatorServiceBehavior">
        <host>
          <baseAddresses>
            <add baseAddress="http://localhost:8000/ServiceModelSamples/service"/>
          </baseAddresses>
        </host>
        <!-- this endpoint is exposed at the base address provided by host: http://localhost:8000/ServiceModelSamples/service  -->
        <endpoint address="" binding="wsHttpBinding" contract="Microsoft.ServiceModel.Samples.ICalculator" bindingConfiguration="wsConfig"/>
        <!-- the mex endpoint is exposed at http://localhost:8000/ServiceModelSamples/service/mex -->
        <endpoint address="mex" binding="mexHttpBinding" contract="IMetadataExchange"/>
      </service>
    </services>

    <!--For debugging purposes set the includeExceptionDetailInFaults attribute to true-->
    <behaviors>
      <serviceBehaviors>
        <behavior name="CalculatorServiceBehavior">
          <serviceMetadata httpGetEnabled="True"/>
          <serviceDebug includeExceptionDetailInFaults="False"/>
        </behavior>
      </serviceBehaviors>
    </behaviors>

The client

Here I have added some multi-threading aspects on top of the sample code.

Code

namespace Microsoft.ServiceModel.Samples
{
    //The service contract is defined in generatedClient.cs, generated from the service by the svcutil tool.

    //Client implementation code.
    class Client
    {
        static void Main()
        {
            Console.WriteLine("Press ENTER to start!");
            Console.ReadLine();

            List<Task> tList = new List<Task>();

            Action a = () =>
            {
                Random random = new Random();
                int mseconds = random.Next(1, 100) * 10;
                System.Threading.Thread.Sleep(mseconds);

                // Create a client
                CalculatorClient client = new CalculatorClient();

                for (int i = 0; i < 10; i++)
                {
                    double result = client.Add(Convert.ToDouble(i), Convert.ToDouble(i));
                    double localResult = Convert.ToDouble(i) + Convert.ToDouble(i);
                    if (result != localResult)
                        Console.WriteLine("{0} !!!!!!!!!!!!!!!!!!! {1}", result, localResult);
                }

                //Closing the client gracefully closes the connection and cleans up resources
                client.Close();
            };

            for (int i = 0; i < 100; i++)
            {
                Task t = new Task(a);
                t.Start();
                tList.Add(t);
            }

            Task.WaitAll(tList.ToArray());

            Console.WriteLine();
            Console.WriteLine("Press <ENTER> to terminate client.");
            Console.ReadLine();
        }
    }
}

As you can see it does not take much, that is – I am not running thousands of threads here, in fact in total I only make a thousand calls, and I get an error every time I have run the app so far.

Let’s examine this a little bit closer. As you can see I am doing the following.

double result = client.Add(Convert.ToDouble(i), Convert.ToDouble(i));
double localResult = Convert.ToDouble(i) + Convert.ToDouble(i);
if (result != localResult)
    Console.WriteLine("{0} !!!!!!!!!!!!!!!!!!! {1}", result, localResult);

That is, I am sending the addition of the two numbers to the service, and the doing the same calculation locally. Then I compare the result I get from the service with my local result. If they do not match, I print the fact.

Config

The clients config (by necessity) matches that of the services. It is available in the download but I am not including a dump of it.

The BizTalk solution

To be able to reproduce the problem in a portable manner I created a simple BizTalk solution.

Visual Studio Solution

At this point I have got three projects in Visual Studio, of which my BizTalk project is the first in the below screenshot.

It contains the following artifacts:

  • CalculatorService_microsoft_servicemodel_samples.xsd – the schema for the Calculator service that was automatically generated for me (I removed the other generated artifacts as they were non-essential for the purpose of this repro).
  • FFAddResult.xsd – a simple flat file schema that will act as the temporary carrier of the result after I extract it from the incoming xml response until the Map transforms the message back into an AddResponse message.
  • Map1.btm – a map that transforms from FFAddResult to CalculatorService_microsoft_servicemodel_samples#AddResponse.
  • ReceiveFFAddResultPipeline.btp – a disassemble pipeline that will take the incoming string and create an FFAddResult xml message.

The FFAddResult.xsd is extremely simple.

As is the Map1.btm.

BizTalk Server configuration

In BizTalk I have a receive port and a receive location with very simple configuration; PassThruReceive and PassThruTransmit pipelines, WCF-Custom WS-Http binding (so I can host it in BizTalk and have fewer moving pieces – not essential to the repro, just easier to move around).

Everything is according to default configuration except no security.

No behaviors, no special parts of the message extracted here or non of that (the xpath is on the send port receive).

Speaking of which, the send port (in the configuration that give me issues) is a solicit-response port running the WCF-WSHttp adapter (to be frank, I have not tested other adapters/bindings) and running the receive pipeline we created.

Receive pipeline has trivial config.

We have our inbound map configured.

And a filter on the receive port name that I won’t include a screenshot of.

The adapter configuration is set to forward the call to the backend service add method.

It also has security set to none (not shown in screenshot) as well as on the Messages tab having the Inbound BizTalk message body – Path,  set to an XPath and String Node Encoding. the xpath in this case is /*[local-name()='AddResponse' and namespace-uri()='http://Microsoft.ServiceModel.Samples']/*[local-name()='AddResult' and namespace-uri()='http://Microsoft.ServiceModel.Samples'], which will forward the string value inside the AddResult node for the pipeline.

Executing the failing code

Below is a screenshot of the app running, where as you can notice, the response is not as expected.

As mentioned before, the app gets a number if these mismatched erroneous responses and then crashes (due to the previously mentioned exception and the sample apps lack of exception handling).

Here is also some sample output from the service (in this case the screenshot is from a test where it has been able to run to completion and what we are seeing are the final tasks/threads doing their last calls).

The workaround

Ok, now that we are aware of the failing component. Can we work around it?

Enter the XPathExtractor pipline component, based of some of BizTalks hidden gems.

Essentially, the solution is – don’t use the BizTalk message body – Path option. Instead, just get the body and extract the XPath you want in a pipeline component. Although I have not done any performance comparisons but I am not expecting the code to have any noticeably difference in performance. You might want to think twice before running very large message through it (as will become evident in the source code included later). But I think the same is true for using the adapters Body Path option, which (as we can see from the callstack the exception had) also gets the content of the node as a string.

I created a new port and a new pipeline, getting only he body in the adapter and instead extracting the string in the pipeline. Configuration as follows.

The Execute method of the pipeline component does this:

Stream stream = new ReadOnlySeekableStream(pInMsg.BodyPart.GetOriginalDataStream());

XmlTextReader xmlTextReader = new XmlTextReader(stream);
XPathCollection xPathCollection = new XPathCollection();
xPathCollection.Add(this.XPath);
XPathReader xPathReader = new XPathReader(xmlTextReader, xPathCollection);

bool matchFound = false;
while (xPathReader.ReadUntilMatch())
{
    if (xPathReader.Match(0))
    {
        string val = xPathReader.ReadString();
        stream = new VirtualStream(new MemoryStream(System.Text.Encoding.GetEncoding(this.Encoding).GetBytes(val)));
        matchFound = true;
        //break; // don't break, read to end to play nice with other components 
                    // that have a streaming approach and might want to process the full message
    }
}

if (!matchFound)
    throw new Exception("xPathReader.ReadUntilMatch() found no match");

stream.Seek(0, SeekOrigin.Begin);
pInMsg.BodyPart.Data = stream; 
pContext.ResourceTracker.AddResource(xPathReader);

I have run this a number of times and never as of yet gotten the same exception.

Remember that if you have any objections on the code in this component (like why is he adding the xPathReader to the resourceTracker, or whatever else) that this is not used when I get the issues, this is used to get around them.

Quick performance comparison

Quick and dirty indeed. This has no intention to go deep or be thorough. With that out of the way

Without Adapter Body Path

Red is proc. Blue is message publishing rate. Green is memory (not sure I got the right counter for that one, but I’ll ignore that for putting together this post).

With Adapter Body Path

It’s not really applicable to performance measures because it fails quite early. The most interesting thing with this graph I would say is that I don’t have to reach higher than 4 simultaneous request to start getting issues.

With XPath extraction in pipeline component

Also note that due to the randomness of my Task execution this may not be altogether comparable, so just keep that in mind. I post it mainly to illustrate that I am not running a really massive load, to show how early it fails, and to note that the workaround is not terrible.

My environment

My repro environment is a Hyper-V virtual machine with 4608MB allocated running alone on a 8 core host machine. It’s BizTalk Server 2010 with CU6, Windows Server 2008 R2 fully patched, SQL Server 2008 R2 SP1 (yes, I am aware there is a later service pack, but at the time it was not applied. I would be very surprised if it makes a difference). I have reproduced this error on several environments so it’s not isolated to mine. Although I am running BizTalk Server 2010 I would not be surprised to find this in BizTalk Server 2009, BizTalk Server 2006 R2 or even BizTalk Server 2013. Though I can neither confirm not deny since I have not tried.

Download

The full source code and bindings for everything I have mentioned in this article, including the code for the pipeline component, is available for download here.

Blog Post by: Johan Hedberg

Submit a Comment