[PATCH] winmm: Default to 1ms resolution like we used to
Wine's winmm is built on an assumption that we default to 1ms resolution without ever calling timeBeginPeriod(1). For simplicity timeGetTime() was backed by GetTickCount() which recently has changed its implementation, and in worst case scenario returns a new value each ~16ms. This breaks our assumption. This patch introduces a proper timeGetTime() that uses QueryPerformanceCounter(). timeGetTime() is now also used instead of GetTickCount() internally by winmm. The research comment was updated with the latest findings. Fixes: cd215bb49bc2 ("kernel32: Use the user shared data to implement GetTickCount().") Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=49564 Signed-off-by: Arkadiusz Hiler <ahiler(a)codeweavers.com> --- dlls/winmm/time.c | 44 +++++++++++++++++++++++++++++++++---------- dlls/winmm/winmm.c | 12 ++++++------ dlls/winmm/winmm.spec | 2 +- 3 files changed, 41 insertions(+), 17 deletions(-) diff --git a/dlls/winmm/time.c b/dlls/winmm/time.c index 22c89852a2..4d802703f1 100644 --- a/dlls/winmm/time.c +++ b/dlls/winmm/time.c @@ -74,17 +74,30 @@ static inline void link_timer( WINE_TIMERENTRY *timer ) /* * Some observations on the behavior of winmm on Windows. - * First, the call to timeBeginPeriod(xx) can never be used - * to raise the timer resolution, only lower it. + * + * First, the call to timeBeginPeriod(xx) can never be used to + * lower the timer resolution (i.e. increase the update + * interval), only to increase the timer resolution (i.e. lower + * the update interval). * * Second, a brief survey of a variety of Win 2k and Win X * machines showed that a 'standard' (aka default) timer * resolution was 1 ms (Win9x is documented as being 1). However, one * machine had a standard timer resolution of 10 ms. * - * Further, if we set our default resolution to 1, - * the implementation of timeGetTime becomes GetTickCount(), - * and we can optimize the code to reduce overhead. + * Further, timeBeginPeriod(xx) also affects the resolution of + * wait calls such as NtDelayExecution() and + * NtWaitForMultipleObjects() which by default round up their + * timeout to the nearest multiple of 15.625ms across all Windows + * versions. In Wine, all of those currently work with sub-1ms + * accuracy. + * + * Effective time resolution is a global value that is the max + * of the resolutions (i.e. min of update periods) requested by + * all the processes. A lot of programs seem to do + * timeBeginPeriod(1) forcing it onto everyone else. + * + * Defaulting to 1ms accuracy in winmm should be safe. * * Additionally, a survey of Event behaviors shows that * if we request a Periodic event every 50 ms, then Windows @@ -97,6 +110,7 @@ static inline void link_timer( WINE_TIMERENTRY *timer ) * no delays. * * Jeremy White, October 2004 + * Arkadiusz Hiler, August 2020 */ #define MMSYSTIME_MININTERVAL (1) #define MMSYSTIME_MAXINTERVAL (65535) @@ -131,7 +145,7 @@ static int TIME_MMSysTimeCallback(void) } timer = LIST_ENTRY( ptr, WINE_TIMERENTRY, entry ); - delta_time = timer->dwTriggerTime - GetTickCount(); + delta_time = timer->dwTriggerTime - timeGetTime(); if (delta_time > 0) break; list_remove( &timer->entry ); @@ -242,16 +256,26 @@ void TIME_MMTimeStop(void) */ MMRESULT WINAPI timeGetSystemTime(LPMMTIME lpTime, UINT wSize) { - if (wSize >= sizeof(*lpTime)) { - lpTime->wType = TIME_MS; - lpTime->u.ms = GetTickCount(); + lpTime->wType = TIME_MS; + lpTime->u.ms = timeGetTime(); } return 0; } +/************************************************************************** + * timeGetTime [WINMM.@] + */ +DWORD WINAPI timeGetTime(void) +{ + LARGE_INTEGER now; + if (!QueryPerformanceCounter(&now)) + WARN("QueryPerformanceCounter should not fail!\n"); + return now.QuadPart/10000; +} + /************************************************************************** * timeSetEvent [WINMM.@] */ @@ -272,7 +296,7 @@ MMRESULT WINAPI timeSetEvent(UINT wDelay, UINT wResol, LPTIMECALLBACK lpFunc, return 0; lpNewTimer->wDelay = wDelay; - lpNewTimer->dwTriggerTime = GetTickCount() + wDelay; + lpNewTimer->dwTriggerTime = timeGetTime() + wDelay; /* FIXME - wResol is not respected, although it is not clear that we could change our precision meaningfully */ diff --git a/dlls/winmm/winmm.c b/dlls/winmm/winmm.c index 9075a78f34..eea29ea61e 100644 --- a/dlls/winmm/winmm.c +++ b/dlls/winmm/winmm.c @@ -1030,7 +1030,7 @@ static DWORD midistream_get_playing_position(WINE_MIDIStream* lpMidiStrm) case MSM_STATUS_PAUSED: return lpMidiStrm->dwElapsedMS; case MSM_STATUS_PLAYING: - return GetTickCount() - lpMidiStrm->dwStartTicks; + return timeGetTime() - lpMidiStrm->dwStartTicks; default: FIXME("Unknown playing status %hu\n", lpMidiStrm->status); return 0; @@ -1080,7 +1080,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI /* FIXME: send out cc64 0 (turn off sustain pedal) on every channel */ if (lpMidiStrm->status != MSM_STATUS_PLAYING) { EnterCriticalSection(&lpMidiStrm->lock); - lpMidiStrm->dwStartTicks = GetTickCount() - lpMidiStrm->dwElapsedMS; + lpMidiStrm->dwStartTicks = timeGetTime() - lpMidiStrm->dwElapsedMS; lpMidiStrm->status = MSM_STATUS_PLAYING; LeaveCriticalSection(&lpMidiStrm->lock); } @@ -1090,7 +1090,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI /* FIXME: send out cc64 0 (turn off sustain pedal) on every channel */ if (lpMidiStrm->status != MSM_STATUS_PAUSED) { EnterCriticalSection(&lpMidiStrm->lock); - lpMidiStrm->dwElapsedMS = GetTickCount() - lpMidiStrm->dwStartTicks; + lpMidiStrm->dwElapsedMS = timeGetTime() - lpMidiStrm->dwStartTicks; lpMidiStrm->status = MSM_STATUS_PAUSED; LeaveCriticalSection(&lpMidiStrm->lock); } @@ -1126,7 +1126,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI case WINE_MSM_HEADER: /* sets initial tick count for first MIDIHDR */ if (!lpMidiStrm->dwStartTicks) - lpMidiStrm->dwStartTicks = GetTickCount(); + lpMidiStrm->dwStartTicks = timeGetTime(); lpMidiHdr = (LPMIDIHDR)msg->lParam; lpData = (LPBYTE)lpMidiHdr->lpData; TRACE("Adding %s lpMidiHdr=%p [lpData=0x%p dwBytesRecorded=%u/%u dwFlags=0x%08x size=%lu]\n", @@ -1235,8 +1235,8 @@ start_header: dwToGo = lpMidiStrm->dwStartTicks + lpMidiStrm->position_usec / 1000; - TRACE("%u/%u/%u\n", dwToGo, GetTickCount(), me->dwDeltaTime); - while (dwToGo - (dwCurrTC = GetTickCount()) <= MAXLONG) { + TRACE("%u/%u/%u\n", dwToGo, timeGetTime(), me->dwDeltaTime); + while (dwToGo - (dwCurrTC = timeGetTime()) <= MAXLONG) { if (MsgWaitForMultipleObjects(0, NULL, FALSE, dwToGo - dwCurrTC, QS_ALLINPUT) == WAIT_OBJECT_0) { /* got a message, handle it */ while (PeekMessageA(&msg, 0, 0, 0, PM_REMOVE)) { diff --git a/dlls/winmm/winmm.spec b/dlls/winmm/winmm.spec index 9c6ed2dfa8..d7c7379d77 100644 --- a/dlls/winmm/winmm.spec +++ b/dlls/winmm/winmm.spec @@ -147,7 +147,7 @@ @ stdcall timeEndPeriod(long) @ stdcall timeGetDevCaps(ptr long) @ stdcall timeGetSystemTime(ptr long) -@ stdcall timeGetTime() kernel32.GetTickCount +@ stdcall timeGetTime() @ stdcall timeKillEvent(long) @ stdcall timeSetEvent(long long ptr long long) @ stdcall waveInAddBuffer(long ptr long) -- 2.28.0
‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐ On Friday, August 14, 2020 1:49 PM, Arkadiusz Hiler <ahiler(a)codeweavers.com> wrote:
Wine's winmm is built on an assumption that we default to 1ms resolution without ever calling timeBeginPeriod(1).
For simplicity timeGetTime() was backed by GetTickCount() which recently has changed its implementation, and in worst case scenario returns a new value each ~16ms. This breaks our assumption.
This patch introduces a proper timeGetTime() that uses QueryPerformanceCounter(). timeGetTime() is now also used instead of GetTickCount() internally by winmm.
The research comment was updated with the latest findings.
Fixes: cd215bb49bc2 ("kernel32: Use the user shared data to implement GetTickCount().") Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=49564 Signed-off-by: Arkadiusz Hiler ahiler(a)codeweavers.com
dlls/winmm/time.c | 44 +++++++++++++++++++++++++++++++++---------- dlls/winmm/winmm.c | 12 ++++++------ dlls/winmm/winmm.spec | 2 +- 3 files changed, 41 insertions(+), 17 deletions(-)
diff --git a/dlls/winmm/time.c b/dlls/winmm/time.c index 22c89852a2..4d802703f1 100644 --- a/dlls/winmm/time.c +++ b/dlls/winmm/time.c @@ -74,17 +74,30 @@ static inline void link_timer( WINE_TIMERENTRY timer ) /
- Some observations on the behavior of winmm on Windows.
- - First, the call to timeBeginPeriod(xx) can never be used - - to raise the timer resolution, only lower it.
- - - - First, the call to timeBeginPeriod(xx) can never be used to - - lower the timer resolution (i.e. increase the update - - interval), only to increase the timer resolution (i.e. lower - - the update interval). - - Second, a brief survey of a variety of Win 2k and Win X - machines showed that a 'standard' (aka default) timer - resolution was 1 ms (Win9x is documented as being 1). However, one - machine had a standard timer resolution of 10 ms. -
- - Further, if we set our default resolution to 1, - - the implementation of timeGetTime becomes GetTickCount(), - - and we can optimize the code to reduce overhead.
- - Further, timeBeginPeriod(xx) also affects the resolution of - - wait calls such as NtDelayExecution() and - - NtWaitForMultipleObjects() which by default round up their - - timeout to the nearest multiple of 15.625ms across all Windows - - versions. In Wine, all of those currently work with sub-1ms - - accuracy. - - - - Effective time resolution is a global value that is the max - - of the resolutions (i.e. min of update periods) requested by - - all the processes. A lot of programs seem to do - - timeBeginPeriod(1) forcing it onto everyone else. - - - - Defaulting to 1ms accuracy in winmm should be safe. - - Additionally, a survey of Event behaviors shows that - if we request a Periodic event every 50 ms, then Windows @@ -97,6 +110,7 @@ static inline void link_timer( WINE_TIMERENTRY *timer )
- no delays. - - Jeremy White, October 2004 - - Arkadiusz Hiler, August 2020 */ #define MMSYSTIME_MININTERVAL (1) #define MMSYSTIME_MAXINTERVAL (65535) @@ -131,7 +145,7 @@ static int TIME_MMSysTimeCallback(void) }
timer = LIST_ENTRY( ptr, WINE_TIMERENTRY, entry );
- delta_time = timer->dwTriggerTime - GetTickCount();
- delta_time = timer->dwTriggerTime - timeGetTime();
if (delta_time > 0) break;
list_remove( &timer->entry );
@@ -242,16 +256,26 @@ void TIME_MMTimeStop(void) */ MMRESULT WINAPI timeGetSystemTime(LPMMTIME lpTime, UINT wSize) {
---------------------------------------------------------------------------------------------------------------------
if (wSize >= sizeof(*lpTime)) {
- lpTime->wType = TIME_MS;
- lpTime->u.ms = GetTickCount();
- lpTime->wType = TIME_MS;
- lpTime->u.ms = timeGetTime();
}
return 0; }
+/**************************************************************************
- - timeGetTime [WINMM.@]
- */ +DWORD WINAPI timeGetTime(void) +{
- LARGE_INTEGER now; - if (!QueryPerformanceCounter(&now)) - WARN("QueryPerformanceCounter should not fail!\\n");
- return now.QuadPart/10000; +}
-
Sorry I'm a bit new so I'm not quite sure what the rules are regarding TRACEs, but would adding a TRACE here be an issue? I think it might be helpful for future debugging if there are any other issues with it.
/**************************************************************************
- timeSetEvent [WINMM.@]
*/ @@ -272,7 +296,7 @@ MMRESULT WINAPI timeSetEvent(UINT wDelay, UINT wResol, LPTIMECALLBACK lpFunc, return 0;
lpNewTimer->wDelay = wDelay;
- lpNewTimer->dwTriggerTime = GetTickCount() + wDelay;
- lpNewTimer->dwTriggerTime = timeGetTime() + wDelay;
/* FIXME - wResol is not respected, although it is not clear that we could change our precision meaningfully / diff --git a/dlls/winmm/winmm.c b/dlls/winmm/winmm.c index 9075a78f34..eea29ea61e 100644 --- a/dlls/winmm/winmm.c +++ b/dlls/winmm/winmm.c @@ -1030,7 +1030,7 @@ static DWORD midistream_get_playing_position(WINE_MIDIStream lpMidiStrm)case MSM_STATUS_PAUSED: return lpMidiStrm->dwElapsedMS;
case MSM_STATUS_PLAYING:
- return GetTickCount() - lpMidiStrm->dwStartTicks;
- return timeGetTime() - lpMidiStrm->dwStartTicks;
default: FIXME("Unknown playing status %hu\n", lpMidiStrm->status);
return 0;
@@ -1080,7 +1080,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI /* FIXME: send out cc64 0 (turn off sustain pedal) on every channel */ if (lpMidiStrm->status != MSM_STATUS_PLAYING) {
EnterCriticalSection(&lpMidiStrm->lock);
- lpMidiStrm->dwStartTicks = GetTickCount() - lpMidiStrm->dwElapsedMS;
- lpMidiStrm->dwStartTicks = timeGetTime() - lpMidiStrm->dwElapsedMS;
lpMidiStrm->status = MSM_STATUS_PLAYING;
LeaveCriticalSection(&lpMidiStrm->lock);
}
@@ -1090,7 +1090,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI /* FIXME: send out cc64 0 (turn off sustain pedal) on every channel */ if (lpMidiStrm->status != MSM_STATUS_PAUSED) {
EnterCriticalSection(&lpMidiStrm->lock);
- lpMidiStrm->dwElapsedMS = GetTickCount() - lpMidiStrm->dwStartTicks;
- lpMidiStrm->dwElapsedMS = timeGetTime() - lpMidiStrm->dwStartTicks;
lpMidiStrm->status = MSM_STATUS_PAUSED;
LeaveCriticalSection(&lpMidiStrm->lock);
}
@@ -1126,7 +1126,7 @@ static BOOL MMSYSTEM_MidiStream_MessageHandler(WINE_MIDIStream* lpMidiStrm, LPWI case WINE_MSM_HEADER: /* sets initial tick count for first MIDIHDR */ if (!lpMidiStrm->dwStartTicks)
- lpMidiStrm->dwStartTicks = GetTickCount();
- lpMidiStrm->dwStartTicks = timeGetTime();
lpMidiHdr = (LPMIDIHDR)msg->lParam;
lpData = (LPBYTE)lpMidiHdr->lpData;
TRACE("Adding %s lpMidiHdr=%p [lpData=0x%p dwBytesRecorded=%u/%u dwFlags=0x%08x size=%lu]\\n",
@@ -1235,8 +1235,8 @@ start_header:
dwToGo = lpMidiStrm->dwStartTicks + lpMidiStrm->position_usec / 1000;
- TRACE("%u/%u/%u\\n", dwToGo, GetTickCount(), me->dwDeltaTime);
- while (dwToGo - (dwCurrTC = GetTickCount()) <= MAXLONG) {
- TRACE("%u/%u/%u\\n", dwToGo, timeGetTime(), me->dwDeltaTime);
- while (dwToGo - (dwCurrTC = timeGetTime()) <= MAXLONG) { if (MsgWaitForMultipleObjects(0, NULL, FALSE, dwToGo - dwCurrTC, QS_ALLINPUT) == WAIT_OBJECT_0) { /* got a message, handle it */ while (PeekMessageA(&msg, 0, 0, 0, PM_REMOVE)) {
diff --git a/dlls/winmm/winmm.spec b/dlls/winmm/winmm.spec index 9c6ed2dfa8..d7c7379d77 100644 --- a/dlls/winmm/winmm.spec +++ b/dlls/winmm/winmm.spec @@ -147,7 +147,7 @@ @ stdcall timeEndPeriod(long) @ stdcall timeGetDevCaps(ptr long) @ stdcall timeGetSystemTime(ptr long) -@ stdcall timeGetTime() kernel32.GetTickCount +@ stdcall timeGetTime() @ stdcall timeKillEvent(long) @ stdcall timeSetEvent(long long ptr long long) @ stdcall waveInAddBuffer(long ptr long)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2.28.0
Am 15.08.2020 um 01:44 schrieb Myah Caron <qsniyg(a)protonmail.com>:
Sorry I'm a bit new so I'm not quite sure what the rules are regarding TRACEs, but would adding a TRACE here be an issue? I think it might be helpful for future debugging if there are any other issues with it.
Those 'rules' are somewhat inconsistent. I would say adding a TRACE here is a good idea, but not strictly necessary. A lot of functions in kernel32/kernelbase and ntdll have no TRACEs because they show up in a +relay log. But since I am used to COM interfaces in d3d which don't show up in relay logs (+relay injects code into DLL exports, and COM interfaces aren't PE exports) I am very used to +ddraw showing me all ddraw calls, so at times I am confused when +winmm doesn't show half the winmm calls.
On 2020-08-15 09:39, Stefan Dösinger wrote:
Am 15.08.2020 um 01:44 schrieb Myah Caron <qsniyg(a)protonmail.com>:
Sorry I'm a bit new so I'm not quite sure what the rules are regarding TRACEs, but would adding a TRACE here be an issue? I think it might be helpful for future debugging if there are any other issues with it.
Those 'rules' are somewhat inconsistent. I would say adding a TRACE here is a good idea, but not strictly necessary.
A lot of functions in kernel32/kernelbase and ntdll have no TRACEs because they show up in a +relay log. But since I am used to COM interfaces in d3d which don't show up in relay logs (+relay injects code into DLL exports, and COM interfaces aren't PE exports) I am very used to +ddraw showing me all ddraw calls, so at times I am confused when +winmm doesn't show half the winmm calls.
Also, +relay doesn't work with some DRMs, so IMHO adding TRACE messages is always useful unless there's a performance penalty or too much verbosity. For instance I would say ntdll could use more TRACE but it may be subjective so I've always kept these patches local. -- Rémi Bernon <rbernon(a)codeweavers.com>
On 8/15/20 5:43 AM, Rémi Bernon wrote:
On 2020-08-15 09:39, Stefan Dösinger wrote:
Am 15.08.2020 um 01:44 schrieb Myah Caron <qsniyg(a)protonmail.com>:
Sorry I'm a bit new so I'm not quite sure what the rules are regarding TRACEs, but would adding a TRACE here be an issue? I think it might be helpful for future debugging if there are any other issues with it.
Those 'rules' are somewhat inconsistent. I would say adding a TRACE here is a good idea, but not strictly necessary.
A lot of functions in kernel32/kernelbase and ntdll have no TRACEs because they show up in a +relay log. But since I am used to COM interfaces in d3d which don't show up in relay logs (+relay injects code into DLL exports, and COM interfaces aren't PE exports) I am very used to +ddraw showing me all ddraw calls, so at times I am confused when +winmm doesn't show half the winmm calls.
Also, +relay doesn't work with some DRMs, so IMHO adding TRACE messages is always useful unless there's a performance penalty or too much verbosity.
For instance I would say ntdll could use more TRACE but it may be subjective so I've always kept these patches local.
The lack of traces in kernel32/ntdll is often an annoyance. +relay is often just not an option, due to slowness or excessive output size. With regard to timeGetTime(), though, and time functions in general, I think it is likely better not to trace it. They may be called many times per second.
participants (5)
-
Arkadiusz Hiler -
Myah Caron -
Rémi Bernon -
Stefan Dösinger -
Zebediah Figura