classification
Title: Python3 threading.Event().wait time is twice as large as Python27
Type: performance Stage:
Components: Library (Lib), Windows Versions: Python 3.10, Python 3.9, Python 3.8
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: Dennis Sweeney, SD, eryksun, ned.deily, paul.moore, pitrou, steve.dower, tim.golden, zach.ware
Priority: normal Keywords:

Created on 2020-07-14 22:15 by SD, last changed 2021-03-01 20:54 by eryksun.

Messages (10)
msg373660 - (view) Author: SD (SD) Date: 2020-07-14 22:15
The overhead in Python 3 for threading.Event().wait() is much larger than Python 2. I am trying to run a script at 60hz which worked correctly in Python2 but does not in Python 3. Here is a minimal example to demonstrate: 

#!/usr/bin/env python

import threading
import time

def sample_thread(stop_ev):
    while not stop_ev.is_set():
        t2 = time.time() 
        stop_ev.wait(0.016999959945)
        print((time.time() - t2))

def main():
    stop_ev = threading.Event()
    sample_t = threading.Thread(target=sample_thread, args=(stop_ev, ))
    sample_t.start()

    # Other stuff here, sleep is just dummy
    time.sleep(14)

    stop_ev.set()

    print('End reached.')

if __name__ == '__main__':
    main()

Python 2.7.0 consistently prints :

0.0169999599457
0.0169999599457
0.0170001983643
0.0169999599457
0.0169999599457
0.0169999599457
0.0169999599457
0.0169999599457

Python 3.8.2 waits much longer

0.031026363372802734
0.0320279598236084
0.031026363372802734
0.031026840209960938
0.031527042388916016
0.031026601791381836
0.03103041648864746
0.03302431106567383
msg373675 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2020-07-15 10:25
Please provide the results of running the following with the two pythons you are using:

python -m test.pythoninfo

For what it's worth, running on macOS 10.15.5, I see a slight difference with more variability in the Python 3 results but nothing as pronounced as what you see. Also the Python 3 results were very similar across recent versions of 3.7.x, 3.8.x, and pre-release 3.9.

$ /usr/local/bin/python2.7 ~/test_41299.py | sort
0.017021894455
0.0170249938965
0.017028093338
0.017028093338
0.0170290470123
0.0170290470123
0.0170290470123
0.0170300006866
0.017030954361
0.0170311927795
[...]
0.0190448760986
0.0190479755402
0.0190498828888
0.0190510749817
0.0190589427948
0.019061088562
0.0190629959106
0.019079208374
0.0190861225128
0.0190970897675
End reached.0.0158078670502

$ /usr/local/bin/python3.8 ~/test_41299.py | sort
0.009722232818603516
0.017028093338012695
0.017033100128173828
0.017034053802490234
0.017034053802490234
0.017035961151123047
0.017037153244018555
0.017037153244018555
0.01703786849975586
0.017038822174072266
[...]
0.021351099014282227
0.021355152130126953
0.021355152130126953
0.02135610580444336
0.021361112594604492
0.021363258361816406
0.02136397361755371
0.021379947662353516
0.02138543128967285
0.021442890167236328
End reached.
msg373680 - (view) Author: Dennis Sweeney (Dennis Sweeney) * Date: 2020-07-15 11:46
I reproduced something similar on Python 3.9.0b1, Windows 64-bit version:

    py -m pyperf timeit -s "import threading; E = threading.Event()" "E.wait(<NUMBER>)"

NUMBER            Mean +- std dev
-------------------------------------------
0.0               5.79 us +- 0.13 us
0.000000000001    15.6 ms +- 0.1 ms
0.001             15.6 ms +- 0.1 ms
0.01              15.6 ms +- 0.6 ms
0.013             15.5 ms +- 0.6 ms
0.015             15.9 ms +- 0.9 ms
0.016             25.2 ms +- 0.5 ms
0.017             31.2 ms +- 0.2 ms
0.018             31.2 ms +- 0.4 ms
0.025             31.2 ms +- 1.0 ms
0.05              62.2 ms +- 0.8 ms
0.1               109 ms +- 2 ms
0.2               201 ms +- 3 ms
0.5               500 ms +- 0 ms
1.0               1.00 sec +- 0.00 sec

On the smaller scale, it looks quantized to multiples of ~15ms (?), but then it gets more accurate as the times get larger. I don't think it's a measurement error since the first measurement manages microseconds.

Perhaps this is just an OS-level thread-scheduling issue?
msg373694 - (view) Author: SD (SD) Date: 2020-07-15 13:30
I have tested this both on vs code terminal and cygwin for windows.

3.8.2 : 

python -m test.pythoninfo
Python debug information
========================

Py_DEBUG: No (sys.gettotalrefcount() missing)
_decimal.__libmpdec_version__: 2.4.2
builtins.float.double_format: IEEE, little-endian
builtins.float.float_format: IEEE, little-endian
datetime.datetime.now: 2020-07-15 09:09:34.936153
expat.EXPAT_VERSION: expat_2.2.8
locale.encoding: cp1252
os.cpu_count: 12
os.environ[APPDATA]: C:\Users\XXXX\AppData\Roaming
os.environ[COMPUTERNAME]: XXXX
os.environ[COMSPEC]: C:\Windows\system32\cmd.exe
os.environ[HOMEDRIVE]: C:
os.environ[HOMEPATH]: \Users\XXXX
os.environ[LANG]: en_GB.UTF-8
os.environ[PATHEXT]: .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.PY;.PYW;.CPL
os.environ[PATH]: C:\Program Files\NVIDIA GPU Computing Toolkit\CUDA\v9.2\bin;C:\Program Files\NVIDIA GPU Computing Toolkit\CUDA\v9.2\libnvvp;C:\Program Files\SlikSvn\bin;C:\Python\Python38\Scripts\;C:\Python\Python38\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Windows\System32\OpenSSH\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Program Files\dotnet\;C:\Program Files\TortoiseSVN\bin;C:\Program Files\CMake\bin;C:\Program Files (x86)\IncrediBuild;C:\Program Files\NVIDIA Corporation\NVIDIA NvDLISR;C:\Users\XXXX\AppData\Local\Microsoft\WindowsApps;;C:\Users\XXXX\AppData\Local\Programs\Microsoft VS Code\bin
os.environ[SYSTEMROOT]: C:\Windows
os.environ[TEMP]: C:\Users\XXXX\AppData\Local\Temp
os.environ[TMP]: C:\Users\XXXX\AppData\Local\Temp
os.environ[USERPROFILE]: C:\Users\XXXX
os.environ[WINDIR]: C:\Windows
os.getcwd: 
os.login: XXXX
os.name: nt
os.supports_bytes_environ: False
os.supports_effective_ids: []
os.supports_fd: ['stat', 'truncate']
os.supports_follow_symlinks: ['stat']
os.umask: 000
platform.architecture: 64bit WindowsPE
platform.platform: Windows-10-10.0.18362-SP0
platform.python_implementation: CPython
pymem.allocator: pymalloc
pymem.with_pymalloc: True
socket.hostname: 
sqlite3.sqlite_version: 3.28.0
sqlite3.version: 2.6.0
ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1d  10 Sep 2019
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 4, 15)
ssl.OP_ALL: -0x7fffffac
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: TLSVersion.MAXIMUM_SUPPORTED
ssl.SSLContext.minimum_version: TLSVersion.MINIMUM_SUPPORTED
ssl.SSLContext.options: Options.OP_NO_SSLv3|OP_CIPHER_SERVER_PREFERENCE|OP_ENABLE_MIDDLEBOX_COMPAT|OP_NO_COMPRESSION|OP_ALL
ssl.SSLContext.protocol: _SSLMethod.PROTOCOL_TLS
ssl.SSLContext.verify_mode: VerifyMode.CERT_NONE
ssl.default_https_context.maximum_version: TLSVersion.MAXIMUM_SUPPORTED
ssl.default_https_context.minimum_version: TLSVersion.MINIMUM_SUPPORTED
ssl.default_https_context.options: Options.OP_NO_SSLv3|OP_CIPHER_SERVER_PREFERENCE|OP_ENABLE_MIDDLEBOX_COMPAT|OP_NO_COMPRESSION|OP_ALL
ssl.default_https_context.protocol: _SSLMethod.PROTOCOL_TLS
ssl.default_https_context.verify_mode: VerifyMode.CERT_REQUIRED
ssl.stdlib_context.maximum_version: TLSVersion.MAXIMUM_SUPPORTED
ssl.stdlib_context.minimum_version: TLSVersion.MINIMUM_SUPPORTED
ssl.stdlib_context.options: Options.OP_NO_SSLv3|OP_CIPHER_SERVER_PREFERENCE|OP_ENABLE_MIDDLEBOX_COMPAT|OP_NO_COMPRESSION|OP_ALL
ssl.stdlib_context.protocol: _SSLMethod.PROTOCOL_TLS
ssl.stdlib_context.verify_mode: VerifyMode.CERT_NONE
subprocess._USE_POSIX_SPAWN: False
sys.api_version: 1013
sys.builtin_module_names: ('_abc', '_ast', '_bisect', '_blake2', '_codecs', '_codecs_cn', '_codecs_hk', '_codecs_iso2022', '_codecs_jp', '_codecs_kr', '_codecs_tw', '_collections', '_contextvars', '_csv', '_datetime', '_functools', '_heapq', '_imp', '_io', '_json', '_locale', '_lsprof', '_md5', '_multibytecodec', '_opcode', '_operator', '_pickle', '_random', '_sha1', '_sha256', '_sha3', '_sha512', '_signal', '_sre', '_stat', '_statistics', '_string', '_struct', '_symtable', '_thread', '_tracemalloc', '_warnings', '_weakref', '_winapi', '_xxsubinterpreters', 'array', 'atexit', 'audioop', 'binascii', 'builtins', 'cmath', 'errno', 'faulthandler', 'gc', 'itertools', 'marshal', 'math', 'mmap', 'msvcrt', 'nt', 'parser', 'sys', 'time', 'winreg', 'xxsubtype', 'zlib')
sys.byteorder: little
sys.dont_write_bytecode: False
sys.executable: C:\Python\Python38\python.exe
sys.filesystem_encoding: utf-8/surrogatepass
sys.flags: sys.flags(debug=0, inspect=0, interactive=0, optimize=0, dont_write_bytecode=0, no_user_site=0, no_site=0, ignore_environment=0, verbose=0, bytes_warning=0, quiet=0, hash_randomization=1, isolated=0, dev_mode=False, utf8_mode=0)
sys.float_info: sys.float_info(max=1.7976931348623157e+308, max_exp=1024, max_10_exp=308, min=2.2250738585072014e-308, min_exp=-1021, min_10_exp=-307, dig=15, mant_dig=53, epsilon=2.220446049250313e-16, radix=2, rounds=1)
sys.float_repr_style: short
sys.hash_info: sys.hash_info(width=64, modulus=2305843009213693951, inf=314159, nan=0, imag=1000003, algorithm='siphash24', hash_bits=64, seed_bits=128, cutoff=0)
sys.hexversion: 50856688
sys.implementation: namespace(cache_tag='cpython-38', hexversion=50856688, name='cpython', version=sys.version_info(major=3, minor=8, micro=2, releaselevel='final', serial=0))
sys.int_info: sys.int_info(bits_per_digit=30, sizeof_digit=4)
sys.maxsize: 9223372036854775807
sys.maxunicode: 1114111
sys.path: ['C:\\Python\\Python38\\python38.zip', 'C:\\Python\\Python38\\DLLs', 'C:\\Python\\Python38\\lib', 'C:\\Python\\Python38', 'C:\\Users\\XXXX\\AppData\\Roaming\\Python\\Python38\\site-packages', 'C:\\Python\\Python38\\lib\\site-packages']
sys.platform: win32
sys.prefix: C:\Python\Python38
sys.stderr.encoding: utf-8/backslashreplace
sys.stdin.encoding: utf-8/surrogateescape
sys.stdout.encoding: utf-8/surrogateescape
sys.thread_info: sys.thread_info(name='nt', lock=None, version=None)
sys.version: 3.8.2 (tags/v3.8.2:7b3ab59, Feb 25 2020, 23:03:10) [MSC v.1916 64 bit (AMD64)]
sys.version_info: sys.version_info(major=3, minor=8, micro=2, releaselevel='final', serial=0)
sys.windowsversion: sys.getwindowsversion(major=10, minor=0, build=18363, platform=2, service_pack='')
sys.winver: 3.8
sysconfig[prefix]: C:\Python\Python38
test_socket.HAVE_SOCKET_ALG: False
test_socket.HAVE_SOCKET_CAN: False
test_socket.HAVE_SOCKET_CAN_ISOTP: False
test_socket.HAVE_SOCKET_QIPCRTR: False
test_socket.HAVE_SOCKET_RDS: False
test_socket.HAVE_SOCKET_VSOCK: False
test_support.IPV6_ENABLED: True
test_support._is_gui_available: True
test_support.python_is_optimized: False
time.altzone: 14400
time.daylight: 1
time.get_clock_info(monotonic): namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, resolution=0.015625)
time.get_clock_info(perf_counter): namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=1e-07)
time.get_clock_info(process_time): namespace(adjustable=False, implementation='GetProcessTimes()', monotonic=True, resolution=1e-07)
time.get_clock_info(thread_time): namespace(adjustable=False, implementation='GetThreadTimes()', monotonic=True, resolution=1e-07)
time.get_clock_info(time): namespace(adjustable=True, implementation='GetSystemTimeAsFileTime()', monotonic=False, resolution=0.015625)
time.time: 1594818575.0377405
time.timezone: 18000
time.tzname: ('Eastern Standard Time', 'Eastern Summer Time')
tkinter.TCL_VERSION: 8.6
tkinter.TK_VERSION: 8.6
tkinter.info_patchlevel: 8.6.9
windows.RtlAreLongPathsEnabled: True
windows.dll_path: C:\Python\Python38\python38.dll
zlib.ZLIB_RUNTIME_VERSION: 1.2.11
zlib.ZLIB_VERSION: 1.2.11


2.7.18 : 

 python -m test.pythoninfo
Python debug information
========================

Py_DEBUG: No (sys.gettotalrefcount() missing)
builtins.float.double_format: IEEE, little-endian
builtins.float.float_format: IEEE, little-endian
datetime.datetime.now: 2020-07-15 09:28:00.404000
expat.EXPAT_VERSION: expat_2.2.8
locale.encoding: cp1252
os.cwd: C:\Python\Python27
os.environ[APPDATA]: C:\Users\XXXX\AppData\Roaming
os.environ[COMPUTERNAME]: 
os.environ[COMSPEC]: C:\Windows\system32\cmd.exe
os.environ[HOMEDRIVE]: C:
os.environ[HOMEPATH]: \Users\XXXX
os.environ[PATHEXT]: .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.PY;.PYW
os.environ[PATH]: C:\Program Files\ConEmu\ConEmu\Scripts;C:\Program Files\ConEmu;C:\Program Files\ConEmu\ConEmu;C:\Python\Python384\Scripts\;C:\Python\Python384\;C:\Users\XXXX\AppData\Local\Microsoft\WindowsApps;;C:\Users\XXXX\AppData\Local\Programs\Microsoft VS Code\bin;C:\Program Files\NVIDIA GPU Computing Toolkit\CUDA\v9.2\bin;C:\Program Files\NVIDIA GPU Computing Toolkit\CUDA\v9.2\libnvvp;C:\Program Files\SlikSvn\bin;C:\Python\Python38\Scripts\;C:\Python\Python38\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Windows\System32\OpenSSH\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Program Files\dotnet\;C:\Program Files\TortoiseSVN\bin;C:\Program Files\CMake\bin;C:\Program Files (x86)\IncrediBuild;C:\Program Files\NVIDIA Corporation\NVIDIA NvDLISR
os.environ[SYSTEMROOT]: C:\Windows
os.environ[TEMP]: C:\Users\XXXX\AppData\Local\Temp
os.environ[TMP]: C:\Users\XXXX\AppData\Local\Temp
os.environ[USERPROFILE]: C:\Users\XXXX
os.environ[WINDIR]: C:\Windows
os.name: nt
os.umask: 000
platform.architecture: 64bit WindowsPE
platform.platform: Windows-10-10.0.18362
platform.python_implementation: CPython
socket.hostname: 
sqlite3.sqlite_version: 3.28.0
sqlite3.version: 2.6.0
ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.0.2t  10 Sep 2019
ssl.OPENSSL_VERSION_INFO: (1, 0, 2, 20, 15)
ssl.OP_ALL: -0x7ffffc01
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext(PROTOCOL_TLS).options: OP_NO_SSLv3|OP_NO_SSLv2|OP_CIPHER_SERVER_PREFERENCE|OP_SINGLE_DH_USE|OP_SINGLE_ECDH_USE|OP_NO_COMPRESSION|OP_ALL
ssl.SSLContext(PROTOCOL_TLS).protocol: PROTOCOL_TLS
ssl.SSLContext(PROTOCOL_TLS).verify_mode: CERT_NONE
ssl.default_https_context.options: OP_NO_SSLv3|OP_NO_SSLv2|OP_CIPHER_SERVER_PREFERENCE|OP_SINGLE_DH_USE|OP_SINGLE_ECDH_USE|OP_NO_COMPRESSION|OP_ALL
ssl.default_https_context.protocol: PROTOCOL_TLS
ssl.default_https_context.verify_mode: CERT_REQUIRED
ssl.stdlib_context.options: OP_NO_SSLv3|OP_NO_SSLv2|OP_CIPHER_SERVER_PREFERENCE|OP_SINGLE_DH_USE|OP_SINGLE_ECDH_USE|OP_NO_COMPRESSION|OP_ALL
ssl.stdlib_context.protocol: PROTOCOL_TLS
ssl.stdlib_context.verify_mode: CERT_NONE
sys.api_version: 1013
sys.builtin_module_names: ('__builtin__', '__main__', '_ast', '_bisect', '_codecs', '_codecs_cn', '_codecs_hk', '_codecs_iso2022', '_codecs_jp', '_codecs_kr', '_codecs_tw', '_collections', '_csv', '_functools', '_heapq', '_hotshot', '_io', '_json', '_locale', '_lsprof', '_md5', '_multibytecodec', '_random', '_sha', '_sha256', '_sha512', '_sre', '_struct', '_subprocess', '_symtable', '_warnings', '_weakref', '_winreg', 'array', 'audioop', 'binascii', 'cPickle', 'cStringIO', 'cmath', 'datetime', 'errno', 'exceptions', 'future_builtins', 'gc', 'imageop', 'imp', 'itertools', 'marshal', 'math', 'mmap', 'msvcrt', 'nt', 'operator', 'parser', 'signal', 'strop', 'sys', 'thread', 'time', 'xxsubtype', 'zipimport', 'zlib')
sys.byteorder: little
sys.dont_write_bytecode: False
sys.executable: C:\Python\Python27\python.exe
sys.filesystem_encoding: mbcs
sys.flags: sys.flags(debug=0, py3k_warning=0, division_warning=0, division_new=0, inspect=0, interactive=0, optimize=0, dont_write_bytecode=0, no_user_site=0, no_site=0, ignore_environment=0, tabcheck=0, verbose=0, unicode=0, bytes_warning=0, hash_randomization=0)
sys.float_info: sys.float_info(max=1.7976931348623157e+308, max_exp=1024, max_10_exp=308, min=2.2250738585072014e-308, min_exp=-1021, min_10_exp=-307, dig=15, mant_dig=53, epsilon=2.220446049250313e-16, radix=2, rounds=1)
sys.float_repr_style: short
sys.hexversion: 34018032
sys.maxsize: 9223372036854775807
sys.maxunicode: 65535
sys.path: ['', 'C:\\Windows\\SYSTEM32\\python27.zip', 'C:\\Python\\Python27\\DLLs', 'C:\\Python\\Python27\\lib', 'C:\\Python\\Python27\\lib\\plat-win', 'C:\\Python\\Python27\\lib\\lib-tk', 'C:\\Python\\Python27', 'C:\\Python\\Python27\\lib\\site-packages']
sys.platform: win32
sys.prefix: C:\Python\Python27
sys.stderr.encoding: cp850
sys.stdin.encoding: cp850
sys.stdout.encoding: cp850
sys.version: 2.7.18 (v2.7.18:8d21aa21f2, Apr 20 2020, 13:25:05) [MSC v.1500 64 bit (AMD64)]
sys.version_info: sys.version_info(major=2, minor=7, micro=18, releaselevel='final', serial=0)
sys.windowsversion: sys.getwindowsversion(major=6, minor=2, build=9200, platform=2, service_pack='')
sys.winver: 2.7
sysconfig[prefix]: C:\Python\Python27
test_support.IPV6_ENABLED: True
test_support._is_gui_available: True
test_support.python_is_optimized: False
time.altzone: 14400
time.daylight: 1
time.time: 1594819680.4
time.timezone: 18000
time.tzname: ('Eastern Standard Time', 'Eastern Summer Time')
tkinter.TCL_VERSION: 8.5
tkinter.TK_VERSION: 8.5
zlib.ZLIB_VERSION: 1.2.11
msg373695 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2020-07-15 13:44
Thanks for the version info.

Windows and/or threading experts: any ideas?
msg373707 - (view) Author: Steve Dower (steve.dower) * (Python committer) Date: 2020-07-15 18:11
At a guess, it's probably the signal emulation (a.k.a. Ctrl+C support). We could save some time by checking the requested handle first without blocking, and only beginning the blocking call if it's not available.
msg373736 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2020-07-16 02:54
> On the smaller scale, it looks quantized to multiples of ~15ms (?), 
> but then it gets more accurate as the times get larger. I don't 
> think it's a measurement error since the first measurement manages
> microseconds.

NT's default system timer resolution for thread dispatching is 15.625 ms. If a wait is for 17 ms, expect to see actual wait times mostly in the range 17 ms up to 31.25 ms. A few outliers may wait longer because the due time on the kernel wait is when the thread is ready to be dispatched, but other threads may preempt it.

The system timer resolution can be increased to about 1 ms (or 500 us with the undocumented NtSetSystemTime system call). But stricter timing still requires combining a dispatcher wait for long course-grained waits with a performance-counter busy wait for short precise waits.

---

But something else is also involved here. I lowered the system timer resolution to 1 ms, and this allowed time.sleep(0.017) to wait for 17-18 ms in about 95% of cases. But the wait for acquiring a _thread.lock stubbornly refused to cooperate. Ultimately it's just calling WaitForSingleObjectEx on a semaphore, so I used ctypes to make a simple alternative lock via CreateSemaphoreW, ReleaseSemaphore, and WaitForSingleObject. This simple implementation performed exactly like the time.sleep wait with regard to the system timer resolution, so the difference is in the _thread.lock wait. I traced it to the following code in EnterNonRecursiveMutex in Python/thread_nt.h:

        /* wait at least until the target */
        ULONGLONG now, target = GetTickCount64() + milliseconds;
        while (mutex->locked) {
            if (PyCOND_TIMEDWAIT(&mutex->cv, &mutex->cs, (long long)milliseconds*1000) < 0) {
                result = WAIT_FAILED;
                break;
            }
            now = GetTickCount64();
            if (target <= now)
                break;
            milliseconds = (DWORD)(target-now);
        }

GetTickCount64 is documented to be "limited to the resolution of the system timer", but what they don't say is that changing the resolution of the system timer has no effect on the minimum increment of the tick count. It still increments by 15-16 ms even if the system timer resolution is set to 1 ms. 

OTOH, the value of QueryInterruptTime [1] and QueryUnbiasedInterruptTime [2] is incremented with the timer interrupt. The biased version [1] is preferred for long waits that may straddle a system sleep or hibernate, but it's only available in Windows 10. I patched EnterNonRecursiveMutex to call QueryInterruptTime instead of GetTickCount64, and this did enable increased precision when waiting on a lock. For example (patched behavior):

    >>> lock = _thread.allocate_lock()
    >>> lock.acquire()
    True
    >>> setup = 'from __main__ import lock'
    >>> stmt = 'lock.acquire(True, 0.017)'

15.625 ms system timer:

    >>> timeit.timeit(stmt, setup, number=1000)
    30.173713599999985

1 ms system timer:

    >>> with set_timer_resolution(0.001):
    ...     timeit.timeit(stmt, setup, number=1000)
    ...
    17.66828049999998

That said, increasing the timer resolution is discouraged in most cases, so  we may simply document that lock waits are limited to the default system timer resolution of 15.625 ms, and increasing the system timer resolution has no effect on this limit.

[1]: https://docs.microsoft.com/en-us/windows/win32/api/realtimeapiset/nf-realtimeapiset-queryinterrupttime
[2]: https://docs.microsoft.com/en-us/windows/win32/api/realtimeapiset/nf-realtimeapiset-queryunbiasedinterrupttime

---

Note that this is unrelated to cancel support via Ctrl+C. Windows Python has no support for canceling a wait on a _thread.lock. It's just a single-object wait in _PyCOND_WAIT_MS, not a multiple-object wait that we set up to include the SIGINT event when called on the main thread (or a variant that I like, which queues a user APC to the main thread for SIGINT instead of using an event, and switches to using alertable waits with SleepEx, WaitForSingleObjectEx, and without needing a wait slot in WaitForMultipleObjectsEx). It's possible to implement a Ctrl+C cancel as long as the lock implementation waits on a kernel semaphore object. However, some effort has gone into developing a different implementation based on condition variables and SRW locks. I don't know whether there's a way to cancel SleepConditionVariableSRW, or whether maybe a different implementation could be used for _thread.lock instead of sharing an implementation with the GIL.
msg373737 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2020-07-16 02:57
> or 500 us with the undocumented NtSetSystemTime system call

Umm... that should be NtSetTimerResolution. ;-)
msg374070 - (view) Author: SD (SD) Date: 2020-07-21 15:57
So there is no advised way around this then. I am currently using time.sleep() to hit my 60hz.
msg387880 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2021-03-01 20:54
>So there is no advised way around this then.

Changing the implementation of EnterNonRecursiveMutex() to use WinAPI QueryInterruptTime() instead of GetTickCount64() would allow increasing the wait precision by setting the system timer resolution to the minimum supported period via timeBeginPeriod() [1]. It seems reasonable to at least support doing this.

That said, changing the system timer resolution shouldn't be encouraged since it affects the entire system and can increase power consumption. If you have results in 2.7 similar what's shown in msg373660, check clockres in a separate terminal to see the current timer interval [2].

---
[1] https://docs.microsoft.com/en-us/windows/win32/api/timeapi/nf-timeapi-timebeginperiod
[2] https://docs.microsoft.com/en-us/sysinternals/downloads/clockres
History
Date User Action Args
2021-03-01 20:54:27eryksunsetmessages: + msg387880
versions: + Python 3.9, Python 3.10
2020-07-21 15:57:54SDsetmessages: + msg374070
2020-07-16 02:57:53eryksunsetmessages: + msg373737
2020-07-16 02:54:01eryksunsetnosy: + eryksun
messages: + msg373736
2020-07-15 18:11:47steve.dowersetmessages: + msg373707
2020-07-15 13:44:55ned.deilysetnosy: + pitrou, paul.moore, tim.golden, zach.ware, steve.dower
messages: + msg373695
components: + Library (Lib), Windows
2020-07-15 13:30:10SDsetmessages: + msg373694
2020-07-15 11:46:45Dennis Sweeneysetnosy: + Dennis Sweeney
messages: + msg373680
2020-07-15 10:25:55ned.deilysetnosy: + ned.deily
messages: + msg373675
2020-07-14 22:15:57SDcreate