Comment mesurer les performances du code dans .NET?

Je fais de la comparaison rapide sur une seule ligne de code C # avec DateTime:

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

Le problème réside dans les résultats:

 Heure de début [633679466564559902]
 Heure de fin [633679466564559902]

 Heure de début [633679466564569917]
 Heure de fin [633679466564569917]

 Heure de début [633679466564579932]
 Heure de fin [633679466564579932]

…etc.

Étant donné que les heures de début et de fin sont identiques, Ticks n’est évidemment pas assez granulaire.

Alors, comment puis-je mieux mesurer les performances?

La classe Stopwatch , disponible depuis .NET 2.0, constitue le meilleur moyen d’y parvenir. C’est un compteur très performant précis à des fractions de milliseconde. Jetez un coup d’oeil à la documentation MSDN , qui est assez claire.

EDIT: Comme suggéré précédemment, il est également conseillé d’exécuter votre code plusieurs fois afin d’obtenir un temps moyen raisonnable.

Exécutez votre code à plusieurs resockets. Le problème semble être que votre code s’exécute beaucoup plus rapidement que la granularité de votre instrument de mesure. La solution la plus simple consiste à exécuter votre code plusieurs fois (des milliers, voire des millions), puis à calculer le temps d’exécution moyen.

Edit: En raison de la nature des compilateurs d’optimisation actuels (et des machines virtuelles telles que le CLR et la JVM), il peut être très trompeur de mesurer la vitesse d’exécution de lignes de code uniques, car la mesure peut influencer beaucoup la vitesse . Une approche bien meilleure consisterait à profiler l’ensemble du système (ou au moins des blocs plus grands) et à vérifier où se trouvent les goulots d’étranglement.

Je trouve ces utiles

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 est une copie réduite du chronomètre qui démarre lorsqu’il est construit et ne prend pas en charge le redémarrage. Il vous informera également si le matériel actuel ne prend pas en charge la synchronisation haute résolution (Stopwatch avale ce problème)

Donc ça

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

va sortir ce

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

DebugTimer est un wrapper pour TickTimer qui écrira le résultat à Debug. (note: il supporte le modèle jetable)

Donc ça

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

va sortir cela à la fenêtre de débogage

 DoStuff: Total 3.6299 ms 

IterationDebugTimer sert à chronométrer le temps nécessaire à l’exécution d’une opération plusieurs fois et à écrire le résultat dans Debug. Il effectuera également une première exécution qui n’est pas incluse pour ignorer le temps de démarrage. (note: il supporte le modèle jetable)

Donc ça

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

Va sortir ce

 Add: Iterations 100000 Total 1.198540 ms Single 0.000012 ms 

Juste pour append à ce que d’autres ont déjà dit à propos de l’utilisation du chronomètre et de la mesure des moyennes.

Assurez-vous d’appeler votre méthode avant de mesurer. Sinon, vous mesurerez également le temps nécessaire pour comstackr le code. Cela peut fausser vos chiffres de manière significative.

Veillez également à mesurer le code du mode de publication lorsque les optimisations sont désactivées par défaut pour les versions de débogage. Le réglage du code de débogage est sans intérêt.

Et assurez-vous de mesurer ce que vous voulez réellement mesurer. Lorsque les optimisations sont lancées, le compilateur / compilateur JIT peut réorganiser le code ou le supprimer complètement, de sorte que vous pouvez finir par mesurer quelque chose de différent de ce qui est prévu. Regardez au moins le code généré pour vous assurer que le code n’a pas été supprimé.

En fonction de ce que vous essayez de mesurer, gardez à l’esprit qu’un système réel mettra l’accent sur l’exécution différemment d’une application de test classique. Certains problèmes de performance sont liés, par exemple, à la manière dont les objects sont collectés. Ces problèmes n’apparaissent généralement pas dans une application de test simple.

En fait, le meilleur conseil est de mesurer les systèmes réels avec des données réelles, car les tests de sandbox peuvent s’avérer très imprécis.

Utilisez un vrai profileur tel que dotTrace.

Vous pouvez utiliser le Stopwatch en supposant que vous utilisez .NET 2.0 ou une version plus récente.

 System.Diagnostics.Stopwatch.StartNew(); 

La classe Stopwatch a également un champ public en lecture seule IsHighResolution qui vous indiquera si le chronomètre est basé sur un compteur de performance haute résolution. Si ce n’est pas le cas, il est basé sur la timer du système.

Je ne suis pas sûr de ce qu’il faut pour que le chronomètre repose sur un compteur de performance à haute résolution. Il y a des appels API, mais je pense que si le chronomètre n’utilise pas une résolution élevée, alors l’API n’est probablement pas là.

Voir la réponse à Est DateTime.Maintenant le meilleur moyen de mesurer les performances d’une fonction? pour une explication ou lire mon blog sur la mesure de haute performance

Le problème est que DateTime a une résolution d’environ 15 ms, il ne peut pas être plus précis que cela. Chronomètre, cependant, peut.

Voici une belle description sur le MSDN sur la façon d’ implémenter un fournisseur de temps haute résolution en continu pour Windows.

Voici le code source de l’article (C ++).

Échantillon pour la classe Stopwatch

  using System.Diagnostics; ...... ... .. Stopwatch sw = new Stopwatch(); sw.Start(); //Your Code Here sw.Stop(); Console.WriteLine("Elapsed={0}",sw.Elapsed); 

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

https://github.com/PerfDotNet/BenchmarkDotNet

“En effet, le microbencmarking est très difficile. Si une opération prend entre 10 et 100ns, la mesure des opérations est un grand défi. Je vous suggère d’utiliser BenchmarkDotNet pour vos tests. C’est une bibliothèque qui vous aide à faire des tests bonne précision. Bien sûr, vous pouvez écrire votre propre benchmark sans bibliothèques supplémentaires. Dans cette section, nous expliquons pourquoi c’est probablement une mauvaise idée et ce que vous devez savoir avant de commencer. ”

Cet article de projet de code montre comment utiliser le minuteur haute performance pour mesurer la vitesse d’exécution de votre code:

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

Vous trouverez ici un certain nombre de profileurs C # open source:

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

Une autre option consiste à insérer automatiquement le code temporel avec Fody . Cela rend votre code beaucoup plus facile à lire car il sépare vos préoccupations transversales. Je pense que cela se rapproche de ce qu’on appelle la programmation orientée aspect , mais effectuée après la compilation.

Voir https://github.com/Fody/MethodTimer pour l’addon fody qui effectue le minutage de la méthode.

Citant le fichier Lisez-moi:

Avec un intercepteur, quelque part dans votre assemblée:

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

Votre code,

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

Est compilé à ceci:

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

Le Stopwatch style jetable me Stopwatch mieux.

 class VWatch : IDisposable { Stopwatch watch = new Stopwatch(); public VWatch() { this.watch.Start(); } public void Dispose() { this.watch.Stop(); Console.WriteLine("Finished. Elapsed={0}", this.watch.Elapsed); } } 

Et alors:

 using (new VWatch()) { /// do something for time measurement } 

Parfois, il peut être préférable d’examiner pourquoi vous devez chronométrer l’opération? Est-ce qu’il tourne lentement? Ou êtes-vous juste curieux? La première règle de l’optimisation est “Don’t do it”. Ainsi, en fonction de ce que vous mesurez réellement, vous pouvez modifier l’opinion sur l’outil le mieux adapté à la tâche.

Plus facile d’utiliser un profileur comme ANTS Performance Profiler , ou l’un des autres disponibles.

J’ai fait une extension qui renvoie des millisecondes à partir des ticks.

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

Usage:

  var start = DateTime.Now; //...your long running code here var endTime = start.GetTotalRunningTimeInMilliseconds(); 

J’ai fait une méthode très simple qui mesure la vitesse d’exécution d’une action , ce qui a pour moi l’avantage de pouvoir la réutiliser quand j’en ai besoin et quel que soit le code à mesurer.

Pour moi, un DateTime était suffisant, mais il est facilement adaptable de DateTime à 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.ToSsortingng()); } return DateTime.Now - start; } 

Comment l’utiliser?:

 private static void StressTest() { List tss = new List(); 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))); } 

ou:

 var ts = MeasureTime(() => { // Some intensive stuff here int a = 1; // more here int b = 2; // and so on }); 

Pour mesurer les performances avec la différence entre les mesures, j’utilise cette classe. La classe StopWatch n’a pas la méthode Split .

 ///  /// Stopwatch like class that keeps track of timelapses. /// Probably low-res because of the usage of DateTime. ///  public class ChronoMeter { ///  /// The name given when the Chronometer was constructed. ///  public ssortingng Name { get; private set; } ///  /// The moment in time Start was called. ///  public DateTime Started { get; private set; } ///  /// All time recordings are added to this list by calling Split and Stop. ///  public List Records { get; private set; } private readonly Stopwatch _stopWatch = new Stopwatch(); private bool _hasBeenStopped = false; ///  /// Constrcutor ///  /// The name is used in logging /// The type of logging appriate for the information yielded by this time recording. public ChronoMeter(ssortingng pName) { Name = pName; Records = new List(); } ///  /// 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. ///  ~ChronoMeter() { if (!_hasBeenStopped) { Stop("Destructor safety net"); } } ///  /// TimeElapsedSinceStart of a ChronoRecord is relative to the moment ChronoMeter was started by calling this function. ///  public void Start() { _stopWatch.Start(); Started = DateTime.Now; } ///  /// Splits the timerecording and add a record of this moment to the list of split records. ///  ///  public void Split(ssortingng pSplitName) { _stopWatch.Stop(); var created = Started + _stopWatch.Elapsed; var previousRecord = Records.LastOrDefault(); Records.Add(new ChronoRecord(pSplitName, Started, created, previousRecord)); _stopWatch.Start(); } ///  /// Indicates you are done and the records will be written to the log. ///  public void Stop(ssortingng pSplitName) { Split(pSplitName); _stopWatch.Stop(); _hasBeenStopped = true; } public class ChronoRecord { public ssortingng 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(ssortingng 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; } } } }