CODEWITHSUNDEEP
pythondecoratorprofiler
Whisht
Whisht

Reputation: 763

Python get the total execution time of a function

Suppose that I have a function:

def func(x):
    time.sleep(x)
    return x

It will be called in every place when needed, for example, func_a in class A, func_b in class B... And all the modules start from a main function, main().

Now I want to statistic the amount of the called freqs and time of func. It's similar to profiler, but I only want to get the statistics of func; I do not care about other methods.

A Decorator can only get the time once, which is not sufficient for the total time. Another problem is that func overrides a function in another package. It may be called by functions in the package, and it is not easy to add a decorator to every call method.

def time(func):
    def wrapper(*args, **kwargs):
         import time
         st = time.time()
         result = func(*args, **kwargs)
         end = time.time()
         print(f"execution time: {end - st}")
         return result
     return wrapper()
@time
def func(x):
    ...

Is there any simple method that I can use to get the total execution of func with the minimum code?

Upvotes: 1

Views: 3520

Answers (2)

ovan
ovan

Reputation: 1

I've made some improvements to the original code snippet by incorporating automatic data collection for decorated functions. This enhancement enables the creation of reports or the storage of collected statistics in MySQL for more in-depth analysis later on.

Let define the decorator as :

def static_vars(**kwargs):
    def decorate(func):
        for k in kwargs:
            setattr(func, k, kwargs[k])
        return func
    return decorate
    
@static_vars(data={}, lock=threading.RLock())
def timing(f):
    @wraps(f)
    def wrap(*args, **kw):
        ts = time.time()
        result = f(*args, **kw)
        te = time.time()
        
        with timing.lock:
            name = f.__module__ + '::' + f.__name__
            fd = timing.data.get(name, {})
            fd['count'] = fd.get('count', 0) + 1
            fd['time'] = fd.get('time', 0) + te - ts
            fd['last'] = te - ts
            timing.data[name] = fd

        return result
    return wrap

Create a table to store the function execution statistics:

CREATE TABLE function_statistics (
    id INT AUTO_INCREMENT PRIMARY KEY,
    function_name VARCHAR(255) NOT NULL,
    iteration INT NOT NULL DEFAULT '0',
    call_count INT NOT NULL DEFAULT '0',
    total_time DOUBLE(10,6) DEFAULT '0.000000',
    average_time DOUBLE(10,6) GENERATED ALWAYS AS ((total_time / nullif(call_count,0))) VIRTUAL
    created_at TIMESTAMP DEFAULT CURRENT_TIMESTAMP
);

Upload the collected statistics to the database:

def upload_function_statitics(iteration, connection, cursor):
    with timing.lock:
        cursor.executemany(
            f"""
                INSERT INTO function_statistics 
                    (function_name, iteration, call_count, total_time)
                VALUES 
                    (%s, %s, %s, %s)
            """,
            [
                (k, iteration, v['count'], v['time'])
                for k,v in timing.data.items()
            ]
        )
        connection.commit()
        
        # reset counter
        timing.data = {}

Apply the timing decorator to any function you want to measure:

@timing
def my_function():
    # Your function code here
    pass

Finally periodically call the upload_function_statistics to insert the collected statistics into the database (and reset underlying data).

Here is my full blog post in this topic, with additional SQL query to do some analysis : https://sleek-think.ovh/blog/89-python-creating-a-function-timing-decorator-and-uploading-statistics-to-mysql

Upvotes: 0

blhsing
blhsing

Reputation: 107015

If you simply want to have the total execution time printed next to the execution time of the current call, you can store the total execution time as a local variable in the decorator and add to it the execution time of each call:

import time

def timer(func):
    def wrapper(*args, **kwargs):
        nonlocal total
        start = time.time()
        result = func(*args, **kwargs)
        duration = time.time() - start
        total += duration
        print(f"Execution time: {duration}   Total: {total}")
        return result

    total = 0
    return wrapper

Demo: Try it online!

Or if you want to be able to access the total execution time separately, you can expose it as an additional attribute of the wrapper function object:

import time

def timer(func):
    def wrapper(*args, **kwargs):
        start = time.time()
        result = func(*args, **kwargs)
        duration = time.time() - start
        wrapper.total_time += duration
        print(f"Execution time: {duration}")
        return result

    wrapper.total_time = 0
    return wrapper

so that:

@timer
def func(x):
    time.sleep(x)
    return x

print(func(1))
print(func(2))
print(f'Total: {func.total_time}')

outputs:

Execution time: 1.00111985206604
1
Execution time: 2.0005435943603516
2
Total: 3.0016634464263916

Demo: Try it online!

Upvotes: 1

Related Questions