Debugging in Python (using PyCharm) – Part 2

This post is part 2 of a multi-part series of posts intended to provide discussion of some basic debugging tools that I have found to be helpful in developing a pure Python simulation model using a Python Integrated Development Environment (IDE) called PyCharm. You can see part 1 of the debugging discussion here, and other discussion of useful PyCharm functionality here.

In this post I will focus on PyCharm’s “Profile” features, which are very useful for debugging by allowing you to see what parts of your program (e.g., modules, classes, methods) are/are not being called, how frequently, and how much time is being spent in them. This has been especially useful to me when my program runs without error messages, but isn’t exactly performing as I expect it to (e.g., the program is taking a very long time to produce a result).

Step 1. Open your python files in PyCharm. In this case, my file is called SedSim_v2.py. I suggest you do this with a file that already executes without errors.

Step 2. In menu at the top of the screen, click Run–>Profile SedSim_v2 (or your file name), as is shown in the image below.

Step 3. This will open a new window in the “Run” section (PyCharm will not execute the file in a console).    Wait for the profiling run to be completed, then within the Run window click on the upper (“capture snapshot”) icon. This will open a new file that summarizes our profile run with a “Statistics” tab and a “Call Graph” tab.

The statistics tab contains an overwhelming amount of information. A screenshot is shown below for just some of the Statistics tab.

The call graph presents a visual summary of function/method calls. An example screen shot of this is shown below. Note that in this case, the diagram we are seeing has a “hierarchical group” layout. Other groups include circular, organic, orthogonal, and directed orthogonal. Right-clicking in the call graph space will reveal various options, including diagram layout.

In the photo below I have zoomed in on a particular area of the figure. We can learn a lot from the small amount of information presented here, as I will describe below.

From the information presented in this figure, we can gather that SedSim_v2.py is responsible for 100% of execution time (this, of course, makes sense, as this was the top-level file I ran). I am still learning about the Profiling features in PyCharm, so my very loose interpretation of the remaining information is as follows. The “Total” run took 264,381 milliseconds (or about 264 seconds). Only 1.7% (“Own” time) of this run-time was taken up by actions within SedSim_v2.py that did not involve calling the other branched methods/functions listed in this diagram.

One can then follow the other branches in the Call diagram to see how much of the time spent calling methods outside of SedSim_v2 was spent in those methods. For example, the “Master_Method_Caller” method (which is a method of the Reservoir class in my model), shown in the upper left of the figure, is responsible for 21.3% of the run time. This method is called 73,000 times.

Step 4. Make necessary adjustments to your code based on what you have discovered. If, for example, you are experiencing a very long program run time, the approach I outline above may allow you to pinpoint what methods are responsible. This diagram helped me figure out that the Reservoir_Volume_Reduction method (another method of the Reservoir class) is taking up far too much time for what it does. Something clearly needed to be fixed!