timo.py

__all__ = 'TimeMeasurement', 'CummulativeTimeMeasurement', 'MeasurementContext'

from datetime import datetime
from itertools import chain

class MeasurementBase(object):
    def __init__(self):
        self.stack = []

    def __call__(self, event_name):
        save_name = '.'.join(chain(self.stack, (event_name,)))
        contextmanger = MeasurementContext(lambda spent: (
            self.save(save_name, spent),
            self.stack and self.stack.pop(),
        ))
        self.stack.append(event_name)
        return contextmanger

    def save(self, event_name, spent):
        raise NotImplementedError()

class TimeMeasurement(MeasurementBase, list):
    def save(self, event_name, spent):
        self.append((event_name, spent))

class CummulativeTimeMeasurement(MeasurementBase, dict):
    def save(self, event_name, spent):
        if event_name in self:
            self[event_name] += spent
        else:
            self[event_name] = spent

class MeasurementContext(object):
    def __init__(self, on_complete=None):
        self.on_complete = on_complete
        self.start = None
        self.end = None

    def __enter__(self):
        self.start = datetime.now()
        return self

    def __exit__(self, exc_type, exc_value, traceback):
        self.end = datetime.now()
        if self.on_complete:
            self.on_complete(self.spent)

    @property
    def spent(self):
        return self.end - self.start

    @property
    def spent_seconds(self):
        return self.spent.total_seconds()


if __name__ == '__main__':
    import time
    with MeasurementContext() as m:
        time.sleep(0.001)
    print 'simple', (m.spent, m.spent_seconds)


    tm = TimeMeasurement()
    with tm('first'):
        time.sleep(1)
        with tm('sublevel'):
            time.sleep(1)
        with tm('sublevel2'):
            time.sleep(1)
            with tm('subsublevel'):
                time.sleep(1)
    with tm('second'):
        time.sleep(1)
    with tm('third'):
        time.sleep(1)

    print 'flat'
    for i in tm:
        print ' -', i


    tm = CummulativeTimeMeasurement()
    with tm('first'):
        time.sleep(1)
        with tm('sublevel'):
            time.sleep(1)
        with tm('sublevel2'):
            time.sleep(1)
            with tm('subsublevel'):
                time.sleep(1)
    with tm('second'):
        time.sleep(1)
    with tm('third'):
        time.sleep(1)

    with tm('first'):
        time.sleep(1)
        with tm('sublevel'):
            time.sleep(1)
        with tm('sublevel2'):
            time.sleep(1)
            with tm('subsublevel'):
                time.sleep(1)
    with tm('second'):
        time.sleep(1)
    with tm('third'):
        time.sleep(1)

    with tm('first'):
        time.sleep(1)
        with tm('sublevel'):
            time.sleep(1)
        with tm('sublevel2'):
            time.sleep(1)
            with tm('subsublevel'):
                time.sleep(1)
    with tm('second'):
        time.sleep(1)
    with tm('third'):
        time.sleep(1)

    print 'cummulative'
    for i in tm.items():
        print ' -', i

sample output

simple (datetime.timedelta(0, 0, 5422), 0.005422)
flat
 - ('first.sublevel', datetime.timedelta(0, 1, 4056))
 - ('first.sublevel2.subsublevel', datetime.timedelta(0, 1, 4060))
 - ('first.sublevel2', datetime.timedelta(0, 2, 8157))
 - ('first', datetime.timedelta(0, 4, 16452))
 - ('second', datetime.timedelta(0, 1, 3966))
 - ('third', datetime.timedelta(0, 1, 7997))
cummulative
 - ('third', datetime.timedelta(0, 3, 16002))
 - ('first.sublevel', datetime.timedelta(0, 3, 20133))
 - ('first.sublevel2.subsublevel', datetime.timedelta(0, 3, 16138))
 - ('second', datetime.timedelta(0, 3, 16013))
 - ('first.sublevel2', datetime.timedelta(0, 6, 36579))
 - ('first', datetime.timedelta(0, 12, 77023))