Title: A basic time profiler
Submitter: Anand Pillai (other recipes)
Last Updated: 2006/08/03
Version no: 1.0
Category: Shortcuts

Description:

This recipe provides a very simple time profiling module which helps you to
measure actual execution time for blocks of Python code without peppering your
code with many time.time() statements.

Source: Text Source

"""
A module that helps to inject time profiling code
in other modules to measures actual execution times
of blocks of code.

"""

__author__ = "Anand B. Pillai"
__version__ = "0.1"

import time

def timeprofile():
    """ A factory function to return an instance of TimeProfiler """

    return TimeProfiler()

class TimeProfiler:
    """ A utility class for profiling execution time for code """
    
    def __init__(self):
        # Dictionary with times in seconds
        self.timedict = {}

    def mark(self, slot=''):
        """ Mark the current time into the slot 'slot' """

        # Note: 'slot' has to be string type
        # we are not checking it here.
        
        self.timedict[slot] = time.time()

    def unmark(self, slot=''):
        """ Unmark the slot 'slot' """
        
        # Note: 'slot' has to be string type
        # we are not checking it here.

        if self.timedict.has_key(slot):
            del self.timedict[slot]

    def lastdiff(self):
        """ Get time difference between now and the latest marked slot """

        # To get the latest slot, just get the max of values
        return time.time() - max(self.timedict.values())
    
    def elapsed(self, slot=''):
        """ Get the time difference between now and a previous
        time slot named 'slot' """

        # Note: 'slot' has to be marked previously
        return time.time() - self.timedict.get(slot)

    def diff(self, slot1, slot2):
        """ Get the time difference between two marked time
        slots 'slot1' and 'slot2' """

        return self.timedict.get(slot2) - self.timedict.get(slot1)

    def maxdiff(self):
        """ Return maximum time difference marked """

        # Difference of max time with min time
        times = self.timedict.values()
        return max(times) - min(times)
    
    def timegap(self):
        """ Return the full time-gap since we started marking """

        # Return now minus min
        times = self.timedict.values()
        return time.time() - min(times)

    def cleanup(self):
        """ Cleanup the dictionary of all marks """

        self.timedict.clear()

if __name__ == "__main__":
    # Demo code
    profiler = timeprofile()
    # Mark time
    profiler.mark()
    # Execute large loop
    for x in xrange(10000):
        pass
    # Get time
    print profiler.elapsed()
    # Do other things
    profiler.mark('t')
    for x in range(10000):
        for y in range(10000):
            pass
    print profiler.elapsed('t')

    # Get total time elapsed
    print profiler.timegap()

    # Get maximum diff for marks
    print profiler.maxdiff()

Discussion:

For profiling actual code execution time, you have to often pepper your Python code with statements like the following:

import time

t1 = time.time()
# Execute my huge memory/CPU intensive chunk of code...
elapsed = time.time() - t1

This recipe provides a wrapper over such time.time() calls and uses a dictionary to slot times using 'marks', so that profiling time becomes a breeze.

This is a simple module. If you want to do some serious time profiling of your code averaged over multiple execution loops, use timeit.py .