Timeit Versus Timing Decorator

timeit versus timing decorator

Use timeit. Running the test more than once gives me much better results.

func_list=[locals()[key] for key in locals().keys() 
           if callable(locals()[key]) and key.startswith('time')]

alist=range(1000000)
times=[]
for f in func_list:
    n = 10
    times.append( min(  t for t,_,_ in (f(alist,31) for i in range(n)))) 

for (time,func_name) in zip(times, func_list):
    print '%s took %0.3fms.' % (func_name, time*1000.)

->

<function wrapper at 0x01FCB5F0> took 39.000ms.
<function wrapper at 0x01FCB670> took 41.000ms.

Decorator for timeit.timeit method?

from functools import wraps
from time import time
def measure(func):
    @wraps(func)
    def _time_it(*args, **kwargs):
        start = int(round(time() * 1000))
        try:
            return func(*args, **kwargs)
        finally:
            end_ = int(round(time() * 1000)) - start
            print(f"Total execution time: {end_ if end_ > 0 else 0} ms")
    return _time_it
@measure
def hello():
    print('hello world')

hello()

Python - measure function execution time with decorator

Your function is running in 0.0001 something seconds. But since the number is so large, it takes almost 3 seconds to print it. So your code is working, I/O(print) is just slow. You can see it yourself if you only print the time it took.

To further demonstrate this and also add emil's comment

def decorator_timer(some_function):
    from time import time

    def wrapper(*args, **kwargs):
        t1 = time()
        result = some_function(*args, **kwargs)
        end = time()-t1
        return result, end
    return wrapper

@decorator_timer
def my_pow(a, b):
    res = a ** b
    return res
    # or just return a ** b, it doesn't really matter

result, exec_time = my_pow(99999 , 99999)
print(exec_time) # prints after 0.07347989082336426 seconds
print(result) # takes ~3 seconds

Measure : ipython timeit vs timeit method

I am not aware of anything standalone, but this can be easily extracted out of IPython, most of what it does is in the TimeitResult class which formats the output https://github.com/ipython/ipython/blob/8520f3063ca36655b5febbbd18bf55e59cb2cbb5/IPython/core/magics/execution.py#L55-L104

Then there's the nicer reporting of the compile time, worst run being much worse than the fastest, and getting the run number automatically like timeit's cli.

Reusing the code from IPython and python's timeit, and removing some checks that are probably unnecessary for the common use, we can get a simple function to do the timing in the same way IPython does:

import math
import timeit

def _format_time(timespan, precision=3):
    """Formats the timespan in a human readable form"""
    units = ["s", "ms", "\xb5s", "ns"]
    scaling = [1, 1e3, 1e6, 1e9]
    if timespan > 0.0:
        order = min(-int(math.floor(math.log10(timespan)) // 3), 3)
    else:
        order = 3
    scaled_time = timespan * scaling[order]
    unit = units[order]
    return f"{scaled_time:.{precision}g} {unit}"

class TimeitResult(object):
    """
    Object returned by the timeit magic with info about the run.

    Contains the following attributes :

    loops: (int) number of loops done per measurement
    repeat: (int) number of times the measurement has been repeated
    best: (float) best execution time / number
    all_runs: (list of float) execution time of each run (in s)
    compile_time: (float) time of statement compilation (s)
    """

    def __init__(self, loops, repeat, best, worst, all_runs, compile_time, precision):
        self.loops = loops
        self.repeat = repeat
        self.best = best
        self.worst = worst
        self.all_runs = all_runs
        self.compile_time = compile_time
        self._precision = precision
        self.timings = [dt / self.loops for dt in all_runs]

    @property
    def average(self):
        return math.fsum(self.timings) / len(self.timings)

    @property
    def stdev(self):
        mean = self.average
        return (
            math.fsum([(x - mean) ** 2 for x in self.timings]) / len(self.timings)
        ) ** 0.5

    def __str__(self):
        return "{mean} {pm} {std} per loop (mean {pm} std. dev. of {runs} run{run_plural}, {loops} loop{loop_plural} each)".format(
            pm="+-",
            runs=self.repeat,
            loops=self.loops,
            loop_plural="" if self.loops == 1 else "s",
            run_plural="" if self.repeat == 1 else "s",
            mean=_format_time(self.average, self._precision),
            std=_format_time(self.stdev, self._precision),
        )

def nice_timeit(
    stmt="pass",
    setup="pass",
    number=0,
    repeat=None,
    precision=3,
    timer_func=timeit.default_timer,
    globals=None,
):
    """Time execution of a Python statement or expression."""

    if repeat is None:
        repeat = 7 if timeit.default_repeat < 7 else timeit.default_repeat

    timer = timeit.Timer(stmt, setup, timer=timer_func, globals=globals)

    # Get compile time
    compile_time_start = timer_func()
    compile(timer.src, "<timeit>", "exec")
    total_compile_time = timer_func() - compile_time_start

    # This is used to check if there is a huge difference between the
    # best and worst timings.
    # Issue: https://github.com/ipython/ipython/issues/6471
    if number == 0:
        # determine number so that 0.2 <= total time < 2.0
        for index in range(0, 10):
            number = 10 ** index
            time_number = timer.timeit(number)
            if time_number >= 0.2:
                break

    all_runs = timer.repeat(repeat, number)
    best = min(all_runs) / number
    worst = max(all_runs) / number
    timeit_result = TimeitResult(
        number, repeat, best, worst, all_runs, total_compile_time, precision
    )

    # Check best timing is greater than zero to avoid a
    # ZeroDivisionError.
    # In cases where the slowest timing is lesser than a microsecond
    # we assume that it does not really matter if the fastest
    # timing is 4 times faster than the slowest timing or not.
    if worst > 4 * best and best > 0 and worst > 1e-6:
        print(
            f"The slowest run took {worst / best:.2f} times longer than the "
            f"fastest. This could mean that an intermediate result "
            f"is being cached."
        )

    print(timeit_result)

    if total_compile_time > 0.1:
        print(f"Compiler time: {total_compile_time:.2f} s")
    return timeit_result

nice_timeit("time.sleep(0.3)", "import time")

# IPython license
# BSD 3-Clause License
#
# - Copyright (c) 2008-Present, IPython Development Team
# - Copyright (c) 2001-2007, Fernando Perez <fernando.perez@colorado.edu>
# - Copyright (c) 2001, Janko Hauser <jhauser@zscout.de>
# - Copyright (c) 2001, Nathaniel Gray <n8gray@caltech.edu>
#
# All rights reserved.
#
# Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions are met:
#
# * Redistributions of source code must retain the above copyright notice, this
#   list of conditions and the following disclaimer.
#
# * Redistributions in binary form must reproduce the above copyright notice,
#   this list of conditions and the following disclaimer in the documentation
#   and/or other materials provided with the distribution.
#
# * Neither the name of the copyright holder nor the names of its
#   contributors may be used to endorse or promote products derived from
#   this software without specific prior written permission.
#
# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
# AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
# DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE
# FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
# DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
# SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
# CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

How do I use timeit module inside a decorator

the problem as I mention is in the setup, doing that import get you the already decorated function, that when executed once again do the import and get the decorated function and goes and execute the import and soo on until it blow up the stack... and we don't want that.

The timeit module can also take function as its stmt, so with just building a lambda function it solve the problem and we can use the undercoated function that way

The stmt and setup parameters can also take objects that are callable without arguments. This will embed calls to them in a timer function that will then be executed by timeit(). Note that the timing overhead is a little larger in this case because of the extra function calls.

import timeit
from functools import wraps
    
def tool(func):
    """Include debug statement and timeit setup"""
    @wraps(func)
    def wrapper(*args):
        print(func.__doc__, args)
        res = func(*args)
        print(res)
        times = timeit.repeat(
            stmt=lambda: func(*args),
            repeat=3, number=10000)
        print(times)
    return wrapper

and a quick test

>>> @tool
def fun():
    return 42
>>> fun()
None ()
42
[0.0013318000000026586, 0.0013294000000314554, 0.0013452000000597764]
>>> 

Decorator to Find the Time of Execution of a Function in Python

A decorator takes a function and returns a new function to replace the original. It is evaluated immediately.

So:

def decorate(func):
  print("Decorate!")
  return func

@decorate
def add(x, y):
  return x + y

will print "Decorate!" even without invoking add.

What you want to do is "wrap" the original function in a newer function which does some work and then invokes the original.

def decorate(func):
  def _wrap(*args, **kwargs):
    print("Start")
    return func(*args, **kwargs)

  return _wrap

@decorate
def add(x, y):
  return x + y

Now "add" will be replaced by _wrap which when invoked will run your print statement first and then invoke the original function with the same args and return the result. If you want to run some "post" logic as well, you can leverage a try...finally:

def decorate(func):
  def _wrap(*args, **kwargs):
    print("Start")
    try:
       return func(*args, **kwargs)
    finally:
      print("End")

  return _wrap

@decorate
def add(x, y):
  return x + y

The finally block is guaranteed to execute. If you don't care about printing "End" in error scenarios, you could also store the return result:

def decorate(func):
  def _wrap(*args, **kwargs):
    print("Start")
    result = func(*args, **kwargs)
    print("End")
    return result

  return _wrap

@decorate
def add(x, y):
  return x + y

If you need to pass args into the decorator, you just create a decorator factory, i.e. a function which takes some args and returns a decorate function.

def makeDecorator(text):
  def decorate(func):
    def _wrap(*args, **kwargs):
      print(f"Start: {text}")
      try:
        return func(*args, **kwargs)
      finally:
        print("End")
    
    return _wrap
  return decorate

@makeDecorator(text="Hi")
def add(x, y):
  return x + y

The key is that decorators "replace" the decorated object. So if you're decorating a function, you need to return a function. The decorate function itself is not the function that gets invoked when you call add().

Additional Tip: When you return the _wrap function, its name will be "_wrap" rather than the name of the original function. The functools standard library provides some helpers such as the wraps decorator which you can use on _wrap to give it the same name as the original function. Useful for debugging.

Python time measure function

First and foremost, I highly suggest using a profiler or atleast use timeit.

However if you wanted to write your own timing method strictly to learn, here is somewhere to get started using a decorator.

Python 2:

def timing(f):
    def wrap(*args):
        time1 = time.time()
        ret = f(*args)
        time2 = time.time()
        print '%s function took %0.3f ms' % (f.func_name, (time2-time1)*1000.0)
        return ret
    return wrap

And the usage is very simple, just use the @timing decorator:

@timing
def do_work():
  #code

Python 3:

def timing(f):
    def wrap(*args, **kwargs):
        time1 = time.time()
        ret = f(*args, **kwargs)
        time2 = time.time()
        print('{:s} function took {:.3f} ms'.format(f.__name__, (time2-time1)*1000.0))

        return ret
    return wrap

Note I'm calling f.func_name to get the function name as a string(in Python 2), or f.__name__ in Python 3.

time.time vs. timeit.timeit

timeit is more accurate, for three reasons:

• it repeats the tests many times to eliminate the influence of other tasks on your machine, such as disk flushing and OS scheduling.
• it disables the garbage collector to prevent that process from skewing the results by scheduling a collection run at an inopportune moment.
• it picks the most accurate timer for your OS, time.time or time.clock in Python 2 and time.perf_counter() on Python 3. See timeit.default_timer.

python timeit: function with decorator

Python code is interpreted "top to bottom". Therefore, if you declare variables either side of your function that are initialised with a "timestamp" you can deduce that the difference between those values will be the time taken to parse the code between them. So, for example,

from functools import cache
import time
import re

start = time.perf_counter()
@cache
def get_color_pattern():
    return re.compile(r'#(?:(?:[\da-f]{3}){1,2}|(?:[\da-f]{4}){1,2})|rgb\(\d{1,3},\d{1,3},\d{1,3}\)')
print(time.perf_counter()-start)

start = time.perf_counter()
re.compile(r'#(?:(?:[\da-f]{3}){1,2}|(?:[\da-f]{4}){1,2})|rgb\(\d{1,3},\d{1,3},\d{1,3}\)')
print(time.perf_counter()-start)

Output:

5.995000265102135e-06
0.00024428899996564724

Thus we see the difference in time taken to parse the function versus compiling the expression

---

Related Topics