Sunday, March 13, 2005

AOP Performance Numbers for .NET - Part 1

A question came up on the Australian .NET mailing list about which is the fastest AOP implementation. I committed to running some performance tests on the subject. Over the weekend I did some testing on the AOP.NET Framework's performance compared to not using AOP and manually coding the aspect. Because logging is so often used as AOP's prototypical 'problem-solved' scenario, I used this in the tests. Obviously cross-cutting something heavy like 2PC transactions would give a different result, and cross-cutting a slow method would also dramatically decrease the relative impact of using AOP.NET.


Anyway, enough of the caveats. I ran the test using the benchmark harness I wrote for Maximizing .NET Performance. The test case was calling a virtual method (which was empty). Before the method executed, I wanted the following line to execute:

Trace.WriteLine("Entering method");

I tested three cases: the generation of the Trace.WriteLine call through AOP.NET, the Trace.WriteLine call manual coded before the call to the empty virtual function, and the Trace.WriteLine call without the virtual function call. The result was that using AOP.NET to cross-cut the logging was eight times slower than manually coding it. Again, these results are for cross-cutting a light-weight logging call onto an empty virtual method. For a fatter cross-cut onto a fatter method, the relative impact of the cross-cut will be much smaller. My test case is close to a worse-case scenario, so don't ditch AOP.NET or AOP in general based on this result. On the same token, don't be dismissive of the impact of doing compile-time-like things at runtime. The cost can be high.


Next weekend I'll try to run the test on a Context Bound Attributes-based AOP framework.


Full dump of results:



TraceWriteLineTest
Compares AOP techniques for generating a simple log message before method execution


AOPdotNET Normalised: 8.630499 Median: 00:00:01.6836290 Mean: 00:00:01.6920000 Min: 00:00:01.6729440 Max: 00:00:01.7263870 StdDev: 00:00:00.0220000
Results:00:00:01.7004660 00:00:01.6836290 00:00:01.7263870 00:00:01.6784470 00:00:01.6729440


Inline Normalised: 1.007284 Median: 00:00:00.1965000 Mean: 00:00:00.1980000 Min: 00:00:00.1946380 Max: 00:00:00.2063730 StdDev: 00:00:00.0050000
Results:00:00:00.1950010 00:00:00.1970740 00:00:00.1946380 00:00:00.2063730 00:00:00.1965000


VirtualCallAndTrace Normalised: 1 Median: 00:00:00.1950790 Mean: 00:00:00.1970000 Min: 00:00:00.1936980 Max: 00:00:00.2054330 StdDev: 00:00:00.0050000
Results:00:00:00.1936980 00:00:00.1954910 00:00:00.1950790 00:00:00.2054330 00:00:00.1947720





Test code:
using System;
using System.Diagnostics;
using DotNetPerformance;
using NAop;

namespace TestCode
{
public class TraceWriteLineTest
{
[Benchmark("Compares AOP techniques for generating a simple log message before method execution")]
public static TestResultGrp RunTest()
{
const int numberIterations = 10000;
const int numberTestRuns = 5;

TestRunner tr = new TestRunner(numberIterations, numberTestRuns);
TestRunner.TestCase testCases = null;

testCases += new TestRunner.TestCase(AOPdotNET);
testCases += new TestRunner.TestCase(Inline);
testCases += new TestRunner.TestCase(VirtualCallAndTrace);

return tr.RunTests(testCases);
}

public static void AOPdotNET(Int32 numberIterations)
{
ContextAOP context = (ContextAOP)NAop.AopXmlFactory.Create(typeof(ContextAOP));
for (int ix = 0; ix < numberIterations; ++ix)
{
context.NoOpMethod();
}
}

public static void VirtualCallAndTrace(Int32 numberIterations)
{
ContextAOP context = new ContextAOP();
for (int ix = 0; ix < numberIterations; ++ix)
{
context.NoOpMethod();
Trace.WriteLine("Entering method");
}
}

public static void Inline(Int32 numberIterations)
{
for (int ix = 0; ix < numberIterations; ++ix)
{
Trace.WriteLine("Entering method");
}
}
}
}

/* AOP.NET Code */
using System;
using System.Diagnostics;
using NAop;


namespace TestCode
{

public class ContextAOP
{
public virtual void NoOpMethod(){}
}

public class AspectLog : IAspect
{
#region IFilter Members

public void BeforeInvoke(IAopContext context)
{
Trace.WriteLine("Entering method");
}

public void AfterInvoke(IAopContext context)
{
}
#endregion

}
}

/*AOP.NET Config*/

<AopNet>

 <AspectAssembly Name="TestCode.dll">

  <AspectClass Name="TestCode.AspectLog">

   <CrosscutClass Name="TestCode.ContextAOP">

    <PointMethod Name="NoOpMethod"/>

   </CrosscutClass>

  </AspectClass>

 </AspectAssembly>

</AopNet>

0 Comments:

Post a Comment

<< Home