Some ZODB introspection magic based on wrappers around the native objects

spy.py

import transaction
import ZODB
from ZODB.utils import u64
import logging
from collections import defaultdict
from pprint import pformat
import inspect, traceback

logger = logging.getLogger('zodb_spy')

stats = defaultdict(int)

class Wrapper(object):
    def __init__(self, target):
        self._target = target

    def __getattr__(self, attr):
        if attr not in self._exceptions:
            return getattr(self._target, attr)
        else:
            return self.__dict__[attr]

    def __setattr__(self, attr, value):
        if attr not in self._exceptions:
            setattr(self._target, attr, value)
        else:
            self.__dict__[attr] = value

class PickleCacheWrapper(Wrapper):

    _exceptions = ['_target', '_conn', 'new_ghost']

    def new_ghost(self, oid, obj):
        logger.debug('\t(cache) new_gost for %s (%s)' % (u64(oid), type(obj)))
        self._target.new_ghost(oid, obj)

    def get(self, oid, default):
        stats['cache_get'] += 1
        obj = self._target.get(oid, default)
        logger.debug("\t(cache) %s => %s"  % (u64(oid), type(obj)))
        return obj

    def __setitem__(self, k, v):
        return self._target.__setitem__(k, v)

    def __getitem__(self, k):
        return self._target.__getitem__(k)


class ObjectReaderWrapper(Wrapper):

    _exceptions = ['_target', '_conn', 'getGhost', 'setGhostState']

    def getGhost(self, obj):
        logger.debug('\t(reader) %s' % repr(obj))
        return self._target.getGhost(obj)

    def setGhostState(self, obj, pickle):
        logger.debug('\t(reader) setting state for %s' % type(obj))
        return self._target.setGhostState(obj, pickle)


class StorageWrapper(Wrapper):

    _exceptions = ['_target', '_conn', 'load']

    def load(self, oid, version):
        pickle = self._target.load(oid, version)
        stats['storage_load'] += 1
        size = len(pickle[0]) + len(pickle[1])
        stats['storage_bytes'] += size
        logger.debug('\t(storage) load %s: %s bytes' % (u64(oid), size))
        return pickle


class SpyConnection(ZODB.Connection.Connection):

    def __init__(self, *args, **kwargs):
        super(SpyConnection, self).__init__(*args, **kwargs)
        self._cache = PickleCacheWrapper(self._cache)
        self._reader = ObjectReaderWrapper(self._reader)
        self._storage = StorageWrapper(self._storage)

    def register(self, obj):
        logger.info("%s: registering %s" % (self, obj))
        frame = inspect.currentframe()
        for l in traceback.format_stack(frame):
            logger.debug(l)
        return super(SpyConnection, self).register(obj)

    def get(self, oid):
        logger.info('%s: getting %s' % (self, u64(oid)))
        obj = super(SpyConnection, self).get(oid)
        return obj


class SpyDB(ZODB.DB):

    klass = SpyConnection

    def open(self):
        conn = super(SpyDB, self).open()
        logger.info('%s: Opened %s' % (self, conn))
        return conn


class TransactionWrapper(Wrapper):

    _exceptions = ['_target', 'join']

    def join(self, resource):
        logger.info("%s joins %s " % (resource, self._target))
        self._target.join(resource)


class ManagerWrapper(Wrapper):

    _exceptions = ['_target', 'begin', 'commit', 'get']

    def get(self):
        return TransactionWrapper(self._target.get())

    def begin(self):
        txn = self._target.begin()
        return TransactionWrapper(txn)

    def commit(self):
        logger.info("%s about to commit" % self._target)
        self._target.commit()
        logger.info("%s committed" % self._target)


def start():
    global stats
    stats = defaultdict(int)


def end():
    data = ""
    for k, v in stats.iteritems():
        data += ("\t%s: %s\n" % (k, v))

    logger.info("\nSTATISTICS:\n%s" % data)
    logger.info("\n**********\nEND")

def install(fname, level=logging.DEBUG):
    transaction.manager = wrapper
    transaction.commit = wrapper.commit

    logger = logging.getLogger('zodb_spy')
    sh = logging.FileHandler(fname)
    logger.addHandler(sh)
    logger.setLevel(level)
    sh.setFormatter(logging.Formatter("%(asctime)s %(name)-16s: %(levelname)-8s - %(message)s"))


wrapper = ManagerWrapper(transaction.manager)

test.py

from spy import transaction, SpyDB, start, end, install

from ZEO.ClientStorage import ClientStorage 
from BTrees.OOBTree import OOBTree

import logging

install('/tmp/log')

start()

cs = ClientStorage(('localhost', 9675))
db = SpyDB(cs)

conn = db.open()

r = conn.root._root

r['c'] = 'a'

#tree = OOBTree()
#for n in xrange(0, 1000):
#    tree[n] = n * 'q'
#r['tree'] = tree

for a in xrange(0, 1000):
    print r['tree'][a]

#transaction.commit()

end()