EnterNonRecursiveMutex on win32 can hang for 49.7 days: use GetTickCount64() rather than GetTickCount()

[bobince]

BPO	39847
Nosy	@pfmoore, @vstinner, @tjguk, @bobince, @zware, @zooba, @miss-islington, @sparrowt
PRs	bpo-39847: win32: don't over-wait for mutex after tickcount overflow #18780 [3.8] bpo-39847: EnterNonRecursiveMutex() uses GetTickCount64() (GH-18780) #18945 [3.7] bpo-39847: EnterNonRecursiveMutex() uses GetTickCount64() (GH-18780) #18959

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2020-03-12.14:29:14.812>
created_at = <Date 2020-03-04.13:20:26.946>
labels = ['type-bug', '3.8', '3.9', '3.7', 'library', 'OS-windows']
title = 'EnterNonRecursiveMutex on win32 can hang for 49.7 days: use GetTickCount64() rather than GetTickCount()'
updated_at = <Date 2020-03-12.14:29:14.811>
user = 'https://github.com/bobince'

bugs.python.org fields:

activity = <Date 2020-03-12.14:29:14.811>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2020-03-12.14:29:14.812>
closer = 'vstinner'
components = ['Library (Lib)', 'Windows']
creation = <Date 2020-03-04.13:20:26.946>
creator = 'aclover'
dependencies = []
files = []
hgrepos = []
issue_num = 39847
keywords = ['patch']
message_count = 7.0
messages = ['363346', '363347', '363351', '363986', '363989', '364022', '364023']
nosy_count = 9.0
nosy_names = ['paul.moore', 'vstinner', 'tim.golden', 'aclover', 'zach.ware', 'steve.dower', 'miss-islington', 'Day Barr', 'sparrowt']
pr_nums = ['18780', '18945', '18959']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue39847'
versions = ['Python 3.7', 'Python 3.8', 'Python 3.9']

[bobince]

Since bpo-15038, waiting to acquire locks/events/etc from _thread/threading on Windows can fail to return long past the requested timeout. Cause:

https://github.com/python/cpython/blob/3.8/Python/thread_nt.h#L85

using 32-bit GetTickCount/DWORD, which will overflow at around 49.7 days of uptime.

If the WaitForSingleObjectEx call in PyCOND_TIMEDWAIT returns later than the 'target' time, and the tick count overflows in that gap, 'milliseconds' will become very large (up to another 49.7 days) and the next PyCOND_TIMEDWAIT will be stuck for a long time.

Where we've seen it is where it's most likely to happen: when the machine is hibernated during the WaitForSingleObjectEx call. I believe the TickCount continues to increase during hibernation so there is a much bigger gap between 'target' and 'now' for the overflow to happen in.

Simplest fix is probably to switch to GetTickCount64/ULONGLONG. We should be able to get away with using this now we no longer support WinXP.

[vstinner]

time.monotonic() is now always implemented with GetTickCount64() on Windows. Previously, there was a fallback on GetTickCount() when GetTickCount64() was not available. GetTickCount() call has been removed when we dropped support for old Windows versions.

Do you want to work on a fix? (PR)

[bobince]

Yep, should be straightforward to fix (though not to test, as fifty-day test cases tend to be frowned upon...)