classification
Title: time.perf_counter() is not system-wide on Windows, in disagreement with documentation
Type: behavior Stage: resolved
Components: Documentation, Library (Lib), Windows Versions: Python 3.9, Python 3.8, Python 3.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: docs@python Nosy List: Mariatta, danielhrisca, docs@python, eryksun, kh90909, paul.moore, steve.dower, tim.golden, vstinner, zach.ware
Priority: normal Keywords: patch

Created on 2019-06-08 18:15 by kh90909, last changed 2021-03-21 21:11 by eryksun. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 23284 merged vstinner, 2020-11-14 13:39
PR 23314 merged vstinner, 2020-11-16 13:31
Messages (12)
msg345057 - (view) Author: Ken Healy (kh90909) Date: 2019-06-08 18:14
The documentation for time.perf_counter() indicates it should return a system-wide value: https://docs.python.org/3/library/time.html#time.perf_counter

This is not true on Windows, as a process-specific offset is subtracted from the underlying QueryPerformanceCounter() value. The code comments indicate this is to reduce precision loss: https://github.com/python/cpython/blob/master/Python/pytime.c#L995-L997

This is relevant in multiprocess applications, where accurate timing is required across multiple processes. Here is a simple test case:

-----------------------------------------------------------
import concurrent.futures
import time

def worker():
    return time.perf_counter()

if __name__ == '__main__':
    pool = concurrent.futures.ProcessPoolExecutor()
    futures = []
    for i in range(3):
        print('Submitting worker {:d} at time.perf_counter() == {:.3f}'.format(i, time.perf_counter()))
        futures.append(pool.submit(worker))
        time.sleep(1)

    for i, f in enumerate(futures):
        print('Worker {:d} started at time.perf_counter() == {:.3f}'.format(i, f.result()))
-----------------------------------------------------------

Output:
-----------------------------------------------------------
C:\...>Python37\python.exe -VV
Python 3.7.3 (v3.7.3:ef4ec6ed12, Mar 25 2019, 22:22:05)
[MSC v.1916 64 bit (AMD64)]

C:\...>Python37\python.exe perf_counter_across_processes.py
Submitting worker 0 at time.perf_counter() == 0.376
Submitting worker 1 at time.perf_counter() == 1.527
Submitting worker 2 at time.perf_counter() == 2.529
Worker 0 started at time.perf_counter() == 0.380
Worker 1 started at time.perf_counter() == 0.956
Worker 2 started at time.perf_counter() == 1.963
-----------------------------------------------------------

See my stackoverflow question for a comparison with Linux: https://stackoverflow.com/questions/56502111/should-time-perf-counter-be-consistent-across-processes-in-python-on-windows
msg345059 - (view) Author: Ken Healy (kh90909) Date: 2019-06-08 18:19
Note that this offset subtraction behavior appears to be inherited from time.clock(), which did not make any guarantees about returning a system-wide value: 

https://github.com/python/cpython/commit/ec89539ccccd6103665a7a5c7234cf09f27c1c72#diff-4a575e94d6ac98a0d82fd93509b6bfd3L91
msg346095 - (view) Author: Ken Healy (kh90909) Date: 2019-06-20 04:20
Hi Terry,

I'm new to this so apologies in advance if this is a silly question...can you explain why you removed 3.5 and 3.6 from the versions list? I have tested that the issue is present in 3.6 and the offending code has been present since time.perf_counter() was introduced in 3.3.

It it because these versions are in maintenance-only status or similar, such that this type of bug fix would not be considered?

Thanks,
Ken
msg346097 - (view) Author: Mariatta (Mariatta) * (Python committer) Date: 2019-06-20 04:36
> can you explain why you removed 3.5 and 3.6 from the versions list? 

3.5 and 3.6 are closed for regular bug fix maintenance. We're only fixing issues in 3.7 and 3.8 now.

Only security fixes will be applied to 3.5 or 3.6, and this issue is not considered a security issue.

More details in https://devguide.python.org/#status-of-python-branches
msg380930 - (view) Author: Daniel Hrisca (danielhrisca) Date: 2020-11-13 19:36
I'm actually surprised that this problem gets so little interest. It's probably so obscure that most people don't even realize it.

Why isn't it implemented using winapi calls for the windows platform?

I took inspiration from this SO thread https://stackoverflow.com/questions/56502111/should-time-perf-counter-be-consistent-across-processes-in-python-on-windows
 
and came up with this function for 64 bit Python (a few more lines would be needed for error checking)

#include <windows.h>
static PyObject* perf_counter(PyObject* self, PyObject* args)
{
	PyObject* ret;

	QueryPerformanceFrequency(lpFrequency);
	QueryPerformanceCounter(lpPerformanceCount);
	
	ret = PyFloat_FromDouble(((double) lpPerformanceCount->QuadPart ) / lpFrequency->QuadPart);
	
	return ret;
}
msg380933 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-11-13 21:45
Since I added time.perf_counter_ns() to Python 3.7, it would be acceptable to reduce the "t0" variable and suggest to use time.perf_counter_ns() instead of time.perf_counter() for best precision.
msg380934 - (view) Author: Daniel Hrisca (danielhrisca) Date: 2020-11-13 22:05
That would be perfect and would help a lot with timings/synchronization across multiple processes.

Which Pyhton version will get this fix?
msg380957 - (view) Author: Daniel Hrisca (danielhrisca) Date: 2020-11-14 05:40
Under the hood perf_counter_ns already uses the two winapi calls (see https://github.com/python/cpython/blob/41761933c1c30bb6003b65eef1ba23a83db4eae4/Python/pytime.c#L970) just that it also sets up a static variable as a time origin which makes it process-wide instead of system-wide
msg380977 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-11-14 13:40
I wrote PR 23284 to make time.perf_counter() on Windows and time.monotonic() on macOS system-wide (remove the offset computed at startup). I also suggested the usage of the _ns() variant functions in the documentation.
msg381092 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-11-16 12:22
New changeset 3df5c68487df9d1d20ab0cd06e7942a4f96d40a4 by Victor Stinner in branch 'master':
bpo-37205: time.perf_counter() and time.monotonic() are system-wide (GH-23284)
https://github.com/python/cpython/commit/3df5c68487df9d1d20ab0cd06e7942a4f96d40a4
msg381105 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-11-16 15:08
New changeset ae6cd7cfdab0599139002c526953d907696d9eef by Victor Stinner in branch 'master':
bpo-37205: time.time() cannot fail with fatal error (GH-23314)
https://github.com/python/cpython/commit/ae6cd7cfdab0599139002c526953d907696d9eef
msg381107 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-11-16 15:13
I close the issue, it's now fixed in master. Thanks for the bug report Ken Healy.


While Python 3.8 and 3.9 are also affected, I prefer to leave them unchanged to avoid bad surprises during a minor update (3.x.y bugfix release). If you disagree, please speak up!


The regression was introduced in Python 3.7 by:

commit bdaeb7d237462a629e6c85001317faa85f94a0c6
Author: Victor Stinner <victor.stinner@gmail.com>
Date:   Mon Oct 16 08:44:31 2017 -0700

    bpo-31773: _PyTime_GetPerfCounter() uses _PyTime_t (GH-3983)
    
    * Rewrite win_perf_counter() to only use integers internally.
    * Add _PyTime_MulDiv() which compute "ticks * mul / div"
      in two parts (int part and remaining) to prevent integer overflow.
    * Clock frequency is checked at initialization for integer overflow.
    * Enhance also pymonotonic() to reduce the precision loss on macOS
      (mach_absolute_time() clock).

This change was related to the implementation of the PEP 564.

If you are curious about this work, I wrote two articles:

* https://vstinner.github.io/python37-pep-564-nanoseconds.html
* https://vstinner.github.io/python37-perf-counter-nanoseconds.html
* https://vstinner.github.io/pytime.html
History
Date User Action Args
2021-03-21 21:11:01eryksunsetmessages: - msg380944
2021-03-21 21:10:58eryksunsetmessages: - msg380941
2020-11-16 15:13:02vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg381107

stage: patch review -> resolved
2020-11-16 15:08:17vstinnersetmessages: + msg381105
2020-11-16 13:31:47vstinnersetpull_requests: + pull_request22205
2020-11-16 12:22:18vstinnersetmessages: + msg381092
2020-11-14 13:40:52vstinnersetmessages: + msg380977
2020-11-14 13:39:56vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request22176
2020-11-14 05:40:42danielhriscasetmessages: + msg380957
2020-11-14 00:18:19eryksunsetmessages: + msg380944
2020-11-13 23:17:21eryksunsetnosy: + eryksun
messages: + msg380941
2020-11-13 22:05:53danielhriscasetmessages: + msg380934
2020-11-13 21:45:08vstinnersetmessages: + msg380933
2020-11-13 19:36:46danielhriscasetnosy: + danielhrisca
messages: + msg380930
2019-06-20 04:36:12Mariattasetnosy: + Mariatta
messages: + msg346097
2019-06-20 04:20:20kh90909setmessages: + msg346095
2019-06-19 04:29:01terry.reedysetversions: - Python 3.5, Python 3.6
2019-06-08 18:19:39kh90909setmessages: + msg345059
2019-06-08 18:15:00kh90909create