KeQueryPerformanceCounter() anomalies

I ran into a problem in the last few days, and I’m wondering if it’s
something that anyone else has ever encountered. The basic problem is
that I have an ISR that needs to run at a particular periodic rate, and
I need to know whether or not it is hitting that rate. We’ve seen a
variety of systems that have had problems with maintaining that rate,
and this has been a good way to verify that we couldn’t maintain the
tick rate, and to know how many ticks to process to catch up.

Until today that is. Today, on several systems, I noticed something
that I didn’t think was possible. Running on a single CPU system (P4)
without hyperthreading, subsequent calls to KeQueryPerformanceCounter()
returned *smaller* numbers.

For example:

Call 1 returned: 222643334
Call 2 returned: 222624197
Call 3 returned: 222648107

Call 2 was supposed to return something in the neighborhood of
222644527, as each function call is supposed to be made 2ms after the
previous call. What I can’t figure out is why call 2 returns a
timestamp that is about 16ms *before* call 1, and then call 3 is 4 ms
after call 1 (as expected), but 20 ms after call 2 (not expected).

Did I just figure out how to tear the fabric of the universe with my
driver, or is this known behavior of the KeQueryPerformanceCounter() API
in single processor systems? Any help would be appreciated.

Thanks in advance,
Brian

I think there was an issue in that KQPC did not synchronize the counts across an MP system. When you are getting the smaller numbers, is that on a different proc then what you retrieved the previous number?

d


From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Nixon, Brian M
Sent: Friday, December 09, 2005 3:41 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] KeQueryPerformanceCounter() anomalies

I ran into a problem in the last few days, and I’m wondering if it’s something that anyone else has ever encountered.? The basic problem is that I have an ISR that needs to run at a particular periodic rate, and I need to know whether or not it is hitting that rate.? We’ve seen a variety of systems that have had problems with maintaining that rate, and this has been a good way to verify that we couldn’t maintain the tick rate, and to know how many ticks to process to catch up.

Until today that is.? Today, on several systems, I noticed something that I didn’t think was possible.? Running on a single CPU system (P4) without hyperthreading, subsequent calls to KeQueryPerformanceCounter() returned *smaller* numbers.
?
For example:
?
Call 1 returned:? 222643334
Call 2 returned:? 222624197
Call 3 returned:? 222648107
?
Call 2 was supposed to return something in the neighborhood of 222644527, as each function call is supposed to be made 2ms after the previous call.? What I can’t figure out is why call 2 returns a timestamp that is about 16ms *before* call 1, and then call 3 is 4 ms after call 1 (as expected), but 20 ms after call 2 (not expected).
?
Did I just figure out how to tear the fabric of the universe with my driver, or is this known behavior of the KeQueryPerformanceCounter() API in single processor systems?? Any help would be appreciated.
?
Thanks in advance,
Brian
?


Questions? First check the Kernel Driver FAQ at http://www.osronline.com/article.cfm?id=256

You are currently subscribed to ntdev as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com

He did explicitly comment that it was a UP system without hyperthreading (because my thought was the same when I first read the question.)

The only other question *I* could think was “how are you reporting these numbers?” If they are reported asynchronously, there might be some reordering, but if this is a DbgPrint message in the ISR it that can’t be the case.

Or maybe he’s found some interesting hardware/cpu bug (not that this is my FIRST theory, but it’s always way down there on the list of possibilities - and one that I’ve been involved with once in my life.)

Regards,

Tony

Tony Mason
Consulting Partner
OSR Open Systems Resources, Inc.
http://www.osr.com

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Doron Holan
Sent: Friday, December 09, 2005 6:59 PM
To: ntdev redirect
Subject: RE: [ntdev] KeQueryPerformanceCounter() anomalies

I think there was an issue in that KQPC did not synchronize the counts across an MP system. When you are getting the smaller numbers, is that on a different proc then what you retrieved the previous number?

d


From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Nixon, Brian M
Sent: Friday, December 09, 2005 3:41 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] KeQueryPerformanceCounter() anomalies

I ran into a problem in the last few days, and I’m wondering if it’s something that anyone else has ever encountered.? The basic problem is that I have an ISR that needs to run at a particular periodic rate, and I need to know whether or not it is hitting that rate.? We’ve seen a variety of systems that have had problems with maintaining that rate, and this has been a good way to verify that we couldn’t maintain the tick rate, and to know how many ticks to process to catch up.

Until today that is.? Today, on several systems, I noticed something that I didn’t think was possible.? Running on a single CPU system (P4) without hyperthreading, subsequent calls to KeQueryPerformanceCounter() returned *smaller* numbers.
?
For example:
?
Call 1 returned:? 222643334
Call 2 returned:? 222624197
Call 3 returned:? 222648107
?
Call 2 was supposed to return something in the neighborhood of 222644527, as each function call is supposed to be made 2ms after the previous call.? What I can’t figure out is why call 2 returns a timestamp that is about 16ms *before* call 1, and then call 3 is 4 ms after call 1 (as expected), but 20 ms after call 2 (not expected).
?
Did I just figure out how to tear the fabric of the universe with my driver, or is this known behavior of the KeQueryPerformanceCounter() API in single processor systems?? Any help would be appreciated.
?
Thanks in advance,
Brian
?


Questions? First check the Kernel Driver FAQ at http://www.osronline.com/article.cfm?id=256

You are currently subscribed to ntdev as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com


Questions? First check the Kernel Driver FAQ at http://www.osronline.com/article.cfm?id=256

You are currently subscribed to ntdev as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com

At least one of the systems experiencing the problem (and the one that I
am pulling the data from) is a single processor P4 with hyperthreading
disabled.

Here’s how I’m getting the numbers (the function sig doesn’t match the
expected sig, as this function is called by the actual ISR):

void IsrFunc( int, int )
{
CurrentTime = KeQueryPerformanceCounter( NULL );
ElapsedTime.QuadPart = CurrentTime.QuadPart -
LastInterrupt.QuadPart;

if( LastInterrupt.QuadPart < CurrentTime.QuadPart )
{
// We traveled back in time - dump the evidence
}

LastInterrupt.QuadPart = CurrentTime.QuadPart;

// Other stuff
}

This system has a perf counter frequency of 1193182, which means that
there are about 1193 ticks per millisecond. So each call to
KeQueryPerformanceCounter() should be about 2386 ticks apart. But, and
here’s something I discovered after I sent the original question out -
every 3450 interrupts (roughly 7 seconds) - KeQueryPerformanceCounter()
returns a value that is almost precisely 16ms (the gaps are almost
always exactly 16ms behind, within 1 or 2 ticks of each other) before
the last tick. And in all cases, the next call to
KeQueryPerformanceCounter(), is exactly where it would be if no problem
had occurred.

I noticed yesterday that the KeQueryPerformanceCounter exhibits this
problem every 3,450 times I call it, at least on this machine. Because
of the periodic nature of the problem, it reminds of a different problem
that I’ve seen on some machines where every 16,099 ticks,
KeQueryPerformanceCounter() was returning numbers that are too far
apart. We originally believed that this was the result of something
environmental on the system that was masking off interrupts for 4-6ms
approximately every 32 seconds, but now I’m not so sure.

Any ideas other than “Dude - stop using KeQueryPerformanceCounter()!!”?
:slight_smile:

Thanks again,

Brian Nixon
Software Engineer
Intel Modular Communications Platform Division
1515 Route 10
Parsippany, NJ 07054
Phone: 973.967.5178

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Tony Mason
Sent: Friday, December 09, 2005 7:07 PM
To: Windows System Software Devs Interest List
Subject: RE: [ntdev] KeQueryPerformanceCounter() anomalies

He did explicitly comment that it was a UP system without hyperthreading
(because my thought was the same when I first read the question.)

The only other question *I* could think was “how are you reporting these
numbers?” If they are reported asynchronously, there might be some
reordering, but if this is a DbgPrint message in the ISR it that can’t
be the case.

Or maybe he’s found some interesting hardware/cpu bug (not that this is
my FIRST theory, but it’s always way down there on the list of
possibilities - and one that I’ve been involved with once in my life.)

Regards,

Tony

Tony Mason
Consulting Partner
OSR Open Systems Resources, Inc.
http://www.osr.com

Don’t know if it helps but the implentation of this function used to be
highly dependant on the particular HAL in the system. In the NT 4.0 days,
different HAL’s did this differently. You might check and see if the
specific system with a problem has a different HAL than the others you are
testing on.


Don Burn (MVP, Windows DDK)
Windows 2k/XP/2k3 Filesystem and Driver Consulting
Remove StopSpam from the email to reply

“Nixon, Brian M” wrote in message
news:xxxxx@ntdev…
At least one of the systems experiencing the problem (and the one that I
am pulling the data from) is a single processor P4 with hyperthreading
disabled.

Here’s how I’m getting the numbers (the function sig doesn’t match the
expected sig, as this function is called by the actual ISR):

void IsrFunc( int, int )
{
CurrentTime = KeQueryPerformanceCounter( NULL );
ElapsedTime.QuadPart = CurrentTime.QuadPart -
LastInterrupt.QuadPart;

if( LastInterrupt.QuadPart < CurrentTime.QuadPart )
{
// We traveled back in time - dump the evidence
}

LastInterrupt.QuadPart = CurrentTime.QuadPart;

// Other stuff
}

This system has a perf counter frequency of 1193182, which means that
there are about 1193 ticks per millisecond. So each call to
KeQueryPerformanceCounter() should be about 2386 ticks apart. But, and
here’s something I discovered after I sent the original question out -
every 3450 interrupts (roughly 7 seconds) - KeQueryPerformanceCounter()
returns a value that is almost precisely 16ms (the gaps are almost
always exactly 16ms behind, within 1 or 2 ticks of each other) before
the last tick. And in all cases, the next call to
KeQueryPerformanceCounter(), is exactly where it would be if no problem
had occurred.

I noticed yesterday that the KeQueryPerformanceCounter exhibits this
problem every 3,450 times I call it, at least on this machine. Because
of the periodic nature of the problem, it reminds of a different problem
that I’ve seen on some machines where every 16,099 ticks,
KeQueryPerformanceCounter() was returning numbers that are too far
apart. We originally believed that this was the result of something
environmental on the system that was masking off interrupts for 4-6ms
approximately every 32 seconds, but now I’m not so sure.

Any ideas other than “Dude - stop using KeQueryPerformanceCounter()!!”?
:slight_smile:

Thanks again,

Brian Nixon
Software Engineer
Intel Modular Communications Platform Division
1515 Route 10
Parsippany, NJ 07054
Phone: 973.967.5178

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Tony Mason
Sent: Friday, December 09, 2005 7:07 PM
To: Windows System Software Devs Interest List
Subject: RE: [ntdev] KeQueryPerformanceCounter() anomalies

He did explicitly comment that it was a UP system without hyperthreading
(because my thought was the same when I first read the question.)

The only other question I could think was “how are you reporting these
numbers?” If they are reported asynchronously, there might be some
reordering, but if this is a DbgPrint message in the ISR it that can’t
be the case.

Or maybe he’s found some interesting hardware/cpu bug (not that this is
my FIRST theory, but it’s always way down there on the list of
possibilities - and one that I’ve been involved with once in my life.)

Regards,

Tony

Tony Mason
Consulting Partner
OSR Open Systems Resources, Inc.
http://www.osr.com

> is this known behavior of the KeQueryPerformanceCounter() API in single

processor systems?
Any help would be appreciated.
Here is the um code I successfully use[d].

The idea (whose idea? Mark’s, of course, who else…) is to replace
QueryPerformanceCounter by a Pentium instruction RDTSC.

Times I am getting from RDTSC are NOT comnpatible with those
fetched through the QueryPerformanceCounter wrapper.

It’s easy to port this snippet to km, but beware of time comparisons!
Either do it through RDTSC in both worlds or … .

Hope it helps.

// HighResTimer.cpp
#include “HighResTimer.h”
// time-measuring stuff - start
// after John Panzer (C/C++ Users Journal, January 1999 Volume 17 Number 1,
// Automatic Code Instrumentation).
// We define void queryTicks(__int64* pTicks) to be as fast as possible in
Pentium case.
// If it’s not Pentium, it’s just a thin wrapper around
QueryPerformanceCounter.

#define PENTIUM
//#undef PENTIUM

#ifdef PENTIUM
inline void RDTSC(DWORD& low, long& high) { // Pentium-specific RDTSC
instruction -
DWORD L; long H; // from www.sysinternals.com
_asm {
push eax
push edx
_emit 0Fh
_emit 31h
mov DWORD PTR [L], eax
mov DWORD PTR [H], edx
pop edx
pop eax
}
low = L; high = H;
}
void queryTickFreq(__int64* pTickFreq) {
static __int64 ticksPerSec=0;
if(!ticksPerSec) { // first time here - calculate ratio
LARGE_INTEGER freq;
QueryPerformanceFrequency(&freq);
__int64 qpf1, qpf2, qc1, qc2;
QueryPerformanceCounter((LARGE_INTEGER*)&qpf1);
RDTSC(((LARGE_INTEGER&)qc1).LowPart,
((LARGE_INTEGER&)qc1).HighPart);
Sleep(100);
QueryPerformanceCounter((LARGE_INTEGER*)&qpf2);
RDTSC(((LARGE_INTEGER&)qc2).LowPart,
((LARGE_INTEGER&)qc2).HighPart);
__int64 qpcTicks=qpf2 - qpf1;
__int64 qcTicks=qc2 - qc1;
long double ratio=((long double)qcTicks)/((long double)qpcTicks);
ticksPerSec=(__int64)(ratio*(long double)freq.QuadPart);
}
*pTickFreq=ticksPerSec;
}
// inline
void queryTicks(__int64* pTicks) {
RDTSC(((LARGE_INTEGER*)pTicks)->LowPart,
((LARGE_INTEGER*)pTicks)->HighPart);
}

#else // not a Pentium:

void queryTickFreq(__int64* pTickFreq) {
QueryPerformanceFrequency((LARGE_INTEGER*)pTickFreq);
}
// inline
void queryTicks(__int64* pTicks) {
QueryPerformanceCounter((LARGE_INTEGER*)pTicks);
}
#endif

double diffSecs(__int64 start, __int64 finish) {
__int64 diff=finish-start, temp;
double ddiff=(double)diff;
queryTickFreq(&temp);
return ddiff / temp;
}
//
****************************************************************************
/*1*
inline void RDTSC_LI(DWORD& low, long& high) { // Pentium-specific RDTSC
instruction -
DWORD L; long H; // from www.sysinternals.com
_asm {
push eax
push edx
_emit 0Fh
_emit 31h
mov DWORD PTR [L], eax
mov DWORD PTR [H], edx
pop edx
pop eax
}
low = L; high = H;
}
void queryTickFreqLI(PLARGE_INTEGER pFreq) {
static LARGE_INTEGER ticksPerSec;
if(!ticksPerSec.QuadPart) { // first time here - calculate ratio
LARGE_INTEGER freq;
QueryPerformanceFrequency(&freq);
LARGE_INTEGER qpf1, qpf2, qc1, qc2;
QueryPerformanceCounter((LARGE_INTEGER*)&qpf1);
RDTSC_LI(((LARGE_INTEGER&)qc1).LowPart, ((LARGE_INTEGER&)qc1).HighPart);
Sleep(100);
QueryPerformanceCounter((LARGE_INTEGER*)&qpf2);
RDTSC_LI(((LARGE_INTEGER&)qc2).LowPart, ((LARGE_INTEGER&)qc2).HighPart);
LARGE_INTEGER qpcTicks;
qpcTicks.QuadPart=qpf2.QuadPart-qpf1.QuadPart;
LARGE_INTEGER qcTicks;
qcTicks.QuadPart=qc2.QuadPart-qc1.QuadPart;
long double ratio=((long double)qcTicks.QuadPart)/((long
double)qpcTicks.QuadPart);
ticksPerSec.QuadPart=(LONGLONG)(ratio*(long double)freq.QuadPart);
}
*pFreq=ticksPerSec;
}
long double queryRatioLI_k(PLARGE_INTEGER pFreq) {
static LARGE_INTEGER ticksPerSec;
static long double ratio;
if(!ticksPerSec.QuadPart) { // first time here - calculate ratio
LARGE_INTEGER freq;
QueryPerformanceFrequency(&freq);
LARGE_INTEGER qpf1, qpf2, qc1, qc2;
QueryPerformanceCounter((LARGE_INTEGER*)&qpf1);
RDTSC_LI(((LARGE_INTEGER&)qc1).LowPart, ((LARGE_INTEGER&)qc1).HighPart);
Sleep(100);
QueryPerformanceCounter((LARGE_INTEGER*)&qpf2);
RDTSC_LI(((LARGE_INTEGER&)qc2).LowPart, ((LARGE_INTEGER&)qc2).HighPart);
LARGE_INTEGER qpcTicks;
qpcTicks.QuadPart=qpf2.QuadPart-qpf1.QuadPart;
LARGE_INTEGER qcTicks;
qcTicks.QuadPart=qc2.QuadPart-qc1.QuadPart;
ratio=((long double)qcTicks.QuadPart)/((long double)qpcTicks.QuadPart);
ticksPerSec.QuadPart=(LONGLONG)(ratio*(long double)freq.QuadPart);
}
*pFreq=ticksPerSec;
return ratio;
}
void queryTicksLI(PLARGE_INTEGER pTicks) {
RDTSC_LI(pTicks->LowPart, pTicks->HighPart);
}
double diffSecsLI(LARGE_INTEGER start, LARGE_INTEGER finish) {
LARGE_INTEGER diff, temp;
diff.QuadPart=finish.QuadPart-start.QuadPart;
double ddiff=(double)diff.QuadPart;
queryTickFreqLI(&temp);
return ddiff/temp.QuadPart;
}
double diffSecsLI_uk(LARGE_INTEGER start_u, LARGE_INTEGER finish_k) {
LARGE_INTEGER diff, temp;
diff.QuadPart=finish_k.QuadPart-(__int64)(start_u.QuadPart*queryRatioLI_k(&temp));
double ddiff=(double)diff.QuadPart;
// queryTickFreqLI(&temp);
return ddiff/temp.QuadPart;
}
*1*/
/*2*/
void queryTickFreqLI(PLARGE_INTEGER pFreq) {
QueryPerformanceFrequency(pFreq);
}
void queryTicksLI(PLARGE_INTEGER pTicks) {
QueryPerformanceCounter(pTicks);
}
double diffSecsLI(LARGE_INTEGER start, LARGE_INTEGER finish) {
LARGE_INTEGER diff, temp;
diff.QuadPart=finish.QuadPart-start.QuadPart;
double ddiff=(double)diff.QuadPart;
queryTickFreqLI(&temp);
return ddiff/temp.QuadPart;
}
/*2*/
//
****************************************************************************

----- Original Message -----
From: Nixon, Brian M
To: Windows System Software Devs Interest List
Sent: Friday, December 09, 2005 6:40 PM
Subject: [ntdev] KeQueryPerformanceCounter() anomalies

I ran into a problem in the last few days, and I’m wondering if it’s
something that anyone else has ever encountered. The basic problem is that
I have an ISR that needs to run at a particular periodic rate, and I need to
know whether or not it is hitting that rate. We’ve seen a variety of
systems that have had problems with maintaining that rate, and this has been
a good way to verify that we couldn’t maintain the tick rate, and to know
how many ticks to process to catch up.

Until today that is. Today, on several systems, I noticed something that I
didn’t think was possible. Running on a single CPU system (P4) without
hyperthreading, subsequent calls to KeQueryPerformanceCounter() returned
*smaller* numbers.

For example:

Call 1 returned: 222643334
Call 2 returned: 222624197
Call 3 returned: 222648107

Call 2 was supposed to return something in the neighborhood of 222644527, as
each function call is supposed to be made 2ms after the previous call. What
I can’t figure out is why call 2 returns a timestamp that is about 16ms
*before* call 1, and then call 3 is 4 ms after call 1 (as expected), but 20
ms after call 2 (not expected).

Did I just figure out how to tear the fabric of the universe with my driver,
or is this known behavior of the KeQueryPerformanceCounter() API in single
processor systems? Any help would be appreciated.

Thanks in advance,
Brian


Questions? First check the Kernel Driver FAQ at
http://www.osronline.com/article.cfm?id=256

You are currently subscribed to ntdev as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com

I thought most current implementations of the HAL already use the RDTSC
instruction? At least on the multiprocessor HALs (which also see this
problem), and some of the single processor HALs as well.

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@Home
Sent: Saturday, December 10, 2005 11:48 AM
To: Windows System Software Devs Interest List
Subject: Re: [ntdev] KeQueryPerformanceCounter() anomalies

is this known behavior of the KeQueryPerformanceCounter() API in
single
processor systems?
Any help would be appreciated.
Here is the um code I successfully use[d].

The idea (whose idea? Mark’s, of course, who else…) is to replace
QueryPerformanceCounter by a Pentium instruction RDTSC.

Times I am getting from RDTSC are NOT comnpatible with those
fetched through the QueryPerformanceCounter wrapper.

It’s easy to port this snippet to km, but beware of time comparisons!
Either do it through RDTSC in both worlds or … .

Hope it helps.

> This system has a perf counter frequency of 1193182, which means that

there are about 1193 ticks per millisecond.

Based on the frequency of 1193182, it sounds like that machine is using the
(logical equivalent of) 8254 timer chip as a source of high resolution
timing (combined with the count of periodic timer interrupts).

My memory is there was an issue sometimes reading back the real-time counter
value. Looking at http://heim.ifi.uio.no/~stanisls/helppc/8253.html it seems
to say the 8253 could not latch the counter value to read, but the 8254
could. The 8253 was used on the original IBM XT.

The counter continually decrements at 1193182 Hz, and causes a timer
interrupt, and then is automatically reloaded to its initial value (which
determines the periodic interrupt interval). The issue with the 8253 was you
had to do 2 port reads to get the full 16-bit count value, and the value was
not latched between those reads. My memory is the solution was you had to
read the high byte twice, and retry the whole read if the high byte changed
between reads.

The 8254 added a way to latch the 2 bytes, so they could be read as a
consistent value. Even the latched read had a problem though if you latched
the value, read one byte, got an interrupt that read the timer, and then on
returning from the interrupt; you read the second byte (which is now the
value from the latching that occurred in the interrupt). You did say you
call KeQueryPerformanceCounter in your ISR. Is your device interrupt IRQL
possibly higher than the timer IRQL?

Some of the possibilities are:

a) this specific chipset is acting like an 8253, not an 8254, and timer
latching does not work

b) The OS code does not protect the 8254 timer with an appropriate spinlock
at a very high IRQL. This means you may get nested calls to
KeQueryPerformanceCounter, and corrupt values will be read.

For calls outside your ISR, you could try raising/lowering the IRQL to the
level of your ISR around calls to KeQueryPerformanceCounter, so you won’t
have nested calls to QueryPerformanceCounter. This only helps on a single
processor. If this helps, I’d class this as an OS bug, as the docs do say
you can call KeQueryPerformanceCounter at ANY IRQL.

Directly reading the processor TSC should not have this problem, but does
have the issue of multiple processors may have unsynced TSC values.

Another question is why does the OS use the 8254 counter as the performance
counter if the processor TSC is available? I believe there also are other
sources of high resolution timing, like from the APIC.

  • Jan

> Directly reading the processor TSC should not have this problem, but does

have the issue of multiple processors may have unsynced TSC values.

last I looked the hal/kernel went to considerable effort to keep the
timestamp counters synced, at least on those processors that could do this.
Still not a guarantee, but they should be close, as long as both CPUs are
running from a common clock.

Another question is why does the OS use the 8254 counter as the
performance
counter if the processor TSC is available? I believe there also are other
sources of high resolution timing, like from the APIC.

An interesting question. Vague memory was that you could force a fallback
to the 8254 with /use8254 in boot.ini; but I think this died with ACPI HALs.
The the hal used the ACPI timer, except that most of the implementations
made it worse to use than the 8254. Perhaps it now uses the 8254 again (if
present) in perference to the acpi timer.

Why it wouldn’t be using the TSC on a single-processor system though is an
interesting question!

Loren

I think that the RDTSC approach will fail on NUMA machines.
Does anyone knows what Microsoft does on such machines? Does it still try to
sync the TSC or use another scheme?

Thanks,
Eran.

“Loren Wilton” wrote in message news:xxxxx@ntdev…
>> Directly reading the processor TSC should not have this problem, but does
>> have the issue of multiple processors may have unsynced TSC values.
>
> last I looked the hal/kernel went to considerable effort to keep the
> timestamp counters synced, at least on those processors that could do
> this.
> Still not a guarantee, but they should be close, as long as both CPUs are
> running from a common clock.
>
>> Another question is why does the OS use the 8254 counter as the
> performance
>> counter if the processor TSC is available? I believe there also are other
>> sources of high resolution timing, like from the APIC.
>
> An interesting question. Vague memory was that you could force a fallback
> to the 8254 with /use8254 in boot.ini; but I think this died with ACPI
> HALs.
> The the hal used the ACPI timer, except that most of the implementations
> made it worse to use than the 8254. Perhaps it now uses the 8254 again
> (if
> present) in perference to the acpi timer.
>
> Why it wouldn’t be using the TSC on a single-processor system though is an
> interesting question!
>
> Loren
>
>
>

Brian,

We’ve seen KeQueryPerformanceCounter going backward or jumping forward on all
kinds of systems, both UP and SMP.
Just reading TSC is has its own problems (mostly on SMP and NUMA systems with
power management)
There are multiple potential time sources for KeQueryPerformanceCounter
(legacy PIT, ACPI timer, TSC, new HPET,
proprietary HW timers requiring a custom HAL). All of them have problems on
some chipsets and/or CPUs.

I wish that a test of KeQueryPerformanceCounter were of a part of HCT and
checked kernels.

Here are some articles about KeQueryPerformanceCounter and TSC problems:

http://support.microsoft.com/default.aspx?scid=kb;EN-US;q274323
http://support.microsoft.com/?id=896256
http://www.veritest.com/bi/cont2000/200012/perfcnt.asp
http://lkml.org/lkml/2005/11/4/173

The bottom line: your code has to tolerate occasional forward and backward
jumps of KeQueryPerformanceCounter()'s return values.

Dmitriy Budko, VMware


From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Nixon, Brian M
Sent: Friday, December 09, 2005 3:41 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] KeQueryPerformanceCounter() anomalies

I ran into a problem in the last few days, and I’m wondering if it’s
something that anyone else has ever encountered. The basic problem is that I
have an ISR that needs to run at a particular periodic rate, and I need to
know whether or not it is hitting that rate. We’ve seen a variety of systems
that have had problems with maintaining that rate, and this has been a good
way to verify that we couldn’t maintain the tick rate, and to know how many
ticks to process to catch up.

Until today that is. Today, on several systems, I noticed something that I
didn’t think was possible. Running on a single CPU system (P4) without
hyperthreading, subsequent calls to KeQueryPerformanceCounter() returned
*smaller* numbers.

For example:

Call 1 returned: 222643334
Call 2 returned: 222624197
Call 3 returned: 222648107

Call 2 was supposed to return something in the neighborhood of 222644527, as
each function call is supposed to be made 2ms after the previous call. What
I can’t figure out is why call 2 returns a timestamp that is about 16ms
*before* call 1, and then call 3 is 4 ms after call 1 (as expected), but 20
ms after call 2 (not expected).

Did I just figure out how to tear the fabric of the universe with my driver,
or is this known behavior of the KeQueryPerformanceCounter() API in single
processor systems? Any help would be appreciated.

Thanks in advance,
Brian

> Another question is why does the OS use the 8254 counter as the performance

counter if the processor TSC is available?

IIRC RDTSC lies a lot with this modern Intel feature of floating CPU clock rate
due to power management.

Maxim Shatskih, Windows DDK MVP
StorageCraft Corporation
xxxxx@storagecraft.com
http://www.storagecraft.com