import time
 
def timefunc(f):
 def f_timer(*args, **kwargs):
  start = time.time()
  result = f(*args, **kwargs)
  end = time.time()
  print f.__name__, 'took', end - start, 'time'
  return result
 return f_timer
 
def get_number():
 for x in xrange(5000000):
  yield x
 
@timefunc
def expensive_function():
 for x in get_number():
  i = x ^ x ^ x
 return 'some result!'
 
# prints "expensive_function took 0.72583088875 seconds"
result = expensive_function()

import time
 
class timewith():
 def __init__(self, name=''):
  self.name = name
  self.start = time.time()
 
 @property
 def elapsed(self):
  return time.time() - self.start
 
 def checkpoint(self, name=''):
  print '{timer} {checkpoint} took {elapsed} seconds'.format(
   timer=self.name,
   checkpoint=name,
   elapsed=self.elapsed,
  ).strip()
 
 def __enter__(self):
  return self
 
 def __exit__(self, type, value, traceback):
  self.checkpoint('finished')
  pass
 
def get_number():
 for x in xrange(5000000):
  yield x
 
def expensive_function():
 for x in get_number():
  i = x ^ x ^ x
 return 'some result!'
 
# prints something like:
# fancy thing done with something took 0.582462072372 seconds
# fancy thing done with something else took 1.75355315208 seconds
# fancy thing finished took 1.7535982132 seconds
with timewith('fancy thing') as timer:
 expensive_function()
 timer.checkpoint('done with something')
 expensive_function()
 expensive_function()
 timer.checkpoint('done with something else')
 
# or directly
timer = timewith('fancy thing')
expensive_function()
timer.checkpoint('done with something')

import cProfile
 
def do_cprofile(func):
 def profiled_func(*args, **kwargs):
  profile = cProfile.Profile()
  try:
   profile.enable()
   result = func(*args, **kwargs)
   profile.disable()
   return result
  finally:
   profile.print_stats()
 return profiled_func
 
def get_number():
 for x in xrange(5000000):
  yield x
 
@do_cprofile
def expensive_function():
 for x in get_number():
  i = x ^ x ^ x
 return 'some result!'
 
# perform profiling
result = expensive_function()

5000003 function calls in 1.626 seconds
 
 Ordered by: standard name
 
 ncalls tottime percall cumtime percall filename:lineno(function)
 5000001 0.571 0.000 0.571 0.000 timers.py:92(get_number)
  1 1.055 1.055 1.626 1.626 timers.py:96(expensive_function)
  1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

try:
 from line_profiler import LineProfiler
 
 def do_profile(follow=[]):
  def inner(func):
   def profiled_func(*args, **kwargs):
    try:
     profiler = LineProfiler()
     profiler.add_function(func)
     for f in follow:
      profiler.add_function(f)
     profiler.enable_by_count()
     return func(*args, **kwargs)
    finally:
     profiler.print_stats()
   return profiled_func
  return inner
 
except ImportError:
 def do_profile(follow=[]):
  "Helpful if you accidentally leave in production!"
  def inner(func):
   def nothing(*args, **kwargs):
    return func(*args, **kwargs)
   return nothing
  return inner
 
def get_number():
 for x in xrange(5000000):
  yield x
 
@do_profile(follow=[get_number])
def expensive_function():
 for x in get_number():
  i = x ^ x ^ x
 return 'some result!'
 
result = expensive_function()

Timer unit: 1e-06 s
 
File: test.py
Function: get_number at line 43
Total time: 4.44195 s
 
Line #  Hits   Time Per Hit % Time Line Contents
==============================================================
 43           def get_number():
 44 5000001  2223313  0.4  50.1  for x in xrange(5000000):
 45 5000000  2218638  0.4  49.9   yield x
 
File: test.py
Function: expensive_function at line 47
Total time: 16.828 s
 
Line #  Hits   Time Per Hit % Time Line Contents
==============================================================
 47           def expensive_function():
 48 5000001  14090530  2.8  83.7  for x in get_number():
 49 5000000  2737480  0.5  16.3   i = x ^ x ^ x
 50   1   0  0.0  0.0  return 'some result!'