2009-01-19 10 views
41

robię jakiś prawdziwy szybki i brudny benchmarkingu na jednej linii kodu C# przy użyciu DateTime:Jak mierzyć wydajność kodu w .NET?

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

Problem polega w wynikach:

 
Start Time [633679466564559902] 
Finish Time [633679466564559902] 

Start Time [633679466564569917] 
Finish Time [633679466564569917] 

Start Time [633679466564579932] 
Finish Time [633679466564579932] 

... i tak dalej.

Biorąc pod uwagę, że czas rozpoczęcia i zakończenia jest identyczny, kleszcze są oczywiście niewystarczająco ziarniste.

Jak mogę lepiej zmierzyć wydajność?

+0

proszę wskazać język –

+6

Jeśli kleszczy nie jest wystarczająco szczegółowa, nie będę się martwić za dużo o wydajności 8) – johnc

+0

możliwy duplikat [Benchmarking małych próbek kodu w C#, czy to wdrożenie może być ulepszone ved?] (http://stackoverflow.com/questions/1047218/benchmarking-small-code-samples-in-c-can-this-implementation-be-improved) – nawfal

Odpowiedz

54

Klasa, dostępna od .NET 2.0, jest najlepszym sposobem na to. Jest to bardzo wydajny licznik z dokładnością do ułamków milisekundy. Spójrz na MSDN documentation, co jest całkiem jasne.

EDYCJA: Zgodnie z wcześniejszymi sugestiami zaleca się również kilkakrotne uruchomienie kodu, aby uzyskać rozsądny średni czas.

+2

Możesz skorzystać z funkcji VS2015, w której zobaczysz czas, jaki upłynął między 2 punktami przerwania podczas debugowania: http://blogs.msdn.com/b /visualstudioalm/archive/2015/07/20/performance-and-diagnostic-tools-in-visual-studio-2015.aspx – Dave

11

Powtórz swój kod. Problem wydaje się, że twój kod wykonuje się dużo szybciej niż ziarnistość twojego przyrządu pomiarowego. Najprostszym rozwiązaniem jest wykonanie kodu wiele razy (tysiące, może miliony), a następnie obliczenie średniego czasu wykonania.

Edycja: Również ze względu na charakter obecnych kompilatorów optymalizujących (i maszyn wirtualnych, takich jak CLR i JVM) może być bardzo mylące mierzenie prędkości wykonywania pojedynczych linii kodu, ponieważ pomiar może wpływać na dość dużo. Znacznie lepszym rozwiązaniem byłoby profilowanie całego systemu (lub przynajmniej większych bloków) i sprawdzanie, gdzie znajdują się wąskie gardła.

5

Użyj prawdziwego profilera, takiego jak dotTrace.

4

Możesz użyć Stopwatch, zakładając, że używasz .NET 2.0 lub nowszego.

System.Diagnostics.Stopwatch.StartNew(); 

Klasa Stopwatch ma również tylko do odczytu pola publicznego IsHighResolution który pozwoli Ci wiedzieć, czy stoper jest na podstawie licznika wydajności wysokiej rozdzielczości. Jeśli nie, opiera się na czasomierzu systemowym.

Nie jestem pewien, co trzeba zrobić, aby stoper był oparty na liczniku wydajności o wysokiej rozdzielczości. Jest kilka wywołań API, ale sądzę, że jeśli stoper nie używa wysokiej rozdzielczości, to prawdopodobnie nie ma tam API.

0

Czasami najlepiej jest spojrzeć na to, dlaczego trzeba czas operacji? Czy działa wolno? A może jesteś ciekawy? Pierwszą zasadą optymalizacji jest "Nie rób tego".Tak więc, w zależności od tego, co faktycznie mierzysz, możesz zmienić zdanie na temat tego, które narzędzie najlepiej nadaje się do tego zadania.

+0

Oczywiście nie jest to coś, co wejdzie w kod produkcyjny. Po prostu coś, co muszę przetestować przed wdrożeniem "prawdziwego" kodu w produkcji. –

7

Wystarczy dodać do tego, co inni już powiedzieli na temat używania stopera i pomiaru średnich.

Upewnij się, że wywołasz swoją metodę przed pomiarem. W przeciwnym razie zmierzysz czas potrzebny na kompilację kodu JIT. To może znacznie przekręcić twoje liczby.

Upewnij się również, że mierzony jest kod trybu zwalniania, ponieważ optymalizacje są domyślnie wyłączone w przypadku kompilacji debugowania. Strojeniowy kod debugowania jest bezcelowy imho.

Upewnij się, że mierzysz to, co chcesz zmierzyć. Po uruchomieniu optymalizacji kompilator/kompilator JIT może zmienić kod lub usunąć go w całości, abyś mógł zmierzyć coś innego niż zamierzony. Przynajmniej spójrz na wygenerowany kod, aby upewnić się, że kod nie został usunięty.

W zależności od tego, co próbujesz zmierzyć, należy pamiętać, że prawdziwy system będzie inaczej podkreślał środowisko wykonawcze niż typowa aplikacja testowa. Niektóre problemy z wydajnością dotyczą np. jak obiekty są zbierane śmieci. Problemy te zwykle nie pojawiają się w prostej aplikacji testowej.

Właściwie najlepiej jest mierzyć rzeczywiste systemy z rzeczywistymi danymi, ponieważ testy piaskownicy mogą okazać się wysoce niedokładne.

8

znajdę te użyteczne

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 jest wycięte kopia stoper, który rozpoczyna się, gdy zbudowane i nie umożliwia ponowne uruchomienie. Będzie również powiadomi Cię, jeśli obecny sprzęt nie obsługuje wysokiej rozdzielczości rozrządu (stoper jaskółki ten problem)

Więc to

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()); 

wyjście będzie to

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

DebugTimer jest opakowaniem dla TickTimer które zapisze wynik do debugowania. (Uwaga: obsługuje jednorazowy wzór)

Więc to

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

wyjście to wola do okna debugowania

DoStuff: Total 3.6299 ms 

IterationDebugTimer jest dla taktowaniu jak długo to trwa, aby uruchomić operację wielokrotnie i zapisz wynik do debugowania. Wykona także początkowe uruchomienie, którego nie uwzględni, aby zignorować czas uruchamiania.(Uwaga: obsługuje jednorazowy wzór)

Więc to wyjście

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

Będzie to

Add: Iterations 100000 
Total 1.198540 ms 
Single 0.000012 ms 
0

najłatwiejszy w obsłudze profilera jak ANTS Performance Profiler, lub jeden z innych, które są dostępne.

+0

Zastrzeżenie: Pracuję dla Red Gate –

+0

i niewielka aktualizacja: ANTS nie jest bezpłatny, ceny zaczynają się od 400 USD. Stoper jest darmowy: P, ale przyznaję, ANTS to świetne narzędzie. – quetzalcoatl

0

Zrobiłem rozszerzenie, które zwraca milisekundy od znaczników.

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

Zastosowanie:

var start = DateTime.Now; 

//...your long running code here 

var endTime = start.GetTotalRunningTimeInMilliseconds(); 
3

Przykładowy Stopwatch klasy

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

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

do pomiaru skuteczności z różnicy pomiarów korzystać z tej klasy. Klasa StopWatch nie ma metody 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; 
      } 
     } 
    } 
} 
+1

Przykłady użycia sprawiłyby, że lepiej byłoby ocenić użyteczność tej klasy. – nawfal

3

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

https://github.com/PerfDotNet/BenchmarkDotNet

„Rzeczywiście, microbencmarking jest bardzo trudne. Jeśli operacja trwa 10-100ns pomiar praca jest dużym wyzwaniem. Proponuję użyć BenchmarkDotNet dla swoich benchmarków Jest to biblioteka, która może pomóc ci w dokonaniu uczciwego testu porównawczego i uzyskać pomiary z dużą dokładnością Oczywiście możesz napisać własny test porównawczy bez dodatkowych bibliotek W tej sekcji mówimy o tym, dlaczego to prawdopodobnie zły pomysł i co ty powinien wiedzieć przed startem. "

1

Inną opcją jest automatyczne wprowadzenie kodu timera z numerem Fody. Dzięki temu Twój kod jest znacznie łatwiejszy do odczytania, ponieważ oddziela twoje przekrojowe kwestie. Myślę, że jest to zbliżone do tego, co nazywa się Aspect Oriented Programming, ale wykonane w czasie po kompilacji.

Patrz: https://github.com/Fody/MethodTimer dla dodatku fody, który wykonuje taktowanie metod.

Cytując z Readme:

Z kolektora, gdzieś w swoim zespole:

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

kodzie

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

jest kompilowany do tego :

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

Zrobiłem bardzo prosty sposób, który mierzy prędkość Zawarcie Action, który ma dla mnie tę zaletę, że mogę używać go zawsze, gdy jest to potrzebne, i cokolwiek kod mam do zmierzenia.

Dla mnie wystarczyło DateTime, ale można go łatwo dostosować z DateTime do 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; 
} 

Jak używać ?:

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

lub:

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

          // more here 
          int b = 2; 

          // and so on 
         });