Writing an IronPython Debugger: Stepping Thru Code

So far, I’ve written seven posts about my IronPython debugger, but frankly it isn’t very functional yet. It runs, breaks on the first line and can show a stack trace. Not exactly Jolt award material. In this post, I’m going to add one of the core functions of any debugger: stepping. Where previously I’ve written a bunch of code but had little to show in terms of features, now I’m getting three new features (basic step, step in and step out) at once!

def _input(self):
  #remaining _input code omitted for clarity

  elif k.Key == ConsoleKey.S:
      print "nStepping"
      self._do_step(False)
      return
  elif k.Key == ConsoleKey.I:
      print "nStepping In"
      self._do_step(True)
      return
  elif k.Key == ConsoleKey.O:
      print "nStepping Out"
      stepper = create_stepper(self.active_thread)
      stepper.StepOut()

def _do_step(self, step_in):
  stepper = create_stepper(self.active_thread)
  mod = self.active_thread.ActiveFrame.Function.Module
  if mod not in self.symbol_readers:
      stepper.Step(step_in)
  else:
    range = get_step_ranges(self.active_thread, self.symbol_readers[mod])
    stepper.StepRange(step_in, range)

Here you can see the _input clauses for step, step in and step out. Of the three, step out is the simplest to implement: create the stepper object and call StepOut. For step and step in, I could simply call Step (the boolean argument indicates if you want to step into or over functions) but that only steps a single IL statement. The vast majority of the time there are multiple IL instructions for every line of source code, so IL statement stepping is very tedious. As we learned when setting a breakpoint, debug symbols contain sequence points that map between source and IL locations. If they’re available, I use the sequence points to determine the range of IL statements to step over so that I can step single source statements instead.

The stepping code above depends on three helper functions defined at global scope.

def create_stepper(thread):
  stepper = thread.ActiveFrame.CreateStepper()
  stepper.SetUnmappedStopMask(CorDebugUnmappedStop.STOP_NONE)
  return stepper  

def create_step_range(start, end):
  range = Array.CreateInstance(COR_DEBUG_STEP_RANGE, 1)
  range[0] = COR_DEBUG_STEP_RANGE(startOffset = UInt32(start),
                                  endOffset = UInt32(end))
  return range

def get_step_ranges(thread, reader):
    frame = thread.ActiveFrame
    offset, mapResult = frame.GetIP()
    method = reader.GetMethod(SymbolToken(frame.FunctionToken))
    for sp in get_sequence_points(method):
        if sp.offset > offset:
            return create_step_range(offset, sp.offset)
    return create_step_range(offset, frame.Function.ILCode.Size)

The first function, create_stepper, simply constructs and configures the stepper object. The call to SetUnmappedStopMask tells the debugger not to stop if it encounters code that can’t be mapped to IL. If you need to debug at that level, ipydbg is *not* for you.

Next is create_step_range, which exists purely for .NET interop purposes. There are three interop warts hidden in this function. First is creating a .NET array of COR_DEBUG_STEP_RANGE structs. Every time I write Array code like this, I wish for a CreateFromCollection static method on Array. However, in this case it isn’t that big a deal since it’s a one element array. Second wart is having to set the values of COR_DEBUG_STEP_RANGE via constructor keyword arguments. It turns out that IronPython disallows direct updates to value type fields (read this for the reason why). Instead, I pass in the field values into the constructor as keyword arguments. Finally, you have to explicitly convert the start and end offsets to a unsigned int in order to set the offset fields in the COR_DEBUG_STEP_RANGE struct constructor.

Finally is get_step_ranges, which iterates thru the list of sequence points in the current method looking for the one with the smallest offset that is larger than the current offset position. If it can’t find a matching sequence point, it sets the range to the end of the current function. The start range offset is always the current offset. I did make a significant change to get_sequence_points – it no longer yields sequence points that have a start line of 0xfeefee. By convention, that indicates a sequence point to be skipped. Originally, the logic to ignore 0xfeefee sequence points was in get_location. But when I originally wrote get_step_ranges, it had essentially the same sequence point skipping logic, so I moved it to get_location instead.

Technically, I’ve built three new features but the reality is that if you end up in IronPython infrastructure code it’s really hard to find your way back to python code. Step in is particularly useless right now. Luckily, the .NET debugger API supports a feature called “Just My Code” that will make stepping much more useful. In the meantime, the latest version of ipydbg is up on GitHub as usual.

Writing an IronPython Debugger: Refactoring

When we last left ipydbg, it was up to about 200 lines of code. Not bad in terms of overall length, but I started to detect some code smell. I was relying pretty heavily on global variables and the structure of my code made it difficult to control how the debugger was run. I wanted to change ipydbg so it would automatically spin up an MTA thread if I forgot to add the –X:MTA command line parameter. But since by debugger and process objects were global, they’d get created on the main thread of ipydbg, regardless if it was STA or MTA. So for this “release” (I’d say I’m almost to version 0.0.0.1), I decided on focusing on enginering and refactoring rather than new features.

The big new addition is the IPyDebugProcess class, which is clearly the workhorse of the application. All of the previously global variables are now class instance variables on IPyDebugProcess. Input and run along with all the event handlers as well as do_break_event and get_location are now class methods, as they need to access instance variables (setting the break event, accessing the symbol reader dictionary, etc.). Functions that didn’t need to access instance variables (get_sequence_points, create_breakpoint, get_dynamic_frames and get_method_info_for_frame) I left as top-level functions. If they get more complex, I may break them out into their own modules, but for now I left them in ipydbg.py.

The conversion process was fairly trivial. I had to add “self.” lots of places and change the indention level all over but that was pretty much it. Once I finished the conversion, I was able to add the run_debugger function to handle the thread creation, if necessary.

def run_debugger(py_file):
    if Thread.CurrentThread.GetApartmentState() == ApartmentState.STA:
        t = Thread(ParameterizedThreadStart(run_debugger))
        t.SetApartmentState(ApartmentState.MTA)
        t.Start(py_file)
        t.Join()
    else:
        p = IPyDebugProcess()
        p.run(py_file)

if __name__ == "__main__":
    run_debugger(sys.argv[1])

Originally, I tried to put this logic in IPyDebugProcess.run. However, since I’m creating the debugger object in the __init__ function, that meant it would be created on the wrong thread. I could have moved the debugger creation to the run method or move the thread management code to __init__, but I decided to factor that logic into a separate function completely. Felt cleaner that way.

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.