Don't use time() to measure the performance of a function in python
3 min read

Don't use time() to measure the performance of a function in python

Intro

If you're reading this article, you're probably used to using the time.time() function instead of time.monotonic() or time.perf_counter() to measure the performance of a task in python. If you're already using one of the two last functions, then great! But if you're not, then keep reading: this article is for you.
Quick note: I won't talk about the time.clock() function as it has been deprecated as of python 3.3.

For the rest of the article, suppose the time library has been imported:
import time

Simple example

For the purpose of keeping it simple, let's say you're tasked with counting the number of occurrences of a value in a 2-dimensional array. But you're not satisfied by just doing that, you also want to measure the time taken to do that. Let's implement that:

def count_value(array, value):
    c = 0
    t_start = time.time()
    for i in array:
        for j in i:
            if j == value:
                c += 1
    t_end = time.time()
    
    return c, t_end-t_start

Let's now use this function on some arrays:

a_1 = [[1,2],[3,3]]
a_2 = [[33]]
a_3 = [[1 for _ in range(10)] for _ in range(100)]
a_4 = [[i*j for j in range(1000)] for i in range(1000)]

print(count_value(a_1, 3))
print(count_value(a_2, 10))
print(count_value(a_3, 1))
print(count_value(a_4, 44))

Output:

(2, 0.0)
(0, 0.0)
(1000, 0.0)
(6, 0.03124070167541504)

Now first of all, before going over the actual issues, I would recommend using decorators to measure the performance of a function, but that's outside the scope of this article, I will go over it in another article.
Alright then, let's talk about the issues. On 3 out of the 4 arrays, we see that the time measured for the search is 0, so that means that the search was instant, right? Not at all, the measures are just wrong. The problem here is that the time.time() function uses the system clock, which has a few issues:

  • The tick rate of this clock is not small enough, if a task is performed between two "ticks" of the clock, we won't be able to measure the actual length of the task as it will be shorter than the resolution of the clock
  • The system clock can be modified by external factors, such as updates, clock calibrations, or leap seconds.

To take care of those problems, the time library has 2 functions: monotonic() and perf_counter (or 4 functions if we also take the nanoseconds alternative into account: monotonic_ns() and perf_counter_ns()) If you want to read more about those functions, read my last article.

The important thing to know is that those functions take care of those two problems: The Monotonic() function is based on a linear clock, which can not be modified externally, and the perf_counter() function has a way higher tick rate.

Showing the tick rate difference

Let's write a function to show the different tick rates of all three functions: time(), monotonic(), and perf_counter. I'll use perf_counter_ns() to measure the elapsed time.

def tick_rate(f):
    tick = 0
    t_start = time.perf_counter_ns()
    last_t = f()
    for i in range(10_000_000):
        t = f()
        if t != last_t:
            tick += 1
        last_t = t
    t_end = time.perf_counter_ns()
    
    return tick, (t_end-t_start)/(10**9) #divided by 10^9 to convert ns to s

print(tick_rate(time.time))
print(tick_rate(time.monotonic))
print(tick_rate(time.perf_counter))

Output:

(59, 0.9173757)
(50, 0.7825792)
(10000000, 1.615493)

Now we can see the huge difference in the capabilities of measuring small tasks using the perf_counter() functions, as a matter of fact, we weren't able to measure the maximum tick rate of the clock used by perf_counter() but it's still huge. The monotonic() function can be used for longer tasks.

Same example, different function

Let's use the same example as before but use perf_counter() instead of time():

def count_value(array, value):
    c = 0
    t_start = time.perf_counter()
    for i in array:
        for j in i:
            if j == value:
                c += 1
    t_end = time.perf_counter()
    
    return c, t_end-t_start
    
a_1 = [[1,2],[3,3]]
a_2 = [[33]]
a_3 = [[1 for _ in range(10)] for _ in range(100)]
a_4 = [[i*j for j in range(1000)] for i in range(1000)]

print(count_value(a_1, 3))
print(count_value(a_2, 10))
print(count_value(a_3, 1))
print(count_value(a_4, 44))

Output:

(2, 4.7999997150327545e-06)
(0, 1.4000002011016477e-06)
(1000, 7.83999998930085e-05)
(6, 0.036078900000120484)

As we can see, we were actually able to measure the time taken just by using the right function!

In my next article, I'll go over decorators and why they're good to use when measuring the performance of a function. If you reached the end of the article, consider subscribing to my newsletter, it's free and keeps me motivated!