Debugging a performance issue

One more post on “back to basics” series.. :)I was playing these days with a generic HTTP handler (.ashx) in ASP.NET 4.0 (it could be a web service, it doesn’t matter in this context).
The http handler tried to do a simple task: return to the client several objects, encoded as JSON. Usually there were around 50 objects, each with 200 string properties (don’t ask why). The list of objects was encoded using Newtonsoft Json.Net, and send to the browser to be displayed using JQuery – nothing special here.

When I first run the code, surprise – it took the server around 1-2 seconds to send the response to the browser, even if I run everything on a fast quad-core machine and the processor was not busy with something else, and the browser was on the same computer (so no network latency..).

The code was also pretty basic:

    public void ProcessRequest(HttpContext context)
      // ...
      context.Response.ContentType = "application/json";
      context.Response.BufferOutput = false;
      // ...
      ResultsList rows = GenerateResultsList(...); // create ~ 50 'rows', each with 200 string properties
      // serialize and write the list of objects directly to the HttpResponse, as JSON
      JsonSerializer jsonSerializer = new JsonSerializer();
      using (JsonWriter writer = new JsonTextWriter(response.Output))
        jsonSerializer.Serialize(writer, rows);


Quite low-level, but simple.
Probably you already spotted the problem in the above code, but since the real code was split into several separate classes and methods, it took me a few more steps to discover the issue.

Trying to figure out what’s happening, I compiled in release mode, fired Fiddler and got this:
Fiddler statistics
– over 2s and ~ 800KB of content.

Taking a closer look at the raw response, I saw this:
Fiddler - raw response
– tiny chunks of data, compressed with GZIP..

Something was not quite right..

Since a local download of 800KB of data should be much faster, I fired RedGate Ant Profiler to see where the bottleneck was:
Ants Profiler - the culprit
Pretty clear – even if I call JsonSerializer.Serialize only once, the response is flushed in tiny bits, 20.000 times (digging deeper with reflector, once for every JSON property and value).
Indeed, the browser receives the response immediately, as soon as it’s generated, but at what cost..

The fix was simple:
context.Response.BufferOutput = true;

Now the profiling looks much nicer:
Ants Profiler 2

Also the amount of data transferred over the wire looks better:
Fiddler statistics final
– the response is almost eight times smaller.

Also the raw HTTP response has only one gzipped chunk:
Fiddler raw final

Note to self: don’t try to be clever by thinking that sending the response immediately to the browser will always improve the ‘responsiveness’ of the application; don’t be quick to blame the JSON serializer for performance issues when the cause might be in my own code. ­čÖé When you see a performance problem, measure and profile the code, don’t try to guess the cause, unless it’s obvious.

This entry was posted in .NET, Web and tagged , , , . Bookmark the permalink.

2 Responses to Debugging a performance issue

  1. Andrei Rinea says:

    BufferOutput set to false has bit me once way back in 2006… I would personally set a compiler warning for this :))

    • Tudor Turcu says:

      It depends – sometimes it’s useful to have BufferOutput set to false (ex.: when dealing with textual content and not-so-fast connections), if you take care not to flush the content in chunks too small.

Leave a Reply

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

You are commenting using your 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