Python profiling: who called the function?

Question

I profile Python using cProfile . I found a function that takes a lot of CPU time. How do you know which function calls this heavy function the most?

EDIT:

I will settle for a workaround: can I write a Python string inside this heavy function that will print the name of the called function?

Answer 1

This may not answer your question directly, but it will definitely help. If you use the profiler with the --sort cumulative option, it will sort the functions by cumulative time. This is useful for detecting not only heavy functions, but also functions that call them.

 python -m cProfile --sort cumulative myScript.py 

There is a workaround for getting the caller function:

 import inspect print inspect.getframeinfo(inspect.currentframe().f_back)[2] 

You can add as many f_back as you want if you want the caller, etc. If you want to calculate frequent calls, you can do this:

 record = {} caller = inspect.getframeinfo(inspect.currentframe().f_back)[2] record[caller] = record.get(caller, 0) + 1 

Then print them in order of frequency:

 print sorted(record.items(), key=lambda a: a[1]) 

Answer 2

I almost always look at the output of the cProfile module using Gprof2dot , it basically converts the output to a graph chart (a .dot file), for example:

It is very easy to determine which function is the slowest, and which function [s] call it.

Using:

 python -m cProfile -o output.pstats path/to/your/script arg1 arg2 gprof2dot.py -f pstats output.pstats | dot -Tpng -o output.png 

Answer 3

inspect.stack () will give you the current caller stack.

Answer 4

You might want to take a look at pycallgraph .

Answer 5

I myself have not used cProfile, but most profilers provide you with a call hierarchy.
Googling I found this slides about cProfile. Maybe this helps. Page 6 looks like this: cProfile provides a hierarchy.

Answer 6

Sorry, I am not familiar with Python, but there the general method works if you can manually interrupt execution at any time.

Just do it and display the call stack. He will tell you, with a high probability, what you want to know. If you want to be more confident, just do it a few times.

This works because the guilty caller must be in the call stack for a fraction of the time wasted, which during this time gives it interruptions, whether it extends to many short calls or to several long ones.

NOTE. This process is more like a diagnosis than a measurement. Suppose a bad call spends 90% of the time. Then every time you stop it, the probability of 90% is that the bad call operator is right on the call stack so you can see and you will see that it is bad. However, if you want to accurately measure the loss, this is another problem. To do this, you will need a lot more samples to find out which% of them contain this call. Or, alternatively, just correct the culprit's call, note the acceleration, and that will tell you exactly what happened.

Answer 7

Pycscope does this. I just found it today, so I can’t talk about how good it is, but the few examples I tried were pretty good (though not perfect).

https://pypi.python.org/pypi/pycscope/

You would use this to create the cscope file and then the cscope plugin from the VIM editor. I tried using it with vanilla cscope, it seems that a simple cscope is confused.

Answer 8

This can be done using the cProfile profiler in the standard library.
In pstats.Stats (profiling result) there is a print_callees method (or, alternatively, print_callers ).

Code example:

 import cProfile, pstats pr = cProfile.Profile() pr.enable() # ... do something ... pr.disable() ps = pstats.Stats(pr).strip_dirs().sort_stats('cumulative') ps.print_callees() 

The result will look something like this:

 Function called... ncalls tottime cumtime ElementTree.py:1517(_start_list) -> 24093 0.048 0.124 ElementTree.py:1399(start) 46429 0.015 0.041 ElementTree.py:1490(_fixtext) 70522 0.015 0.015 ElementTree.py:1497(_fixname) ElementTree.py:1527(_data) -> 47827 0.017 0.026 ElementTree.py:1388(data) 47827 0.018 0.053 ElementTree.py:1490(_fixtext) 

On the left you have the caller, on the right you have the caller.
(for example, _fixtext is called from _data 47827 times and from _start_list 46429 times)

See also:

• docs.python.org/..# print_callees - show call hierarchy. Group by caller. (used above)
• docs.python.org/..# print_callers - show call hierarchy. Call group.

A couple of notes:

• To do this, you need to edit the code (insert these profile statements).
  (i.e. it is impossible to use from the command line, for example python -m cProfile myscript.py . Although you can write a separate script for this)
• A bit unrelated, but strip_dirs() should go before sort_stats() (otherwise sorting doesn't work)