Measuring elapsed time with the Time module

With the Time module in python i开发者_Python百科s it possible to measure elapsed time? If so, how do I do that?

I need to do this so that if the cursor has been in a widget for a certain duration an event happens.

start_time = time.time()
# your code
elapsed_time = time.time() - start_time

You can also write simple decorator to simplify measurement of execution time of various functions:

import time
from functools import wraps

PROF_DATA = {}

def profile(fn):
    @wraps(fn)
    def with_profiling(*args, **kwargs):
        start_time = time.time()

        ret = fn(*args, **kwargs)

        elapsed_time = time.time() - start_time

        if fn.__name__ not in PROF_DATA:
            PROF_DATA[fn.__name__] = [0, []]
        PROF_DATA[fn.__name__][0] += 1
        PROF_DATA[fn.__name__][1].append(elapsed_time)

        return ret

    return with_profiling

def print_prof_data():
    for fname, data in PROF_DATA.items():
        max_time = max(data[1])
        avg_time = sum(data[1]) / len(data[1])
        print "Function %s called %d times. " % (fname, data[0]),
        print 'Execution time max: %.3f, average: %.3f' % (max_time, avg_time)

def clear_prof_data():
    global PROF_DATA
    PROF_DATA = {}

Usage:

@profile
def your_function(...):
    ...

You can profile more then one function simultaneously. Then to print measurements just call the print_prof_data():

time.time() will do the job.

import time

start = time.time()
# run your code
end = time.time()

elapsed = end - start

You may want to look at this question, but I don't think it will be necessary.

For users that want better formatting,

import time
start_time = time.time()
# your script
elapsed_time = time.time() - start_time
time.strftime("%H:%M:%S", time.gmtime(elapsed_time))

will print out, for 2 seconds:

'00:00:02'

and for 7 minutes one second:

'00:07:01'

note that the minimum time unit with gmtime is seconds. If you need microseconds consider the following:

import datetime
start = datetime.datetime.now()
# some code
end = datetime.datetime.now()
elapsed = end - start
print(elapsed)
# or
print(elapsed.seconds,":",elapsed.microseconds) 

strftime documentation

For the best measure of elapsed time (since Python 3.3), use time.perf_counter().

Return the value (in fractional seconds) of a performance counter, i.e. a clock with the highest available resolution to measure a short duration. It does include time elapsed during sleep and is system-wide. The reference point of the returned value is undefined, so that only the difference between the results of consecutive calls is valid.

For measurements on the order of hours/days, you don't care about sub-second resolution so use time.monotonic() instead.

Return the value (in fractional seconds) of a monotonic clock, i.e. a clock that cannot go backwards. The clock is not affected by system clock updates. The reference point of the returned value is undefined, so that only the difference between the results of consecutive calls is valid.

In many implementations, these may actually be the same thing.

Before 3.3, you're stuck with time.clock().

On Unix, return the current processor time as a floating point number expressed in seconds. The precision, and in fact the very definition of the meaning of “processor time”, depends on that of the C function of the same name.

On Windows, this function returns wall-clock seconds elapsed since the first call to this function, as a floating point number, based on the Win32 function QueryPerformanceCounter(). The resolution is typically better than one microsecond.

Update for Python 3.7

New in Python 3.7 is PEP 564 -- Add new time functions with nanosecond resolution.

Use of these can further eliminate rounding and floating-point errors, especially if you're measuring very short periods, or your application (or Windows machine) is long-running.

Resolution starts breaking down on perf_counter() after around 100 days. So for example after a year of uptime, the shortest interval (greater than 0) it can measure will be bigger than when it started.

Update for Python 3.8

time.clock is now gone.

For a longer period.

import time
start_time = time.time()
...
e = int(time.time() - start_time)
print('{:02d}:{:02d}:{:02d}'.format(e // 3600, (e % 3600 // 60), e % 60))

would print

00:03:15

if more than 24 hours

25:33:57

That is inspired by Rutger Hofste's answer. Thank you Rutger!

In programming, there are 2 main ways to measure time, with different results:

>>> print(time.process_time()); time.sleep(10); print(time.process_time())
0.11751394000000001
0.11764988400000001  # took  0 seconds and a bit
>>> print(time.perf_counter()); time.sleep(10); print(time.perf_counter())
3972.465770326
3982.468109075       # took 10 seconds and a bit

• Processor Time: This is how long this specific process spends actively being executed on the CPU. Sleep, waiting for a web request, or time when only other processes are executed will not contribute to this.

  • Use time.process_time()

• Wall-Clock Time: This refers to how much time has passed "on a clock hanging on the wall", i.e. outside real time.

  • Use time.perf_counter()

    • time.time() also measures wall-clock time but can be reset, so you could go back in time
    • time.monotonic() cannot be reset (monotonic = only goes forward) but has lower precision than time.perf_counter()

You need to import time and then use time.time() method to know current time.

import time

start_time=time.time() #taking current time as starting time

#here your code

elapsed_time=time.time()-start_time #again taking current time - starting time 

Another nice way to time things is to use the with python structure.

with structure is automatically calling __enter__ and __exit__ methods which is exactly what we need to time things.

Let's create a Timer class.

from time import time

class Timer():
    def __init__(self, message):
        self.message = message
    def __enter__(self):
        self.start = time()
        return None  # could return anything, to be used like this: with Timer("Message") as value:
    def __exit__(self, type, value, traceback):
        elapsed_time = (time() - self.start) * 1000
        print(self.message.format(elapsed_time))

Then, one can use the Timer class like this:

with Timer("Elapsed time to compute some prime numbers: {}ms"):
    primes = []
    for x in range(2, 500):
        if not any(x % p == 0 for p in primes):
            primes.append(x)
    print("Primes: {}".format(primes))

The result is the following:

Primes: [2, 3, 5, 7, 11, 13, 17, 19, 23, 29, 31, 37, 41, 43, 47, 53, 59, 61, 67, 71, 73, 79, 83, 89, 97, 101, 103, 107, 109, 113, 127, 131, 137, 139, 149, 151, 157, 163, 167, 173, 179, 181, 191, 193, 197, 199, 211, 223, 227, 229, 233, 239, 241, 251, 257, 263, 269, 271, 277, 281, 283, 293, 307, 311, 313, 317, 331, 337, 347, 349, 353, 359, 367, 373, 379, 383, 389, 397, 401, 409, 419, 421, 431, 433, 439, 443, 449, 457, 461, 463, 467, 479, 487, 491, 499]

Elapsed time to compute some prime numbers: 5.01704216003418ms

Vadim Shender response is great. You can also use a simpler decorator like below:

import datetime
def calc_timing(original_function):                            
    def new_function(*args,**kwargs):                        
        start = datetime.datetime.now()                     
        x = original_function(*args,**kwargs)                
        elapsed = datetime.datetime.now()                      
        print("Elapsed Time = {0}".format(elapsed-start))     
        return x                                             
    return new_function()  

@calc_timing
def a_func(*variables):
    print("do something big!")

Here is an update to Vadim Shender's clever code with tabular output:

import collections
import time
from functools import wraps

PROF_DATA = collections.defaultdict(list)

def profile(fn):
    @wraps(fn)
    def with_profiling(*args, **kwargs):
        start_time = time.time()
        ret = fn(*args, **kwargs)
        elapsed_time = time.time() - start_time
        PROF_DATA[fn.__name__].append(elapsed_time)
        return ret
    return with_profiling

Metrics = collections.namedtuple("Metrics", "sum_time num_calls min_time max_time avg_time fname")

def print_profile_data():
    results = []
    for fname, elapsed_times in PROF_DATA.items():
        num_calls = len(elapsed_times)
        min_time = min(elapsed_times)
        max_time = max(elapsed_times)
        sum_time = sum(elapsed_times)
        avg_time = sum_time / num_calls
        metrics = Metrics(sum_time, num_calls, min_time, max_time, avg_time, fname)
        results.append(metrics)
    total_time = sum([m.sum_time for m in results])
    print("\t".join(["Percent", "Sum", "Calls", "Min", "Max", "Mean", "Function"]))
    for m in sorted(results, reverse=True):
        print("%.1f\t%.3f\t%d\t%.3f\t%.3f\t%.3f\t%s" % (100 * m.sum_time / total_time, m.sum_time, m.num_calls, m.min_time, m.max_time, m.avg_time, m.fname))
    print("%.3f Total Time" % total_time)