Python execution time measurement memo

Sudden conclusion

After all, perf_counter () is safe. It's nothing new, so it may not be worth reading.

Assumed reader

Perhaps you have measured the execution speed with Python, but have not considered it in depth.

The reason for investigating

I inadvertently used time.time () to measure the execution time. It was enough because I didn't have to worry about the accuracy, but when I changed the execution order of the functions that should be independent, the execution time changed significantly. The cause of this is unknown, but I decided to re-examine the time measurement as a result of this. (I gave up trying to find out why the function itself wasn't practical. Maybe it's due to garbage collection.)

environment

Windows 10 Pro 64bit Python 3.8.3

time module

Consider only the time module, which is the standard library

A function to measure the execution time between two points

The functions that can be used in the time module to measure the execution time are as follows. It is monotonic = True when checked withtime.get_clock_info (). In other words, it is guaranteed that it will not be subtracted due to external factors.

I think what you mean by "high (low)" resolution is that the specifications obtained by time.get_clock_info () have high resolution, but when you actually move it, it is low. Since it is a resolution, it is written like this. It may be influenced by your development environment.

A little explanation is as follows.

perf_counter () is used to measure how much real time has passed since the program ran. Since the elapsed time during sleep is also included, there is a possibility that the intended time will not come out. However, it seems to be the most stable. It seems safe to use this, such as being set to the default timer with timeit etc.

process_time () or thread_time () is used to find out how long a program has run in a process (thread). I think many people, including myself, want to measure this time. However, the actual resolution seems to be lower than the specifications. I really want to use this, but I hesitate to use it. Also, in the case of Windows, I actually use C'GetProcessTimes () `, but to explain it,

text

Note that this value can exceed the amount of real time elapsed (between lpCreationTime and lpExitTime) if the process executes across multiple CPU cores.

is what it reads. It doesn't seem to be very reliable.

monotonic () is used to find out the uptime of the system. In other words, this PC is used to find out how many days have passed since it was up and running. I don't think I use it much.

time () gets the time and is not used to measure the execution time.

The influence of garbage collection

Garbage collection seems to affect the speed of program execution. The timeit () described below stops garbage collection as the default behavior to avoid its effects. Similarly, if you want to exclude the effects of garbage collection from the measurement, you need to stop garbage collection. The method is to write as follows.

python

import gc

gc.disable() #Stop
#Measurement processing
gc.enable() #Resume

How to use

It's simple to use the time module, but you just have to take the time before and after you want to measure and subtract it as shown below.

python

import time
import timeit

def stopwatchPrint(func):

  @functools.wraps(func)
  def wrapper(*args, **kwargs):
    start = time.perf_counter()
    result = func(*args, **kwargs)
    end = time.perf_counter()
    print(f"{func.__name__}: {end - start:.3f} s.")
    return result

  return wrapper

@stopwatchPrint
def func1():
  #Processing something
  return

def func2():
  start = time.perf_counter()
  #Processing something
  end = time.perf_counter()
  print(f"Execution time: {end - start}"
  return

timeit module

Basically, there is no problem if you use time as above. However, the standard library also provides timeit to measure execution speed. Most of them just call time.perf_counter (), but I'll explain it briefly. I will not touch on how to use it from the command line. I've listed two functions, but I think you should only use timeit.repeat ().

python

import time
import timeit

timeit.timeit(stmt=func1, setup=func2, timer=time.time.perf_counter, number=1000000)
timeit.repeat(stmt=func1, setup=func2, timer=time.time.perf_counter, number=1000000, repeat=5)

• timeit(): --stmt: Pass the function whose execution time you want to measure, or the character string that can be evaluated as an expression. If it is a string, it is evaluated by ʻeval (). --setup: Pass a function that performs preprocessing or a character string that can be evaluated as an expression. The execution time of this is not included in the measured value. --timer: Pass the timer function used for measurement. The default is time.time.perf_counter. You may pass time.process_time etc. --number: Number of executions. The default is 1000000. --globals: Specify the namespace. The default is None. If you want to change it, specify globals = globals ()orglobals = locals (). -- repeat () : A repetitive version of time it. In addition to the timeit argument, it has the following: -- repeat: Number of repetitions. If number = 100 and repeat = 3`, the execution of 100 times is repeated 3 times.

How to use

Actually, it is used as follows. result is a list of 3 lengths elapsed when one element executeslongLongLongCat ()100 times.

python

def longLongLongCat(): #Function you want to measure time
   pass

result = timeit.repeat(longLongLongCat, ,number=100, repeat=3)
print(result)

Pass arguments to the timeit execution function

The timeit execution function is not designed to pass arguments. It may be a premise to run it as a string, but there is resistance to using it as standard. Therefore, I tried various things. There may be other good ways.

python

import math
import timeit
import functools

def func():
  print("func")

def funcN(n):
  print(f"funcN: {n}")

class Test():
  def __init__(self, n=100, r=3):
    self.number = n
    self.repeat = r

  def glo(self):
    #print(globals())
    #print(locals())
    result = timeit.repeat("print(a, b)", number=self.number, repeat=self.repeat, globals=globals())
    print(result)

  def loc(self):
    a = 33
    b = 4
    #print(globals())
    #print(locals())
    result = timeit.repeat("print(a, b)", number=self.number, repeat=self.repeat, globals=locals())
    print(result)

  def mix(self):
    a = 33
    b = 44
    #print(globals())
    #print(locals())
    result = timeit.repeat("print(a , b)", number=self.number, repeat=self.repeat, globals={"a": 30, "b": 50})
    print(result)
    result = timeit.repeat("print(a , b)", number=self.number, repeat=self.repeat, globals={
        "a": globals()["a"],
        "b": locals()["b"]
    })
    print(result)

a = 2525
b = 2828
t = Test(1, 1)
t.glo()
t.loc()
t.mix()

timeit.repeat(func, number=1, repeat=1)
timeit.repeat(lambda: print(a, b), number=1, repeat=1)
n = 1129
timeit.repeat("funcN(n)", number=1, repeat=1, globals=globals())
timeit.repeat("funcN(n)", number=1, repeat=1, globals={"funcN": funcN, "n": 714})
g = globals()
g.update({"n": 1374})
timeit.repeat("funcN(n)", number=1, repeat=1, globals=g)
timeit.repeat(functools.partial(funcN, 184), number=1, repeat=1)

Output result

shell

2525 2828
[0.001136100000000001]
33 4
[0.026095200000000013]
30 50
[0.01867479999999999]
2525 44
[0.001263299999999995]
func
2525 2828
funcN: 1129
funcN: 714
funcN: 1374
funcN: 184

Clock information

Information in your own environment.

shell

>>> time.get_clock_info("monotonic")
namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, resolution=0.015625)

>>> time.get_clock_info("perf_counter")
namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=1e-07)

>>> time.get_clock_info("process_time")
namespace(adjustable=False, implementation='GetProcessTimes()', monotonic=True, resolution=1e-07)

>>> time.get_clock_info("thread_time")
namespace(adjustable=False, implementation='GetThreadTimes()', monotonic=True, resolution=1e-07)

>>> time.get_clock_info("time")
namespace(adjustable=True, implementation='GetSystemTimeAsFileTime()', monotonic=False, resolution=0.015625)