Hooks overhead

Following hook performance discussion at the NOLA Hackathon:

Number of hook calls[edit]

Special:BlankPage: 384 calls
en:Barack Obama import: 62112 calls (Cite and PF were disabled)
en:Barack Obama uncached page view: 138797 calls (with Cite and PF)

Hook performance[edit]

Code used

<?php

require_once( dirname( __FILE__ ) . '/Maintenance.php' );

class HookPerf extends Maintenance {
	function __create() {
	}

	function execute() {
		global $wgHooks;
		
		$cycles = 10000;
		
		$this->output( "Running tests with $cycles repetititons:\n\n" );
		
		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) wfRunHooks( 'nonexistent' );
		$this->output( "No hooks defined, repeatedly running the same hook via wfRunHooks(): " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );

		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( 'nonexistent' );
		$this->output( "No hooks defined, repeatedly running the same hook via Hooks::run(): " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );
		
		$this->output( "From now on, using the fastest calling method, Hooks::run()....\n" );

		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( "nonexistent$i" );
		$this->output( "No hooks defined, different hook called each time: " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );

		
		$wgHooks['somehook'][] = 'HookPerf::staticHandler';
		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( 'somehook' );
		$this->output( "Calling the same empty static hook: " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );

		$wgHooks['somehook'][0] = array( $this, 'memberHandler' );
		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( 'somehook' );
		$this->output( "Calling the same empty member function hook: " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );

		for ( $i = 0; $i < 199; $i++ ) $wgHooks["foo$i"][] = 'explosion';

		$wgHooks['somehook'][0] = 'HookPerf::staticHandler';
		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( 'nonexistent' );
		$this->output( "200 hooks defined, calling the same unset hook: " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );

		$t = microtime( true );
		for ( $i = 0; $i < $cycles; $i++ ) Hooks::run( 'somehook' );
		$this->output( "200 hooks defined, calling the same defined hook: " . ( ( microtime( true ) - $t ) / $cycles ) . " s/call\n" );
	}

	public static function staticHandler() {
		return true;
	}

	public function memberHandler() {
		return true;
	}
}

$maintClass = 'HookPerf';
require_once( RUN_MAINTENANCE_IF_MAIN );

Running tests with 10000 repetititons:

No hooks defined, repeatedly running the same hook via wfRunHooks(): 3.2485961914063E-6 s/call
No hooks defined, repeatedly running the same hook via Hooks::run(): 2.5429964065552E-6 s/call
From now on, using the fastest calling method, Hooks::run()....
No hooks defined, different hook called each time: 2.9288053512573E-6 s/call
Calling the same empty static hook: 2.8852891921997E-5 s/call
Calling the same empty member function hook: 3.0839109420776E-5 s/call
200 hooks defined, calling the same unset hook: 2.6947021484375E-6 s/call
200 hooks defined, calling the same defined hook: 0.00013253707885742 s/call

So that's something on the order of 1ms delay per 300-ish calls?