devhawk_ipy

As I write various python modules (many of which get blogged about), I dump them into a special folder on my machine(s). In my powershell profile script, I set the IRONPYTHONPATH environment variable so that these modules are available to the IPy interpreter (i.e. ipy.exe). To date, I’ve been pretty haphazard about this. But I decided to get a little more structured and put that folder under source control and make it available as “devhawk_ipy”.

So far, I’ve only got three scripts (plus an empty __init__.py) in devhawk_ipy.

Eventually I’ll put my code for working with WPF, LiveFX and Azure into this package, but I’m not happy with where they are yet.

Like ipydbg, devhawk_ipy is up on GitHub. For those non-Git users, I’m will continue to these files up on my SkyDrive. I kind of see SkyDrive as a dumping ground for random content while devhawk_ipy is where stuff goes when it’s a little more polished.

Like IronPython, devhawk_ipy is licensed under the MS-PL. If you’re interested in contributing, feel free to fork and send me patches.

Writing an IronPython Debugger: Dynamic Stack Trace

Now that I can interact with my debugger, it’s time to add a command. I decided to start with something simple – or at least something I thought would be simple – printing a stack trace.

In the unmanaged debugger API, threads have the concept of both stack chains and stack frames. A stack chain represents a segment of the physical stack. In a typical managed app, you’ll have at least two stack chains: the unmanaged stack chain and the managed stack chain. You can interate through the stack chains for a given thread via the Chains property. However, ipydbg is a managed only debugger, so I can ignore the unmanaged stack chain. Instead, I just retrieve the current (managed) chain via the thread’s ActiveChain property.

Within a managed stack chain, there is a collection of stack frames. This is the call stack that managed developers are typically used to working with. It turns out that printing a raw stack trace is very easy to do. Here was my first stab at it:

elif k.Key == ConsoleKey.T:
  print "nManaged Stack Trace"
  for f in active_thread.ActiveChain.Frames:
    offset, sp = get_location(f)
    metadata_import = CorMetadataImport(f.Function.Module)
    method_info = metadata_import.GetMethodInfo(f.FunctionToken)
    print "  ",
      "%s::%s --" % (method_info.DeclaringType.Name, method_info.Name),
      sp if sp != None else "(offset %d)" % offset

This elif block is part of the input method I showed last time. It loops thru the frames in the Active Chain of the active thread and prints some data to the console. As I said, pretty easy. Of course, the devil is in the details.

First detail I should call out is that active_thread variable. As per Mike Stall, “there is no notion of “active thread” in the underlying debug APIs. It’s purely a construct in a debugger UI to make it easier for end-users.” My console based UI may be rudimentary, but it’s still a UI. Events like OnBreakpoint include the active thread as a event argument, so I stash that away in a variable so it’ll be available to the input loop.

Second detail is the call to get_location. When we last saw get_location, it was returning a formatted string. Since my last post, I’ve refactored the code so it returns the raw location data – a tuple of the raw IP offset and the associated sequence point, if available. I’ve also added a __str__ method to my sequence point object, so when I print it to the console, I get the filename and line nicely formatted.

Finally, there’s all CorMetadataImport code. In addition to wrapping the unmanaged debugger API, CorDebug also wraps the unmanaged metadata API. This code lets me get MethodInfo compatible view of the function metadata for a given stack frame. I use it here to get the type and function name for each frame on the stack.

The end result looks something like this. Note, I’ve replaced “Microsoft.Scripting” with “MS.Scripting” to avoid word wrapping.

OnBreakpoint Initialize Location: simpletest.py:1 (offset: 84)
» t
Managed Stack Trace
   S$2::Initialize simpletest.py:1 (offset: 84)
   MS.Scripting.Runtime.OptimizedScriptCode::InvokeTarget (offset 72)
   MS.Scripting.ScriptCode::Run (offset 0)
   IronPython.Hosting.PythonCommandLine::RunFileWorker (offset 77)
   IronPython.Hosting.PythonCommandLine::RunFile (offset 15)
   MS.Scripting.Hosting.Shell.CommandLine::Run (offset 46)
   IronPython.Hosting.PythonCommandLine::Run (offset 240)
   MS.Scripting.Hosting.Shell.CommandLine::Run (offset 74)
   MS.Scripting.Hosting.Shell.ConsoleHost::RunCommandLine (offset 158)
   MS.Scripting.Hosting.Shell.ConsoleHost::ExecuteInternal (offset 32)
   MS.Scripting.Hosting.Shell.ConsoleHost::Execute (offset 63)
   MS.Scripting.Hosting.Shell.ConsoleHost::Run (offset 390)
   PythonConsoleHost::Main — (offset 125)

As we can see, we may be on the first line of the python script, but we’ve got a pretty deep stack trace already. Everything but the top-most frame are from the underlying IronPython implementation. Those extra frames obscure the stack frames I actually care about, so it would be nice to hide any stack frames from IronPython or the DLR. It’s easy enough to write a python generator function that filters out frames that from the DLR or IronPython namespaces. In order to get the type name, we need the method_info like we did above. I’ve factored that code into a separate function in order to avoid code duplication.

def get_method_info_for_frame(frame):
    if frame.FrameType != CorFrameType.ILFrame:
      return None
    metadata_import = CorMetadataImport(frame.Function.Module)
    return metadata_import.GetMethodInfo(frame.FunctionToken)

def get_dynamic_frames(chain):
  for f in chain.Frames:
    method_info = get_method_info_for_frame(f)
    if method_info == None:
      continue
    typename = method_info.DeclaringType.Name
    if typename.startswith("Microsoft.Scripting.")
      or typename.startswith("IronPython.")
      or typename == "PythonConsoleHost":
        continue
    yield f

You’ll notice I’ve added a guard to get_method_info_for_frame in order to ensure that the frame argument is an IL Frame. There are three types of stack frames in the debugger API: IL, native and internal. Most of the frames we’re dealing with are IL frames, but you do run into the occasional lightweight function (i.e. DynamicMethod) frame when debugging IronPython code. Typically, IronPython generates DynamicMethods for all python code except for a few cases related to .NET interop. However, you can’t debug DynamicMethods, so when you run with –D, we generate normal non-dynamic methods instead. However, even when running with –D, we still use DynamicMethods for call site dispatch. Since they’re an implementation detail, we want to filter those out in get_dynamic_frames too.

This gives us a much more manageable stack trace:

OnBreakpoint Initialize Location: simpletest.py:1 (offset: 84)
» t
Stack Trace
   S$2::Initialize -- simpletest.py:1 (offset: 84)

As usual, the latest ipydbg source is up on GitHub.

Writing an IronPython Debugger: Adding Interactivity

Now that ipydbg can set a breakpoint, it’s time to add some interactivity to the app. MDbg supports dozens of commands and currently ipydbg supports none. I’d love for ipydbg to support a wide range of commands like MDbg does, but for now let’s keep it simple and start with two: Continue and Quit. These aren’t very interesting as commands go, but that lets me focus this blog post on adding basic interactivity and future posts on specific commands.

First off, we have to understand how the CorDebug managed API supports interactivity. As we’ve seen, callbacks into the debugger are surfaced as managed events. If we look at the base class for all the debugger event arguments, we see that it exposes a Continue property. If you want the debugger to automatically continue after the event handler finishes running, you set the Continue property to true (which is the default). If you want the debugger to stay paused while you provide the developer a chance to poke around, you set Continue to false. In that case, the debugger stays paused until call process.Continue explicitly.

Once we set the Continue property to false, we need a mechanism to signal the main thread of execution that it’s time to wake up and ask the user what they want to do next. Of course, that’s what WaitHandle and it’s descendents are for. In fact, we’re already using an AutoResetEvent in OnProcessExit to signal that the debugged app has exited so we should exit the debugger. However, now we have two different signals that we want to send: exit the debugger or enter the input loop. I decided to differentiate by using two separate AutoResetEvents:

terminate_event = AutoResetEvent(False)  
break_event = AutoResetEvent(False)  

def OnProcessExit(s,e):  
  print "OnProcessExit"  
  terminate_event.Set()  

def OnBreakpoint(s,e):  
  print "OnBreakpoint", get_location(  
    symbol_readers[e.Thread.ActiveFrame.Function.Module], e.Thread)  
  e.Continue = False  
  break_event.Set()  

#code to create debugger and process omitted for clarity


handles = Array.CreateInstance(WaitHandle, 2)  
handles[0] = terminate_event  
handles[1] = break_event  

while True:  
  process.Continue(False)  

  i = WaitHandle.WaitAny(handles)  
  if i == 0:  
    break  

  input()

Instead of a single call to process.Continue I had before, I’ve created an infinite “while True” loop that calls Continue, waits for one of the events to signal, then either exits the loop of enters the input loop (via the input function). Since there are two AutoResetEvents, I need to use the WaitAny method to wait for one of them to signal. WaitAny takes an array, which is kind of clunky to use from IronPython since the array has to be strongly typed. It would be much more pythonic if I could call WaitHandle.WaitAny([terminate_event, break_event]). WaitAny then returns an index into the array indicating which one received the signal. If it was the terminate_event that signaled, I exit the loop (and the application). Otherwise, I enter the input loop. Notice, by the way, in OnBreakpoint that I’m both setting Continue to false and signaling the break_event.

The “input loop” needs to be a loop because the user may want to type in multiple commands before letting the debugged app continue to execute. This means that the input function is implemented as another “while True” loop. When the user does chooses a command that implies the process should continue, I simply exit out of the input function and the outer “while True” loop above executes the continue and waits for a signal.

Here’s what the input function looks like right now with our two basic commands:

def input():
  while True:
    Console.Write("» ")
    k = Console.ReadKey()

    if k.Key == ConsoleKey.Spacebar:
      Console.WriteLine("nContinuing")
      return  
    elif k.Key == ConsoleKey.Q:
      Console.WriteLine("nQuitting")
      process.Stop(0)
      process.Terminate(255)
      return
    else:
      Console.WriteLine("n Please enter a valid command")

I’ve mapped “q” to quit the debugger and spacebar to continue. Since I’m using Console ReadKey, you only have to type the key in question – no return needed. For continue, we don’t do anything but exit the input loop by returning. Continue gets called as part of the other loop and since we haven’t/can’t add additional breakpoints the debugged app will run until it ends. For quit, I call the Terminate method on process, hard coding the return value to 255. However, Terminate implicitly continues the debugged process. Since you can’t continue a running process, the call to Continue in the outer loop throws an exception. I avoid this exception by adding the call to Stop before Terminate. As per the Stop docs, the debugger maintains a “stop counter” and only resumes the debugged process when the counter reaches zero.  Calling Stop increases the stop counter by one, calling Terminate decreases it by one, then the outer loop Continue  call decreases it to zero and the process continues, terminates and fires the OnProcessExit event handler as usual.

Now that we have a basic interactive loop, I’ll be able to add more interesting commands. I’m guessing at some point, I’ll need to refactor input a bit – I’m guessing a huge if/elif/else statement is going to get ugly fast, but I’ll worry about that when it gets out of hand. As usual, the latest ipydbg source is up on GitHub.

Writing an IronPython Debugger: Setting a Breakpoint

Now that we have a debugger process up and running, let start adding some actual features. First up, we want to be able to set breakpoints. One of the nice things MDbg does is auto-set a breakpoint on the entrypoint function. For ipydbg, we’re going to auto-set a breakpoint on the first line of the python file being debugged.

In order to set a breakpoint, we need debugger symbols. They allow us to translate between “line one of simpletest.py” and the actual location in the code and back. We’re all used to seeing the PDB files that are produced when we compile a C# assembly. Unsurprisingly, the symbol store binder provides a method to load these PDB files from disk. But where do IronPython debug symbols come from? I know from my extensive reading of the ipy.exe command line parameters that you pass –D to enable application debugging, but since all the IL is being generated in memory, how does the debugger get access to the PDB files?

It turns out the debugger API includes a UpdateModuleSymbols callback method that the runtime uses to notify the debugger when the symbols change. The debugger symbols are provided in an IStream, and then you use the symbol binder to get a symbol reader. The .NET Framework already provides a managed API for reading and writing debug symbols. However, that API doesn’t support loading symbols from a stream, so the MDbg code includes it’s own wrapper around the symbol binder API to include that functionality. Here’s some code to get the debug symbol reader for an updated module and iterate through the associated files:

sym_binder = SymbolBinder()

def OnUpdateModuleSymbols(s,e):
  print "OnUpdateModuleSymbols"

  metadata_import = e.Module.GetMetaDataInterface[IMetadataImport]()
  reader = sym_binder.GetReaderFromStream(metadata_import, e.Stream)

  for doc in reader.GetDocuments():
    print "t", doc.URL

process.OnUpdateModuleSymbols += OnUpdateModuleSymbols

If we run this version of ipydbg on simpletest.py with the IPy 2.0.1 release and the Python standard library installed, OnUpdatedModuleSymbols gets called six times, once for each python file that gets loaded when simpletest runs. (site.py, os.py, ntpath.py, stat.py, UserDict.py and simpletest.py). BTW, I tried running this code on the latest build of IPy (changeset 47624) and I’m getting a COM Interop exception. So for now, stick with 2.0.1.

Now that we can get these dynamically generated debug symbols, we can use them to create a breakpoint on the first line of the script being debugged. Everytime OnUpdateModuleSympols is called, I try to bind the initial breakpoint (unless it’s already been bound of course) by calling the following create_breakpoint function.

def create_breakpoint(doc, line, module, reader):
  line = doc.FindClosestLine(line)
  method = reader.GetMethodFromDocumentPosition(doc, line, 0)
  function = module.GetFunctionFromToken(method.Token.GetToken())

  for sp in get_sequence_points(method):
    if sp.doc.URL == doc.URL and sp.start_line == line:
      bp = function.ILCode.CreateBreakpoint(sp.offset)
      bp.Activate(True)
      return bp

  bp = function.CreateBreakpoint()
  bp.Activate(True)
  return bp

This code translates a given document/line into a function/offset where we can set a breakpoint. To do this, we use sequence points which as per Rick Byers are “used to mark a spot in the IL code that corresponds to a specific location in the original source”. So once we find the function that corresponds to a given line of code, we iterate over the sequence points until we find the one that matches the line we want to break on. If we find a matching sequence point, we set the breakpoint there. If we don’t, we set the breakpoint on the function itself. get_sequence_points is a simple wrapper around ISymbolMethod GetSequencePoints. The original API is pretty ugly to use – managing six separate arrays of information – so get_sequence_points turns it into a generator function you can iterate over.

Now that the breakpoint is set, we want to trap the breakpoint event as well. That’s easy enough, we create an event handler for process.OnBreakpoint similar to the OnUpdateModuleSymbols event above. Eventually, we’ll have the ability to step when we break, but for now I’m just going to print out the current location when the breakpoint is hit. This is kind of the reverse of the operation above. Setting a breakpoint means going from a source location to an IL offset within a function. Printing the current location means going from an IL offset in a function back to the source location. Here’s the function to do that:

def get_location(reader, thread):  
  frame = thread.ActiveFrame  
  function = frame.Function  

  offset, mapping_result = frame.GetIP()  
  method = reader.GetMethod(SymbolToken(frame.Function.Token))  

  real_sp = None  
  for sp in get_sequence_points(method):  
    if sp.offset > offset:
      break  
    if sp.start_line != 0xfeefee:
      real_sp = sp  

  if real_sp == None:  
    return "Location (offset %d)" % (offset)  

  return "Location %s:%d (offset %d)" % (  
    Path.GetFileName(real_sp.doc.URL), real_sp.start_line, offset)  

def OnBreakpoint(s,e):
  print "OnBreakpoint", get_location(
    symbol_readers[e.Thread.ActiveFrame.Function.Module], e.Thread)

Given a symbol reader and a debug thread, get_location returns a location string. It loops thru the sequence points, similar to create_breakpoint, in order to find the closest corresponding line of python code to the current offset (check out Mike Stall’s blog as for why I’m checking for 0xfeefee). In order to make this work, I need the symbol reader for the module that I retrieved in OnUpdateModuleSymbols. For now, I’m stashing the reader in a global dictionary keyed by the module named symbol_readers where OnBreakpoint can access it.

Ipydbg isn’t interactive yet, but it is now running, setting a breakpoint and successfully breaking at that breakpoint. As usual, the latest version of ipydbg is up on GitHub.