Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

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

I timed a section of python code on Ubuntu using time.clock and time.time:

clock elapsed time: 8.770 s
time  elapsed time: 1.869 s

I understand that time.time uses system time and time.clock uses the processor clock. It makes sense to me when time.time gives a larger elapsed time than time.clock: the processor was just not active the entire time (e.g. time a call to time.sleep).

But why/when would the processor clock give an elapsed time so much greater than the system time does?


addendum

I did a rough test computing the same function with a standard map, with a process pool map, and a thread pool map. Understandably, the process pool is faster and the thread pool is slower. More interestingly: the clock timing is less than the time timing with the processor pool but greater in the thread pool.

Again, I understand why the clock timing is less with the processor pool: presumably the master process doesn't do much and just waits for the pool processes to complete. But why is the clock timing more with the thread pool? Any insights?

Results:

map
  time  1738.8
  clock 1739.6
mp pool
  time   580.1
  clock   15.9
thread pool
  time  3455.3
  clock 5378.9

Code:

from time import clock, sleep, time
from multiprocessing.pool import ThreadPool
from multiprocessing import Pool
import random

def f(i):
    x = [random.random() for j in range(100000)]
    return x[i]

def t(fn):
    t0, c0 = time(), clock()
    for i in range(10): fn(f,range(16))
    print '  time ', round(1000*(time()-t0),1)
    print '  clock', round(1000*(clock()-c0),1)

if __name__ == '__main__':
    print 'map'
    t(map)

    pool = Pool(8)
    print 'mp pool'
    t(pool.map)

    pool = ThreadPool(8)
    print 'thread pool'
    t(pool.map)
like image 993
jmilloy Avatar asked Jan 09 '15 15:01

jmilloy


1 Answers

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.

like image 149
b4hand Avatar answered Nov 04 '22 23:11

b4hand