Main Content

Checking server performance for PHP generated pages

Archive - Originally posted on "The Horse's Mouth" - 2008-06-06 16:13:22 - Graham Ellis

I had a couple of reports recently about web pages from our site being a little slow to load, and my independent spy tells me that they're not bad, but not the world's fastest either. And a little thought lead me to conclude that could be because of the various PHP scripting elements included at the front of each page.

How should I investigate this? I have added in a whole array of microtime(); captures at strategic points in the included code ... like
$timer[14] = microtime();
and I have added a labelling array too:
$tabo[14] = "Starting top of page preps";

And I have added an extra page in which uses the included code, producing an elapsed time analysis - loop code like

foreach (array_keys($timer) as $subs) {
list($ins,$outs) = explode(" ",$timer[$subs]);
# Normalise to second to retain accuracy
if ($oldout == 0) $oldout = $outs;
$elt = ($outs-$oldout) + $ins;
# Format time difference
$newelt = sprintf("%.4f",$elt - $oldelt);
$oldelt = $elt;
print "$elt<br>";
}


Suddenly ... from a black hole which holds the server response for around a second, a series of timings is revealed which gives the "game" away as to where it's worth looking at the efficiency. You can see how my test page runs here and compare it one I did during testing that started like this:

0 0.34967100 1212773196 .
1 0.34970500 1212773196 (0.0000) initialised page script.
2 0.35110600 1212773196 (0.0014) processed whcstd.
3 0.35263500 1212773196 (0.0015) processed webhelpers2.
4 0.23460400 1212773198 (1.8820) processed login.
5 0.23563200 1212773198 (0.0010) processed hotel.
6 0.23650700 1212773198 (0.0009) processed booking.
7 0.23667900 1212773198 (0.0002) recovered booking session.
8 0.23894900 1212773198 (0.0023) set up courses and calendars.
9 0.23900200 1212773198 (0.0001) 4 layer - preprocessor for special cases.
10 0.23907100 1212773198 (0.0001) 4 layer - finish previous page.
11 0.23945500 1212773198 (0.0004) 4 layer - prepare next page.
12 0.24002300 1212773198 (0.0006) 4 layer - Fill in page variables into template.
14 0.24747000 1212773198 (0.0074) Starting top of page preps.
15 0.24776500 1212773198 (0.0003) Connected to database and handled 'navigation on'.
16 0.59276600 1212773198 (0.3450) DDA preference, country, languages handled.
17 0.59296500 1212773198 (0.0002) Identifying browser string.
18 0.41007200 1212773200 (1.8171) Throttling back systems doing a denial of service.
19 0.41257100 1212773200 (0.0025) Recent history database tidied.
20 0.10485400 1212773201 (0.6923) 'See Also' links evaluated.
21 0.21190500 1212773201 (0.1071) User Comments handled.
22 0.21242300 1212773201 (0.0005) Course Price table loaded.
23 0.21324600 1212773201 (0.0008) User's language preference logged.
24 0.21483800 1212773201 (0.0016) Country identified and output tailored.
25 0.21498100 1212773201 (0.0001) Side image and world zone set.
26 0.21500600 1212773201 (0.0000) Top image and data mine set up for Google arrivals.
27 0.21505800 1212773201 (0.0001) Back links calculated.
28 0.21510800 1212773201 (0.0000) Amazon referrals handled.
29 0.21544600 1212773201 (0.0003) Changes to user preferences saved.