5
\$\begingroup\$

Here's what I've right now:

#!/usr/bin/env python
# -*- coding: utf-8 -*-
import functools
import math
import time
class Timer(object):
 def __init__(self):
 self.__values = []
 def start(self):
 self.__start = time.time()
 return self
 def stop(self):
 self.__values.append(int(round((time.time() - self.__start) * 1000)))
 self.__start = None
 return self
 @property
 def average(self):
 return sum(self.__values) / len(self.__values) 
 @property
 def deviation(self):
 if self.average:
 return math.sqrt(sum((v - self.average) ** 2 for v in self.__values) / self.runs)
 return 0
 @property
 def elapsed(self):
 return sum(self.__values)
 @property
 def runs(self):
 return len(self.__values)
class Profiler(object):
 __timers = {}
 @staticmethod
 def info(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 return Profiler.__timers[timer_id]
 @staticmethod
 def profile(f):
 @functools.wraps(f)
 def wrap(self=None, *args, **kwargs):
 method = self.__class__.__name__ + '.' + f.func_name if self \
 else f.func_name
 Profiler.start(method)
 r = f(self, *args, **kwargs) if self else f(*args, **kwargs)
 Profiler.stop(method)
 return r
 return wrap
 @staticmethod
 def reset(timer_id):
 Profiler.__timers[timer_id] = Timer()
 @staticmethod
 def start(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 Profiler.reset(timer_id)
 Profiler.__timers[timer_id].start()
 @staticmethod
 def stop(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 Profiler.__timers[timer_id].stop()
if __name__ == '__main__':
 class Test(object):
 def isPrime(self, n):
 if n < 2 or (n % 2) == 0:
 return n == 2
 f = 3
 while (f * f) <= n:
 if (n % f) == 0:
 return False
 f += 2
 return True
 @Profiler.profile
 def run(self):
 return filter(self.isPrime, range(1, 1000001))
 test = Test()
 for x in range(5):
 test.run()
 p = Profiler.info('Test.run')
 print 'runs = %d' % p.runs
 print 'elapsed = %d ms' % p.elapsed
 print 'average = %d ms' % p.average
 print 'deviation = %d ms' % p.deviation

I'm looking for suggestions to improve it and you're welcome to suggest. :)

The Profiler.profile decorator supports both functions and class methods. I've written a small test to demonstrate my profiler.

James Draper
7463 gold badges7 silver badges22 bronze badges
asked Feb 28, 2011 at 3:43
\$\endgroup\$
2
  • \$\begingroup\$ As written it doesn't seem to handle recursion. If you move the start/stop time tracking into profile() it would. \$\endgroup\$ Commented Feb 28, 2011 at 8:37
  • \$\begingroup\$ Why not start from cProfile, and then operate on the Stats object generated by that? \$\endgroup\$ Commented Mar 1, 2011 at 19:00

1 Answer 1

6
\$\begingroup\$
#!/usr/bin/env python
# -*- coding: utf-8 -*-
import functools
import math
import time
class Timer(object):
 def __init__(self):
 self.__values = []

You are using prefix __ to denote private attributess. This is perfectly valid and has special support within python. Having said that, I'm not a fan of it. Its designed for use when you are subclassing objects to prevent accidents. I think that if you are not designing your object to be subclassed, you should stick with single underscores.

 def start(self):
 self.__start = time.time()
 return self

Some frameworks do make use of this return self paradigm. However, its kinda unusual and will lead to code being confusing if you are not used to it. As it is you don't seem to be making use of this. I'd just get rid of return self. This doesn't seem to be the type of object which works well with the pattern anyways.

 def stop(self):
 self.__values.append(int(round((time.time() - self.__start) * 1000)))

The operations being performed here are just long enough to come across as awkward, I'd write it as

seconds_elapsed = time.time() - self.__start
milliseconds_elapsed = int(round(seconds_elapsed*1000))
self.__values.append(milliseconds_elapsed)

As another note, don't be afraid of floats. You'd probably be better off storing a list of floating point seconds rather then integer milliseconds. The code would be clearer and there is probably no noticeable difference in efficiency.

 self.__start = None
 return self
 @property
 def average(self):
 return sum(self.__values) / len(self.__values) 
 @property
 def deviation(self):
 if self.average:
 return math.sqrt(sum((v - self.average) ** 2 for v in self.__values) / self.runs)
 return 0

I recommend using the numpy library which has functions to calculate average/stdev/pretty much everything. The math done in numpy will be much more efficient then your python versions.

 @property
 def elapsed(self):
 return sum(self.__values)
 @property
 def runs(self):
 return len(self.__values)

I don't like the name Timer for the class because it spends most of its effort keeping track of values not measuring time.

class Profiler(object):
 __timers = {}
 @staticmethod
 def info(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 return Profiler.__timers[timer_id]

If you are going to store state on your class object, use classmethod like so:

 @classmethod
 def info(cls, timer_id):
 if not cls.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 return cls.__timers[timer_id]

There also does not appear to be a good reason to be storing this state statically. I suggest that you really should implement this as a normal object. There are few cases where storing state on a static object is justified.

 def info(self, timer_id):
 if not self.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 return self.__timers[timer_id]

Additionally, don't be afraid of exceptions. In python you shouldn't (in general) try to detect whether an exception will be thrown before attempting an operation. Just perform the operation and catch the exception. The above version ends up locating an element in a dictionary twice, which is just a waste. The above function should be implemented as:

 def info(self, timer_id):
 try:
 return self.__timers[timer_id] 
 except KeyError:
 raise Exception('Timer not started')

Similar comments apply to your other functions.

 @staticmethod
 def profile(f):
 @functools.wraps(f)
 def wrap(self=None, *args, **kwargs):

You assume that your first parameter will be self (if it exists). Depending on how this is called, self may actually already be bundled into f as a method object. Also, if you are calling a function which is not a method something else will come in there. You shouldn't capture self this way, just let all parameters go into *args

 method = self.__class__.__name__ + '.' + f.func_name if self \
 else f.func_name

As mentioned, you shouldn't capture self the way you do. The correct place to find the class is f.im_class. Be careful! That attribute won't be there on non-methods.

 Profiler.start(method)
 r = f(self, *args, **kwargs) if self else f(*args, **kwargs)

I recomment calling r, return_value for better clarity. Also by eliminating self, you'll make this bit of code cleaner Profiler.stop(method)

This is actually wrong in the case of recursion as another commenter has pointed out. Also, since Timer is really concerned with keeping track of times, perhaps calculating time spent would be better here.

 return r
 return wrap

Your API is counterintuitive on this point. I'd except a function called profile to profile a function, not return a new function which I then have to call in order to profile it. For what the function does it should be called profiled.

 @staticmethod
 def reset(timer_id):
 Profiler.__timers[timer_id] = Timer()
 @staticmethod
 def start(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 Profiler.reset(timer_id)
 Profiler.__timers[timer_id].start()
 @staticmethod
 def stop(timer_id):
 if not Profiler.__timers.has_key(timer_id):
 raise Exception('Timer not started')
 Profiler.__timers[timer_id].stop()
if __name__ == '__main__':
 class Test(object):
 def isPrime(self, n):
 if n < 2 or (n % 2) == 0:
 return n == 2
 f = 3
 while (f * f) <= n:
 if (n % f) == 0:
 return False
 f += 2
 return True
 @Profiler.profile
 def run(self):
 return filter(self.isPrime, range(1, 1000001))
 test = Test()
 for x in range(5):
 test.run()
 p = Profiler.info('Test.run')
 print 'runs = %d' % p.runs
 print 'elapsed = %d ms' % p.elapsed
 print 'average = %d ms' % p.average
 print 'deviation = %d ms' % p.deviation

I think a better API to implement would be one that works like this:

 class Test(object):
 def isPrime(self, n):
 if n < 2 or (n % 2) == 0:
 return n == 2
 f = 3
 while (f * f) <= n:
 if (n % f) == 0:
 return False
 f += 2
 return True
 @profiled
 def run(self):
 return filter(self.isPrime, range(1, 1000001))
 test = Test()
 for x in range(5):
 test.run()
 stats = Test.run.stats
 print 'runs = %d' % stats.runs
 print 'elapsed = %d ms' % stats.elapsed
 print 'average = %d ms' % stats.average
 print 'deviation = %d ms' % stats.deviation

Essentially, store your Timer object on the function object itself. That will simplify your code considerably because you are using python's name resolution rather then your own.

As a final note, there are plenty of good profiling tools out there for python. You are probably best off using one one of those.

answered Mar 2, 2011 at 22:38
\$\endgroup\$

Your Answer

Draft saved
Draft discarded

Sign up or log in

Sign up using Google
Sign up using Email and Password

Post as a guest

Required, but never shown

Post as a guest

Required, but never shown

By clicking "Post Your Answer", you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.