Egy nagyon lassú oldalt kellett megvizsgálnom. Az ASP.NET oldalak legfontosabb eseményei között eltelt idő jó kiinduló pont lehet ilyenkor. Ezt nagyon könnyen megnézhetjük a beépített ASP.NET Trace segítségével. A lassú oldal vonatkozó idejei itt láthatók:
| Category | Message | From First(s) | From Last(s) |
| aspx.page | Begin PreInit | | |
| aspx.page | End PreInit | 0,178878653 | 0,178879 |
| aspx.page | Begin Init | 0,179063965 | 0,000185 |
| aspx.page | End Init | 0,181212485 | 0,002149 |
| aspx.page | Begin InitComplete | 0,181295225 | 0,000083 |
| aspx.page | End InitComplete | 0,181335912 | 0,000041 |
| aspx.page | Begin PreLoad | 0,181372153 | 0,000036 |
| aspx.page | End PreLoad | 0,181636103 | 0,000264 |
| aspx.page | Begin Load | 0,181682602 | 0,000046 |
| aspx.page | End Load | 1,483567446 | 1,301885 |
| aspx.page | Begin LoadComplete | 1,483645058 | 0,000078 |
| aspx.page | End LoadComplete | 1,483719935 | 0,000075 |
| aspx.page | Begin PreRender | 1,483758912 | 0,000039 |
| aspx.page | End PreRender | 4,683605124 | 3,199846 |
| aspx.page | Begin PreRenderComplete | 4,683677265 | 0,000072 |
| aspx.page | End PreRenderComplete | 4,746124869 | 0,062448 |
| aspx.page | Begin SaveState | 5,907560301 | 1,161435 |
| aspx.page | End SaveState | 5,99230239 | 0,084742 |
| aspx.page | Begin SaveStateComplete | 5,992393336 | 0,000091 |
| aspx.page | End SaveStateComplete | 5,992420347 | 0,000027 |
| aspx.page | Begin Render | 5,992443254 | 0,000023 |
| aspx.page | End Render | 7,129650397 | 1,137207 |
A táblázat egy sorának utolsó oszlopa az előző bejegyzés óta eltelt időt mutatja. Ez alapján kivastagítottam azokat a bejegyzéseket, amik között nagyon sok idő telt el. Tehát ezen a lassú oldalon (figyeljük meg a több, mint hét másodperces szerveroldalon töltött időt!), lassú a PageLoad(), különösen lassú a PreRender(), elég sokáig tart a Render(), és valami történik a PreRender és a SaveState között!!! Mi a szösz! A PageLoad()-ról, a PreRender()-ről és a Render()-ről is valamennyire mi, fejlesztők tehetünk. Hála Istennek, mert így javítani is lehet rajta. De mi történik a a PreRender és a SaveState között? Mi folyik itt?
Reflectorban rákerestem a Begin SaveState szövegre, és a Sytem.Web dll Page osztályának ProcessRequestMain() metódusában találtam meg:
else if (!this.IsCrossPagePostBack)
{
if (context.TraceIsEnabled)
{
this.Trace.Write("aspx.page", "Begin PreRenderComplete");
}
this.PerformPreRenderComplete();
if (context.TraceIsEnabled)
{
this.Trace.Write("aspx.page", "End PreRenderComplete");
}
if (context.TraceIsEnabled)
{
this.BuildPageProfileTree(this.EnableViewState);
this.Trace.Write("aspx.page", "Begin SaveState");
}
...
Itt az is látszik, hogy az End PreRenderComplete és a Begin SaveState üzenetek között egyetlenegy dolog történik (lefut a BuildPageProfileTree()), de az is csak, ha a Trace be van kapcsolva.
Tehát ez a metódus éles rendszeren nem fut le, így a futási időt sem befolyásolja. A mérés egyetlen fura eredményét maga a mérés okozta. Hála Istennek, így már csak a lassúság valódi okait kell felderíteni.