Go Back   vb.org Archive > vBulletin Article Depository > Read An Article > vBulletin 3 Articles
FAQ Community Calendar Today's Posts Search

Reply
 
Thread Tools
How To Check Your Plugins For Performance
Kentaurus's Avatar
Kentaurus
Join Date: Dec 2001
Posts: 332

 

Show Printable Version Email this Page Subscription
Kentaurus Kentaurus is offline 01-20-2007, 10:00 PM

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):

Code:
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:

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

PHP Code:
        return
            
"
            global \$db;
            \$db->query_write(\"INSERT INTO "
.TABLE_PREFIX."hookstats (hookname, start) VALUES ('".$hookname."', '\".microtime(true).\"')\");
            \$hookid = \$db->insert_id();
            
            "
.
            
$this->pluginlist["$hookname"].
            
"
            \$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):


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

Code:
+-------------------------------+---------------------+
| 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.
Reply With Quote
  #2  
Old 01-21-2007, 10:43 PM
scotsmist scotsmist is offline
 
Join Date: May 2005
Posts: 25
Благодарил(а): 0 раз(а)
Поблагодарили: 0 раз(а) в 0 сообщениях
Default

that's a handy little routine. thanks for sharing, it will be put to good use.
Reply With Quote
  #3  
Old 02-11-2007, 05:03 PM
ragtek ragtek is offline
 
Join Date: Mar 2006
Location: austria, croatia
Posts: 1,630
Благодарил(а): 0 раз(а)
Поблагодарили: 0 раз(а) в 0 сообщениях
Default

one thing isnt correkt

you make a table hookstats but you insert things into ".TABLE_PREFIX."hookstats
so use just one
Reply With Quote
Reply


Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump


All times are GMT. The time now is 01:21 AM.


Powered by vBulletin® Version 3.8.12 by vBS
Copyright ©2000 - 2024, vBulletin Solutions Inc.
X vBulletin 3.8.12 by vBS Debug Information
  • Page Generation 0.03708 seconds
  • Memory Usage 2,217KB
  • Queries Executed 16 (?)
More Information
Template Usage:
  • (1)SHOWTHREAD
  • (1)ad_footer_end
  • (1)ad_footer_start
  • (1)ad_header_end
  • (1)ad_header_logo
  • (1)ad_navbar_below
  • (1)ad_showthread_beforeqr
  • (3)bbcode_code
  • (2)bbcode_php
  • (1)footer
  • (1)forumjump
  • (1)forumrules
  • (1)gobutton
  • (1)header
  • (1)headinclude
  • (1)modsystem_article
  • (1)navbar
  • (4)navbar_link
  • (120)option
  • (3)post_thanks_box
  • (3)post_thanks_button
  • (1)post_thanks_javascript
  • (1)post_thanks_navbar_search
  • (3)post_thanks_postbit_info
  • (2)postbit
  • (3)postbit_onlinestatus
  • (3)postbit_wrapper
  • (1)spacer_close
  • (1)spacer_open
  • (1)tagbit_wrapper 

Phrase Groups Available:
  • global
  • inlinemod
  • postbit
  • posting
  • reputationlevel
  • showthread
Included Files:
  • ./showthread.php
  • ./global.php
  • ./includes/init.php
  • ./includes/class_core.php
  • ./includes/config.php
  • ./includes/functions.php
  • ./includes/class_hook.php
  • ./includes/modsystem_functions.php
  • ./includes/functions_bigthree.php
  • ./includes/class_postbit.php
  • ./includes/class_bbcode.php
  • ./includes/functions_reputation.php
  • ./includes/functions_post_thanks.php 

Hooks Called:
  • init_startup
  • init_startup_session_setup_start
  • init_startup_session_setup_complete
  • cache_permissions
  • fetch_threadinfo_query
  • fetch_threadinfo
  • fetch_foruminfo
  • style_fetch
  • cache_templates
  • global_start
  • parse_templates
  • global_setup_complete
  • showthread_start
  • showthread_getinfo
  • forumjump
  • showthread_post_start
  • showthread_query_postids
  • showthread_query
  • bbcode_fetch_tags
  • bbcode_create
  • showthread_postbit_create
  • postbit_factory
  • postbit_display_start
  • post_thanks_function_post_thanks_off_start
  • post_thanks_function_post_thanks_off_end
  • post_thanks_function_fetch_thanks_start
  • post_thanks_function_fetch_thanks_end
  • post_thanks_function_thanked_already_start
  • post_thanks_function_thanked_already_end
  • fetch_musername
  • postbit_imicons
  • bbcode_parse_start
  • bbcode_parse_complete_precache
  • bbcode_parse_complete
  • postbit_display_complete
  • post_thanks_function_can_thank_this_post_start
  • tag_fetchbit_complete
  • forumrules
  • navbits
  • navbits_complete
  • showthread_complete