.NET System.Diagnostics.Stopwatch 问题(返回值太低)
在我的计算机上,秒表返回的值太低。例如,当我指定 Thread.Sleep(1000) 时为 200 毫秒。该程序应该等待 1 秒。我还使用 ManualResetEvent.WaitOne(1000)
进行了测试,并得到了相同的结果。框架 2.0 和 3.0 都给出了这种奇怪的行为。我正在运行带有 .NET Framework 3.5 SP1 的 Windows XP SP3。
这是我的测试结果(代码如下):
1000 ms for DateTime.Now.Ticks
0201 ms for Stopwatch.ElapsedTicks
0142 ms for Stopwatch.ElapsedMilliseconds
0139 ms for Stopwatch.ElapsedTicks after Reset
0264 ms for Stopwatch.ElapsedTicks setting ThreadAffinity
0151 ms for Stopwatch.ElapsedTicks setting ProcessorAffinity (and more)
0371 ms for Stopwatch.ElapsedTicks with Syncronized object
Done!
// Program.cs file
class Program
{
static void Main(string[] args)
{
StopWatchTest.Go();
Console.WriteLine("Done!");
Console.ReadLine();
}
}
// StopWatchTest.cs class
internal static class StopWatchTest
{
public const int SleepTime = 1000;
public static void Go()
{
#region Test #0 with DateTime.Now.Ticks
long startTick = DateTime.Now.Ticks;
Thread.Sleep(SleepTime);
long stopTick = DateTime.Now.Ticks;
long elapsedDt = (stopTick - startTick) * 100;
Display((int)(elapsedDt / 1000 / 1000), "DateTime.Now.Ticks");
#endregion Test #0 with DateTime.Now.Ticks
Stopwatch watch = Stopwatch.StartNew();
long frequency = Stopwatch.Frequency;
double nanosecPerTick = (1000.0 * 1000.0 * 1000.0) / frequency;
#region Test #1 with Stopwatch.ElapsedTicks
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
double elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks");
#endregion Test #1 with Stopwatch.ElapsedTicks
#region Test #2 with Stopwatch.ElapsedMilliseconds
startTick = watch.ElapsedMilliseconds;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedMilliseconds;
Display((int)(stopTick - startTick), "Stopwatch.ElapsedMilliseconds");
#endregion Test #2 with Stopwatch.ElapsedMilliseconds
#region Test #3 with Stopwatch.ElapsedTicks after Reset
watch.Stop();
watch.Reset();
watch.Start();
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks after Reset");
#endregion Test #3 with Stopwatch.ElapsedTicks after Reset
#region Test #4 with Stopwatch.ElapsedTicks and ThreadAffinity
Thread.BeginThreadAffinity();
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks setting ThreadAffinity");
Thread.EndThreadAffinity();
#endregion Test #4 with Stopwatch.ElapsedTicks and ThreadAffinity
#region Test #5 with Stopwatch.ElapsedTicks and ProcessorAffinity (and more)
const int affinity = 0x0001;
Process proc = Process.GetCurrentProcess();
proc.ProcessorAffinity = new IntPtr(affinity);
proc.PriorityClass = ProcessPriorityClass.High;
ProcessThreadCollection ptc = proc.Threads;
foreach (ProcessThread pt in ptc)
{
pt.IdealProcessor = 0;
pt.ProcessorAffinity = new IntPtr(affinity);
}
Thread.CurrentThread.Priority = ThreadPriority.Highest;
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks setting ProcessorAffinity (and more)");
#endregion Test #5 with ProcessorAffinity and more
#region Test #6 with Syncronized object
elapsedSw = new SyncTimer().Go();
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks with Syncronized object");
#endregion Test #6 with Syncronized object
}
private static void Display(int milliseconds, string testName)
{
Console.WriteLine("{0:0000} ms for {1}", milliseconds, testName);
}
}
[Synchronization]
internal class SyncTimer : ContextBoundObject
{
[MethodImpl(MethodImplOptions.Synchronized)]
public double Go()
{
Stopwatch.StartNew();
long frequency = Stopwatch.Frequency;
double nanosecPerTick = (1000.0 * 1000.0 * 1000.0) / frequency;
long startTick = Stopwatch.GetTimestamp();
Thread.Sleep(StopWatchTest.SleepTime);
long stopTick = Stopwatch.GetTimestamp();
return (stopTick - startTick) * nanosecPerTick;
}
}
On my computer the Stopwatch is returning values way too low. For example, 200 ms when I specified Thread.Sleep(1000)
. The program is supposed to wait 1 second. I also tested with ManualResetEvent.WaitOne(1000)
and got the same results. Both framework 2.0 and 3.0 gives this strange behavior. I am running Windows XP SP3 with .NET Framework 3.5 SP1.
Here is the result of my tests (code below):
1000 ms for DateTime.Now.Ticks
0201 ms for Stopwatch.ElapsedTicks
0142 ms for Stopwatch.ElapsedMilliseconds
0139 ms for Stopwatch.ElapsedTicks after Reset
0264 ms for Stopwatch.ElapsedTicks setting ThreadAffinity
0151 ms for Stopwatch.ElapsedTicks setting ProcessorAffinity (and more)
0371 ms for Stopwatch.ElapsedTicks with Syncronized object
Done!
// Program.cs file
class Program
{
static void Main(string[] args)
{
StopWatchTest.Go();
Console.WriteLine("Done!");
Console.ReadLine();
}
}
// StopWatchTest.cs class
internal static class StopWatchTest
{
public const int SleepTime = 1000;
public static void Go()
{
#region Test #0 with DateTime.Now.Ticks
long startTick = DateTime.Now.Ticks;
Thread.Sleep(SleepTime);
long stopTick = DateTime.Now.Ticks;
long elapsedDt = (stopTick - startTick) * 100;
Display((int)(elapsedDt / 1000 / 1000), "DateTime.Now.Ticks");
#endregion Test #0 with DateTime.Now.Ticks
Stopwatch watch = Stopwatch.StartNew();
long frequency = Stopwatch.Frequency;
double nanosecPerTick = (1000.0 * 1000.0 * 1000.0) / frequency;
#region Test #1 with Stopwatch.ElapsedTicks
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
double elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks");
#endregion Test #1 with Stopwatch.ElapsedTicks
#region Test #2 with Stopwatch.ElapsedMilliseconds
startTick = watch.ElapsedMilliseconds;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedMilliseconds;
Display((int)(stopTick - startTick), "Stopwatch.ElapsedMilliseconds");
#endregion Test #2 with Stopwatch.ElapsedMilliseconds
#region Test #3 with Stopwatch.ElapsedTicks after Reset
watch.Stop();
watch.Reset();
watch.Start();
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks after Reset");
#endregion Test #3 with Stopwatch.ElapsedTicks after Reset
#region Test #4 with Stopwatch.ElapsedTicks and ThreadAffinity
Thread.BeginThreadAffinity();
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks setting ThreadAffinity");
Thread.EndThreadAffinity();
#endregion Test #4 with Stopwatch.ElapsedTicks and ThreadAffinity
#region Test #5 with Stopwatch.ElapsedTicks and ProcessorAffinity (and more)
const int affinity = 0x0001;
Process proc = Process.GetCurrentProcess();
proc.ProcessorAffinity = new IntPtr(affinity);
proc.PriorityClass = ProcessPriorityClass.High;
ProcessThreadCollection ptc = proc.Threads;
foreach (ProcessThread pt in ptc)
{
pt.IdealProcessor = 0;
pt.ProcessorAffinity = new IntPtr(affinity);
}
Thread.CurrentThread.Priority = ThreadPriority.Highest;
startTick = watch.ElapsedTicks;
Thread.Sleep(SleepTime);
stopTick = watch.ElapsedTicks;
elapsedSw = (stopTick - startTick) * nanosecPerTick;
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks setting ProcessorAffinity (and more)");
#endregion Test #5 with ProcessorAffinity and more
#region Test #6 with Syncronized object
elapsedSw = new SyncTimer().Go();
Display((int)(elapsedSw / 1000 / 1000), "Stopwatch.ElapsedTicks with Syncronized object");
#endregion Test #6 with Syncronized object
}
private static void Display(int milliseconds, string testName)
{
Console.WriteLine("{0:0000} ms for {1}", milliseconds, testName);
}
}
[Synchronization]
internal class SyncTimer : ContextBoundObject
{
[MethodImpl(MethodImplOptions.Synchronized)]
public double Go()
{
Stopwatch.StartNew();
long frequency = Stopwatch.Frequency;
double nanosecPerTick = (1000.0 * 1000.0 * 1000.0) / frequency;
long startTick = Stopwatch.GetTimestamp();
Thread.Sleep(StopWatchTest.SleepTime);
long stopTick = Stopwatch.GetTimestamp();
return (stopTick - startTick) * nanosecPerTick;
}
}
如果你对这篇内容有疑问,欢迎到本站社区发帖提问 参与讨论,获取更多帮助,或者扫码二维码加入 Web 技术交流群。
绑定邮箱获取回复消息
由于您还没有绑定你的真实邮箱,如果其他用户或者作者回复了您的评论,将不能在第一时间通知您!
发布评论
评论(7)
查看以下链接:
https: //connect.microsoft.com/VisualStudio/feedback/details/94083/stopwatch-returns-negative-elapsed-time
System.Diagnostics.Stopwatch 在 Elapsed... 属性中返回负数
秒表精度似乎存在问题,可能导致它返回负 Elapsed时代,而且时代也千差万别。如果您查看连接问题,大多数人都在谈论在虚拟机上看到该问题,这就是我们看到负的经过值问题的地方。
查看 QueryPerformanceCounter 文档,似乎暗示由于 BIOS 或硬件抽象层错误,该问题可能发生在多处理器系统上,但没有提供进一步的信息,也没有具体说明虚拟机。
至于这个问题的解决方案...我在谷歌上搜索了很多都没有找到。您可以忽略小于零的值,这并不理想,但在某些情况下是可行的。但这并不能解决您的问题 - 您如何知道哪些值无效?
希望这有所帮助。
Have a look at the following links:
https://connect.microsoft.com/VisualStudio/feedback/details/94083/stopwatch-returns-negative-elapsed-time
System.Diagnostics.Stopwatch returns negative numbers in Elapsed... properties
It seems there is an issue with Stopwatch accuracy which can lead to it returning negative Elapsed times, and also wildly varying times. If you look at the Connect issue, most of the people there are talking about seeing the issue on a virtual machine, which is where we are seeing the negative Elapsed values issue.
Looking at the QueryPerformanceCounter doc, it seems to imply this issue can happen on multiprocessor systems due to BIOS or hardware abstraction layer bugs, but gives no further information and is not specific about virtualised machines.
As for the solution to this problem... I haven't found one in a lot of googling. You can ignore values less than zero, which is not ideal but workable in some cases. But that doesn't solve your problem - how do you know what values are invalid?
Hope this helps somewhat.
我知道这是一个老问题,但我想在解决同样的问题后我应该提供 2 美分:
我开始按照@AllonGuralnek 的建议查看频率,它确实提供了以秒为单位的准确时间,但它放弃了剩余的时间我也想捕获毫秒。
不管怎样,经过多次来回却一无所获,我注意到 sw.Elapsed 有一个 Ticks 属性,这个属性为我提供了准确的刻度数,一旦转换回来,它就为我提供了准确的时间。
就代码而言,这就是我最终得到的结果:
运行测试时,调用:
sw.Elapsed.ToString()
: "00:00:11.6013029"sw.ElapsedTicks
: 返回 "40692243" 并在调用 < 时转换为 "00:00:04.0692243" code>TimeSpan.FromTicks(sw.ElapsedTicks).ToString() 不准确。sw.Elapsed.Ticks
:调用TimeSpan.FromTicks(sw.Elapsed.Ticks).ToString()< 时返回“116013029”并转换为“00:00:11.6013029” /code> 准确。
虽然我可能遗漏了一些东西,但我觉得 sw.ElaspedTicks 返回与 sw.Elapsed.Ticks 不同的值是没有意义的,所以如果有人想阐明这一点,请这样做,但从我的角度来看,我将其视为一个错误,如果不是,至少感觉非常不一致!。
注意:调用
sw.ElapsedTicks / Stopwatch.Frequency
返回11(即秒),但正如我所说,它会减少毫秒,这对我来说没有用。I know this an old question, but I thought I'd provide my 2 cents after struggling with the same problem:
I started looking at the Frequency as suggested by @AllonGuralnek and it did provide the accurate time in seconds, but it dropped the remaining milliseconds which I also wanted to capture.
Anyway, after a lot of back and forth and not getting anywhere with this, I noticed that the sw.Elapsed had a Ticks property and this one provided me with the accurate number of ticks and once converted back it provided me with an accurate time.
Code wise, this is what I ended up with:
When running a test, calling:
sw.Elapsed.ToString()
: "00:00:11.6013029"sw.ElapsedTicks
: Returns "40692243" and converts to "00:00:04.0692243" when callingTimeSpan.FromTicks(sw.ElapsedTicks).ToString()
which is inaccurate.sw.Elapsed.Ticks
: Returns "116013029" and converts to "00:00:11.6013029" when callingTimeSpan.FromTicks(sw.Elapsed.Ticks).ToString()
which accurate.While I may be missing something, I feel it doesn't make sense that sw.ElaspedTicks returns a different value than sw.Elapsed.Ticks, so if someone wants to shed some light on this, please do, but from my point of view, I see it as a bug and if not, at least it feels very inconsistent!.
NOTE: Calling
sw.ElapsedTicks / Stopwatch.Frequency
returns 11 (i.e. seconds) but as I said, it drops the milliseconds which is no use to me.您可以使用该代码来修复“Stopwatch.Elapsed”方法问题:
用法:
You can use that code to fix "Stopwatch.Elapsed" method problem:
Usage:
我得到这个:(
无法运行最后一个测试)
在 Linqpad 中带有 .NET4 的四核 i7 机器上。
我只倾向于使用 Stopwatch.ElapsedMilliseconds 但我从未见过它有任何奇怪的地方。听起来您的机器或虚拟化平台确实有问题。
I got this:
(Couldn't run the last test)
On a quad-core i7 machine with .NET4 in Linqpad.
I only ever tend to use Stopwatch.ElapsedMilliseconds but I've never seen anything odd about it. It does sound like there's something broken about your machine or virtualization platform.
似乎您在某些情况下使用了刻度计数。请记住,默认情况下,例如在现代 Windows 上,操作系统将节省 CPU。这意味着滴答计数和经过的时间不成线性比例。
我建议您尝试以最基本的形式使用 Stopwatch.ElapsedMilliseconds :
Seems like you're using Tick count in some cases. Remember that by default on modern Windows for example, the OS will save CPU. This means that the tick count and the time elapsed are not in linear proportion.
I suggest you try using the
Stopwatch.ElapsedMilliseconds
in the most basic form:如果秒表不起作用,您可以使用 Windows 上的
QueryPerformanceCounter
。请参阅 http://www.windojitsu.com/code/hirestimer.cs 上的这个小课程。 html
If the Stopwatch doesn't work, you can use the
QueryPerformanceCounter
on Windows.See this little class on http://www.windojitsu.com/code/hirestimer.cs.html
我相信你会在这里找到答案:
http://social. msdn.microsoft.com/Forums/en-US/netfxbcl/thread/eec73d6e-f597-4342-be48-5d2ce30202f0/
但有关更多详细信息和说明,另请参阅:
http://msdn.microsoft.com/en-us/magazine/cc163996.aspx
http://stackoverflow.com/questions/394020/stopwatch-accuracy
http://msdn.microsoft.com/en-us/library /system.diagnostics.stopwatch.aspx
I believe you'll find the answer here:
http://social.msdn.microsoft.com/Forums/en-US/netfxbcl/thread/eec73d6e-f597-4342-be48-5d2ce30202f0/
but for more detail and explanation see also:
http://msdn.microsoft.com/en-us/magazine/cc163996.aspx
http://stackoverflow.com/questions/394020/stopwatch-accuracy
http://msdn.microsoft.com/en-us/library/system.diagnostics.stopwatch.aspx