This post is part two of a mini series where I (1) explain why keeping track of WordPress load timing is important and (2) discuss how WordPress load time profiling can be done using a newly created plugin. If you want to skip the chatter and go straight to the plugin, you can download it here.
I’ve updated my load time profiling plugin a little bit over the weekend. There are now two new features:
- The output will show you memory consumption at each log point
- The plugin will trace time spent in each function called via an ‘add_action’ callback.
Lets talk about both these two a bit and why they make sense
Memory consumption
There are a few reasons that you want your WordPress installation to have as low memory consumption as possible.
First of all, there is a limit. Sometimes on some hosts, you will get an error that tells you that your PHP script tried to allocate more memory than is available and it will halt execution. This is not a specific WordPress error, but since WordPress is built on PHP, you’ll get it sometimes. When troubleshooting this type of error, it’s not always obvious what code that is causing the problem. Even if Plugin A uses a lot of memory and pushes memory consumption right to the limit, it will sometimes load just fine anyway. But a little later, when Plugin B is initializing, your total memory consumption may hit the limit and processing will halt. When that happens, finding the problematic piece of code can be very time consuming, not to mention frustrating.
The other reason is that allocating memory pretty much always takes a lot of time, memory allocation is simply an expensive operation. Not that each call to emalloc in itself is all that expensive, but when a script gradually built up memory consumption there have usually been quite a few emalloc calls under the hood. So the mere act of consuming memory also costs a lot of CPU cycles.
The last reason is a matter of scalability. A script that uses 256Mb of memory will occupy the server RAM with… well, 256Mb. If your webserver only have 1024Mb available it can only make room for four 256Mb scripts running at the exact same time. If the script on average takes 2 seconds to finish it means that the maximum requests/sec that your server can handle will be heavily reduced. So you want your WordPress requests to consume as little RAM memory as possible simply because it means that the server can fit more requests into memory at any given point of time.
All the three above reasons makes it important to be able to track how your WordPress installation uses memory. I hope you find it useful.
Hooked functions
One of the features that makes WordPress such a wonderful product is the ability for a theme or plugin to hook into it. In practical terms it means that a plugin or theme can request to be notified via a callback whenever WordPress hits a certain point in it’s execution, in WordPress lingo, such a callback is referred to as an action. For instance, most plugins uses a hook for the Init event that fires early in the startup process and allows a plugin to perform certain initialization before the page starts to render. Plugins and themes can register that they want a callback for the Init event by simply calling the add_action function. More than one plugin can hook up to the same event and when this happens WordPress will just execute them one by one.
A potential problem with callbacks is that all plugins are not written with performance and memory efficiency in mind. On the contrary, some plugins will spend ages doing expensive initialization tasks and consuming a lot of memory for no particular reason at all. For the end user this means that the requested page is delayed until some plugin is done doing unneeded work. One example is the very popular NexGen Gallery plugin that on initialization will load a lot of PHP files into memory and perform some quite expensive initialization work on every single request, regardless if the resulting web page will actually display a gallery.
In the first version of my Load time profiler plugin you could track how long time WordPress took to complete a few of the actions, but it was not possible to see how long each individual callback would take. In this version, I’ve added code to track this so that for instance when the Init action is fired, you can see the time consumed by each individual callback (click image to enlarge)
One tiny drawback
The traditional way to do profiling would be to run the code in a specific profiling tool that needs to be installed on the same server as your code is running on. In the case of WordPress, the challenge is that many production installations are running in hosted environments where the web developers can’t just go and install debugging and profiling extensions at will. This plugin is really an attempt to overcome this limitation by actually modifying how WordPress is executed in a controlled way. Three core WordPress files are copied to the plugin directory and are modified to (1) collect data on timing and memory consumption and (2) alter the include paths a little to avoid the standard version of those files. Feel free to check the modified files, they are stored under /path/to/plugins/loadtimeprofiler/resources and have the suffix _custom.php
The drawback of this should be fairly obvious, since the code is modified, it’s not the exact same as in production and therefore, the results will differ ever so slightly between what’s reported and reality. So as long as you keep this in mind and use the tool sensibly, I think you can draw some
Download
I swear I will start the process to get the plugin into the official repository at wordpress.org asap, in the meantime click here to download the current version of the plugin.
I’m eager to hear back from your. I’ll answer technical questions or listen to your critique. Whatever feedback you think is appropriate. Use the comments below to let me know what you think.