Deprecated: preg_replace(): The /e modifier is deprecated, use preg_replace_callback instead in /share/CACHEDEV1_DATA/Web/www/libraries/UBBcode/text_parser.class.php on line 228

Deprecated: preg_replace(): The /e modifier is deprecated, use preg_replace_callback instead in /share/CACHEDEV1_DATA/Web/www/libraries/UBBcode/text_parser.class.php on line 228
Increasing website performance, part #1: profiling

Comments Blog About Development Research Sites

Increasing website performance, part #1
Profiling

Aug 28, 2010
With modern hardware, it is relatively easy to build fast websites. There is a lot you can do with even a second of processing power when your hardware can perform several billion operations per second.

It is therefore surprising to see complex frameworks crawling to a standstill with only half a dozen users active. How can this be, and more importantly, how can this be prevented? Since I was recently tasked with optimizing several webapplications, each with its own peculiar problem, I decided to write a few articles on this interesting subject. For today, this means starting at the very begining: profiling.

Profiling performance
In order to find out what makes your site slow, you need to know how long each part takes to process. Some platforms have buildin profilers to do this for you, but for PHP for example you will usually have to write your own profiler. An easy way to do this is place timers at the start and end of function calls, as well as at the very beginning and end of your script. By measuring the duration of specific function calls as well as the duration of your entire script you can check how long each call takes, and how much time the selected calls require compared to the rest of the application.

At the very basic level, this means writing a function to store method execution times for the entire duration your script runs. A very simple implementation can be found here. An example log as created by this profiler:

Code (php) (nieuw venster):
1
2
3
4
5
6
7
8
9
10
11
12
13
[SITE....................................................................]
    [
total.................................................][0.1604][   1]
[
CLASSLOADER.............................................................]
    [
construct.............................................][0.0001][   1]
    [
load..................................................][0.0332][  17]
[
DATABASE................................................................]
    [
connect...............................................][0.0103][   1]
    [
query.................................................][0.0073][   3]
[
CLASSTREE...............................................................]
    [
executeAction.........................................][0.0129][   1]
[
PAGEHANDLER.............................................................]
    [
showPage..............................................][0.0812][   1]
    [
contentHandler........................................][0.0106][   1]

We can already see some bottlenecks: the showPage method in our pageHandler for example is very slow, and the load method in our classloader is executed often (once for each class that needs to be loaded).

The reason our showPage is slow is because this was run with DEBUG set to true - the used template engine, Smarty, checks this variable to output a lot of debugging information. Usefull when writing code, but also fairly slow. By setting DEBUG to false (which should be done always on production environments) we already solve this little bottleneck. So how about the classtree loading calls?

It turns out these can be eliminated, or at least speeded up a lot, by caching & compiling our classes. With debugging off and these caching mechanisms in place, the profile for the same page looks something like this:
Code (php) (nieuw venster):
1
2
3
4
5
6
7
8
9
10
11
12
[SITE....................................................................]
    [
total.................................................][0.0389][   1]
[
CLASSLOADER.............................................................]
    [
construct.............................................][0.0001][   1]
[
DATABASE................................................................]
    [
connect...............................................][0.0017][   1]
    [
query.................................................][0.0039][   3]
[
CLASSTREE...............................................................]
    [
executeAction.........................................][0.0034][   1]
[
PAGEHANDLER.............................................................]
    [
showPage..............................................][0.0063][   1]
    [
contentHandler........................................][0.0011][   1]

As should be clear, no loading calls are made at all, the showPage method is now ten times as fast, and the entire page was loaded over four times as fast! We are also missing parts of our profile: the site total execution time is 38 milliseconds while our profiled methods only account for about 17 milliseconds. In other words, there are still bottlenecks left to find. By carefully profiling every likely method these can eventually be found and possibly removed.

If you want to know more on how I managed to reduce execution times by a factor four, keep an eye out for the next article, which will feature some interesting caching and compiling techniques to increase the speed of (PHP) webapplications :)

FragFrog out!

New comment

Your name:
Comment: