Ошибка .NET System.Diagnostics.Stopwatch(слишком низкие значения)

На моем компьютере секундомер возвращает значения слишком низко. Например, 200 мс, когда я указал Thread.Sleep(1000). Предполагается, что программа будет ждать 1 секунду. Я также тестировал с помощью ManualResetEvent.WaitOne(1000) и получил те же результаты. Оба варианта 2.0 и 3.0 дают это странное поведение. Я запускаю Windows XP SP3 с .NET Framework 3.5 SP1.

Вот результат моих тестов (код ниже):

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

class Program
{
    static void Main(string[] args)
    {
        StopWatchTest.Go();
        Console.WriteLine("Done!");
        Console.ReadLine();
    }
}

//Класс StopWatchTest.cs

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;
    }
}

Ответ 1

Посмотрите на следующие ссылки:

https://connect.microsoft.com/VisualStudio/feedback/details/94083/stopwatch-returns-negative-elapsed-time

System.Diagnostics.Stopwatch возвращает отрицательные числа в свойствах Elapsed...

Кажется, что существует проблема с точностью секундомера, которая может привести к возврату отрицательных истекших времен, а также к разным временам. Если вы посмотрите на проблему Connect, большинство людей там говорят о проблеме на виртуальной машине, в которой мы видим отрицательные проблемы с истекшими значениями.

Глядя на QueryPerformanceCounter doc, похоже, эта проблема может возникнуть в многопроцессорных системах из-за ошибок уровня BIOS или аппаратных абстракций, но не дает никакой дополнительной информации и не относится к виртуализированным машинам.

Что касается решения этой проблемы... Я не нашел ее во многих поисковых системах. Вы можете игнорировать значения, меньшие нуля, что в некоторых случаях не является идеальным, но может быть полезным. Но это не решает вашу проблему - как вы знаете, какие значения недействительны?

Надеюсь, что это поможет.

Ответ 2

Я получил это:

1000 ms for DateTime.Now.Ticks
0999 ms for Stopwatch.ElapsedTicks
1000 ms for Stopwatch.ElapsedMilliseconds
0999 ms for Stopwatch.ElapsedTicks after Reset
0999 ms for Stopwatch.ElapsedTicks setting ThreadAffinity
0999 ms for Stopwatch.ElapsedTicks setting ProcessorAffinity (and more)

(Не удалось запустить последний тест)

На четырехъядерной машине i7 с .NET4 в Linqpad.

Я только когда-либо склонен использовать Stopwatch.ElapsedMilliseconds, но я никогда не видел ничего странного в этом. Похоже, что что-то сломалось на вашей машине или платформе виртуализации.

Ответ 3

Я знаю этот старый вопрос, но я думал, что предоставил бы свои 2 цента после борьбы с одной и той же проблемой:

Я начал смотреть на частоту, как было предложено @AllonGuralnek, и это обеспечило точное время в секундах, но оно опустило оставшиеся миллисекунды, которые я также хотел захватить.

Во всяком случае, после многого назад и вперед и никуда не денусь, я заметил, что у sw.Elapsed есть свойство Ticks, и это обеспечило мне точное количество тиков, и после того, как оно было переведено обратно, оно предоставило мне точное время.

Код мудрый, вот что я закончил:

Stopwatch sw = new Stopwatch();
sw.Start();

... DO WORK

sw.Stop();

long elapsedTicks = sw.Elapsed.Ticks;
Debug.WriteLine(TimeSpan.FromTicks(elapsedTicks).ToString());

При запуске теста вызов:

sw.Elapsed.ToString(): "00: 00: 11.6013029"
sw.ElapsedTicks: Возвращает "40692243" и преобразуется в "00: 00: 04.0692243" при вызове TimeSpan.FromTicks(sw.ElapsedTicks).ToString(), который является неточным.
sw.Elapsed.Ticks: Возвращает "116013029" и конвертируется в "00: 00: 11.6013029" при вызове TimeSpan.FromTicks(sw.Elapsed.Ticks).ToString(), который является точным.

Хотя мне может что-то не хватает, я чувствую, что не имеет смысла, что sw.ElaspedTicks возвращает другое значение, чем sw.Elapsed.Ticks, поэтому, если кто-то хочет пролить свет на это, пожалуйста, сделайте это, но из моего Я считаю, что это ошибка, а если нет, по крайней мере, это кажется очень непоследовательным!

ПРИМЕЧАНИЕ. Вызов sw.ElapsedTicks / Stopwatch.Frequency возвращает 11 (то есть секунды), но, как я уже сказал, он отключает миллисекунды, которые мне не подходят.

Ответ 4

Похоже, вы используете количество тиков в некоторых случаях. Помните, что по умолчанию в современных Windows, например, ОС будет экономить процессор. Это означает, что количество проходов и время не соответствуют линейной пропорции.

Я предлагаю вам попробовать использовать Stopwatch.ElapsedMilliseconds в самой базовой форме:

var sw = new Stopwatch();
sw.Start();
Thread.Sleep(1000);
var elpased = sw.Elapsed;

Ответ 5

Если секундомер не работает, вы можете использовать QueryPerformanceCounter в Windows.

Смотрите этот маленький класс на http://www.windojitsu.com/code/hirestimer.cs.html

Ответ 6

Я верю, что вы найдете ответ здесь: 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/info/394020/stopwatch-accuracy http://msdn.microsoft.com/en-us/library/system.diagnostics.stopwatch.aspx