[Python-Dev] User + sys time bigger than real time, in case of no real parallelism

[Hans-Peter Jansen]

On Sonntag, 5. Februar 2017 07:59:04 Marco Buttu wrote:
> I am really sorry for the OT :-( I asked elsewhere but without any
> answer :-(
> I can not figure out why in this short example the user+sys time is
> bigger than real time. The example executes the task() functions twice,
> with each execution in a separate thread. The task() just increment
> 10**6 times a global int:
> 
> $ cat foo.py
> from threading import Thread, Lock
> 
> result = 0
> lock = Lock()
> 
> def task():
>      global result
>      for i in range(10**6):
>          lock.acquire()
>          result += 1
>          lock.release()
> 
> if __name__ == '__main__':
>      t1, t2 = Thread(target=task), Thread(target=task)
>      t1.start()
>      t2.start()
>      t1.join()
>      t2.join()
>      print('result:', result)
> 
> When I execute it (Python 3.6), I get a sys+user time bigger than the
> real time:
> 
> $ time python foo.py
> result: 2000000
> 
> real   0m7.088s
> user   0m6.597s
> sys    0m5.043s
> 
> That is usually what I can expect in case of tasks executed in parallel
> on different CPUs. But my example should not be the case, due to the
> GIL. What am I missing? Thank you very much, and sorry again for the OT :(

/usr/bin/time(!) gives some insight:

$ /usr/bin/time python3 foo.py
result: 2000000
1.18user 1.30system 0:01.52elapsed 163%CPU (0avgtext+0avgdata 
8228maxresident)k
8inputs+0outputs (0major+1151minor)pagefaults 0swaps

Obviously, the spinning happens outside the GIL...

Cheers,
Pete