Proximamente voy a hacer un comparativo de performance entre Entity Framework y Subsonic, así que se me ocurrió de una vez escribir este post sobre la manera correcta en que se debe medir el tiempo de ejecución de un cierto bloque de código utilizando C# y .NET.
La medición del tiempo se hace usando una instancia de la clase StopWatch, que se encuentra en el namespace de System.Diagnostics. La clase StopWatch provee un conjunto de métodos y propiedades que pueden ser usados para medir con alta precisión el tiempo transcurrido entre intervalos.
Los métodos disponibles sobre esta instancia serían:
- Start() – inicia el contador a partir del último lapso. La cuenta es acumulativa, es decir, si se verifica la propiedad ElapsedMilliseconds después de 4 llamadas a los métodos de Start y Stop, el tiempo desplegado será el acumulado de los 4 intervalos.
- Stop() – detiene momentaneamente el timer.
- Reset() – reinicia los valores almacenados del timer
Las propiedades disponibles, que usaríamos para desplegar el tiempo que tomó alguna rutina, serían:
- Elapsed – Regresa una instancia de tipo TimeSpan que determina el tiempo que ha transcurrido desde que se llamó al método Start() por primera vez.
- ElapsedMilliseconds – Regresa un valor de tipo long que indica los milisegundos transcurridos desde la primera vez que se llamó al método Start().
- ElapsedTicks – Regresa un valor de tipo long, que indica los Ticks que han pasado desde la primera vez que se llamó al método Start(). Nota importante respecto a esta propiedad: Los ticks de un StopWatch no son iguales a los ticks de un DateTime. En DateTime, cada tick representa un intervalo de 100 nanosegundos. En StopWatch, un tick representa un intervalo de tiempo equivalente a 1 segundo dividido entre la propiedad Frequency del StopWatch.
- IsRunning – determina si el timer está activo y contando Ticks.
Las propiedades IsHighResolution y Frequency no son propias de una instancia StopWatch, sino de la clase StopWatch.
IsHighResolution indica si el timer utilizado está basado en un contador de performance de alta resolución. Esto depende del procesador/arquitectura de la computadora en la que está corriendo el código
Frequency representa el numero de StopWatch ticks por segundo.
Ahora, un poco de código de ejemplo:
Console.WriteLine(string.Format(“IsHighResolution: {0}”, Stopwatch.IsHighResolution ? “Yes” : “No”));
Console.WriteLine(string.Format(“Frequency: {0}”, Stopwatch.Frequency));
Console.WriteLine(“———————-“);
var dos = “2”;
var suma = 0;
//Medir int.Parse
var timer = Stopwatch.StartNew();
for (var i = 1; i <= 1000; i++)
{
suma += int.Parse(dos) * i;
}
timer.Stop();
Console.WriteLine(string.Format("Suma: {0}", suma));
Console.WriteLine(string.Format("Elapsed para int.Parse: {0}", timer.Elapsed));
Console.WriteLine(string.Format("ElapsedMilliseconds para int.Parse: {0}", timer.ElapsedMilliseconds));
Console.WriteLine(string.Format("ElapsedTicks para int.Parse: {0}", timer.ElapsedTicks));
Console.WriteLine("----------------------");
suma = 0;
//Medir Convert.ToInt32()
timer = Stopwatch.StartNew();
for (var i = 1; i <= 1000; i++)
{
suma += Convert.ToInt32(dos) * i;
}
timer.Stop();
Console.WriteLine(string.Format("Suma: {0}", suma));
Console.WriteLine(string.Format("Elapsed para Convert.ToInt32: {0}", timer.Elapsed));
Console.WriteLine(string.Format("ElapsedMilliseconds para Convert.ToInt32: {0}", timer.ElapsedMilliseconds));
Console.WriteLine(string.Format("ElapsedTicks para Convert.ToInt32: {0}", timer.ElapsedTicks));
[/code]
da el siguiente resultado:
Midiendo intervalos de tiempo con la clase StopWatch
Como se puede apreciar, int.Parse es ligeramente más rapido que Convert.ToInt32().
De manera simplemente informativa…hay otra manera de medir intervalos de tiempo que mucha gente usa, y NO es correcto ni recomendable. Lo hacen asignando el valor de DateTime.Now a una variable de tipo DateTime y luego lo resta al valor de DateTime.Now en el momento que quieren dejar de medir.
Hay todavía otra manera similar al uso de DateTimes, que es usando la propiedad Environment.TickCount.Esto es incorrecto por tres razones:
1. Si existe una clase especializada para hacer esto en el framework, digase StopWatch, hay que usarla.
2. Environment.TickCount es signed (puede representar valores negativos también) lo cual implica que después de 25 dias, se va a entrar al rango negativo y se tendría que eliminar el bit del símbolo para poder hacer calculos correctos. Después de 50 dias, se llenarían todos los bits de la variable y la cuenta se reiniciaría. Ver discusión en StackOverflow.com donde se menciona esto.
3. En palabras del mismo Scott Hanselman, y mencionado en el mismo link de la razon #2: As an unrelated aside, if you DO use DateTime for Date-related math calculations, always use DateTime.UtcNow as DateTime.Now is susceptible to Daylight Savings Time…your calculations could be off by a hour, or worse, negative numbers.
Es decir, es muy facil que a la gente se le olvide que si va a cronometrar de esta manera, usar DateTimes para medir intervalos puede ser susceptible a los conocidos “horarios de verano”, que desfazan por temporadas el reloj por +- 1 hora. Cualquiera de las dos alternativas a StopWatch (DateTime o Environment.Ticks) es relativamente riesgosa para ser útil.
Links de Referencia:
Clase StopWatch @ MSDN
