.NET System.Diagnostics.Stopwatch issue (devuelve valores demasiado bajos)

Question

En mi computadora, el cronómetro devuelve valores demasiado bajos. Por ejemplo, 200 ms cuando especifiqué Thread.Sleep(1000). Se supone que el programa debe esperar 1 segundo. También probé con ManualResetEvent.WaitOne(1000) y obtuve los mismos resultados. Ambos framework 2.0 y 3.0 dan este extraño comportamiento. Estoy ejecutando Windows XP SP3 con .NET Framework 3.5 SP1.

Este es el resultado de mis pruebas (código de abajo):

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 archivo

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

// StopWatchTest.cs clase

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

Answer 1

I cree que encontrará la respuesta aquí: http://social.msdn.microsoft.com/Forums/en-US/netfxbcl/thread/eec73d6e-f597-4342-be48-5d2ce30202f0/

pero para más detalles y explicaciones ver también: 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

Answer 2

parece que estás usando recuento de paso en algunos casos. Recuerde que por defecto en Windows moderno, por ejemplo, el sistema operativo ahorrará CPU. Esto significa que el recuento de ticks y el tiempo transcurrido son no en proporción lineal.

le sugiero que intente utilizar el Stopwatch.ElapsedMilliseconds en la forma más básica:

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

Answer 3

si el cronómetro no funciona, puede utilizar el QueryPerformanceCounter en Windows.

Ver esta pequeña clase sobre http://www.windojitsu.com/code/hirestimer.cs.html

Answer 4

tengo esto:

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) 

(No se ha podido ejecutar la última prueba)

En una máquina i7 de cuatro núcleos con .NET4 en LINQPad .

Yo siempre suelo usar Stopwatch.ElapsedMilliseconds pero nunca he visto nada extraño al respecto. Parece que hay algo roto en su máquina o plataforma de virtualización.

Answer 5

Tener un vistazo a los siguientes enlaces:

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

System.Diagnostics.Stopwatch returns negative numbers in Elapsed... properties

Parece que hay un problema con la precisión de cronómetro que puede conducir a que devolver los tiempos transcurridos negativos, y los tiempos también varían ampliamente . Si nos fijamos en el problema de Connect, la mayoría de las personas que están hablando de ver el problema en una máquina virtual, que es donde estamos viendo el problema de los valores de Elapsed negativos.

En cuanto a QueryPerformanceCounter doc, parece implicar que este problema puede ocurrir en los sistemas multiprocesador debido a BIOS o errores de capa de abstracción de hardware, pero no proporciona más información y no es específico acerca de las máquinas virtualizadas.

En cuanto a la solución a este problema ... No he encontrado uno en una gran cantidad de Google. Puede ignorar valores menores que cero, lo que no es ideal pero viable en algunos casos. Pero eso no resuelve tu problema, ¿cómo sabes qué valores son inválidos?

Espero que esto ayude un poco.

Answer 6

Sé que esto una vieja pregunta, pero pensé que había proporciono mis 2 centavos después de luchar con el mismo problema:

empecé a buscar a la frecuencia según lo sugerido por @AllonGuralnek y lo hizo dar la hora exacta en segundos, pero dejó caer los milisegundos restantes que también quería capturar.

De todos modos, después de mucho ir y venir y no conseguir nada con esto, noté que sw.Elapsed tenía una propiedad Ticks y esta me proporcionó la cantidad precisa de tics y una vez convertida me proporcionó un tiempo preciso.

Código sabia, esto es lo que terminó con:

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

... DO WORK 

sw.Stop(); 

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

Cuando se ejecuta una prueba, llamando al:

• sw.Elapsed.ToString(): "00: 00: 11.6013029"

• sw.ElapsedTicks: devuelve "40692243" y se convierte a "00: 00: 04.0692243" al llamar al TimeSpan.FromTicks(sw.ElapsedTicks).ToString(), que es inexacto.

• sw.Elapsed.Ticks: Devuelve "116013029" y se convierte en "00: 00: 11.6013029" al llamar al TimeSpan.FromTicks(sw.Elapsed.Ticks).ToString() que es preciso.

Mientras yo pueda estar pasando algo, creo que no tiene sentido que sw.ElaspedTicks devuelve un valor diferente que sw.Elapsed.Ticks, así que si alguien quiere arrojar algo de luz sobre esto, por favor , pero desde mi punto de vista, lo veo como un error y si no, al menos se siente muy inconsistente.

NOTA: Llamada sw.ElapsedTicks/Stopwatch.Frequency declaraciones de 11 segundos (es decir), pero como he dicho, se deja caer los milisegundos que es inútil para mí.