Requestdauer mit einem HttpModule und Response.Filter ausgeben
Auf die Frage hin von Kristof auf der ASP.NET Zone, habe ich noch eine schönere und genauere Lösung gesucht, als sich in die Render Methode einer Seite einzuhängen.
Gefordert war die Anzeige von der Dauer des gesamten Requests (Von BeginRequest bis EndRequest, in Ereignissen gesprochen).
Zu lösen wäre dies einerseits, indem man sich in den BeginReques Event auf Applikatinonsebene einhängt (HttpModule oder Global.asax), und zusätzlich die Ausgabe auch dort an den bestehenden Response anhängt (Http Antwort).
Problem hierbei ist aber, das diese Ausgabe nach "</html>" folgt und deswegen nur für ein Logging interessant und brauchbar wäre.
Es geht zwar auch die Ausgabe der Zeit vor dem Rendern der Basisklasse (base.Render()), aber dann ist die Zeit des Renderns nicht miteinberechnet. Also auch nicht eine wirklich praktikable Lösung.
Schlussendlich kam mir dann die Idee, einen Platzhalter (Text) zu verwenden, und diesen dann am Schluss zu ersetzen.
Bspw (irgendwo im Text der ASPX Seite bzw. Masterpage): "{ExecutionTime}".
Diesen kann dann einfach _nach_ dem Rendern in der Master- oder Page per <String>.Replace(... durch den Wert (Zeit in Milisekunden) ausgetauscht werden.
Das geht wunderbar, aber wir haben eine starke Koppelung bzw. Miteinbeziehung der Master- / Page selber.
D.h. die Render Methode der Masterpage(s) oder einer jeweiligen Basisklasse für die Seiten müsste immer überschrieben werden.
Hier kommt das HttpModul ins Spiel.
Ich habe hier schon früher vom HttpHandler gesprochen und auch davon das die Page Klasse (Also die Klasse für eine ASPX Seite), neben einem Control auch einen HttpHandler darstellt (Implementation des IHttpHandler Interfaces).
Ein Handler ist die ausführende Instanz vom Typ IHttpHandler für einen Request, siehe meine früheren Postings.
Hingegen ein HttpModul ist ein Teil in der ASP.NET Pipeline, der sich durch den ganzen Request zieht.
D.h. die HttpModule hängen sich in den gesamten Zyklus ein und bieten dafür auch eine schöne Reihe an Events an.
Man könnte auch behaupten, das ein HttpModul eine modulare (Wie der Name schon sagt) Global.asax ist.
Wobei Global.asax global wirkt und auch nur einmal vorhanden sein kann.
Mehr Infos zur Arbeitsweise von ASP.NET findet ihr auf Rick Strahls (ASP.NET MVP) Website: http://www.west-wind.com/presentations/howaspnetworks/howaspnetworks.asp
Module können mehrere vorhanden sein, sowie auch beliebig ausgetauscht werden können (solange keine Referenzierung darauf im eigentlichen Anwendungscode besteht).
So, genug abgeschweift. Mehr Informationen zu HttpModules selber findet ihr unter anderem in folgenden Links:
Nun zum eigentlichen Thema. Es sieht so aus, als wäre das HttpModul dazu geschaffen, uns bei unserem Problem zu helfen.
Im BeginRequest Event kann die aktuelle Zeit (oder aber auch Ticks, oder ein genauerer Timer) in den aktuellen HttpContext geschrieben werden.
<HttpContext>.Items ist eine Auflistung von Objekten die über den ganzen Request Zyklus gültig sind und von überall erreichbar sind.
Im EndRequest Event müsste man jetzt die aktuelle Response auslesen, verändern und neu zuweisen.
Die schlägt aber fehl, weil die <HttpContext>.Response.Output Eigenschaft schreibgeschützt ist, und sich das darin befindliche Objekt vom Typ "TextWriter" auch im Schreibgeschützten Modus befindet.
Hier gibt es aber auch eine schöne Lösung, um das Ziel zu erreichen, den Outputstream zu verändern.
Wir müssen uns in das geeignete Event "ReleaseRequestState" einhängen, und dort einen Response Filter in der Pipeline zu registrieren. (Siehe: http://aspnetresources.com/articles/HttpFilters.aspx)
ResponseFilter sind nach dem Decorator Design Pattern (Dekorator Entwurfsmuster) in ASP.NET implementiert. Zu Entwurfsmustern, auch zum Decorator gibts später in diesem Blog bald mehr Infos.
Für eine ResponseFilter Implementation muss von der Klasse "Stream" abgeleitet, und einige Eigenschaften / Methoden überschrieben werden.
In Kürze setzen wir aus einem Buffer jeweils den gesamten Output als Stringform zusammen und tauschen dann den Platzhalter mit dem Wert der Zeitdifferenz (Start / Aktuelle Zeit) aus.
Nach der .Write() Methode des ResponseFilters werden die Methoden .Flush(), .Close() und .Dispose vom aktuellen Stream ausgeführt, und anschliessend das EndRequest gefeuert, das heisst das wir das Ziel erreicht haben, die Zeitdifferenz von BeginRequest und EndRequest zu protokollieren und in die Seite zu schreiben.
Folgend die Implementierung des HttpModules sowie auch des Response Filters.
Viel Spass damit, ich freue mich auf jegliche Kommentare!
namespace pb.Web.HttpModules
{
/// <summary>
/// Stellt ein HttpModule dar, das die Startzeit
/// in BeginRequest im HttpContext speichert,
/// und daraufhin einen Filter registriert,
/// um die Zeitdifferenz zwischen Begin- und EndRequest
/// mithilfe eines Platzhalters auf der Seite auszugeben.
/// </summary>
public class RequestTimeModule : IHttpModule
{
#region IHttpModule Members
/// <summary>
/// Methode um benötigte Eventhandler zu registrieren.
/// </summary>
/// <param name="context">Aktueller HttpContext</param>
public void Init(HttpApplication context) {
context.BeginRequest += context_BeginRequest;
context.ReleaseRequestState += context_ReleaseRequestState;
}
/// <summary>
/// Wird beim Begin jedes Requests gefeuert
/// (Achtung: Je nach Version und Konfiguration
/// des benutzten Webservers, wird dieser Event nicht
/// bei jeder Resource gefeuert.
///
/// Speichert die aktuelle- bzw. Start-Zeit im HttpContext.
/// </summary>
/// <param name="sender">Aktuelle HttpApplication</param>
/// <param name="e">EventArgs</param>
void context_BeginRequest(object sender, EventArgs e) {
HttpApplication app = sender as HttpApplication;
app.Context.Items.Add("beginRequestTime", DateTime.Now);
}
// Wird vor EndRequest ausgelöst (Passender Zeitpunkt um Filter
// zu registrieren.
void context_ReleaseRequestState(object sender, EventArgs e) {
HttpApplication app = (HttpApplication)sender;
HttpResponse response = app.Context.Response;
// Wenn es sich beim aktuellen Handler um eine
// ASPX Seite handelt, Filter anwenden.
if (app.Context.CurrentHandler is Page)
response.Filter = new ExecutionTimeReplaceFilter(response.Filter);
}
public void Dispose() {}
#endregion
}
/// <summary>
/// Stellt einen Filter dar, der den Platzhalter
/// "{ExecutionTime}" zur passenden Zeit gegen einen Wert erstetzt,
/// der im aktuellen HttpContext zu finden ist.
/// </summary>
public class ExecutionTimeReplaceFilter : Stream {
private Stream _responseStream;
private StringBuilder _responseHtml;
private long _position;
public ExecutionTimeReplaceFilter(Stream inputStream) {
this._responseStream = inputStream;
this._responseHtml = new StringBuilder();
}
#region Overriden Properties
public override bool CanRead {
get { return true; }
}
public override bool CanSeek {
get { return true; }
}
public override bool CanWrite {
get { return true; }
}
public override long Position {
get { return this._position; }
set { this._position = value; }
}
#endregion
#region Overriden Methods
public override void Close() {
this._responseStream.Close();
}
public override void Flush() {
this._responseStream.Flush();
}
public override long Length {
get { return 0; }
}
public override long Seek(long offset, SeekOrigin origin) {
return this._responseStream.Seek(offset, origin);
}
public override void SetLength(long length) {
this._responseStream.SetLength(length);
}
public override int Read(byte[] buffer, int offset, int count) {
return this._responseStream.Read(buffer, offset, count);
}
public override void Write(byte[] buffer, int offset, int count) {
string bufferValue = UTF8Encoding.UTF8.GetString(buffer, offset, count);
if (bufferValue.IndexOf("</html>") == -1) {
// Jede Linie des Output Streams an den Streamreader anhängen
this._responseHtml.Append(bufferValue);
} else {
// Wenn am Ende angelangt, die Zeitdifferenz ausrechnen
// und den Platzhalter mit der Stringrepräsentation der Differenz
// ersetzen.
this._responseHtml.Append(bufferValue);
string finalHtml = this._responseHtml.ToString();
object item = HttpContext.Current.Items["beginRequestTime"];
if (item != null) {
TimeSpan ts = DateTime.Now - (DateTime)item;
finalHtml = finalHtml.Replace("{ExecutionTime}",
ts.TotalMilliseconds.ToString());
}
byte[] data = UTF8Encoding.UTF8.GetBytes(finalHtml);
this._responseStream.Write(data, 0, data.Length);
}
}
#endregion
}
}
Damit das HttpModul auch aktiviert ist, müssen wir dieses noch in der web.config unter der Sektion "System.Web" wie folgt registrieren.
<httpModules>
<add name="RequestTimeModule" type="pb.Web.HttpModules.RequestTimeModule"/>
</httpModules>