Wrong Line Number on Stack Trace

Wrong line numbers in stack trace

Thanks everyone for your help! We found out that the SCOM APM agent running on the machines in production caused our application to log wrong line numbers in the stack traces. As soon as we deactivated the agent, the line numbers were correct.

Wrong line number on stack trace

Yes, this is a limitation in the exception handling logic. If a method contains more than one throw statement that throws an exception then you'll get the line number of the last one that threw. This example code reproduces this behavior:

using System;

class Program {
    static void Main(string[] args) {
        try {
            Test();
        }
        catch (Exception ex) {
            Console.WriteLine(ex.ToString());
        }
        Console.ReadLine();
    }
    static void Test() {
        try {
            throw new Exception();  // Line 15
        }
        catch {
            throw;                  // Line 18
        }
    }
}

Output:

System.Exception: Exception of type 'System.Exception' was thrown.
   at Program.Test() in ConsoleApplication1\Program.cs:line 18
   at Program.Main(String[] args) in ConsoleApplication1\Program.cs:line 6

The work-around is simple, just use a helper method to run the code that might throw an exception.

Like this:

static void Test() {
    try {
        Test2();                // Line 15
    }
    catch {
        throw;                  // Line 18
    }
}
static void Test2() {
    throw new Exception();      // Line 22
}

The underlying reason for this awkward behavior is that .NET exception handling is built on top of the operating system support for exceptions. Called SEH, Structured Exception Handling in Windows. Which is stack-frame based, there can only be one active exception per stack frame. A .NET method has one stack frame, regardless of the number of scope blocks inside the method. By using the helper method, you automatically get another stack frame that can track its own exception. The jitter also automatically suppresses the inlining optimization when a method contains a throw statement so there is no need to explicitly use the [MethodImpl] attribute.

How can the line numbers in my stack traces be wrong?

This happens when you change the source file after the code is running. The compiled source has line number references to the source code, but the stack traceback fills in the actual source text by reloading the source file. I think there is some kind of caching as well but that's not relevant here.

So the problem here is just that the source file no longer matches the (compiled) program that is actually running, likely because it was changed after the program started or perhaps they have become out of sync by some more complicated trickery ...

Why does the stack trace for my jest tests point to the wrong line numbers?

Why does the stack trace for jest tests point to the wrong line numbers? How can I fix it?

It has to do with source maps. If those are not correctly generated or processed, the debugger will show the wrong line.

I found three ways how to fix this issue:

1. Changing <rootDir>/node_modules to node_modules in your
   moduleDirectories

   Why does this fix the issue?

   • If <rootDir> is added,
     jest or more precisely its underlying module source-map-support uses the source_map module from node_modules/source-map. Which in my case with a fresh install of your example, is 0.7.3. But the source_map_support relies on ^0.6.0. It actually brings the right version under node_modules/source-map-support/source-map. But for some reason with the <rootDir> specified, it can't access it anymore. And that brings us to the second solution.

2. Downgrade the source-map module to ^0.6.0 by manually including it as a dependency of your project. In that case node_modules/source-map will provide the right version again, but that might break something else, since it is not clear, where this wrong version is originating from.

3. Upgrade your project dependencies to the newest version.
   try npm outdated and you will see, that they are all outdated:
   

How Can a Stack Trace Point to the Wrong Line (the return Statement) - 40 Lines Off

I have seen this kind of behavior in production code once. Although the details are a little vague (It was approximately 2 years ago, and although I can find the email, I don't have access to the code anymore, and neither the dumps etc.)

FYI, this is what I wrote to the team (very small parts from the large mail) -

// Code at TeamProvider.cs:line 34
Team securedTeam = TeamProvider.GetTeamByPath(teamPath); // Static method call.

"No way null reference exception can happen here."

Later, after more dump diving

"Findings -

1. The issue was happening in DBI because it did not have root/BRH team. UI is not handling the null returned by CLib gracefully, and hence the exception.
2. The stack trace shown on UI was misleading, and was due to the fact that Jitter and CPU can optimize / reorder instructions, causing stack traces to "lie".

Digging into a process dump revealed the issue, and has been confirmed that DBI indeed did not have above mentioned team."

---

I think, the thing to note here is the statement in bold above, in contrast with your analysis and statement -

"I just looked at the decompiled source, and it does not appear to have been rearranged.", or

"Production build running on my local machine shows the correct line number."

The idea is that optimizations can happen at different levels.. and those done at compile time are just some of them. Today, especially with Managed environment like .Net, there are actually relatively fewer optimizations done while emitting IL (Why should 10 compilers for 10 different .Net languages try to do same set of optimizations, when the emitted Intermediate Language code will be further transformed into machine code, either by ngen, or Jitter).

Hence what you have observed, can only be confirmed by looking at the jitted machine code (aka assembly) from a dump from the production machine.

---

One question I can see coming is - Why would Jitter emit different code on Production machine, compared to your machine, for the same build?

Answer - I don't know. I am not a Jit expert, but I do believe it can... because as I said above.. Today these things are way more sophisticated compared to technologies used 5-10 years ago. Who knows, what all factors.. like "memory, number of CPUs, CPU load, 32 bit vs 64 bit, Numa vs Non-Numa, Number of times a method has executed, how small or big a method is, Who calls it, what does it call, how many times, access patterns for memory locations, etc etc" does it look at while making these optimizations.

For your case, so far only you can reproduce it, and only you have access to your jitted
code in production. Hence, (If I may say so :)) this is the best answer anyone can come up with.

---

EDIT:
An important difference between the Jitter on one machine vs the other, can also be the version of the jitter itself. I'd imagine that as several patches and KBs are released for .net framework, who knows what differences of optimization behavior jitter with even minor version differences may have.

In other words, it is not sufficient to assume that both machines have same Major version of the framework (lets say .Net 4.5 SP1). Production may not have patches which are released every day, but your dev / private machine may have patch released last Tuesday.

---

EDIT 2: Proof of concept - i.e. Jitter optimizations can lead to lying stack traces.

Run following code yourself, Release build, x64, Optimizations on, all TRACE and DEBUG turned off, Visual Studio Hosting Process turned off. Compile from visual studio, but run from explorer. And try to guess which line the stack trace will tell you the exception is at?

class Program
{
    static void Main(string[] args)
    {
        string bar = ReturnMeNull();

        for (int i = 0; i < 100; i++)
        {
            Console.WriteLine(i);
        }

        for (int i = 0; i < bar.Length; i++)
        {
            Console.WriteLine(i);
        }

        Console.ReadLine();

        return;
    }

    [MethodImpl(MethodImplOptions.NoInlining)]
    static string ReturnMeNull()
    {
        return null;
    }
}

Unfortunately, after few attempts, I still cannot reproduce exact problem you have seen (i.e. error on return statement), because only you have access to exact code, and any specific code pattern it may have. Or, once again, it is some other Jitter optimization, which is not documented, and hence hard to guess.

StackTrace return wrong line number of exception in release mode

Why?

Because in release mode, the optimizer can inline functions and do other things that change the actual line number from what you have in source code.

Just outputting the stack trace is probably not helpful (IMHO). What type of exception did you get? What was the error message? What method did it originate from? Those are more helpful for diagnosing problems in my experience. I would change you exception handling to at least Console.WriteLine(ex). That will give you all of that data plus the stack trace.

This link can be helpful.

Wrong line numbers in stack trace (release)

Not a .net expert, but at least in other languages, when high compiler optimizations are chosen, the compiler may make significant reordering of code. This can and often does make it very difficult to pin the source of an error down to a particular line. If the compiler is able to make optimisations across basic blocks, then this effect can be very significant, putting the apparent line location in a totally different part of the source file.

---

Related Topics