Last week I got a call from a colleague who was struggling with a .NET performance issue. He's working a s a developer on a really large .NET project in the finance sector. The project is one of the largest implementations of a service oriented architecture in Norway. My colleague was working on a calculation service exposing some core calculation formulas and models used within the company. The formulas are fairly complex (I didn't understand any of it), but consisted mostly of large sums being accumulated iterative and there was no obvious reason why it took more than 3 minutes to calculate the numbers. Excel crunched the numbers in no time. Where had they had screwed up so badly?

Armed with ANTS profiler I showed up Monday afternoon to have a look at the problem. Following good programming practices the calculation service was well tested using unit tests, and they had a local test environment set up. All we had to do to profile the code was to run ANTS on one of the test suites. And the result from ANTS immediately revealed the problem. More than 99% of the entire running time of the test was spent on the EntityBase.Clone method. By following the "slowest code path" inside ANTS we managed to track down the code responsible for all the cloning. Turns out one libraries exposing "standard" math functions (relevant to the business domain) used and cloned an object derived from EntityBase. The EntityBase object is developed by another team within the business responsible for some of the core functionality across all services in the SOA architecture. The entity library was more or less a "black box" component to my colleague who hadn't thought that this might be the source of the problem.

The EntityBase class exposed some simple base functionality other developers could relay on. One of the major parts of the base class was the implementation of the IClonable interface. The IClonable is the standard way to implement deep copying of .NET objects. To make a shallow copy of an object you use the MemberwiseClone method. The implementation of IClonable in the base class used reflection to make it possible to clone any derived object with out writing any cloning code yourself. Using reflection to make your objects behavior dynamic is a really powerful concept. If you want to learn more about this there is an article and example base class for cloning objects up on The Code Project.

Using reflection is one of the most performance expensive things you can do within .NET. In some cases it's an invaluable feature, but in cases like this one it's the root of the problem. To solve the performance problem in this particular case the solution was to write a custom implementation of the Clone method on the object being cloned all the time by the math library.

By cloning the object field by field, instead of using reflection, we managed to get the time used to clone the object down from 190 to 1.5 seconds!

I've re-created the problem with a really simple example. The example is a tiny console application with one base class (BaseEntity) and one derived class (PersonEntity). The base class implements cloning using reflection, and the derived class implements a separate cloning method called QuickClone. In the Main method I create an instance of the person object and clone it 250 000 times using both Clone and QuickClone. The screenshot shows the results of the ANTS profiler. Cloning the object 250 000 times using Clone and reflection took 13.8 seconds. Cloning the object using QuickClone took 0.5 seconds… 

The point of this story is that if you play with reflection you might get burned. You need to know what you are doing. In this case I have no doubt that the framework guys knew what they where doing in the base entity class. I think the problem was that other teams within the company didn't know that the base class used reflection, and that this is something that might hurt performance badly. Another lesson learned is that if you have .NET performance problems, bring in ANTS right away. It's an amazing tool!