[issue37205] time.perf_counter() is not system-wide on Windows, in disagreement with documentation

New submission from Ken Healy healykb+pythonbugs@gmail.com:
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-con...
---------- assignee: docs@python components: Documentation, Library (Lib), Windows messages: 345057 nosy: docs@python, kh90909, paul.moore, steve.dower, tim.golden, vstinner, zach.ware priority: normal severity: normal status: open type: behavior versions: Python 3.5, Python 3.6, Python 3.7, Python 3.8, Python 3.9
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Ken Healy healykb+pythonbugs@gmail.com added the comment:
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/ec89539ccccd6103665a7a5c7234cf09f27...
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Change by Terry J. Reedy tjreedy@udel.edu:
---------- versions: -Python 3.5, Python 3.6
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Ken Healy healykb+pythonbugs@gmail.com added the comment:
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
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Mariatta Wijaya mariatta@python.org added the comment:
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
---------- nosy: +Mariatta
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Daniel Hrisca daniel.hrisca@gmail.com added the comment:
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-con...
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; }
---------- nosy: +danielhrisca
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

STINNER Victor vstinner@python.org added the comment:
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.
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Daniel Hrisca daniel.hrisca@gmail.com added the comment:
That would be perfect and would help a lot with timings/synchronization across multiple processes.
Which Pyhton version will get this fix?
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Eryk Sun eryksun@gmail.com added the comment:
suggest to use time.perf_counter_ns() instead of time.perf_counter() for best precision.
QPC typically has a frequency of 1e7, which requires 24 bits for the fraction of a second. So a system can be up for years before the 53-bit precision of a float is an issue. What am I missing?
---------- nosy: +eryksun
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Eryk Sun eryksun@gmail.com added the comment:
QPC typically has a frequency of 1e7,
Never mind. Apparently with some combinations of chipset, processor, and Windows version, the QPC frequency runs far beyond the 1-10 MHz range. I thought Windows divided by 1024 instead of letting it run in the GHz range, but apparently not from what I see in search results. I misread "*in many cases*, QueryPerformanceFrequency returns the TSC frequency divided by 1024".
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Daniel Hrisca daniel.hrisca@gmail.com added the comment:
Under the hood perf_counter_ns already uses the two winapi calls (see https://github.com/python/cpython/blob/41761933c1c30bb6003b65eef1ba23a83db4e...) just that it also sets up a static variable as a time origin which makes it process-wide instead of system-wide
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Change by STINNER Victor vstinner@python.org:
---------- keywords: +patch pull_requests: +22176 stage: -> patch review pull_request: https://github.com/python/cpython/pull/23284
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

STINNER Victor vstinner@python.org added the comment:
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.
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

STINNER Victor vstinner@python.org added the comment:
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/3df5c68487df9d1d20ab0cd06e7942a4f96...
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Change by STINNER Victor vstinner@python.org:
---------- pull_requests: +22205 pull_request: https://github.com/python/cpython/pull/23314
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

STINNER Victor vstinner@python.org added the comment:
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/ae6cd7cfdab0599139002c526953d907696...
----------
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

STINNER Victor vstinner@python.org added the comment:
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
---------- resolution: -> fixed stage: patch review -> resolved status: open -> closed
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Change by Eryk Sun eryksun@gmail.com:
---------- Removed message: https://bugs.python.org/msg380941
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________

Change by Eryk Sun eryksun@gmail.com:
---------- Removed message: https://bugs.python.org/msg380944
_______________________________________ Python tracker report@bugs.python.org https://bugs.python.org/issue37205 _______________________________________
participants (6)
-
Daniel Hrisca
-
Eryk Sun
-
Ken Healy
-
Mariatta Wijaya
-
STINNER Victor
-
Terry J. Reedy