Vrijeme iscrtavanja stranice

Kopam ja tako po ekstenzijama za Blogengine.net (njih čak 20-tak! Ako vam je do šale, pogledajte koliko ekstenzija ima WordPress!) i naiđem na dodatak koji ispisuje vrijeme potrebno za učitavanje/iscrtavanje stranice. Kako mi je jako važno da se stranica brzo učitava, da ne bi ovih 5 posjetioca dnevno (tjedno) čekali koju sekundu previše i otišli sa stranice, valja imati precizna vremena učitavanja!

Dodam ga na blog, oduševljeno gledam vremena ispod 0,1 sekunde i divim se kako je ASP.NET brz! Potom promijenim nešto u kodu, napravim refresh stranice, čekam 5-10 sekundi da se dinamička kompilacija izvrši, kada ono u footeru opet piše: “Page loaded in 0.00569874 seconds”. Znači, nešto ne valja. Ja sam čekao barem 50-tak puta više od prikazanog vremena. [more]

Ovo je kod od ekstenzije, koji se nalazi unutar ASCX user kontrole:

public partial class User_controls_PageLoadTime : System.Web.UI.UserControl
{
    private DateTime _start;
    private DateTime _end;

    protected void Page_Init(object sender, System.EventArgs e)
    {
        _start = DateTime.Now;
    }

    protected void Page_PreRender(object sender, System.EventArgs e)
    {
        _end = DateTime.Now;
        TimeSpan time = _end.Subtract(_start);
        lblPageLoadTime.Text = string.Format("Page loaded in {0} seconds.", time.TotalSeconds.ToString());
    }
}

Kao što se vidi iz priloženog, vrijeme se mjeri od početka izvršavanja OnInit događaja, pa do PreRender događaja.

Ako pogledamo sam trace stranice:

vidimo da ekstenzija ne radi dobro! Za stranicu je bilo potrebno sigurno oko 4-5 sekundi za iscrtavanje, ali OnInit i OnPreRender događaji su se desili negdje u srediti samoga izvršavanja. Pregledom nekoliko dostupnih primjera nađenih na internetu se vidi da se većina primjera uglavnom bazira na ova dva događaja, ali pregledom trace rezultata možemo vidjeti da je vrijeme između ta dva događaja samo manji dio ukupnog vremena izvršavanja page life cycle-a.

Zbog toga ovdje dajem svoj prijedlog jednostavnog koda za računanje vremena potrebnog za iscrtavanje stranice. Zasniva se na događaju Application_BeginRequest koji se definiran u Global.asax datoteci. Trenutno vrijeme se spremi u HttpContext.Items Dictionary objekt (korisno spremište za objekte koji će imati životni vijek trajanja jednog requesta – npr. za DataContext od LINQ2SQLa i slično, jer se sadržaj tog Dictionarya briše nakon kraja requesta).
Na kraju same stranice (u ovom slučaju u Master stranici), u inline kodu unutar aspx datoteke se dohvati trenutno vrijeme i oduzme od vremena unutar HttpContext.Items.

Kod iz Global.asax:

void Application_BeginRequest()
{
	if(HttpContext.Current.Request.Url.AbsolutePath.Contains(".aspx"))
		HttpContext.Current.Items["load"] = DateTime.Now;
}

Provjera “.aspx” stringa unutar request URL-a je zbog mogućnosti da se BeginRequest događaj pokreće i za druge datoteke osim .aspx stranica, poput CSS, JPG,…, što je specifično za lokalni developmnet server od Visual Studia (cassini, jel?) i za IIS7 koji isto daje ASP.NET frameworku requeste na svaku datoteku i folder (IIS6 hvata samo .aspx, .asmx i slične ekstenzija).

Kod na kraju aspx stranice:

Stranica učitana u <%= DateTime.Now.Subtract( (DateTime)HttpContext.Current.Items["load"] ).TotalSeconds.ToString() %> sekundi

(Molim zanemarite nedostatak provjere dali nešto uopće postoji unutar HttpContext.Items! Ovo može rezultirati sa poznatim yellow screen of death od asp.net)

Nakon ovakve implementacije mjerenja vremena, brojka mi osobno izgleda puno uvjerljivije: 

primijetite na vrhu slike desno, “ … 2.6651 sekundi”, u odnosu na prijašnjih 0.21s.

Ako postoji neki drugi način mjerenja (osim dodavanja Http Modula, za to sam previše ljen, iako pogledom na primjer od Phil Haacka vidim da koristi jako slični način mjerenja, vjerojatno i marginalno točniji), ili je ova implementacija pogrešna u nečemu, molim vas da napišete komentar ili mi pošaljete mail.