Die Leistungsmessung von ASP.NET MVC 3

Question

Ich habe einen JSON-Service in ASP.NET MVC 3 erstellt und möchte die Ausführungszeit der Aktionen in meiner Anwendung messen können (ich möchte, dass langsame Aktionen automatisch protokolliert werden).

Deshalb sah das großartig aus; http://coderjournal.com/2010/10/timing-the-execution-time-of-your-mvc-actions/ (Es wurde auch hier auf Stack Overflow erwähnt)

Das Problem ist, dass ich mit dieser Methode Messungen bekomme, die FALSCH sein MÜSSEN; Ich habe eine weitere Stoppuhr hinzugefügt, die direkt am Anfang der Aktion startet und kurz vor dem Return endet.

Beispiel:

• Stoppuhr innerhalb der Methode => 10ms (das Serialisieren nach JSON ist hier ausgelassen, daher kann ich verstehen, dass es kürzer ist als in der Realität)
• Stoppuhr-Attribut (oben stehender Code) => 676ms
• Firefox gibt an, dass die Anfrage => 70ms dauerte.

Ich glaube, dass Firefox hier die richtige Zeit hat (aber es beinhaltet den Download, also ist es etwas größer), aber ich möchte verstehen, warum der Attribut-Code nicht funktioniert, irgendwelche Ideen dazu?

Answer 1

Dies könnte möglicherweise nicht der Grund dafür sein, warum es eine lange Ausführungszeit anzeigt, aber dieses Attribut funktioniert nicht korrekt mit mvc 3, wenn Sie mehrere Anfragen gleichzeitig haben.

In früheren Versionen von ASP.NET MVC werden Aktionsfilter pro Anfrage erstellt, außer in ein paar Fällen. Dieses Verhalten war nie ein garantiertes Verhalten, sondern nur ein Implementierungsdetail und der Vertrag für Filter war, sie als zustandslos zu betrachten. In ASP.NET MVC 3 werden Filter aggressiver zwischengespeichert. Daher können benutzerdefinierte Aktionsfilter, die Instanzzustand unsachgemäß speichern, defekt sein.

Ich würde empfehlen, einen neuen Stoppuhr in OnActionExecuting zu instantiieren und sie in HttpContext.Current.Items zu speichern - dann können Sie sie in OnActionExecuted abrufen und das Ergebnis ausdrucken.

Answer 2

Eine genauere Herangehensweise zusätzlich zur Antwort https://stackoverflow.com/a/5823555/504082 besteht darin, die OnResultExecuted-Überschreibung am Ende der Ausführung des Codes zu verwenden. Wenn Sie zurückkehren

ActionResponse.Success(arr.Select(x => func(x)).ToJson();

d.h. eine Art faule LINQ-Anweisung als Ergebnis Ihrer Aktion, wird sie nach der Ausführung der Aktion berechnet (die Ausführung der Funktion 'func' wird nicht zur Ausführungszeit der Aktion gezählt). Ich hatte diesen fiesen Bug und konnte nicht herausfinden, warum die "Ausführungszeit" meiner Aktion 100 ms beträgt, obwohl die Webanforderung 10 Sekunden dauert. Modifizierter Code unten.

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Web;
using System.Web.Mvc;

namespace SW
{
    public class StopwatchAttribute : ActionFilterAttribute
    {
        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            var stopwatch = new Stopwatch();
            filterContext.HttpContext.Items["Stopwatch"] = stopwatch;

            stopwatch.Start();
        }

        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            var stopwatch = (Stopwatch)filterContext.HttpContext.Items["Stopwatch"];
            stopwatch.Stop();

            var httpContext = filterContext.HttpContext;
            var response = httpContext.Response;

            response.AddHeader("X-Runtime", stopwatch.Elapsed.TotalMilliseconds.ToString());
        }
    }
}

Answer 3

Warum sehen Sie sich nicht das Seitenperformance-Modul von Rhino Commons an?

Answer 4

Sieht aus, als wärst du um eine Größenordnung daneben. Bist du sicher, dass du das Ergebnis richtig liest? Versuche die Stopwatch.ElapsedMilliseconds Eigenschaft zu verwenden.