View Full Version : How To Check Your Plugins For Performance

21 Jan 2007, 01:08
Warning: Advanced tutorial - for developers only.

We all love the new product & plugins system that was introduced in vbulletin. No more doing file modifications, no more writing a lot of instructions in a long txt and following them for an hour to install a hack, just upload the product, run.. ready (with some exceptions, of course).

I found myself trying to find a "good" method for checking my plugins for performance. After all, I don't want a hack or modification going wild and slowing my whole forum. I seriously needed to find a way to find out how much resources my plugins were using. And, while developing, I wanted to make sure that I didn't have "bad code" that used too many resources.

We already had the solution, for logging the page load time, a microtime() is used. Why not do it with every hook as well, then we could check the statistics and if a hook is taking too much time to execute, disable it, or reprogram it.

Gettings these statistics is a simple modification.

1) We'll need to create a new table, run the following query (add your table prefix if necessary):

CREATE TABLE hookstats (
hookid int auto_increment primary key,
hookname varchar(250) not null,
start varchar(30) not null,
end varchar(30) null
2) Open class_hook.php (in the includes directory), and find:

return $this->pluginlist["$hookname"];
Change it to:

global \$db;
\$db->query_write(\"INSERT INTO ".TABLE_PREFIX."hookstats (hookname, start) VALUES ('".$hookname."', '\".microtime(true).\"')\");
\$hookid = \$db->insert_id();

\$db->query_write(\"UPDATE ".TABLE_PREFIX."hookstats SET end='\".microtime(true).\"' WHERE hookid=\$hookid\");
Curious? I just added to every hook some lines to insert into the database the start and end time, the microtime. Now all the hook execution time is logged into the database.

3) Open a couple pages on which the plugins are used. Browse a while. We need the plugins to be executed before checking the stats!

4) Run the following query on your favorite sql client, phpmyadmin, the console, or wherever you want to check the stats (add the table prefix if necessary):

hookname,avg(end-start) runtime
FROM hookstats
WHERE end > 0
GROUP BY hookname
ORDER BY runtime DESC;
You will get something like this:

| hookname | runtime |
| forumhome_complete | 0.54312801516406 |
| newpost_process | 0.020376857913686 |
| editpost_edit_complete | 0.014933427174886 |
| profile_editusergroups_start | 0.0098423132529626 |
| profile_updateavatar_complete | 0.0098001956939697 |
| global_shutdown | 0.0080306405620168 |
This means that forumhome_complete, on average, takes 0.5 seconds to execute. Depending on your server that could be ok, or very bad. newpost_process takes 0.02 seconds to execute (that's better).

You can check the average execution time for every hook.

These are the average execution times for each hook on your forum. Of course, what you probably needed was the execution time for a plugin, or a product, not the whole hook. Doing so is out of the scope of this tutorial, this technique shouldn't be so difficult to extend for logging the time per plugin or per product. For now, seeing the information per hook is useful and a good start.

The irony? Try not to use this on a production environment since logging in the database takes some resources. You are adding a lot of queries, 2 per hook. This should be used whenever you need to benchmark performance, test your mod, and disabled after.

22 Jan 2007, 00:43
that's a handy little routine. thanks for sharing, it will be put to good use.

11 Feb 2007, 19:03
one thing isnt correkt

you make a table hookstats but you insert things into ".TABLE_PREFIX."hookstats ;)
so use just one