Theme & Plugin Profiler

Computing power is so ubiquitous these days that few developers see it as a constraint. For sure, you don’t want your plugin or theme to be slow, but else, why bother? Well, you’re wrong, for two reasons.

First, your theme or plugin may be fast in your test environment, but will it still be on a shared hosting site with many other active plugins? Saving 0.003 seconds on a theme call seems like nothing. But with, say, a page built every second, things add up quickly, to ten seconds per hour of 4 minutes per day.

Second, your theme or plugin may be used on thousands of sites. That adds up again: 360 installs times 4 minutes makes 24 hrs. That’s a whole server running solely to accomodate your sloppy programming, if you hadn’t gone that extra mile to save a seemingly marginal amount of time.

By some accounts getting rid of inefficient software could reduce the energy cost of data centres by 80 percent. There is no reason why you should not make an attempt to contribute your effort to greener IT. This is what the Theme & Plugin Profiler will help you with by revealing which parts of your code are using most server time.

The Theme and Plugin Profiler uses a little known PHP feature known as ticks. Basically, this is an internal event that occurs every time a code block is executed,  marked (roughly) by a function call or curly {} brackets.

The nice thing is, you can hook a function into a tick event. This enables you to determine at what point in the code you are and how much time has lapsed since last tick. This information can be used to determine how much time is spent in each function. By maintaining a stack of function calls it is also possible to determine how often a certain function is called.

A little more detail on the code

The code starts by declaring that the plugin want to use ticks.Note: if you research PHP ticks you will find sites stating that ticks have been deprecated as of PHP 5.3. This is not true. It was deprecated, but was then undeprecated. Ticks are available in PHP 7 as well. However, the Theme & Plugin Profiler has been tested with 5.3 only.

Next the earliest possible WordPress hook, muplugins_loaded, is used to register the function that is executed at every tick. This means that you must test your plugin as a regular plugin, because muplugins have already been loaded by the time the Theme & Plugin Profiler starts.

At every tick the native PHP function debug_backtrace is called. This returns information on the code currently being executed. For the moment, the plugin only uses the name of the current function. Also at every tick the current server time is retrieved.

If the current function name is the same as the previous function name, it is assumed that we’re still in the same function. The time elapsed since last tick is then added to the total time consumed by this function.

If the current function name is different from the previous function name, there are two possibilities. Either execution has returned from a subroutine or a subroutine has been called. A stack of function calls is maintained to establish which of these is true. In this way it is possible to keep track of how many times a function is called.

The code is not watertight

While this approach will accurately count how much time is spent in each function, the approach with the stack is not watertight.

First, if you call a function recursively, this wil definitely mess up the stack.

Second, if execution returns from a subroutine and immediately another subroutine is called, the ticks may miss the return and stack will think the second subroutine has been called from the first. When later on the return to the main function is registered, it is  counted as a new call. So, the call count stated by the plugin may be inflated. For testing purposes you  might insert a line like if (true==true) {echo '';} between subroutine calls to make sure a tick is registered within the main function.

The code generates errors

Unfortunately the debug_backtrace command generates a usort_warning. This is a known PHP bug. It’s just a warning, everything is still working fine (or, at least, should).

As a follow up of this warning PHP or WordPress will likely also throw a Cannot Modify Header Information error once you try to save the plugin’s options. Simply hitting backspace will fix this.

The output

As described the plugin collects a list of the functions that were executed, how often they were called and how much time they took in total. The plugin’s option page gives some filters to select and sort the results.

The plugin remains active until the very last moment to analyse as much code as possible. This means it starts printing output after the </body> tag has been generated. So, the page with the output table will not be valid html, but still should render fine.

 

The plugin will install an option page in the tools menu. You will still have to activate it on that page. Before you do, read the bewares, to avoid being surprised by the errors that the plugin will inevitably generate (see How the plugin works for an explanation).

Also, don’t use this plugin on a production site, as it will add a table with technical information to every page that is generated. Of course, you wouldn’t be developing your theme or plugin on a production site anyway.

To effectively use the plugin, make sure that all your functions use the same prefix. This will allow you to select those to print out. Else, you will find that a single page involves calling hundreds of functions by WordPress, other plugins and so on. Of course, you can also use the Theme and Plugin Profiler to test somebody else’s theme or plugin.

It is also possible to sort the results in several ways. Generally, you would first look if there is a single function that eats time and see if you can find what is causing it. Next, look at the functions that are called most often. A simple tweak may already help there.

WordPress opimization usually covers the complete install. You should check this out. The Theme & Plugin Profiler delves into your code to give you clues for detailed optimizing.  Here are some tricks that may come in handy:

• Split frontend and backend, so the former isn’t weighed down by unnecessary actions. There is, for instance, no need to initialize the options page on the frontend. Before you call a function, always wonder ‘Should I prefix this with if (is_admin()) ?’
• Be smart with textdomains. The load_textdomain function is not very fast, partly because it involves reading data from a file rather than from the database. Because .mo files are unlikely to change very often (or never), you should consider using load_textdomain only when the theme/plugin is run first and transfer the content of the .mo file to the database.
• Be smart with the theme customizer. Adding a lot of customizing options is great, but looping through them at every page load is time consuming. Perhaps you should store the results of the loop in an option variable and call that instead. After all, once the user is done designing, the customization mods are not likely to change often anymore.
• Use transients. Some information, for instance in widgets, is the same for every page. If you use a transient to store the content of your widget, it will not have to rebuilt every time. Effectively, this is a caching method for parts of your site (as opposed to caching plugins that store complete pages only).

If you have any more ideas, please leave them in the comments.