Tracking down rogue print statements

I’ve spend the last hour hunting for a rogue print somewhere in my code. I almost never use a debugger these days, relying almost exclusively on debug prints. Python makes it easy and Scite makes that even easier. That habit has just bit me in the ass. Like I said, I spend the last hour hunting for that rogue print statement I’ve put somewhere and couldn’t find. Turns out it was in one of Python’s built-in modules.

I wrote a small class that to help me out. This class prints the current call stack every time somebody tries to print something. When the class was ready, it took me just a few seconds to locate the evil print.

import traceback
class Tracer:
    def __init__(self, oldstream):
        self.oldstream = oldstream
        self.count = 0
        self.lastStack = None
   
    def write(self, s):
        newStack = traceback.format_stack()
        if newStack != self.lastStack:
            self.oldstream.write("".join(newStack))
            self.lastStack = newStack
        self.oldstream.write(s)

The class uses the builtin traceback module’s format_stack function to get the stack info and prints it. One thing I learned while doing that is that a print statement is actually translated to two writes. Don’t know if that means anything, but that’s the reason for the comparison trick in the code.

This is how you’d use the class:

import sys
sys.stdout = Tracer(sys.stdout)
sys.stderr = Tracer(sys.stderr)

Enjoy.

Comments are closed.