Terrible lag in WaitForMultipleObjects

Hey everyone, I've been using WaitForMultipleObjects in my server, and I find that its fourth argument, the timeout in milliseconds, is *terribly* inaccurate. In 100 tries, of waits of .4 to 3.0 seconds, it's on average late returning by 1.154189 seconds (results at WFMO Timeout Accuracy - Pastebin.com and testing code at WFMO Timeout Tester - Pastebin.com).

Is this normal? Perhaps WFMO really only has down-to-the-second accuracy?

In any case, is there any way I can mimic WFMO with a better timer?

You seem to mix microseconds and ticks. Look up QueryPerformanceFrequency, you cannot make comparisons from ticks to time units without this value.

Code:

---

#include <iostream>
using namespace std;
#include <windows.h>
#include <cstdlib>

#pragma comment(lib, "winmm.lib")

DWORD getSystemTimeMilliseconds() {
    return timeGetTime();
}

int test() {
    HANDLE hEvent = CreateEvent(NULL, FALSE, FALSE, NULL);

    const int numTrials = 100;
    srand(GetTickCount());

    DWORD millisecondsLateSum = 0;
    DWORD bytes = 0;

    for (int i = 0; i < numTrials; i++) {
        DWORD timeBeforeWaitMilliseconds = getSystemTimeMilliseconds();
        DWORD desiredWaitMilliseconds = rand();
        DWORD desiredTimeAfterWaitMilliseconds = timeBeforeWaitMilliseconds + desiredWaitMilliseconds;
        WaitForMultipleObjects(1, &hEvent, FALSE, desiredWaitMilliseconds);
        DWORD timeAfterWaitMilliseconds = getSystemTimeMilliseconds();

        DWORD millisecondsLate = timeAfterWaitMilliseconds - desiredTimeAfterWaitMilliseconds;

        std::cout << "from " << timeBeforeWaitMilliseconds << " desired wait of " << desiredWaitMilliseconds << " to desired end time of " << desiredTimeAfterWaitMilliseconds << " actually ended " << timeAfterWaitMilliseconds << " late by " << millisecondsLate << " milliseconds" << std::endl;
        millisecondsLateSum += millisecondsLate;
    }
    CloseHandle(hEvent);

    std::cout << "late by on average " << millisecondsLateSum / numTrials << " milliseconds" << std::endl;

    return 0;
}

---

Results are here, bottom line:
late by on average 0 milliseconds.

Also the default period for timeGetTime() is usually 5ms which is not ideal. You should use timeBeginPeriod() and timeEndPeriod() to set the desired period. AFAIK it can have a resolution of 1 ms but I would not count on getting that every time. Also this information was true for Windows NT / 2000 / XP but I cannot find any info as to whether it applies in Vista and Windows 7. In Windows 95 the default resolution of timeGetTime() was 1 ms.

Yeah, you can print the current resolution and the allowable ranges with this

Code:

---

// a rare sighting of the mythical timeGetPeriod
void PrintCurrentTimerResolutions()
{
    // reutrn should be NTSTATUS but the typedef isn't in windows.h or ntstatus.h (go figure)
    // adding winternl.h or ntsecapi.h solely for it is overkill
    typedef long (NTAPI*pfnNtQueryTimerResolution)(PULONG pMaxRes, PULONG pMinRes, PULONG pCurRes);
    HMODULE hNtDll = GetModuleHandleW(L"ntdll.dll");
    pfnNtQueryTimerResolution ntQueryTimerResolution =
        (pfnNtQueryTimerResolution)GetProcAddress(hNtDll, "NtQueryTimerResolution");
    // 100-nanosecond units in 1 MS
    static const ULONG REFTIMES_PER_MILLISEC = 10000;
    if(ntQueryTimerResolution)
    {
        ULONG curRes = 0, minRes = 0, maxRes = 0;
        ntQueryTimerResolution(&maxRes, &minRes, &curRes);
        printf(
            "Max res: %lu, ms: %lu\nMin res: %lu, ms: %lu\nCur res: %lu, ms: %lu\n",
            maxRes, maxRes / REFTIMES_PER_MILLISEC,
            minRes, minRes / REFTIMES_PER_MILLISEC,
            curRes, curRes / REFTIMES_PER_MILLISEC
        );
    }
}

---

The test above was done with results of
Max res: 156001, ms: 15
Min res: 5000, ms: 0
Cur res: 10000, ms: 1

I reran it on a 7x64 VM with timer results of
Max res: 156250, ms: 15
Min res: 5000, ms: 0
Cur res: 156250, ms: 15
and the bottom line was "late by on average 16 milliseconds". The takeaway is 'as late as the clock' which is logical. The other would seem to be you can set the period to <1ms but not via any Microsoft documented functions.

Awesome, you guys were right! I was mixing microseconds and ticks. Once I put in that frequency call, it started working, being off on average by 100 microseconds or less.

Something odd did happen though, WFMO was sometimes returning 100 microseconds *before* it should have, but I suppose that should be expected with millisecond precision waiting.