I am working on driving down the execution time on a program I've refactored, and I'm having trouble understanding the profiler output in PyCharm and how it relates to the output I would get if I run cProfile directly. (My output is shown below, with two lines of interest highlighted that I want to be sure I understand correctly before attempting to make fixes.) In particular, what do the Time and Own Time columns represent? I am guessing Own Time is the time consumed by the function, minus the time of any other calls made within that function, and time is the total time spent in each function (i.e. they just renamed tottime and cumtime, respectively), but I can't find anything that documents that clearly.
Also, what can I do to find more information about a particularly costly function using either PyCharm's profiler or vanilla cProfile? For example, _strptime seems to be costing me a lot of time, but I know it is being used in four different functions in my code. I'd like to see a breakdown of how those 2 million calls are spread across my various functions. I'm guessing there's a disproportionate number in the calc_near_geo_size_and_latency function, but I'd like more proof of that before I go rewriting code. (I realize that I could just profile the functions individually and compare, but I'm hoping for something more concise.)
I'm using Python 3.6 and PyCharm Professional 2018.3.
Python Profilers, like cProfile helps to find which part of the program or code takes more time to run. This article will walk you through the process of using cProfile module for extracting profiling data, using the pstats module to report it and snakeviz for visualization.
In Python's standard library, we have the timeit module that allows us to do some simple profiling. The output of timeit is to find the best performance among multiple runs (default to be 5).
The yappi stands for yet another python profiler. The yappi is a Python profiler that is designed in C and supports the profiling of multi-threaded, asyncio, and gevent code. As it's designed in C, it runs quite fast compared to other profilers which are designed in pure python.
In particular, what do the Time and Own Time columns represent? I am guessing Own Time is the time consumed by the function, minus the time of any other calls made within that function, and time is the total time spent in each function (i.e. they just renamed tottime and cumtime, respectively), but I can't find anything that documents that clearly.
You can see definitions of own time and time here: https://www.jetbrains.com/help/profiler/Reference__Dialog_Boxes__Properties.html
Own time - Own execution time of the chosen function. The percentage of own time spent in this call related to overall time spent in this call in the parentheses.
Time - Execution time of the chosen function plus all time taken by functions called by this function. The percentage of time spent in this call related to time spent in all calls in the parentheses.
This is also confirmed by a small test:
Also, what can I do to find more information about a particularly costly function using either PyCharm's profiler or vanilla cProfile?
By default pycharm does use cProfile as a profiler. Perhaps you're asking about using cProfile on the command line? There are plenty of examples of doing so here: https://docs.python.org/3.6/library/profile.html
For example, _strptime seems to be costing me a lot of time, but I know it is being used in four different functions in my code. I'd like to see a breakdown of how those 2 million calls are spread across my various functions.
Note that the act of measuring something will have an impact on the measurement retrieved. For a function or method that is called many times, especially 2 million, the profiler itself will have a significant impact on the measured value.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With