Pyinstrument is a statistical profiler. That means that it measures on an interval to record what function is being called. By repeating this many times on a short interval you should get a pretty good idea of where the most time is being spent ... but it won't be a perfect measurement.
Let's consider our example once more.
import time
from pyinstrument import Profiler
profiler = Profiler()
profiler.start()
sleep_time = 0.1
def start():
time.sleep(sleep_time)
do_sleep1()
do_sleep2()
def do_sleep1():
time.sleep(sleep_time)
def do_sleep2():
do_sleep1()
time.sleep(sleep_time)
start()
profiler.stop()
profiler.print()
This example runs just fine, but let's now change the sleep_time
parameter to make it sleep for a very short period of time.
import time
from pyinstrument import Profiler
profiler = Profiler()
profiler.start()
sleep_time = 0.00001
def start():
time.sleep(sleep_time)
do_sleep1()
do_sleep2()
def do_sleep1():
time.sleep(sleep_time)
def do_sleep2():
do_sleep1()
time.sleep(sleep_time)
start()
profiler.stop()
profiler.print()
When you run this, the output will change severly!
Fix
To fix this, you can specify at what interval
the profiler should measure.
import time
from pyinstrument import Profiler
# Note the interval value is 1/10th the sleeptime!
profiler = Profiler(interval=0.000001)
profiler.start()
sleep_time = 0.00001
def start():
time.sleep(sleep_time)
do_sleep1()
do_sleep2()
def do_sleep1():
time.sleep(sleep_time)
def do_sleep2():
do_sleep1()
time.sleep(sleep_time)
start()
profiler.stop()
profiler.print()
When we decrease the interval
then we will collect many more samples.
While this may be a good thing in some situations, we should be mindful
that we may also increase the measurement overhead.
One can also wonder if spending effort to measure the shortest calls in our stack is going to help us achieve the biggest speedup.