Why subsequent direct method call is much faster than the first call?

Question

As is explained in this MSDN article, when one uses .NET Reflection API such as InvokeMember, the first call takes much more time to run than the subsequent calls because of caching of metadata.

When I tested the direct method call without using Reflection, I also see the similar effect both on Mono and .NET 4.

The first number is the result of the operation, and the second number after '-' is the time spent for this operation in ms. I used '<--' mark to identify the first method call.

300 - 0.192 <--
300 - 0.004
300 - 0.004
-100 - 0.096 <--
-100 - 0.004
-100 - 0.004

Why is this? I can understand that the first call can be slower, but 50x slower is not what I expected.

Attached is the source code to get this result.

library

namespace MyClass
{
    public class Calculator
    {
        public int Value1 {get; set;}
        public int Value2 {get; set;}
        public Calculator()
        {
            Value1 = 100;
            Value2 = 200;
        }

        public int Add(int val1, int val2)
        {
            Value1 = val1; Value2 = val2;
            return Value1 + Value2;
        }

        public int Sub(int val1, int val2)
        {
            Value1 = val1; Value2 = val2;
            return Value1 - Value2;
        }
    }
}

Code to call this library

// http://msdn.microsoft.com/en-us/magazine/cc163759.aspx
using System;
using System.IO;
using System.Reflection;
using System.Diagnostics;
using System.Collections.Generic;
using MyClass;

class TestOne
{
    static void DirectTest()
    {
        Stopwatch sw;
        Calculator t = new Calculator();

        sw = Stopwatch.StartNew();
        int value1 = t.Add(100,200);
        sw.Stop();
        double time1 = sw.Elapsed.TotalMilliseconds;

        sw = Stopwatch.StartNew();
        int value2 = t.Add(100,200);   
        sw.Stop();
        double time2 = sw.Elapsed.TotalMilliseconds;

        sw = Stopwatch.StartNew();
        int value3 = t.Add(100,200); 
        sw.Stop();
        double time3 = sw.Elapsed.TotalMilliseconds;

        Console.WriteLine("{0} - {1}", value1, time1);
        Console.WriteLine("{0} - {1}", value2, time2);
        Console.WriteLine("{0} - {1}", value3, time3);

        sw = Stopwatch.StartNew();
        value1 = t.Sub(100,200);
        sw.Stop();
        time1 = sw.Elapsed.TotalMilliseconds;

        sw = Stopwatch.StartNew();
        value2 = t.Sub(100,200);  
        sw.Stop();
        time2 = sw.Elapsed.TotalMilliseconds;

        sw = Stopwatch.StartNew();
        value3 =  t.Sub(100,200); 
        sw.Stop();
        time3 = sw.Elapsed.TotalMilliseconds;

        Console.WriteLine("{0} - {1}", value1, time1);
        Console.WriteLine("{0} - {1}", value2, time2);
        Console.WriteLine("{0} - {1}", value3, time3);
    }
    static void Main()
    {
        DirectTest();
        DirectTest();
    }
}

Answer 1

This is because of the Just In Time (JIT) compilation method that is used for .NET apps. The MSIL bytecode is translated to machine code once by the JIT compiler and subsequent executions of that code are much faster because the native version has been generated and cached.

You pay a one time penalty when you run your code, but the JIT compiler can also perform optimizations for the current architecture that it could not be performed if the code were native from the get-go. You can however force a JIT pass by calling RuntimeHelpers.PrepareMethod.