2
Vote

Implement .NET expression evaluator (Improve current line detection on exceptions)

description

When an exception stops a program that is being debugged, it highlights the line that is currently being executed and presumably has the error. However, this is only rarely the actual line with the problem. In practice, running the program through a shell, where the full traceback is visible, is necessary in order to find the correct line.

For example:

IronPython.Runtime.UnboundNameException was unhandled by user code
Message=global name 'crash' is not defined
Source=IronPython
StackTrace:
   at IronPython.Compiler.PythonGlobal.GetCachedValue(Boolean lightThrow)
   at IronPython.Compiler.PythonGlobal.get_CurrentValue()
   at __main__$1.show_face_down$76(PythonFunction $function, Object self, Object x, Object y, Object card) in C:\Documents\Administrator\My Documents\Visual Studio 2010\Projects\Lab3\Lab3\Program.py:line 79
   at IronPython.Runtime.PythonFunction.FunctionCaller`4.Call4(CallSite site, CodeContext context, Object func, T0 arg0, T1 arg1, T2 arg2, T3 arg3)
   at IronPython.Runtime.Method.MethodBinding`3.SelfTarget(CallSite site, CodeContext context, Object target, T0 arg0, T1 arg1, T2 arg2)
   at System.Dynamic.UpdateDelegates.UpdateAndExecute5[T0,T1,T2,T3,T4,TRet](CallSite site, T0 arg0, T1 arg1, T2 arg2, T3 arg3, T4 arg4)
   at __main__$1.update_display$74(PythonFunction $function, Object self) in C:\Documents\Administrator\My Documents\Visual Studio 2010\Projects\Lab3\Lab3\Program.py:line 64
   at IronPython.Runtime.PythonFunction.FunctionCaller`1.Call1(CallSite site, CodeContext context, Object func, T0 arg0)
   at IronPython.Runtime.Method.MethodBinding.SelfTarget(CallSite site, CodeContext context, Object target)
   at System.Dynamic.UpdateDelegates.UpdateAndExecute2[T0,T1,TRet](CallSite site, T0 arg0, T1 arg1)
   at __main__$1.__init__$72(PythonFunction $function, Object self) in C:\Documents\Administrator\My Documents\Visual Studio 2010\Projects\Lab3\Lab3\Program.py:line 41
   at Microsoft.Scripting.Interpreter.FuncCallInstruction`4.Run(InterpretedFrame frame)
   at Microsoft.Scripting.Interpreter.Interpreter.Run(InterpretedFrame frame)
InnerException:

With this exception, Visual Studio highlights line 41 in the program (the last - highest - line in the trace), but should highlight line 79 (the first - lowest - line in the trace).

file attachments

comments

Zooba wrote Sep 9, 2011 at 2:50 AM

Without seeing the code in Program.py, it's hard to tell where the exception is being caused. However, the reason we break at the line that is currently executing is simply because this is the top of the stack. If we wait for the stack to unwind to the bottom before interrupting execution then we lose all the local variables in every frame to that point. The entire callstack can be seen in the debugger, and pressing F5 should continue unwinding the stack and display the normal traceback.

Having said that, it looks like you're using .NET debugging rather than Python debugging, which may explain why there are (apparently) unrelated stack entries. Seeing the code for Program.py that's causing the exception will help us understand what the correct behaviour should be.

tonyandrewmeyer wrote Sep 15, 2011 at 4:10 AM

This happens with nearly any program, which is why I didn't include an example. Here's one. If you run it, then you first get line 11 highlighted. Continuing highlights line 17 (and continuing further is not possible). Neither of those are the line where the error is (line 13).

This is a simplistic example, but this is a significant problem with debugging in Visual Studio (I rarely, if ever, get the code stopping on the correct line). If I run this program with ipy.exe in a console, the last line of the traceback is:

File "Program.py", line 13, in crash
NameError: global name 'crash' is not defined

All I actually need to know to fix this problem is "NameError" and "line 13", and there it is. I'm missing half that information in Visual Studio, and in practice this makes debugging there worthless, despite the wealth of other information that is available.

What is "Python Debugging" versus ".NET" debugging? I don't see any options relating to debugging (other than tee'ing output) in the Python Options. Is there some other method of debugging this?

Zooba wrote Sep 15, 2011 at 5:09 AM

Thanks for the script, it makes it a lot easier to verify. As it happens, I can't repro the issue on my own machine, but I'm also using a later version that I've built from source, so possibly it's been fixed. IIRC, there was an issue with breaking on IronPython exceptions that we didn't fix for 1.0 but it's going into 1.1, but I'm not sure if that was this one. Dino or John will know better.

IronPython marks-up its dynamic compilation in such a way that you can step through in the Managed debugging engine. It isn't quite mixed-mode debugging, but it has a similar effect - this debugger will give a stack trace like the one in the original question, with both managed and Python frames listed. PTVS has a Python-specific debugging engine (it's partially written in Python, so it works with CPython, IronPython, etc.). This debugger will give a traceback like python.exe/ipy.exe, except it normally breaks the first time the exception appears and then automatically continues up the stack (if you hit Continue). If you go through Attach To Process and click the "Select" button you'll see all the available debugging engines.

joxn wrote Sep 15, 2011 at 6:33 AM

If you go to Project -> Properties -> Debug, there's a dropdown box for "Launch mode". The default mode for IronPython projects is "IronPython (.NET) launcher", which was the default behavior for IronPython Tools. You can change that to "Standard Python launcher" to get Python-only debugging.

Using the IronPython launcher, I can repro the behavior above. Using the Standard Python launcher, I break on line 13 with the following exception:
exceptions.NameError
Traceback (most recent call last):
File "D:\users\John S Costello\Documents\Visual Studio 2010\Projects\IronPythonApplication1\IronPythonApplication1\IronPythonApplication1.py", line 0, in crash
NameError: global name 'crash' is not defined

We can look into the IronPython launcher behavior, but it may be an IronPython bug/behavior and not a PTVS bug. If you don't need to debug .Net code, I suggest trying the Standard Python launcher, which has much better understanding of the structure of the Python code.

dinov wrote Sep 15, 2011 at 10:59 PM

This is related to Just my Code and when VS is configured to break.

If you disable Just my Code then it breaks on line 13 (after annoyingly breaking at other locations).
If you keep Just my Code on then go to Debug->Exceptions and check the Thrown column for Common Language Runtime Exceptions then it'll also break on line 13.

It's not breaking on line 13 for unhandled because of the way IronPython does exception handling. It has to emit try/catch/rethrow blocks which VS doesn't know will actually rethrow and therefore it thinks the exception is handled. I don't think there's much we can do about this w/ this as we can't change the .NET debugger and IronPython needs to behave the way it does to get proper Python semantics on .NET. As joxn pointed out you can switch to the Python debugger where we have better control of our debugging semantics.

tonyandrewmeyer wrote Sep 28, 2011 at 9:20 PM

Switching to "Standard Python launcher" (an option I never knew existed, since it's buried in the project properties) it indeed gives an uglier but actually useful debugger. This is probably the better choice for me (teaching students who are learning [Iron]Python). It still gets the line number wrong (it says it's 0), but it indicates the right line in Visual Studio, so that's better.

It's still not great. For example, in the attached program the "Standard Python Launcher" breaks into unittest code, not the program code. (This example is taken from Michael's IronPython book). In this case, the .NET launcher gives a superior result.

dinov wrote Oct 4, 2011 at 4:48 PM

Can you describe how you think the Python standard launcher is uglier? Is it just the unit test code issue? In general I'd expect the standard launcher to be better because it gives you a Python view of the program instead of the .NET view which exposes the IronPython runtime implementation details.

Regarding breaking into unittest code, that's actually surprising and might by another issue. I'll take a look.

dinov wrote Oct 4, 2011 at 5:13 PM

The line number for the exception is IronPython bug 31547: http://ironpython.codeplex.com/workitem/31547

dinov wrote Oct 4, 2011 at 6:19 PM

tonyandrewmeyer wrote Oct 5, 2011 at 11:40 PM

Can you describe how you think the Python standard launcher is uglier?
I meant literally uglier, not less useful. e.g. the same program crashing with .NET debugger (looks like a natural part of Visual Studio) and the Python debugger (looks like a TextBox with the str(e) and traceback pasted into it). Ugly but works is absolutely better than pretty but doesn't.

tonyandrewmeyer wrote Oct 5, 2011 at 11:40 PM

I wish you could attach multiple files with a single comment...

dinov wrote Oct 6, 2011 at 2:27 AM

good point, I'll try and figure out what the .NET debugger is doing to get the pretty UI.

dinov wrote Oct 10, 2011 at 6:55 PM

I've updated us to use the pretty exception dialog box now: http://pytools.codeplex.com/SourceControl/changeset/changes/2186e79581fa

dinov wrote Jan 4, 2012 at 5:28 PM

Changing this to a feature - we should implement a .NET expression evaluator which would then let us control the behavior in VS more precisely.