Why Is Time.Clock Giving a Greater Elapsed Time Than Time.Time

Why is time.clock giving a greater elapsed time than time.time?

CPU time can exceed wall time if you execute on multiple CPUs. I've not specifically seen this in Python, but I've definitely seen this when using the clock function with multiple threads from C, and presumably the Python code is just directly calling this C function.

Regarding "why": you're thinking about it the wrong way. What's important is how many cores are running your program. If one core runs for one second over the course of two seconds of wall time that makes sense to you, but what if four cores each run for one second over that same time interval. Then you have 4 seconds of CPU time in 2 seconds of wall time. The kernel accounts for CPU time measuring all cores. If multiple cores run during the same second then you spent multiple CPU seconds during that second. That's the cost measurement that matters to the scheduler, and presumably that's the metric which clock is built upon. This may not be the metric you care about, but that's how it works.

Understanding time.clock() and time.time()

In a multi-processing system (such as Linux or Windows), several independent processes each run in turn. While one process is running, all of the other processes are waiting^*. Occasionally the running process gives up its turn (sometimes cooperatively, sometimes it is forced to stop running). Some other process then gets a turn to run.

This process switch can happen dozens, hundreds or even thousands of times per second. From the human user's perspective, all of the processes appear to be running simultaneously. But in truth, they are all running in turns.

When a process invokes time.sleep(2.5), it announces that it is giving up the remainder of its current turn, and is not interested in any future turns for at least the next 2.5 seconds. So, for the next 2.5 seconds, it consumes no processor time.

Conversely, if this were the only process in the system:

while True:
    i += 1

it would never give up its turn; it would use 100% of the processor.

So, what has this to do with time.clock()? In Linux, time.clock() returns the sum of the durations of all of the turns that your process has taken since it was first launched. This is a fair measure of how hard your process's task is. If you only measure wall-clock time (i.e. time.time()), then your task's duration would depend upon how many other processes were running and what they were doing.

---

^* This description is valid for single processor multiprocessing systems. For multiprocessor sytems (or multi-core systems), a number of processes actually can run simultaneously. Regardless, time.clock() returns the sum of the durations all of the turns taken.

Measuring elapsed time with the Time module

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():

Why does time.clock() return a wrong result?

time.time() and time.clock() are measuring different things.

time.time() measures wall clock elapsed time, since the Unix epoch.

On a Linux system, time.clock() is measuring processor time, which isn't the elapsed time in seconds.

Processor time is an approximation of how much time was spent by the processor executing that code, as defined in the man pages for clock (which is the underlying call to the operating system that time.clock() makes on a Linux system).

Python source: https://docs.python.org/2/library/time.html

Clock source: http://linux.die.net/man/3/clock

Understanding time.perf_counter() and time.process_time()

There are two distincts types of 'time', in this context: absolute time and relative time.

Absolute time is the 'real-world time', which is returned by time.time() and which we are all used to deal with. It is usually measured from a fixed point in time in the past (e.g. the UNIX epoch of 00:00:00 UTC on 01/01/1970) at a resolution of at least 1 second. Modern systems usually provide milli- or micro-second resolution. It is maintained by the dedicated hardware on most computers, the RTC (real-time clock) circuit is normally battery powered so the system keeps track of real time between power ups. This 'real-world time' is also subject to modifications based on your location (time-zones) and season (daylight savings) or expressed as an offset from UTC (also known as GMT or Zulu time).

Secondly, there is relative time, which is returned by time.perf_counter and time.process_time. This type of time has no defined relationship to real-world time, in the sense that the relationship is system and implementation specific. It can be used only to measure time intervals, i.e. a unit-less value which is proportional to the time elapsed between two instants. This is mainly used to evaluate relative performance (e.g. whether this version of code runs faster than that version of code).

On modern systems, it is measured using a CPU counter which is monotonically increased at a frequency related to CPU's hardware clock. The counter resolution is highly dependent on the system's hardware, the value cannot be reliably related to real-world time or even compared between systems in most cases. Furthermore, the counter value is reset every time the CPU is powered up or reset.

time.perf_counter returns the absolute value of the counter. time.process_time is a value which is derived from the CPU counter but updated only when a given process is running on the CPU and can be broken down into 'user time', which is the time when the process itself is running on the CPU, and 'system time', which is the time when the operating system kernel is running on the CPU on behalf on the process.

---

Related Topics