Log time of execution for each line in Python script?

Question

I have a Python script which executes fairly straightforward from the first to the last line with plain logic. The script performance is very different on a couple of machines with different environments, so I am trying to find out which line of the code gives me a hard time.

I have seen cProfiler and some questions (timeit) on recording time of execution for the whole function. I am, however, interested in finding out the time Python spent on executing each line of the code in my script.

The source code:

import math
result = pow(2,5)
newlist = []
newlist.append(result)
print newlist

What I want to get (number of row - time it took to execute in seconds):

1 - 0.04
2 - 0.01
3 - 0.06
4 - 0.08
5 - 0.1

EDIT: I have tried to use hotshot, a standard library available, however I am getting an error message.

The source code I run:

import hotshot
import hotshot.stats

logfile = r"C:\testlog.prof"
prof_obj = hotshot.Profile(logfile,lineevents=True,linetimings=False)
prof_obj.start()
a = 1000
b = 2000
c = a + b
print c
prof_obj.stop()
prof_obj.close()

stats_obj = hotshot.stats.load(logfile) #getting error on this line *
stats_obj.strip_dirs()
stats_obj.sort_stats('time', 'calls')
stats_obj.print_stats(20)

---

*     for event in log:
  File "C:\Python27\ArcGIS10.2\Lib\hotshot\log.py", line 115, in next
    filename, firstlineno, funcname = self._stack[-1]
IndexError: list index out of range

---

EDIT: I have found another example on using a hotshot from the Python Essential Reference book.

import hotshot
import hotshot.stats

def function_to_call():
    print "AA"
    print "BB"

logfile = r"C:\testlog.prof"
prof_obj = hotshot.Profile(logfile,lineevents=True,linetimings=True)
prof_obj.runcall(function_to_call)
prof_obj.close()

stats_obj = hotshot.stats.load(logfile)
stats_obj.sort_stats('time', 'calls')
stats_obj.print_stats()

However, this does not give me any information on execution per line of code, only per function call:

5 function calls in 0.012 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        4    0.012    0.003    0.012    0.003 <string>:6(write)
        1    0.000    0.000    0.012    0.012 c:\gis\temp\simple_hotshot.py:11(function_to_call)
        0    0.000             0.000          profile:0(profiler)

Answer 1

There is a line profiler module that might do what you are looking for. It also has nice decorators that you can put over functions you want to profile on a line by line level. You can read the docs here.

Also take a look at hotshot. It looks like you can set the linetimings parameter to get what you are looking for. I'm not sure hotshot will be supported in future versions, though.