¿Cómo medir el rendimiento del código en .NET?

Question

estoy haciendo un poco de la evaluación comparativa rápida y sucia real en una sola línea de código C# usando DateTime:

long lStart = DateTime.Now.Ticks; 
// do something 
long lFinish = DateTime.Now.Ticks; 

El problema está en los resultados:

 
Start Time [633679466564559902] 
Finish Time [633679466564559902] 

Start Time [633679466564569917] 
Finish Time [633679466564569917] 

Start Time [633679466564579932] 
Finish Time [633679466564579932] 

... y así sucesivamente.

Dado que los tiempos de inicio y finalización son idénticos, Ticks obviamente no es lo suficientemente granular.

Entonces, ¿cómo puedo medir mejor el rendimiento?

Answer 1

La clase Stopwatch, disponible desde .NET 2.0, es la mejor manera de hacerlo. Es un contador de muy alto rendimiento con precisión de fracciones de milisegundos. Eche un vistazo al MSDN documentation, que es bastante claro.

EDITAR: Como se sugirió anteriormente, también es recomendable ejecutar su código varias veces para obtener un tiempo medio razonable.

Answer 2

Ejecute su código repetidamente. El problema parece ser que su código se ejecuta mucho más rápido que la granularidad de su instrumento de medición. La solución más simple para esto es ejecutar su código muchas, muchas veces (miles, tal vez millones) y luego calcular el tiempo promedio de ejecución.

Editar: Además, debido a la naturaleza de los compiladores de optimización actuales (y máquinas virtuales como el CLR y la JVM) puede ser muy engañoso medir la velocidad de ejecución de líneas únicas de código, ya que la medición puede influir en velocidad bastante Un enfoque mucho mejor sería perfilar todo el sistema (o al menos bloques más grandes) y verificar dónde están los cuellos de botella.

Answer 3

Utilice un generador de perfiles real como dotTrace.

Answer 4

Puede usar el Stopwatch, suponiendo que esté utilizando .NET 2.0 o posterior.

System.Diagnostics.Stopwatch.StartNew(); 

La clase Stopwatch también tiene ámbito público de sólo lectura IsHighResolution que le permitirá saber si el cronómetro se basa en un contador de rendimiento de alta resolución. Si no es así, se basa en el temporizador del sistema.

No estoy seguro de qué se necesita para que el cronómetro se base en el contador de rendimiento de alta resolución. Hay algunas llamadas a la API, pero supongo que si el cronómetro no usa una resolución alta, entonces la API probablemente no esté allí.

Answer 5

Véase la respuesta a Is DateTime.Now the best way to measure a function’s performance? para una explicación o leer mi blog post about high performance measurement

El problema es que DateTime tiene una resolución de aproximadamente 15 ms, no puede ser más precisa que eso. Cronómetro, sin embargo, puede.

Answer 6

Aquí es una buena escritura hacia el MSDN sobre cómo Implement a Continuously Updating, High-Resolution Time Provider for Windows

Aquí está la sample source code para el artículo (C++).

Answer 7

A veces puede ser mejor ver por qué necesita sincronizar la operación? ¿Corre lento? ¿O solo tienes curiosidad? La primera regla de optimización es "No lo hagas".Entonces, dependiendo de lo que realmente está midiendo, podría cambiar la opinión sobre qué herramienta es más adecuada para la tarea.

Answer 8

Simplemente para agregar a lo que otros ya han dicho sobre el uso de Cronómetro y medición de promedios.

Asegúrese de llamar a su método antes de realizar la medición. De lo contrario, medirá el tiempo necesario para compilar JIT también el código. Eso puede sesgar sus números de manera significativa.

Además, asegúrese de medir el código del modo de liberación ya que las optimizaciones están desactivadas de forma predeterminada para las compilaciones de depuración. Ajustar el código de depuración no tiene sentido.

Y asegúrese de estar midiendo lo que realmente quiere medir. Cuando las optimizaciones entran en juego, el compilador/compilador JIT puede reorganizar el código o eliminarlo por completo, por lo que puede terminar midiendo algo un poco diferente de lo previsto. Al menos eche un vistazo al código generado para asegurarse de que el código no se haya eliminado.

Dependiendo de lo que intente medir, tenga en cuenta que un sistema real acentuará el tiempo de ejecución de forma diferente a una aplicación de prueba típica. Algunos problemas de rendimiento están relacionados, p. cómo se recogen los objetos basura Estos problemas generalmente no aparecerán en una aplicación de prueba simple.

En realidad, el mejor consejo es medir sistemas reales con datos reales, ya que las pruebas de espacio aislado pueden ser muy imprecisas.

Answer 9

puedo encontrar estos útiles

http://accelero.codeplex.com/SourceControl/changeset/view/22633#290971 http://accelero.codeplex.com/SourceControl/changeset/view/22633#290973 http://accelero.codeplex.com/SourceControl/changeset/view/22633#290972

TickTimer es una copia reducida de cronómetro que comienza cuando se construyen y no apoya el reinicio. También le notifique si el hardware actual no soporta la sincronización de alta resolución (golondrinas Cronómetro este problema)

Así que este

var tickTimer = new TickTimer(); 
//call a method that takes some time 
DoStuff(); 
tickTimer.Stop(); 
Debug.WriteLine("Elapsed HighResElapsedTicks " + tickTimer.HighResElapsedTicks); 
Debug.WriteLine("Elapsed DateTimeElapsedTicks " + tickTimer.DateTimeElapsedTicks); 
Debug.WriteLine("Elapsed ElapsedMilliseconds " + tickTimer.ElapsedMilliseconds); 
Debug.WriteLine("Start Time " + new DateTime(tickTimer.DateTimeUtcStartTicks).ToLocalTime().ToLongTimeString()); 

dará salida a esta

Elapsed HighResElapsedTicks 10022886 
Elapsed DateTimeElapsedTicks 41896 
Elapsed ElapsedMilliseconds 4.18966178849554 
Start Time 11:44:58 

DebugTimer es un contenedor de TickTimer que escribirá el resultado en Debug. (Nota: es compatible con el patrón desechable)

Así que este

using (new DebugTimer("DoStuff")) 
{ 
    //call a method that takes some time 
    DoStuff(); 
} 

dará salida a esto a la ventana de depuración

DoStuff: Total 3.6299 ms 

IterationDebugTimer es para cronometrar el tiempo que se tarda en ejecutar una operación varias veces y escribe el resultado en Debug. También realizará una ejecución inicial que no está incluida para ignorar el tiempo de inicio.(Nota: es compatible con el patrón desechable)

Así que esta salida

int x; 
using (var iterationDebugTimer = new IterationDebugTimer("Add", 100000)) 
{ 
    iterationDebugTimer.Run(() => 
    { 
     x = 1+4; 
    }); 
} 

Will este artículo del proyecto

Add: Iterations 100000 
Total 1.198540 ms 
Single 0.000012 ms 

Answer 10

Este código muestra cómo utilizar el temporizador de alto rendimiento para medir la velocidad de ejecución de su código:

http://www.codeproject.com/KB/cs/highperformancetimercshar.aspx

Aquí se puede encontrar un número de código abierto de C# perfiladores:

http://csharp-source.net/open-source/profilers

Answer 11

más fácil de usar un perfilador como ANTS Performance Profiler, o uno de los otros que están disponibles.

Answer 12

Hice una extensión que devuelve milisegundos de tics.

public static int GetTotalRunningTimeInMilliseconds(this DateTime start) 
{ 
    var endTicks = DateTime.Now.Ticks - start.Ticks; 
    return TimeSpan.FromTicks(endTicks).Milliseconds; 
} 

Uso:

var start = DateTime.Now; 

//...your long running code here 

var endTime = start.GetTotalRunningTimeInMilliseconds(); 

Answer 13

muestra para Stopwatch clase

using System.Diagnostics; 
    ...... 
    ... 
    .. 
    Stopwatch sw = new Stopwatch(); 
    sw.Start(); 
    //Your Code Here 

    sw.Stop(); 
    Console.WriteLine("Elapsed={0}",sw.Elapsed); 

Answer 14

para medir el rendimiento con diferencia entre las mediciones que utilizo esta clase. La clase StopWatch no tiene el método Split.

/// <summary> 
/// Stopwatch like class that keeps track of timelapses. 
/// Probably low-res because of the usage of DateTime. 
/// </summary> 
public class ChronoMeter 
{ 
    /// <summary> 
    /// The name given when the Chronometer was constructed. 
    /// </summary> 
    public string Name { get; private set; } 
    /// <summary> 
    /// The moment in time Start was called. 
    /// </summary> 
    public DateTime Started { get; private set; } 

    /// <summary> 
    /// All time recordings are added to this list by calling Split and Stop. 
    /// </summary> 
    public List<ChronoRecord> Records { get; private set; } 

    private readonly Stopwatch _stopWatch = new Stopwatch(); 

    private bool _hasBeenStopped = false; 

    /// <summary> 
    /// Constrcutor 
    /// </summary> 
    /// <param name="pName">The name is used in logging</param> 
    /// <param name="pLoggingType">The type of logging appriate for the information yielded by this time recording.</param> 
    public ChronoMeter(string pName) 
    { 
     Name = pName; 
     Records = new List<ChronoRecord>(); 
    } 

    /// <summary> 
    /// Not calling Stop is bad practise. Therefore a little safety net zo the end is still recorderd. 
    /// Keep in mind that the garbase collector invokes the destructor, so the moment of time probably doesn't make much sense. 
    /// It is more to notify that you should have used Stop for the latest split. 
    /// </summary> 
    ~ChronoMeter() 
    { 
     if (!_hasBeenStopped) 
     { 
      Stop("Destructor safety net"); 
     } 
    } 

    /// <summary> 
    /// TimeElapsedSinceStart of a ChronoRecord is relative to the moment ChronoMeter was started by calling this function. 
    /// </summary> 
    public void Start() 
    { 
     _stopWatch.Start(); 
     Started = DateTime.Now; 
    } 

    /// <summary> 
    /// Splits the timerecording and add a record of this moment to the list of split records. 
    /// </summary> 
    /// <param name="pSplitName"></param> 
    public void Split(string pSplitName) 
    { 
     _stopWatch.Stop(); 
     var created = Started + _stopWatch.Elapsed; 
     var previousRecord = Records.LastOrDefault(); 
     Records.Add(new ChronoRecord(pSplitName, Started, created, previousRecord)); 
     _stopWatch.Start(); 
    } 

    /// <summary> 
    /// Indicates you are done and the records will be written to the log. 
    /// </summary> 
    public void Stop(string pSplitName) 
    { 
     Split(pSplitName); 
     _stopWatch.Stop(); 
     _hasBeenStopped = true; 
    } 

    public class ChronoRecord 
    { 
     public string Name { get; private set; } 
     public TimeSpan TimeElapsedSinceStart { get; private set; } 
     public TimeSpan TimeElapsedSincePrevious { get; private set; } 
     public DateTime Start { get; private set; } 
     public DateTime Created { get; private set; } 

     public ChronoRecord(string pName, DateTime pStartDateTime, DateTime pCreated, ChronoRecord pPreviousRecord=null) 
     { 
      if (pCreated == default(DateTime)) //Ignore DefaultDateTimeComparison 
      { 
       pCreated = DateTime.Now; 
      } 
      Created = pCreated; 
      Name = pName; 
      Start = pStartDateTime; 

      TimeElapsedSinceStart = Created - Start; 
      if (pPreviousRecord != null) 
      { 
       TimeElapsedSincePrevious = Created - pPreviousRecord.Created; 
      } 
      else 
      { 
       TimeElapsedSincePrevious = TimeElapsedSinceStart; 
      } 
     } 
    } 
} 

Answer 15

https://andreyakinshin.gitbooks.io/performancebookdotnet/content/science/microbenchmarking.html

https://github.com/PerfDotNet/BenchmarkDotNet

"De hecho, microbencmarking es muy difícil. Si una operación se lleva 10-100ns, la medición de la operación es un gran reto. Sugiero que usted utilice para sus puntos de referencia BenchmarkDotNet Es una biblioteca que puede ayudarlo a establecer un punto de referencia honesto y obtener mediciones con buena precisión. Por supuesto, puede escribir referencias propias sin necesidad de bibliotecas adicionales. En esta sección, hablamos sobre por qué es probablemente una mala idea y qué debería saber antes de comenzar ".

Answer 16

Otra opción es tener el código del temporizador insertado automáticamente con Fody. Esto hace que su código sea mucho más fácil de leer ya que separa sus preocupaciones transversales. Creo que esto está cerca de lo que se llama Aspect Oriented Programming, pero hecho en tiempo de compilación posterior.

Ver https://github.com/Fody/MethodTimer para el complemento fody que realiza el tiempo del método.

Citando el Léame:

Con un interceptor, en algún lugar de su montaje:

public static class MethodTimeLogger { 
    public static void Log(MethodBase methodBase, long milliseconds) 
    { 
    //Do some logging here 
    } 
} 

Su código,

public class MyClass 
{ 
    [Time] 
    public void MyMethod() 
    { 
     //Some code u are curious how long it takes 
     Console.WriteLine("Hello"); 
    } 
} 

se compila a este :

public class MyClass 
{ 
    public void MyMethod() 
    { 
     var stopwatch = Stopwatch.StartNew(); 
     try 
     { 
      //Some code u are curious how long it takes 
      Console.WriteLine("Hello"); 
     } 
     finally 
     { 
      stopwatch.Stop(); 
      MethodTimeLogger.Log(methodof(MyClass.MyMethod), stopwatch.ElapsedMilliseconds); 
     } 
    } 
} 

Answer 17

que he hecho un método muy simple que mide la velocidad de ejecución de un Action, que tiene para mí el beneficio que pueda volver a usarla cuando lo necesito, y cualquiera que sea el código que tengo que medir.

Para mí, un DateTime fue suficiente, pero es fácilmente adaptable desde DateTime a Stopwatch.

public static TimeSpan MeasureTime(Action action) 
{ 
    DateTime start = DateTime.Now; 

    if (action == null) 
    { 
     throw new ArgumentNullException("action"); 
    } 

    try 
    { 
     action(); 
    } 
    catch (Exception ex) 
    { 
     Debugger.Log(1, "Measuring",ex.ToString()); 
    } 

    return DateTime.Now - start; 
} 

---

Cómo usarlo ?:

private static void StressTest() 
{ 
    List<TimeSpan> tss = new List<TimeSpan>(); 

    for (int i = 0; i < 100; i++) 
    { 
     // here is the measuring: 
     var ts = MeasureTime(() => instance.Method("param1")); 

     tss.Add(ts); 
    } 

    Console.WriteLine("Max: {0}", tss.Max()); 
    Console.WriteLine("Min: {0}", tss.Min()); 
    Console.WriteLine("Avg: {0}", TimeSpan.FromMilliseconds(tss.Average(i => i.TotalMilliseconds))); 
} 

o:

var ts = MeasureTime(() => 
         { 
          // Some intensive stuff here 
          int a = 1; 

          // more here 
          int b = 2; 

          // and so on 
         });