Today I will show how to use the pstats python module.
It’s just some simple example, but can be useful for us.
1 | $ nano test.py |
Let’s add some source code to test this python module.
1 2 3 4 5 | import os, sys import math for i in range(100000): i=i+i print(i) |
The documentation tells us:
A profiler is a program that describes the run time performance of a program, providing a variety of statistics.
This documentation describes the profiler functionality provided in the modules cProfile, profile, and pstats.
Let’s make one.
1 | $ python3.2 -m cProfile -o rep.prof test.py |
And now will parse the profiler file>
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 | >>> import pstats >>> p=pstats.Stats('rep.prof') >>> p.sort_stats('cumulative').print_stats(10) Fri Aug 24 22:21:25 2012 rep.prof 100003 function calls in 9.997 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1 0.000 0.000 9.997 9.997 {built-in method exec} 1 1.116 1.116 9.997 9.997 test.py:1() 100000 8.881 0.000 8.881 0.000 {built-in method print} 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects} |
Now we try to see more about Django module.
You can make one python script with the name test-django.py.
Add the next source code:
1 | import django |
You can save the file and use the next command:
1 | $ python3.2 -m cProfile -o rep-django.prof test-django.py |
Go to and run the next python commands in the python3.2 shell:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 | >>> import pstats >>> p=pstats.Stats('rep-django.prof') >>> p.sort_stats('cumulative').print_stats(10) Fri Aug 24 22:28:10 2012 rep-django.prof 4 function calls in 0.066 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1 0.000 0.000 0.066 0.066 {built-in method exec} 1 0.066 0.066 0.066 0.066 test-django.py:1() 1 0.000 0.000 0.000 0.000 /usr/local/lib/python3.2/site-packages/django/__init__.py:1() 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects} |
We see the time to import the Django module is about 0.066 seconds.
All 4 functions it’s called during this period of time.
We sort the profile by cumulative time, and then only prints the ten most significant lines.
The python module can show us what functions were looping a lot, and taking a lot of time.
1 2 3 | >>> import pstats >>> p=pstats.Stats('rep-django.prof') >>> p.sort_stats('time').print_stats(10) |
Try with one more complex example with functions. In this case the output it’s the same.
1 2 3 4 5 6 7 8 9 10 11 | Valid Arg Meaning 'calls' call count 'cumulative' cumulative time 'file' file name 'module' file name 'pcalls' primitive call count 'line' line number 'name' function name 'nfl' name/file/line 'stdname' standard name 'time' internal time |
You can read more about pstats and deterministic profiling of Python programs with all limitation here.