12

We are using System.Reflection.Emit to generate code at runtime from source code (yes - as in a compiler). We provide correct symbol information to the ILGenerator with MarkSequencePoint etc, and enable all debug flags on the AssemblyBuilder. The assembly is kept in memory in the same process that compiled it and is executed directly.

When using the Visual Studio debugger to step through the source for the dynamically generated code it actually works perfectly, and Visual Studio seems to be fully aware of where code comes from in terms of files and line numbers.

HOWEVER - When exceptions are thrown by the generated code, the System.Exception objects contain stack traces that are completely wrong. They point to other (valid, but wrong) files and line numbers. It gets the class and method name right, but the file and line number pointed to has nothing to do with the code path the exception actually came from.

The files pointed to are so unrelated it seems it can't be linked to inlining or optimizations. The only pattern I can spot is that it seems to be offset by some files (in an imaginary alphabetically sorted list of source files the assembly was built from). However, this pattern is not 100% consistent, and it seems irrational that this is linked to the source of the problem.

If i construct a System.Diagnostics.Debug object from the Exception, it contains the same faulty information.

I am assuming that the .NET runtime uses the same metadata to construct Exception stack traces as the debugger uses for stepping through the code, in which case this behavior is really weird.

I'm trying to find out if this is a known bug in .NET when dealing with dynamic in-memory assemblies, or if anyone has seen similar problems in other areas.

svick
  • 236,525
  • 50
  • 385
  • 514
Duckers
  • 140
  • 6
  • 5
    Any chance you could post a small and complete program that we could test? You could for instance hardcode a "language" of two lines or something like that, you wouldn't need to post a full compiler. – Lasse V. Karlsen Jan 13 '14 at 13:33
  • 1
    Are you compiling with the `optimize` flag? – poy Jan 13 '14 at 13:36
  • Andrew: On the compiler or on the assemblybuilder? I have tried to set as many "yes I want as much debug information as possible" flags as possible, but I might not be aware of them all. – Duckers Jan 13 '14 at 13:39
  • Sounds pretty interesting thing to do. Just really long shot here. How does compiler know which line it is that throws the error? I mean the file layout. I have noticed incorrect line numbers a few times my guess would be encoding and file layout. I wont put my money on it though. – danish Jan 13 '14 at 13:50
  • @LasseV.Karlsen You just want his source code and then get rich selling your own compiler. (joke) – danish Jan 13 '14 at 13:53
  • @danish: It knows because when you generate the CIL instructions you can associate a document (file) and line number with a block of instructions (typically each statement or expression root). This metadata is kept separately and used by debuggers. I also assume it's used to construct stack traces for exceptions - but as that doesn't work in my case - this is the part of what is being discussed here. – Duckers Jan 13 '14 at 13:56
  • @Duckers Can you take a look at this project - https://www.dropbox.com/sh/jvjdyroivzl9tgt/7csRtroedq - and tell me if it exhibits the same problem as you have? And obviously tell me if I did something horribly wrong, it's the first time I've messed with symbol writing with dynamic types. – Lasse V. Karlsen Jan 13 '14 at 13:59
  • @LasseV.Karlsen: Thanks a lot for the effort of making the test case. I was actually working on a very similar test case myself in parallel here. I am unable to reproduce the problem with these much simpler cases, your case included. In our real case there are many hundred source files and thousands of methods generated. Trying various things now to see if I can reproduce it, but I am afraid the bug is triggered by complexity/data amount, or potentially other circumstancial issues in the real use case. – Duckers Jan 13 '14 at 16:36
  • FYI, in my test case I am using multiple documents/source files without this triggering the bug either. – Duckers Jan 13 '14 at 16:37
  • Actually, in the sample project, when the exception was thrown, on the Div instruction on line 4, the debugger stopped on line 1, so I was hoping that would be the same. – Lasse V. Karlsen Jan 13 '14 at 19:27
  • what happens if you remove newline characters from the dynamic source code? do the new line numbers in the call stack give you some new clues? I wrote an ECMAScript interpreter and early on my lexer wasn't always setting rows and columns correctly. I'm not saying that c# is doing that but I was able to see that there was a pattern of offsets. It wasn't just random. So making your dynamic source 1 line tall could help you see something new. – drankin2112 Jan 14 '14 at 05:27
  • @LasseV.Karlsen: When I traced it the exception was thrown at line 3, as it should. The same was indicated in the Exception object's stack trace. To be clear: in my real case the debugger also reports the exception on the right line, it's just the stack trace generated within the exception object that contains faulty information :/ – Duckers Jan 14 '14 at 08:53
  • OK. I'll remove the project from my dropbox now then. – Lasse V. Karlsen Jan 14 '14 at 09:08
  • I don't know that you are doing this, but one thing that will mess up stack traces is directly rethrowing a caught exception in the catch block, i.e. `try { // Do something } catch (Exception ex) { throw ex; }`. If you are, use `throw new Exception("My message.", ex);` to wrap it or just use `throw;` for your throw statements instead. – JamieSee Mar 03 '14 at 15:59

1 Answers1

2

Okay, I was NOT able to figure out what was causing the problem nor how to make .NET behave correctly, but at least I was able to find a work-around that might also work for others experiencing the same problem.

  1. As I am generating the CIL bytecode I am building a separate database that maps method names (full path) and IL-offset back to the original file names and line numbers.

  2. When exceptions are caught I examine the stack trace and use only the GetMethod() and GetILOffset() information from the stack frame objects. This information from the CLR happens to be correct, even when GetFileName() and GetFileLineNumber() are wrong.

  3. I then for each stack frame use the Method name and IL offset retrieved from the exception to look up into my generated database to determine actual file name and line number for each stack frame I have information about.

  4. The frames I don't find information about in the database are typically stack frames in precompiled .NET modules, for which the information retrieved from CLR is actually correct. For these frames I use GetFileName() and GetFileLineNumber() on the stack frame directly.

Duckers
  • 140
  • 6