Chris's Wiki :: blog/python/PhaseTracking

Phase objects: simple decent error reporting for Python programs

September 28, 2007

For a lot of the sort of utility programs I write in Python, the only thing the program can really do when it runs into an operating system level error is report whatever the problem is and exit. So programs start out as one big try:/except: block:

try:
    fp1 = open(fnameA, "r")
    ....
    fp2 = open(fnameB, "r")
    ....
except EnvironmentError, e:
    die("OS error: %s" % str(e))

The problem with this is that the error reported, while accurate, is basically without context; you don't know what the program was doing when it reported 'permission denied' or whatever. So simple programs mutate slightly to keep track of what they are doing in a variable:

try:
    phase = "opening %s" % fnameA
    fp1 = open(fnameA, "r")
    phase = "parsing %s" % fnameA
    ....
except EnvironmentError, e:
    die("%s: error: %s" % (phase, str(e)))

(Well, my simple programs do, since I have no desire to wrap each separate operation that might fail in its own try:/except: block. That's too much work.)

The problem with this approach is that it doesn't work very well when your program grows subroutines, because updating a global variable to track the phase is a pain. The solution I have adopted is to create a special class to track what phase of execution the program is in; with my typical (lack of) imagination, I call this class Phase, and it looks like this:

class Phase(object):
    def __init__(self):
        self.phase = ["starting",]
    def __call__(self, ph):
        self.phase = [ph, ]
    def __str__(self):
        return ": ".join(self.phase)
    def push(self, ph):
        self.phase.append(ph)
    def pop(self):
        self.phase.pop()

It is used as phase("reading file whatever"). It supports push() and pop() operations so that you can have nested situations (such as the ability of configuration files to include other configuration files) that report the full chain of events of how you wound up doing whatever it was that failed.

My programs just make a single global Phase instance and then use it directly as a global variable, but I suppose a more elegant and reusable method would be to create the instance at the top level and pass it down through the call chain.

Comments on this page:

From 98.202.21.76 at 2007-09-29 01:27:46:

Why not just inspect the stack when you catch an exception and pull whatever you need from that? Seems cleaner than trying to manually duplicate a subset of that at all times in a Phase.

-- Jonathan Ellis

By cks at 2007-09-29 01:39:54:

There's two issues with that approach. First, I am pretty sure that digging all of the necessary information out of the stack is going to be far from trivial. You are going to wind up building in knowledge of what arguments are important to report for many os module functions, for example.

Second, generally you need to know why the program was trying to do something as well as exactly what failed, and that can't be reverse engineered out of the stack without very specific and fragile knowledge of the code. (Essentially that knowledge is equivalent to the phase information.)

From 87.79.236.202 at 2007-09-30 06:02:59:

This is, btw, one rare case where temporal rather than lexical scoping is very useful. (Sometimes also called dynamic scope.) Shell has this, and Perl borrowed it from there (but only for global variables; Perl 6 will add the ability to lexicals also), though confusingly called it local.

Your example would translate something like this:
   sub frobnicate {
       local @phase = ( @phase, 'frobnicating the veeblefitzer' );
       # ...
   }
The nice thing is that at the end of the scope, the localised shadow of the global variable magically disappears, so you don’t need to remember to pop the phase at all.

You can emulate this in garbage collected languages or in C++ by letting objects fall out of scope and then doing something in their destructor when that happens, though.

—Aristotle Pagaltzis

From 98.210.203.61 at 2008-09-07 17:36:11:

seems like a great usage for a decorator:

 def withPhase(phase_description):
   def decorate(fn):
     def _wrapper(*args, *kwargs):
       phase.push(phase_description)
       result = fn(*args, **kwargs)
       phase.pop()
       return result
     return _wrapper
   return decorate

 @withPhase("setting up foo")
 def setup_foo():
   frotz_bar()

 @withPhase("frotzing bar")
 def frotz_bar():
   print phase

Now, that having been said, I think it's just as easy to inspect the stack to get the same information.

Written on 28 September 2007.

«	Fixing Ubuntu's ethN device names when you swap hardware

The first rule of free email-based services