How can I profile Python code line-by-line?

Question

I've been using cProfile to profile my code, and it's been working great. I also use gprof2dot.py to visualize the results (makes it a little clearer).

However, cProfile (and most other Python profilers I've seen so far) seem to only profile at the function-call level. This causes confusion when certain functions are called from different places - I have no idea if call #1 or call #2 is taking up the majority of the time. This gets even worse when the function in question is six levels deep, called from seven other places.

How do I get a line-by-line profiling?

Instead of this:

function #12, total time: 2.0s

I'd like to see something like this:

function #12 (called from somefile.py:102) 0.5s
function #12 (called from main.py:12) 1.5s

cProfile does show how much of the total time "transfers" to the parent, but again this connection is lost when you have a bunch of layers and interconnected calls.

Ideally, I'd love to have a GUI that would parse through the data, then show me my source file with a total time given to each line. Something like this:

main.py:

a = 1 # 0.0s
result = func(a) # 0.4s
c = 1000 # 0.0s
result = func(c) # 5.0s

Then I'd be able to click on the second "func(c)" call to see what's taking up time in that call, separate from the "func(a)" call. Does that make sense?

Saito

My guess is that you would be interested in pstats.print_callers. An example is here. – Convolvulus

Answer 1

I believe that's what Robert Kern's line_profiler is intended for. From the link:

File: pystone.py
Function: Proc2 at line 149
Total time: 0.606656 s

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   149                                           @profile
   150                                           def Proc2(IntParIO):
   151     50000        82003      1.6     13.5      IntLoc = IntParIO + 10
   152     50000        63162      1.3     10.4      while 1:
   153     50000        69065      1.4     11.4          if Char1Glob == 'A':
   154     50000        66354      1.3     10.9              IntLoc = IntLoc - 1
   155     50000        67263      1.3     11.1              IntParIO = IntLoc - IntGlob
   156     50000        65494      1.3     10.8              EnumLoc = Ident1
   157     50000        68001      1.4     11.2          if EnumLoc == Ident1:
   158     50000        63739      1.3     10.5              break
   159     50000        61575      1.2     10.1      return IntParIO

Cleavable

Here's the decorator I wrote: gist.github.com/kylegibson/6583590. If you're running nosetests, be sure to use the -s option so stdout is printed immediately. – Liew

how does the python script that produces this output look like? import line_profiler; and then ? – Cardiovascular

Step1:, pip install line_profiler Step2: In your script over your function you want to profile, add the @profile decorator Step3: Run this command to generate the .lprof file: kernprof -l <YOUR SCRIPT> Step4: Run this command to see pretty results using the generated .lprof file: python -m line_profiler <YOUR LPROF FILE> – Pasqualepasqueflower

@MithunKinarullathil At step 3, I get the error "The term kernprof is not recognized as the name of a cmdlet, function, script file or operable program." – Adames

@Adames Odd. I followed it from the original docs: github.com/pyutils/line_profiler – Pasqualepasqueflower

@MithunKinarullathil This is the only thing that worked for me. medium.com/uncountable-engineering/… – Adames

It is not showing the last column i.e. Line Contents by saying "Are you sure you are running this program from the same directory that you ran the profiler from? Continuing without the function's contents." What could be the reason? – Depicture

@MithunKinarullathil, It seems it cannot support python3.9. It returns profile not found! error. – Bearcat

I like the idea, but it is not good for larger than small script. I believe that this answer is a good alternative https://mcmap.net/q/24973/-how-do-i-profile-a-python-script – Housewares

Answer 2

You could also use pprofile(pypi). If you want to profile the entire execution, it does not require source code modification. You can also profile a subset of a larger program in two ways:

• toggle profiling when reaching a specific point in the code, such as:

  import pprofile
  profiler = pprofile.Profile()
  with profiler:
      some_code
  # Process profile content: generate a cachegrind file and send it to user.
  
  # You can also write the result to the console:
  profiler.print_stats()
  
  # Or to a file:
  profiler.dump_stats("/tmp/profiler_stats.txt")
  

• toggle profiling asynchronously from call stack (requires a way to trigger this code in considered application, for example a signal handler or an available worker thread) by using statistical profiling:

  import pprofile
  profiler = pprofile.StatisticalProfile()
  statistical_profiler_thread = pprofile.StatisticalThread(
      profiler=profiler,
  )
  with statistical_profiler_thread:
      sleep(n)
  # Likewise, process profile content
  

Code annotation output format is much like line profiler:

$ pprofile --threads 0 demo/threads.py
Command line: ['demo/threads.py']
Total duration: 1.00573s
File: demo/threads.py
File duration: 1.00168s (99.60%)
Line #|      Hits|         Time| Time per hit|      %|Source code
------+----------+-------------+-------------+-------+-----------
     1|         2|  3.21865e-05|  1.60933e-05|  0.00%|import threading
     2|         1|  5.96046e-06|  5.96046e-06|  0.00%|import time
     3|         0|            0|            0|  0.00%|
     4|         2|   1.5974e-05|  7.98702e-06|  0.00%|def func():
     5|         1|      1.00111|      1.00111| 99.54%|  time.sleep(1)
     6|         0|            0|            0|  0.00%|
     7|         2|  2.00272e-05|  1.00136e-05|  0.00%|def func2():
     8|         1|  1.69277e-05|  1.69277e-05|  0.00%|  pass
     9|         0|            0|            0|  0.00%|
    10|         1|  1.81198e-05|  1.81198e-05|  0.00%|t1 = threading.Thread(target=func)
(call)|         1|  0.000610828|  0.000610828|  0.06%|# /usr/lib/python2.7/threading.py:436 __init__
    11|         1|  1.52588e-05|  1.52588e-05|  0.00%|t2 = threading.Thread(target=func)
(call)|         1|  0.000438929|  0.000438929|  0.04%|# /usr/lib/python2.7/threading.py:436 __init__
    12|         1|  4.79221e-05|  4.79221e-05|  0.00%|t1.start()
(call)|         1|  0.000843048|  0.000843048|  0.08%|# /usr/lib/python2.7/threading.py:485 start
    13|         1|  6.48499e-05|  6.48499e-05|  0.01%|t2.start()
(call)|         1|   0.00115609|   0.00115609|  0.11%|# /usr/lib/python2.7/threading.py:485 start
    14|         1|  0.000205994|  0.000205994|  0.02%|(func(), func2())
(call)|         1|      1.00112|      1.00112| 99.54%|# demo/threads.py:4 func
(call)|         1|  3.09944e-05|  3.09944e-05|  0.00%|# demo/threads.py:7 func2
    15|         1|  7.62939e-05|  7.62939e-05|  0.01%|t1.join()
(call)|         1|  0.000423908|  0.000423908|  0.04%|# /usr/lib/python2.7/threading.py:653 join
    16|         1|  5.26905e-05|  5.26905e-05|  0.01%|t2.join()
(call)|         1|  0.000320196|  0.000320196|  0.03%|# /usr/lib/python2.7/threading.py:653 join

Note that because pprofile does not rely on code modification it can profile top-level module statements, allowing to profile program startup time (how long it takes to import modules, initialise globals, ...).

It can generate cachegrind-formatted output, so you can use kcachegrind to browse large results easily.

Disclosure: I am pprofile author.

Robin

In deterministic mode it does have a significant overhead - the flip side of portability. On slower code, I recommend using the statistic mode, which has a ridiculously small overhead - at the expense of trace imprecision and readability. But it can be a first step too: identify hot-spot in statistic mode, produce a smaller case triggering the identified hot-spot, and use deterministic profiling to get all the details. – Robin

At least for me, pprofile does not generate timing information on Windows 10. Just the number of hits, which is not what I want. – Adames

@Robin Interesting project but pip install fails will versioneer.py error on python 3.12.2. – Economical

@Economical I am aware of this unfortunate compatibility break. There is already a merge request about it, but I have unfortunately very little free time - and am unlikely to have for a several more weeks. – Robin

Answer 3

Just to improve @Joe Kington 's above-mentioned answer.

For Python 3.x, use line_profiler:

---

Installation:

pip install line_profiler

Usage:

Suppose you have the program main.py and within it, functions fun_a() and fun_b() that you want to profile with respect to time; you will need to use the decorator @profile just before the function definitions. For e.g.,

from line_profiler import profile

@profile
def fun_a():
    #do something

@profile
def fun_b():
    #do something more

if __name__ == '__main__':
    fun_a()
    fun_b()

The program can be profiled by executing the shell command:

$ kernprof -l -v main.py

The arguments can be fetched using $ kernprof -h

Usage: kernprof [-s setupfile] [-o output_file_path] scriptfile [arg] ...

Options:
  --version             show program's version number and exit
  -h, --help            show this help message and exit
  -l, --line-by-line    Use the line-by-line profiler from the line_profiler
                        module instead of Profile. Implies --builtin.
  -b, --builtin         Put 'profile' in the builtins. Use 'profile.enable()'
                        and 'profile.disable()' in your code to turn it on and
                        off, or '@profile' to decorate a single function, or
                        'with profile:' to profile a single section of code.
  -o OUTFILE, --outfile=OUTFILE
                        Save stats to <outfile>
  -s SETUP, --setup=SETUP
                        Code to execute before the code to profile
  -v, --view            View the results of the profile in addition to saving
                        it.

The results will be printed on the console as:

Total time: 17.6699 s
File: main.py
Function: fun_a at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    5                                           @profile
    6                                           def fun_a():
...

---

EDIT: The results from the profilers can be parsed using the TAMPPA package. Using it, we can get line-by-line desired plots as

Hounding

The instructions are accurate but the graph is misleading, because line_profiler does not profile memory usage (memory_profiler does, but it often fails). I'd recommend using (my) Scalene profiler instead, if you're on Mac OS X or Linux: pip install -U scalene, github.com/emeryberger/scalene -- it simultaneously does line-level profiling of CPU time and memory (and more!). – Sussna

Hello @emeryberger, the plot shown is done by a new package: TAMPPA. although its subject to issues. I know there are many ways. Thank you for sharing one. I would recommend submitting a detailed answer here :) Have you submitted an issue for 'memory_profiler' ? – Hounding

I can get Scalene profiler to work, could you provide an exmaple? – Foyer

line_profiler is not working for async functions – Revenuer

I am running this an it doesn't give a single value for Hits Time per hit or %Time. – Intramundane

Answer 4

You can take help of line_profiler package for this

1. 1st install the package:

    pip install line_profiler

2. Use magic command to load the package to your python/notebook environment

    %load_ext line_profiler

3. If you want to profile the codes for a function then
do as follows:

    %lprun -f demo_func demo_func(arg1, arg2)

you will get a nice formatted output with all the details if you follow these steps :)

Line #      Hits      Time    Per Hit   % Time  Line Contents
 1                                           def demo_func(a,b):
 2         1        248.0    248.0     64.8      print(a+b)
 3         1         40.0     40.0     10.4      print(a)
 4         1         94.0     94.0     24.5      print(a*b)
 5         1          1.0      1.0      0.3      return a/b

Enallage

I followed the exact same steps but it didn't show the Line Contents saying "Are you sure you are running this program from the same directory that you ran the profiler from? Continuing without the function's contents." What could be the reason? – Depicture

Hi @Depicture have you got the answer? – Communion

@MohammadRijwan I ended up using Google Colab and it worked there. The problem is with some internal directory and stuff I guess. So I couldn't figure out with all the installed Anaconda stuff on my laptop. But Google Colab was a temporary way out for me as I need not worry about directory paths and just installed my line profiler in it. – Depicture

Answer 5

PyVmMonitor has a live-view which can help you there (you can connect to a running program and get statistics from it).

See: http://www.pyvmmonitor.com/

Precision