Closed
Bug 124695
Opened 23 years ago
Closed 19 years ago
PR_IntervalNow is slow on Windows
Categories
(NSPR :: NSPR, defect)
Tracking
(Not tracked)
RESOLVED
FIXED
4.6.2
People
(Reporter: bratell, Assigned: wtc)
References
Details
(Keywords: perf)
Attachments
(3 files)
1.38 KB,
text/plain
|
Details | |
3.39 KB,
patch
|
darin.moz
:
review+
|
Details | Diff | Splinter Review |
706 bytes,
patch
|
Details | Diff | Splinter Review |
The documentation of PR_IntervalNow says:
"PR_IntervalNow is both very efficient and nonblocking..."
"Interval times ... are very cheap to acquire"
This is not true for Windows where QueryPerformanceCounter is used. That is the
slowest of all timing functions making PR_IntervalNow the bad choice.
In bug 75001 I measured the speed of different timing functions and got these
results:
Function Time in us
==========================================
timeGetTime 209
ftime 809
QueryPerfomanceCounter 4205
The one problem is that timeGetTime on NT/2000/XP have a default interval of 5ms
which have to be set down to 1ms by using timeBeginPeriod and timeEndPeriod.
----
If it for some reason isn't possible to change to a faster time function for
PR_IntervalNow I want to change this bug to a request for a fast, and maybe less
accurate timing function.
Assignee | ||
Comment 1•23 years ago
|
||
Thanks for the report.
Your finding is disturbing because we have always assumed
that QueryPerfomanceCounter is cheap. PR_IntervalNow()
should be cheap, and I believe we must have verified that
QueryPerfomanceCounter is cheap before (back in NT 3.51
or 4.0).
Reporter | ||
Comment 2•23 years ago
|
||
That depends on what you mean by cheap. Since we can be calling that method so
very often it piles up.
The previous measurements were done on a Windows NT4 machine with an Intel
Pentium II 400MHz processor.
I redid the measurements on a Windows 2000 computer (Duron 800MHz):
QueryPerformanceCounter 10000000 times: 12473ms, 1.247300 us/call
_ftime 10000000 times: 6301ms, 0.630100 us/call
timeGetTime 10000000 times: 1700ms, 0.170000 us/call
It seems to be faster than on NT4, but still _ftime and timeGetTime is much faster.
Reporter | ||
Comment 3•23 years ago
|
||
This is the test program I used. It just calls the funtion in a tight loop.
It's probably more costly in real life since this usage will keep the timing
code in the caches, but the relative times should be right.
Updated•23 years ago
|
Keywords: mozilla1.0,
perf
Updated•23 years ago
|
Keywords: mozilla1.0+
Updated•23 years ago
|
Keywords: mozilla1.0
Updated•23 years ago
|
Keywords: mozilla1.2
Comment 4•22 years ago
|
||
Do we have any updated time saving stats?
Reporter | ||
Comment 5•22 years ago
|
||
There is also a GetTickCount function that could be useful.
Comment 6•19 years ago
|
||
Usefull links:
http://www.compuphase.com/vbtiming.htm
Comment 7•19 years ago
|
||
Tested on WinXPsp2, IBM Thinkpad T40, 1.5Ghz Pentium M, 1GB RAM
QueryPerformanceCounter 10000000 times: 11656ms, 1.165600 us/call
_ftime 10000000 times: 2254ms, 0.225400 us/call
timeGetTime 10000000 times: 671ms, 0.067100 us/call
Compiled with Visual C++,m version 6.0, but these are system calls and (should
be) indepent from compiler version.
So, the difference is still there and very real.
So, timeGetTime with timeBeginPeriod set to 1 should improve performance of
PR_IntervalNow
Pointers to the code:
http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/nsprpub/pr/src/md/windows/ntthread.c#118
http://lxr.mozilla.org/seamonkey/source/nsprpub/pr/src/md/windows/ntinrval.c#90
So, the code is even there, but disabled/replaced by QueryPerformanceCounter.
Note, Bug 176881 (PRInterval timers may be incorrect on Windows with processor
speed > 4 GHz) also notes problems with the QPC call... (see also
http://support.microsoft.com/default.aspx?scid=KB;EN-US;Q274323& for the jumping
QBC thing).
Right, summary:
Let's use timeGetTime which is about 17 times faster than QPC, and doesn't have
the jumping issues of QPC. Also because it is using 1ms accuracy it makes
conversions redundant (internally to NSPR though).
Assignee | ||
Comment 8•19 years ago
|
||
Could you also measure GetTickCount()?
The reason we prefer GetTickCount() to timeGetTime()
is that timeGetTime() requires linking with winmm.lib.
In fact NSPR used timeGetTime() before and we had to
switch to GetTickCount() to eliminate the winmm.lib
dependency.
Comment 9•19 years ago
|
||
How about this?
QueryPerformanceCounter 10000000 times: 11603ms, 1.160300 us/call
_ftime 10000000 times: 2542ms, 0.254200 us/call
timeGetTime 10000000 times: 575ms, 0.057500 us/call
GetTickCount 10000000 times: 63ms, 0.006300 us/call
So, GetTickCount is even faster than timeGetTime.
However, GetTickCount only provides 10mseconds (or worse) accuracy, even with '
timeBeginPeriod(1);'
So GetTickCount is useless?
Comment 10•19 years ago
|
||
More info at:
http://gpwiki.org/index.php/VB:Timers
timeGetTime seams really be the only solution on windows to get 1msecond
accurate timing.
Assignee | ||
Comment 11•19 years ago
|
||
I wrote a test program to obtain the resolution of
GetTickCount and timeGetTime. On my Windows XP SP2
machine, the resolution of GetTickCount is 15-16 ms
while the resolution of timeGetTime is 1 ms. So I
am in favor of timeGetTime. Can anyone help me measure
the startup time penalty due to loading winmm.dll?
Here is my test program and a few sample outputs.
C:\temp>cat tick.c
#include <windows.h>
#include <stdio.h>
int main()
{
DWORD tick0;
DWORD tick;
tick0 = GetTickCount();
for (;;) {
tick = GetTickCount();
if (tick != tick0) {
break;
}
}
printf("GetTickCount: tick0=%d tick=%d resolution=%d\n", tick0, tick, (tick-
tick0));
tick0 = timeGetTime();
for (;;) {
tick = timeGetTime();
if (tick != tick0) {
break;
}
}
printf("timeGetTime: tick0=%d tick=%d resolution=%d\n", tick0, tick, (tick-t
ick0));
return 0;
}
C:\temp>.\tick.exe
GetTickCount: tick0=18564656 tick=18564671 resolution=15
timeGetTime: tick0=18564663 tick=18564664 resolution=1
C:\temp>.\tick.exe
GetTickCount: tick0=18565390 tick=18565406 resolution=16
timeGetTime: tick0=18565395 tick=18565396 resolution=1
C:\temp>.\tick.exe
GetTickCount: tick0=18566062 tick=18566078 resolution=16
timeGetTime: tick0=18566069 tick=18566070 resolution=1
C:\temp>.\tick.exe
GetTickCount: tick0=18603031 tick=18603046 resolution=15
timeGetTime: tick0=18603031 tick=18603032 resolution=1
Comment 12•19 years ago
|
||
Note, bug 307527 has a patch (and which is recently 2006/02/06) also submitted to some tree's) to switch to timeGetTime.
So, if that patch is accepted and the bug 307527 is closed, then this one is also implicetely closed?
Let's depend this bug on bug 307527 for the time being...
Depends on: 307527
Assignee | ||
Comment 13•19 years ago
|
||
It's more correct to make this NSPR bug block the Thunderbird
bug 307527.
Here is a summary for developers of other NSPR-based products
who will be affected by this change.
Right now, on Windows, PR_IntervalNow() calls QueryPerformanceCounter().
QueryPerformanceCounter() may return the wrong value because of bugs
in the BIOS or motherboard device drivers, and it may have problems
with multiprocessor systems (including the dual-core and multi-core
processors) and processors with variable clock speeds (for low
power consumption). Microsoft considers these problems outside
the boundary of Windows and refers the consumers to the processor
or motherboard vendors for help.
Recently, older versions of AMD's drivers for dual-core Athlon64
X2 processors cause QueryPerformanceCounter() to return the wrong
value again and cause connection timeout in Thunderbird (bug 307527).
So I decided it's time to use a different implementation for
PR_IntervalNow() on Windows. There are only two alternatives,
but they each have their own problem with resolution.
1. timeGetTime(): the resolution can be adjusted by the application.
On most systems, you can set the resolution to 1 ms. However,
the documentation about setting the resolution of timeGetTime()
seems to suggest that the resolution is a process-global property.
As a library, NSPR is not in a good position to set any process-global
property.
2. GetTickCount(): the resolution is fixed and is too coarse. For
example, on one of my Windows XP SP2 machine, the resolution of
GetTickCount() is 16 ms. This is 60% coarser than the traditional
Unix time resolution of 10 ms.
So, there is no ideal solution to this problem that I must fix.
I decided to go with timeGetTime() and rely on its default
resolution. An NSPR-based application can call timeBeginPeriod()
and timeEndPeriod() to set the timeGetTime() resolution to a desired
value. I considered calling timeBeginPeriod() and timeEndPeriod()
in NSPR's DllMain function, but Microsoft's DllMain documentation
warns that only kernel32.dll functions should be called in DllMain,
and those two functions are defined in winmm.dll.
Comment 14•19 years ago
|
||
FYI, I ran the program from comment #11 on my WinXP sp2 IBM T41p notebook, and I found that timeGetTime has a resolution of 1ms. That seems to contradict the theory that the default resolution of timeGetTime is higher (e.g., 5 - 10 ms).
Assignee | ||
Comment 15•19 years ago
|
||
Darin, a resolution of 5-10 ms is acceptable because it
is as good as the traditional Unix resolution of 10 ms.
Microsoft only documents that on Windows NT/2000 the
default resolution of timeGetTime can be >= 5 ms. On
my Windows XP SP2 machine, the resolution of timeGetTime()
is also 1 ms.
Comment 16•19 years ago
|
||
Comment on attachment 211084 [details] [diff] [review]
Proposed patch to use timeGetTime() (carried over from bug 307527)
r=darin
Attachment #211084 -
Flags: review+
Assignee | ||
Comment 17•19 years ago
|
||
I should clarify the issue with the resolution of timeGetTime().
It is not that the default resolution of 5-10 ms (on some
versions of Windows) is too coarse. It is that the resolution
may be set by the application to a very coarse value, say
20 ms, which may be too coarse for certain NSPR customers.
It seems inappropriate for NSPR to set the resolution. Also,
Microsoft documentation doesn't say what happens if the
application and NSPR try to set the resolution to different
values.
Comment 18•19 years ago
|
||
Hello,
I'm building Mozilla Sunbird on Windows 2000 from trunk using cygwin/mingw.
I did not build for some days but when I tried today the build succeeded but Sunbird crashed during startup. I did a debug build from scratch and got the following stack trace:
Program received signal SIGSEGV, Segmentation fault.
#0 0x780290d6 in time () from /cygdrive/c/WINNT/system32/msvcrt.dll
#1 0x30026060 in _PR_MD_GET_INTERVAL ()
at c:/dev/mozilla/nsprpub/pr/src/md/windows/ntinrval.c:54
#2 0x30012c28 in PR_IntervalNow ()
at c:/dev/mozilla/nsprpub/pr/src/misc/prinrval.c:77
#3 0x0d58fc92 in nsSocketTransportService::Poll (this=0x2547040, interval=0x13eeff04)
at c:/dev/mozilla/netwerk/base/src/nsSocketTransportService2.cpp:357
#4 0x0d5906e1 in nsSocketTransportService::Run (this=0x2547040)
at c:/dev/mozilla/netwerk/base/src/nsSocketTransportService2.cpp:568
#5 0x00742fba in nsThread::Main (arg=0x2547758)
at c:/dev/mozilla/xpcom/threads/nsThread.cpp:118
(More stack frames follow...)
Looking at the stack I think the check in for this bug could be the cause.
Any ideas?
Assignee | ||
Comment 19•19 years ago
|
||
Stefan, could you try this patch?
The crash in time() is most likely because we aren't
passing an argument to time(). But I think it is
wrong to use the time() function anyway; its resolution
is too coarse (1 second). I don't understand why the
MinGW code was using time() here.
Comment 20•19 years ago
|
||
(In reply to comment #19)
> Stefan, could you try this patch?
Sunbird build with this patch was successful and no longer crashes during startup.
Assignee | ||
Comment 21•19 years ago
|
||
Comment on attachment 211433 [details] [diff] [review]
Patch to fix MinGW build crash in time()
I checked in the MinGW build fix on the NSPR trunk
(NSPR 4.7), NSPRPUB_PRE_4_2_CLIENT_BRANCH (mozilla
1.9 alpha), MOZILLA_1_8_BRANCH (mozilla 1.8.1), and
MOZILLA_1_8_0_BRANCH (mozilla 1.8.0.2).
Comment 22•19 years ago
|
||
Can we mark this fixed now?
Comment 23•19 years ago
|
||
Patch has been committed, and after the MinGW followup patch, everything seems ok.
Marking fixed.
Status: ASSIGNED → RESOLVED
Closed: 19 years ago
Resolution: --- → FIXED
You need to log in
before you can comment on or make changes to this bug.
Description
•