When you can't trust the stack trace

Disclaimer: This article is for x86 Jit compiler Only.

Why did I notice that the stack trace was different from what was expected?
We have an abstract base class that our test script derive from, which provides all the necessary functionality to make the logging of data transparent for the script author. To put data into the log (database, file, whatever) the script just invoke the log method from the base class and it will then find out from where that method came from based on the information on the stack.

The problem that I encountered was that we have some methods that only acts as proxies and thus are very small, e.i. 2-3 lines of code, with one being the call to the log method. These methods where in-lined, thus giving some strange data.

When is code in-lined?
To answer when the JIT compiler does not in-line code, and thus also indicated when it might in-line code, here is an excerpt from David Notario's WebLog (link)

These are some of the reasons for which we won't inline a method:

• Size of inlinee is limited to 32 bytes of IL
  
• Method is marked as not inline with the CompilerServices.MethodImpl attribute.
  
• Virtual calls
  
• Call targets that are in MarshalByRef classes won't be inlined
  
• VM restrictions
  
• loops, methods with exception handling regions, etc...
  
• Other: Exotic IL instructions, security checks that need a method frame, etc...
  

Why does the release build have the full call stack in VS
If you try to debug this behavior by setting the configuration manager to "Release" and run the executable from within Visual Studio, you will notice that the stack looks just as if it was run in "Debug". This is because that VS has its own host process (vshost.exe) that starts up the CLR which tells the JIT'er not to in-line code.

The code below gives an example on what the problem is:

using System;
using System.Diagnostics;
using System.Runtime.CompilerServices;

class Program
{
 public Program()
 {
  NotInlined();
  Attribute();
  Inlined();
 }

 private void NotInlined()
 {
  try
  {return;}
  finally
  {CallerID();}
 }

 [MethodImpl(MethodImplOptions.NoInlining)]
 private void Attribute()
 {
  CallerID();
 }

 private void Inlined()
 {
  CallerID();
 }

 protected void CallerID()
 {
  StackTrace st = new StackTrace(true);
  StackFrame sf = st.GetFrame(1);
  Console.WriteLine("Caller is: " + sf.GetMethod().Name);
 }

 static void Main(string[] args)
 {
  new Program();
 }
}

Running the debug and release builds from the command line the gives the following:


output from a Debug build:

Caller is: NotInlined
Caller is: Attribute
Caller is: Inlined

And output from a Release build:

Caller is: NotInlined
Caller is: Attribute
Caller is: .ctor