mu-plugin to track timing of all actions/filters of a whitelisted list of tags ( or all of them! )

mu-plugin-profile-actions.php

<?php

$xteam_profile_whitelisted_tags = array(
	'save_post'
);

// Do action hack
function xteam_profile_all_action( $value ) {
	global $wp_filter, $merged_filters, $wp_current_filter, $xteam_profile_whitelisted_tags;
	$tag = end( $wp_current_filter );
	if ( empty( $wp_filter[ $tag ] ) /*|| ! in_array( $tag, $xteam_profile_whitelisted_tags )*/ ) {
		return $value;
	}
	// Parse callbacks and inject time calculating functions
	foreach ( $wp_filter[ $tag ] as $priority => $callbacks ) {
		$_callbacks = array();
		$_idx = 0;
		// Inject time_start function before each filter, which in turn runs
		// time_stop on the previous entry
		foreach ( $callbacks as $callback => $args ) {
			$_callbacks[ 'xteam_profile_time_start_' . ++$_idx ] = array(
				'function' => 'xteam_profile_time_start',
				'accepted_args' => 1,
			);
			$_callbacks[ $callback ] = $args;
		}
		// Stop timer for the last filter, and store all filters to compare 
		// later ( so any remove_filter instances are accounted for )
		$_callbacks[ 'xteam_profile_time_end' ] = array(
			'function' => 'xteam_profile_time_end',
			'accepted_args' => 1,
		);
		$wp_filter[ $tag ][ $priority ] = $_callbacks;
	}
}

function xteam_profile_time_start( $value ) {
	global $wp_current_filter, $xteam_profile_timing;
	xteam_profile_time_stop();
	$xteam_profile_timing[ end( $wp_current_filter ) ][] = microtime( true );
	return $value;
}

function xteam_profile_time_stop() {
	global $wp_current_filter, $xteam_profile_timing;
	// Skip if first filter in tag
	if ( ! isset( $xteam_profile_timing[ end( $wp_current_filter ) ] ) ) {
		return;
	}
	// $last = key( $xteam_profile_timing[ end( $wp_current_filter ) ] );
	$xteam_profile_timing[ end( $wp_current_filter ) ][] = microtime( true );
}

/**
 * Stores list of filters that has been already executed
 */
function xteam_profile_time_end( $value ) {
	global $wp_filter, $wp_current_filter, $xteam_profile_timing, $xteam_profile_hooks;
	xteam_profile_time_stop();
	if ( empty( $xteam_profile_hooks ) ) {
		$xteam_profile_hooks = array();
	}
	$xteam_profile_hooks[ end( $wp_current_filter ) ] = $wp_filter[ end( $wp_current_filter ) ];
	return $value;
}

function xteam_profile_show_data() {
	global $xteam_profile_hooks, $xteam_profile_timing, $xteam_profile_time_started;
	$timings = array();
	if ( ! isset( $xteam_profile_timing ) ) {
		return;
	}
	foreach ( $xteam_profile_hooks as $tag => $tree ) {
		foreach ( $tree as $priority => $callbacks ) {
			foreach ( $callbacks as $callback => $args ) {
				if ( false !== strpos( $callback, 'xteam_profile_time_end' ) || false !== strpos( $callback, 'time_stop' ) ) {
					continue;
				}
				if ( false !== strpos( $callback, 'xteam_profile_time_start_' ) ) {
					$xteam_profile_time_started = array_shift( $xteam_profile_timing[ $tag ] );
				} else {
					// There is a callback that we didn't record!
					if ( is_null( $xteam_profile_time_started ) ) {
						die( 'we have got a problem, housten!' );
					}
					$timings[ $tag ][ $callback ] = array_shift( $xteam_profile_timing[ $tag ] ) - $xteam_profile_time_started;
					$xteam_profile_time_started = null;
				}
			}
		}
	}
	sort( $timings );
	error_log( $timings );
	// {echo '<pre>';var_dump( $timings );echo '</pre>';die();}
}

add_action( 'all', 'xteam_profile_all_action', 99, 1 );
register_shutdown_function( 'xteam_profile_show_data' );