Main Site Documentation

Exceptions with Line Numbers in StackTrace


#1

I am new to NETMF (4.3) and while writing an error logger for our application, it seems that there are no line numbers available with the Exception.StackTrace property in NETMF, although the MSDN-NETMF-4.3-documentation for that property on
http://msdn.microsoft.com/en-us/library/system.exception.stacktrace(v=vs.102).aspx
says “… to follow the call stack to the line number in the method …”

I tried setting “Debug info:” to full (for Debug build) or pdb-only (for Release build) in the VS2012 Project/Properties/Build/Advanced dialog, but line numbers aren’t available, neither in Debug nor in Release build.

The only thing I get with the StackTrace is an [IP: xxxx]-value for each StackTrace-entry in the m_stackTrace byte-array which may be something like an local “instruction pointer” or similar?. Am I doing something wrong or could anyone confirm the lack of line numbers?

If they are not already implemented in NETMF, maybe this would be worth a feature request on CodePlex. I think line numbers in the Exception.StackTrace would be very useful, not only for Debugging but also for extensively testing Release builds (with pdb files).


#2

@ Harald - My initial reading of the line in that link is that the StackTrace string provides a way for you to follow the call chain manually until you get to the end, which should hopefully bring you to the exact line that threw, but I could be wrong.


#3

@ John - I can’t find a line number anywehere in the Exception.StackTrace, neither at the end nor anywhere. Has anybody tried this in practice and can give me a hint how or where I can find the exception’s line number, maybe I am just overlooking something ?


#4

I haven’t seen any line number in NETMF callstacks so far.
What I do sometimes is to set the Debugger to stop on specific exceptions, even if they are handled.


#5

@ Harald - I’ve never seen line numbers either which is why I think the MSDN documentation is a bit poorly worded. My guess is that they didn’t mean to say you’d get an exact line number in the property but that the call stack list could help you find the exact line number yourself.


#6

The NETMF API Docs are often copied from the full .NET documentation, and does not always reflect the limitations of NETMF.


#7

Thanks to all for your feedback. Line number availability (as in full .NET framework or any “cheap” GNU compiler) saved us a lot of time and many headaches :-[ in bug tracing, not only for Debug builds but also for Release builds with pdb files. I made an issue on Codeplex, please feel free to vote for: https://netmf.codeplex.com/workitem/2333


#8

@ Harald - My assumption is that NETMF has limited the amount of debug info loaded onto the physical hardware to limit the amount of memory taken by an assembly.

However, you can do that mapping manually if it is really required. The IP (instruction pointer) address included in the exception is the address of the offending IL instruction (actually it is 1 higher than the start of the address) relative to the start of the method, so using ILDasm you can inspect the code and relatively easily map it back to your original source code.

Just to share an example of what I am saying, here is a contrived and admittedly non-complex demonstration.

Given the following code


public class Test
{
    static void Main(string[] args)
    {
        DoSomething(5);
        DoSomething(0);
        Debug.Print("Done");
    }

    static int DoSomething(int x)
    {
        return 15 / x;
    }
}

We will get the following DivideByZeroException


  #### Exception System.Exception - CLR_E_DIVIDE_BY_ZERO (1) ####
  #### Message: 
  #### StackTraceDemo.Test::DoSomething [IP: 0005] ####
  #### StackTraceDemo.Test::Main [IP: 000a] ####

Here we see that the initial exception was raised in DoSomething at address 5 and that was caused by and earlier call from Main at address 0x000a.

Using ILDasm our code decompiles to

DoSomething.IL


.method private hidebysig static int32  DoSomething(int32 x) cil managed
{
  // Code size       10 (0xa)
  .maxstack  2
  .locals init ([0] int32 CS$1$0000)
  IL_0000:  nop
  IL_0001:  ldc.i4.s   15
  IL_0003:  ldarg.0
  IL_0004:  div
  IL_0005:  stloc.0
  IL_0006:  br.s       IL_0008
  IL_0008:  ldloc.0
  IL_0009:  ret
} // end of method Test::DoSomething

Remember I said that the IP address is one more than the address of the offending IL instruction, so in our case the IP was address 5 we look at address 4 and see a div instruction, so this is the IL instruction that caused the exception, so why?

Like normal we follow the stack trace and we take a look at Main, the stack trace says we need to look at IP 0x000a, one less than that is 0x0009.


.method private hidebysig static void  Main(string[] args) cil managed
{
  .entrypoint
  // Code size       27 (0x1b)
  .maxstack  8
  IL_0000:  nop
  IL_0001:  ldc.i4.5
  IL_0002:  call       int32 StackTraceDemo.Test::DoSomething(int32)
  IL_0007:  pop
  IL_0008:  ldc.i4.0
  IL_0009:  call       int32 StackTraceDemo.Test::DoSomething(int32)
  IL_000e:  pop
  IL_000f:  ldstr      "Done"
  IL_0014:  call       void [Microsoft.SPOT.Native]Microsoft.SPOT.Debug::Print(string)
  IL_0019:  nop
  IL_001a:  ret
} // end of method Test::Main

Add address 0x0009 we see this is our second call to DoSomething, that makes sense and just before that the arguments to the function call would have been loaded to the stack. We see the following just before the operation


IL_0008:  ldc.i4.0

This is loading the value 0 onto the stack, yip, we are passing a 0 to the function which is the root of our problem.

Like I said a rather contrived and very very simple example, other scenarios involving variables etc. or a little more complex, but not so complex that we cannot follow the same process to identify the source of the issue. Fortunately the IL will still have the variable names associated with the code etc.

Sometimes this helps because if you have a complex expression that is blowing up, normally you only know that on that line something is going wrong, while at the IL level the expression is broken down into separate pieces and you have a fair chance at matching the IL to a specific part of the expression that is causing the exception, this can get quite complex with the compiler optimizations but once you get a handle on reading IL it is not that tough.

Hope this helps in the meantime…


#9

@ taylorza - hats off to the expert details, thanks


#10

@ taylorza - And now code a VS plugin that parses and reformats the output window contents, and replaces the addresses with the line number :whistle:
Please :slight_smile:


#11

Technically it is not very difficult to do, I have previously written and worked on native and managed debuggers so I am reasonably familiar with the PDB files and the related APIs (DIA), I will need to dust off the cobwebs though.

It is on the surface not even a huge amount of work, though you would need to walk the code guided by the stack trace to get the method tokens for the specific overload being invoked. The stack trace text as it stands does not provide any indication which overload of a method is being called.

I might take sometime and look at doing something like this as a sample, esp. since I have not looked at how/if NETMF tweaks the assemblies post compile, it might be a good opportunity to get into those details.


#12

@ andre.m - Too be honest, I agree with you, it is not something I have personally missed. If you have the exception output going to the Visual Studio then Visual Studio will break on the line causing the exception (assuming that has not been disabled and I assume the express editions do the same, I have not used express for .NETMF development) and you have the call stack view so all is already revealed.

But I opted to go with giving the benefit of the doubt and assume that the exceptions are really being viewed via one of the config tools rather than in Visual Studio, in which case it can help to know that your 3rd expression in the function is the one that is causing the problem rather than the second or eight one (just making stuff up here…).


#13

It depends on the length of your methods: the longer the more important are line numbers (yes I am aware that long methods are bad coding practice).
And if the exception occurs only once in a while, or only in a special timing situation which you can not reproduce by stepping through your code, line number are a great help.