Overhead in returning from a method

Question

I have a method A() that processes some queries. This method, from opening bracket to just before its return statement, times at +/-70ms. A good 50% of which comes from opening the connection, about 20% comes from the actual queries, 5-10% is used by some memory access, the rest is (probably) used for disposing the connection, commands and reader.

Although this big chunk of time used for handling the connection is annoying enough, what bothers me more is that when I call A() from method B():

B()
{
    var timer = Stopwatch.Startnew()
    A(); 
    timer.Stop(); // elapsed: +/- 250ms
    Debugger.Break();
}

Another 180ms of lag gets added and I can't seem to figure out why. I already tried having A return null, which changes nothing.

The only disk I/O and networking happens in A. I thought the transfer from disk and network to local memory should've happened in A, and therefore a call to A from B should not be influenced by this, but apparently this is not the case? Is this network latency I'm experiencing here? If so, then why does this also happen when I just let B return null?

I have no other explanation at the moment...

• Everything resides in the same assembly,
• Measuring without a debugger attached changes nothing,
• Returning 'null' immediately show 0 ms, returning null instead of the normal return value changes nothing (but enforces the idea this is somehow related to latency).

A is roughly implemented as follows, like any simple method accessing a database. It's contrived, but shows the basic idea and flow:

A()
{   
    var totalTimer = Stopwatch.StartNew();
    var stuff = new Stuffholder();

    using(connection)
    {
         using(command)
         {
              using(reader) 
              { 
                  // fill 'stuff' 
              }
         } 
    }

    totalTimer.Stop(); // elapsed: +/- 70ms
    return stuff;
}

Any ideas?

Answer 1

The overhead that you are seeing is due to just-in-time compilation. The first time method B() is called method A() has not been natively compiled (it is partially compiled in the dll as IL), so you see a slight lag while the compiler compiles A() into machine code.

When profiling a method call it is important to call the method a large number of times and take the average time (discarding the first call if you like, although over enough calls the compilation overhead should become insignificant).