Monday, January 20, 2014

C# Extension Methods Performance

Today I read a blog regarding extension methods from Serena Yeoh. In her blog, she shows that how extension methods can be very helpful in making the code look more meaningful and cleaner. If you are interested to checkout how she uses extension methods to beautify the data access component in layered architecture, feel free to visit her blog.

I know a lot of people including myself are concerned about the performance of using extension methods. Therefore, I have done some comparison and testing to find out whether is it bad to use extension methods?

Now, I am comparing the layered architecture sample code that uses extension methods which is given by Serena versus the same sample that uses normal way (object methods) which you can find it from HERE. The following are the code snippets from both sample code:

Extension Method Way

public Leave Apply(Leave leave)
{
    leave.Status = LeaveStatuses.Pending;
    leave.DateSubmitted = DateTime.Now;
    leave.IsCompleted = false;

    LeaveStatusLog log = CreateLog(leave);

    Validations.ValidateLeaveDates(leave);

    // Check for overlapping leaves.
    if (leave.IsOverlap())
    {
        throw new ApplicationException("Date range is overlapping with another leave.");
    }

    using (TransactionScope ts =
        new TransactionScope(TransactionScopeOption.Required))
    {
        // Step 1 - Calling Create.
        leave.Create();

        // Step 2 - Calling Create on log.
        log.LeaveID = leave.LeaveID;
        log.Create();

        ts.Complete();
    }

    return leave;

}

Object Method Way

public Leave Apply(Leave leave)
{
    leave.Status = LeaveStatuses.Pending;
    leave.DateSubmitted = DateTime.Now;
    leave.IsCompleted = false;

    LeaveStatusLog log = CreateLog(leave);

    // Data access component declarations.
    var leaveDAC = new LeaveDAC();
    var leaveStatusLogDAC = new LeaveStatusLogDAC();

    Validations.ValidateLeaveDates(leave);

    // Check for overlapping leaves.
    if (leaveDAC.IsOverlap(leave))
    {
        throw new ApplicationException("Date range is overlapping with another leave.");
    }

    using (TransactionScope ts =
        new TransactionScope(TransactionScopeOption.Required))
    {
        // Step 1 - Calling Create on LeaveDAC.
        leaveDAC.Create(leave);

        // Step 2 - Calling Create on LeaveStatusLogDAC.
        log.LeaveID = leave.LeaveID;
        leaveStatusLogDAC.Create(log);

        ts.Complete();
    }

    return leave;
}

Note the yellow highlighted differences. First is the extension method way, second is the normal object or instance method way.

Compare #1: MSIL - Microsoft Intermediate Language

First, let's find out how the above sample codes get translated into MSIL. Open up the intermediate language disassembler first by opening the Visual Studio Command Tool, then execute the ildasm.exe.

Next, use the IL disassembler to open up the compiled dll.



A bunch of IL codes will appear. Keep the window open. Then, repeat the same steps above to open another IL disassembler and open another compiled dll that contain the source code that use normal object method way.

Extension Method Way

  // Code size       136 (0x88)
  .maxstack  2
  .locals init ([0] class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog log,
           [1] class [System.Transactions]System.Transactions.TransactionScope ts,
           [2] class [LeaveSample.Entities]LeaveSample.Entities.Leave CS$1$0000,
           [3] bool CS$4$0001)

The following IL codes are from within try catch block only.

  .try
  {
    IL_004b:  nop
    IL_004c:  ldarg.1
    IL_004d:  call       void [LeaveSample.Data]LeaveSample.Data.LeaveDAC::Create(class [LeaveSample.Entities]LeaveSample.Entities.Leave)
    IL_0052:  nop
    IL_0053:  ldloc.0
    IL_0054:  ldarg.1
    IL_0055:  callvirt   instance int64 [LeaveSample.Entities]LeaveSample.Entities.Leave::get_LeaveID()
    IL_005a:  callvirt   instance void [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog::set_LeaveID(int64)
    IL_005f:  nop
    IL_0060:  ldloc.0
    IL_0061:  call       class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog [LeaveSample.Data]LeaveSample.Data.LeaveStatusLogDAC::Create(class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog)
    IL_0066:  pop
    IL_0067:  ldloc.1
    IL_0068:  callvirt   instance void [System.Transactions]System.Transactions.TransactionScope::Complete()
    IL_006d:  nop
    IL_006e:  nop
    IL_006f:  leave.s    IL_0081

  }  // end .try

Object Method Way

  // Code size       157 (0x9d)
  .maxstack  2
  .locals init ([0] class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog log,
           [1] class [LeaveSample.Data]LeaveSample.Data.LeaveDAC leaveDAC,
           [2] class [LeaveSample.Data]LeaveSample.Data.LeaveStatusLogDAC leaveStatusLogDAC,
           [3] class [System.Transactions]System.Transactions.TransactionScope ts,
           [4] class [LeaveSample.Entities]LeaveSample.Entities.Leave CS$1$0000,
           [5] bool CS$4$0001)

The following IL codes are from within try catch block only.

  .try
  {
    IL_005a:  nop
    IL_005b:  ldloc.1
    IL_005c:  ldarg.1
    IL_005d:  callvirt   instance class [LeaveSample.Entities]LeaveSample.Entities.Leave [LeaveSample.Data]LeaveSample.Data.LeaveDAC::Create(class [LeaveSample.Entities]LeaveSample.Entities.Leave)
    IL_0062:  pop
    IL_0063:  ldloc.0
    IL_0064:  ldarg.1
    IL_0065:  callvirt   instance int64 [LeaveSample.Entities]LeaveSample.Entities.Leave::get_LeaveID()
    IL_006a:  callvirt   instance void [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog::set_LeaveID(int64)
    IL_006f:  nop
    IL_0070:  ldloc.2
    IL_0071:  ldloc.0
    IL_0072:  callvirt   instance class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog [LeaveSample.Data]LeaveSample.Data.LeaveStatusLogDAC::Create(class [LeaveSample.Entities]LeaveSample.Entities.LeaveStatusLog)
    IL_0077:  pop
    IL_0078:  ldloc.3
    IL_0079:  callvirt   instance void [System.Transactions]System.Transactions.TransactionScope::Complete()
    IL_007e:  nop
    IL_007f:  nop
    IL_0080:  leave.s    IL_0094

  }  // end .try

Appendix for IL instruction:

nop = do nothing, for breakpoint purpose
ldloc = load local variable
ldarg = load argument
callvirt = call a late-bound object method
call = call a method
pop = pop a value from stack

The Differences

The method that use extension methods has smaller code size. The local variable count also lesser during initialization because missing LeaveDAC and LeaveStatusLogDAC objects.

Notice the call and callvirt IL instruction? Extension method is translated into call instruction, while the object method is translated into callvirt instruction. Understood that the extension methods are declared as static method, no doubt it is early binding, but the newly instantiated object method is considered as late-binding, serious? @.@

Anyway, the IL codes are later needed to be compiled with JIT compiler. By looking at the IL codes, it may not sufficient to tell which perform better.

Compare #2: Profiling

Let's see the response time comparison for both extension method and object method by using instrumentation profiling with Visual Studio 2013 Premium or Ultimate edition. You can use any other profiler tool to perform the similar testing. Please refer to this post to see how to use the Visual Studio Profiler.

Test Scenario: Submit 10 leave application.

Here is the result of using extension method:
Avg Elapsed Exclusive Time : 0.06 ms




Here is the result of using object method:
Avg Elapsed Exclusive Time : 0.07 ms


The Difference:

Woot! @.@
Extension method win by 0.01ms difference. Unbelievable!

Compare #3: Stress Test

Let's see what happen if the Apply leave method is called 10,000 times. I wrote a very simple unit test to stress the service that would call the extension method or object method for 10,000 times.

[TestMethod]
public void StressTest()
{
    //Prepare the test data first
    List<Leave> leaves = new List<Leave>();
    for (int i = 1; i <= 10000; i++)
    {
        leaves.Add(new Leave()
        {
            StartDate = DateTime.Today,
            EndDate = DateTime.Today,
            Duration = 1,
            Category = LeaveCategories.Annual,
            Employee = "Unit Test " + i.ToString(),
            Description = "Unit Test",
        });
    }
           
    LeaveController upc = new LeaveController();
    Stopwatch watch = new Stopwatch();

    //Start the timing
    watch.Start();

    //Start stressing the WCF service
    foreach(Leave leave in leaves)
    {
        upc.Apply(leave);
    }

    //Stop the timing
    watch.Stop();

    Debug.WriteLine("Total milisecond: " + watch.ElapsedMilliseconds.ToString());
}

I ran the unit test for 3 times in order to be fair.

The extension method result after completed the test:
Round 1: 221695 ms
Round 2: 218811 ms
Round 3: 228312 ms
Average: 222939 ms

The object method result after completed the test:
Round 1: 226168 ms
Round 2: 218680 ms
Round 3: 214087 ms
Average: 219645 ms

The Differences:

The object method win! When multiple instances versus singleton, logically multiple instances should win. When there are a lot of tasks need to be completed, a group of people work on it is always quicker to finish compare to one person works on it.

Summary

The extension method performance has not much different compare to object method. If the extension methods really can make your code look cleaner and meaningful, IMHO, just go for it. For more information about implementing layered architecture with extension methods, please visit Serena blog.

If you find my test above is not accurate to tell which is perform better, feel free to share your thought in the comment section below.


4 comments:

Send Transactional SMS with API

This post cover how to send transactional SMS using the Alibaba Cloud Short Message Service API. Transactional SMS usually come with One Tim...