Debug: Module to track python objects.

[Stidolph, David]

First and foremost I want to thank Guido for the traceback system - just
having made this module possible and my task MUCH easier.

This is an update to a debugging module that I posted before.  See the end
of this mail for the module.

Purpose:  The Debug module tracks python class instances between their
__init__ and __del__ method calls.  The idea is to provide tracking for
objects so that a report can be generated with objects that have not been
freed.  When we first ran this on our code we found almost 300 objects that
were not being destroyed (more than half were windows resources like graphic
texture files).

Asumptions:  The __init__ method of every class calls LogInit method of the
debug class.  The __del__ method calls LogDel.  We have a special method
called Destroy for every class that is designed to remove references to
other objects and handle the circular reference problem.  The Destroy method
calls LogDel

Useage (we have a Globals module with specific instance variables to grant
access to modules like Debug):  

	#sample
	import Globals

	class Name:
	  def __del__(self):
	    if __debug__:
	      Globals.debug.LogDel(self)

	  def __init__(self):
	    if __debug__:
	      Globals.debug.LogInit(self)
	    # your code

	  def Destroy(self):
	    if __debug__:
	      Globals.debug.LogDestroy(self)
	    # your code

Questions:

1. We are losing the tracebacks.  At some point the output terminates.  This
happens after a large output, so I suspect a buffer overrun.
2. Can we shrink the tracebacks?  Keeping all the strings while the program
runs seems a little much.  We also want to modify the output for MSVC.
3. Is there any other tracking we can do for catching bugs?  Ways to enhance
this module?

I'm open to comments, include those designed to make it more effecient,
powerful or easier to use.

Thank you for your help,

David Stidolph
Origin.

#Debug Module
#
#This class is designed to track Python objects between their __init__() and
__del__() method calls.
#There are different 'levels' to the tracking.  If we do it at all, we will
track the objects by the object
#id() using a dictionary.  If we have 'holdTraceback' active, then in
LogInit we get the current
#stack, translate it into a list of strings and use that list as the value
and the object reference as
#the key in the dictionary.
#
#As a dictionary we keep only one copy and don't allow for
LogInit/LogDestroy to be called more than
#once (have setting to throw exception if it occurs).  This means you put
the calls to LogInit and
#LogDestroy in the base class .. not the derived classes.  Proper class name
of the object is used
#by __class__.__name__.
#
#TODO:
#       Fix output for MSVC IDE to use absolute paths to Python files for
double-clicking
#       (Note that this works now for Windows 95, but not 98)
#       Add Python object for output in LogReport to allow output to file or
sending across net
#       Add print formatted output to wrap output (allow to send across
net).
#       Optimize use of stack trace to reduce memory requirements.
#       Clipping problem on the traceback - gets cut-off.

from sys import exc_info
from traceback import extract_stack

class Debug:
  """Only one instance allowed"""

  __refDebugCount = 0 # class variable

  def __del__(self):
    Debug.__refDebugCount = Debug.__refDebugCount - 1

  def __init__(self, trackObjects = 1, holdTraceback = 1,
raiseExceptionOnDuplicate = 0, displayInit = 0, displayDestroy = 0):
    if Debug.__refDebugCount != 0:
      raise "Only one copy of debug allowed"

    if __debug__:
      self.trackObjects = trackObjects
      self.holdTraceback = holdTraceback
      self.raiseExceptionOnDuplicate = raiseExceptionOnDuplicate
      self.displayInit = displayInit
      self.displayDestroy = displayDestroy
    else:
      self.trackObjects = 0               #if we don't have debug mode, then
it doesn't matter what
      self.holdTraceback = 0              #settings we use since nothing
SHOULD be calling us.
      self.raiseExceptionOnDuplicate = 0  #Just in case we ignore and set
for nothing.
      self.displayInit = 0
      self.displayDestroy = 0

    self.activeObjects = {}     #clear dictionary
    Debug.__refDebugCount = 1    #we are initialized

  def Destroy(self):
    Debug.__refDebugCount = 0
    self.activeObjects = None

  def LogDel(self,object):
    #We wrap the destruction of the key inside a try..except block in case
the LogDestroy is called without
    #calling the LogInit (rare) or LogDestroy is being called for a second
time (far more likely).
    try:
      objectID = id(object)
      value = self.activeObjects[objectID]
      if 0 == value[1]:
        if self.raiseExceptionOnDuplicate:
          raise "MEM: LogDel called on "+object.__class__.__name__+" without
calling Destroy()"
        else:
          print
          print "MEM: LogDel called on "+object.__class__.__name__+" without
calling Destroy()"
          print
      del self.activeObjects[objectID]
    except:
      if self.raiseExceptionOnDuplicate:
        raise "MEM: LogDel called twice on "+object.__class__.__name__+".
See if base class doing LogInit/LogDestroy/LogDel (only one should)"
      else:
        print
        print "MEM: LogDel called twice on "+object.__class__.__name__+".
See if base class doing LogInit/LogDestroy/LogDel (only one should)"
        print

  #Called from each base object Destroy() method.
  def LogDestroy(self,object):
    if self.trackObjects:
      if self.displayDestroy:
        print 'MEM: ',repr(object),'of class',object.__class__.__name__,'is
being Destroyed'
      #We wrap the destruction of the key inside a try..except block in case
the LogDestroy is called without
      #calling the LogInit (rare) or LogDestroy is being called for a second
time (far more likely).
      self.activeObjects[id(object)][1] = 1

  #Called from base object __init__(self) routines
  def LogInit(self,object):
    if self.trackObjects:
      if self.displayInit:
        #display that the object has been constructed and its __init__ has
been called
        print 'MEM: ',repr(object),'of class',object.__class__.__name__,'is
being initialized'

      #traceback of stack is generated using extract_stack() and used as the
value in the
      #dictionary with the object reference used as the key.
      if self.holdTraceback:
        #We check for the object already being in the dictionary ONLY if we
will throw an 
        #exception, silent otherwise
        if self.raiseExceptionOnDuplicate:
          if self.activeObjects.haskey(object):
            raise "Object has already called LogInit"
        tb = extract_stack()
        self.activeObjects[id(object)] = [object.__class__.__name__,0,tb]
      else:
        self.activeObjects[id(object)] = [object.__class__.__name__,0,1]

  #Called at program end to report on undestroyed Python objects.
  def LogReport(self):
    # For formatting that Visual Studio can recognize, we're adjusting
    # output to look like:
    # c:\test\gagob.cpp(236) : error C2065: 'Clear' : undeclared identifier
    if self.trackObjects:
      if len(self.activeObjects) > 0:
        print 
        print 'MEM: UnDestroyed Python Objects Report:'
        print '     %s python objects total.' % len(self.activeObjects)
        print
        print 'Summary:  These objects were not released.  Individual stack
traces follow'
        for objectID,value in self.activeObjects.items():
          print ' class ' + value[0]
        print
        print
        #Get Object reference and stack traceback for each undestroyed
Python object
        for objectID,value in self.activeObjects.items():
          className = value[0]
          destroyCalled = value[1]
          tb = value[2]
          if destroyCalled == 1:
            print 'MEM:  class ' + className + ' Destroy() called, but not
__del__.'
          else:
            print 'MEM:  class ' + className + ' Destroy() and __del__
methods not called.'
          if self.holdTraceback:
            for tuple in tb[:-2]: #-2 is to eliminate report of call to
LogInit()
              print str(tuple[0])+'('+str(tuple[1])+'): in
'+str(tuple[2])+','
              print '  '+str(tuple[3])
          print #blank line between
      else:
        print 'MEM: Congratulations!  No Python object leaks!'