XmlSerializer deserialization time fluctuates on WCF service

Question

Updated

This problem was determined to not be an issue with XmlSerializer and deserialization, but actually an issue with reading the response stream from the remote source. Thanks to Chris Sinclair and Jesse C. Slicer for their help and direction in determining the discrepency I was seeing.

---

I've been profiling the time it takes XmlSerializer to deserialize a static block of XML data into my custom MyXmlObject class, and the time seems to fluctuate quite dramatically from request to request, despite the data being exactly the same.

I start timing the deserialization at the moment the XML is passed to the serializer.Deserialize() method, and stop the timing as soon as it is finished:

HttpWebRequest request = (HttpWebRequest)WebRequest.Create(uri);
//initialization stuff and writing to request stream.

using (HttpWebResponse response = (HttpWebResponse)request.GetResponse()) {
    //If I run a stopwatch up to this point, I get the round trip time,
    //so I know that the stream has already been received at this point.

    using (Stream stream = response.GetResponseStream()) //In production this stream is received from a remote server.
    {
        Stopwatch stopwatch = new Stopwatch();
        stopwatch.Start();

        MyXmlObject obj = (MyXmlObject)serializer.Deserialize(stream);

        stopwatch.Stop();
    }
}

My XmlSerializer object is defined as follows:

private static readonly XmlSerializer serializer = new XmlSerializer(typeof(MyXmlObject));

My WCF web service is a Singleton that is multi-threaded.

[ServiceBehavior(
    ConcurrencyMode = ConcurrencyMode.Multiple,
    InstanceContextMode = InstanceContextMode.Single)]

Here are the results I got for 15 concurrent requests to deserialize a static block of XML data that is only 177,792 bytes:

Static XML file of 177,792 bytes

Request   Execution (ms)
1         300
2         302
3         303
4         303
5         368 *High
6         303
7         302
8         242 *Low
9         243
10        244
11        245
12        242
13        243
14        883 *Outlier
15        260

As you can see it's somewhat consistent, but it still fluctuates by about +/-100ms

On this relatively small XML file, the fluctuation is minimal, but if I feed it a much larger file (which I will be receiving more often in my WCF web service, it fluctuates much more drastically:

Static XML file of 3,851,199 bytes

Request   Execution (ms)
1         1384
2         2402
3         1715
4         4000 *Outlier
5         1310
6         2132
7         1388
8         1654
9         1183
10        1464
11        2368
12        2752 *High
13        1094 *Low
14        1838
15        1940

So as you can see the amount of time it takes to deserialize the XML file is fluctuating much more than it did on the smaller file.

I would expect it to be relatively the same (only +/- 100ms), but instead, I'm seeing a difference of +/- 1200ms or greater.

Furthermore, 2.5s is simply more time than I wish to give up for the deserialization of the XML into C# POD objects. What's interesting is that WCF serializes the C# POD objects into JSON in relatively no time at all when I return the data to the server.

Questions

• Why are these fluctuations happening?
• What can I do to minimize these fluctuations, if anything?
• Is there another type of Xml deserialization that might be faster at turning an incoming Xml of this size into an hierarchy of C# POD objects?
  • Perhaps DataContractSerializer?
  • Doesn't DataContractSerializer use XmlSerializer beneath the hood?

Please let me know if there is any information needed that I've left out that would be useful to diagnosing this problem. Thanks.

Answer 1

As per the comments, here's a chunk of code to measure purely the deserialization time, rather than the receiving of the response stream over the network. Note, it does rely on .NET 4's CopyTo() method on Stream to work.

var request = (HttpWebRequest)WebRequest.Create(uri);
// initialization stuff and writing to request stream.

using (var response = (HttpWebResponse)request.GetResponse())
using (var stream = response.GetResponseStream())
using (var memoryStream = new MemoryStream())
{
    // In production this stream is fully received from a remote server.
    stream.CopyTo(memoryStream);
    memoryStream.Seek(0, SeekOrigin.Begin);

    // If I run a stopwatch up to this point, I get the round trip time,
    // so I know that the stream has already been received at this point.
    var stopwatch = Stopwatch.StartNew();

    var obj = (MyXmlObject)serializer.Deserialize(memoryStream);

    stopwatch.Stop();
}

Answer 2

Given your comments and the way you're benchmarking, I don't believe the source of the slow speed or fluctuations are due to the XML deserialization.

In my experience, using the XmlSerializer for deserialization is pretty fast, and certainly not in the realm of 2-4 seconds for a ~3.5 megabyte file. I'd bet if you were to do another test simply deserializing a static XML string without any of the networking you'd find it to be very, very fast (I'd wager less than 50ms; certainly nowhere near 2000ms).

However, with the code you posted, I believe there is some networking issues or other factors impacting the time. If you alter your benchmarking tests to separate the stream reading from the XML deserialization, you'll find that the deserialization itself likely contributes negligibly to the overall time.

I suspect that other networking issues are in play here with the WCF services. I would suggest posting a new question trimming out the XML deserialization altogether and simply measuring the speed reading the stream of raw data. Maybe a user will be able to provide you with a better idea of how to optimize/configure/improve that aspect since serialization is not the issue here.