From e105a5490c8b471435f6659b934b2600fb2e0b30 Mon Sep 17 00:00:00 2001 From: Daniel Bachhuber Date: Tue, 27 Sep 2016 07:58:36 -0700 Subject: [PATCH 1/3] Take a more durable approach to timing callbacks by wrapping each --- inc/class-command.php | 76 ++++++++++++++++++++++++------------------- 1 file changed, 43 insertions(+), 33 deletions(-) diff --git a/inc/class-command.php b/inc/class-command.php index 90fc95f..115b881 100644 --- a/inc/class-command.php +++ b/inc/class-command.php @@ -140,10 +140,37 @@ class Command { } if ( $this->focus_hook && $current_filter === $this->focus_hook ) { - $this->current_filter_callbacks = $wp_filter[ $current_filter ]; - unset( $wp_filter[ $current_filter ] ); - call_user_func_array( array( $this, 'do_action' ), func_get_args() ); - throw new \Exception( self::$exception_message ); + if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { + $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]->callbacks; + } else { + $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]; + } + + if ( is_array( $callbacks ) ) { + foreach( $callbacks as $priority => $priority_callbacks ) { + foreach( $priority_callbacks as $i => $the_ ) { + $callbacks[ $priority ][ $i ] = array( + 'function' => function() use( $the_, $i ) { + if ( ! isset( $this->loggers[ $i ] ) ) { + $this->loggers[ $i ] = new Logger( 'callback', self::get_name_from_callback( $the_['function'] ) ); + } + $this->loggers[ $i ]->start(); + $value = call_user_func_array( $the_['function'], func_get_args() ); + $this->loggers[ $i ]->stop(); + return $value; + }, + 'accepted_args' => $_the['accepted_args'], + ); + } + } + } + + if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { + $wp_filter[ $current_filter ]->callbacks = $callbacks; + } else { + $wp_filter[ $current_filter ] = $callbacks; + } + } WP_CLI::add_wp_hook( $current_filter, array( $this, 'wp_hook_end' ), 999 ); @@ -226,6 +253,14 @@ class Command { } } + if ( $this->focus_hook && $current_filter === $this->focus_hook ) { + if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { + $wp_filter[ $current_filter ]->callbacks = $this->current_filter_callbacks; + } else { + $wp_filter[ $current_filter ] = $this->current_filter_callbacks; + } + } + return $filter_value; } @@ -268,15 +303,7 @@ class Command { $logger = new Logger( 'stage', 'bootstrap' ); $logger->start(); } - try { - WP_CLI::get_runner()->load_wordpress(); - } catch( \Exception $e ) { - // If this was thrown by our do_action implementation, then we need to bail - if ( self::$exception_message === $e->getMessage() ) { - return; - } - // Otherwise, pass through. - } + WP_CLI::get_runner()->load_wordpress(); if ( isset( $this->loggers['wp_profile_last_hook'] ) && $this->loggers['wp_profile_last_hook']->running() ) { $this->loggers['wp_profile_last_hook']->stop(); } @@ -298,15 +325,7 @@ class Command { $logger = new Logger( 'stage', 'main_query' ); $logger->start(); } - try { - wp(); - } catch( \Exception $e ) { - // If this was thrown by our do_action implementation, then we need to bail - if ( self::$exception_message === $e->getMessage() ) { - return; - } - // Otherwise, pass through. - } + wp(); if ( isset( $this->loggers['wp_profile_last_hook'] ) && $this->loggers['wp_profile_last_hook']->running() ) { $this->loggers['wp_profile_last_hook']->stop(); } @@ -337,20 +356,11 @@ class Command { $logger->start(); } ob_start(); - try { - require_once( ABSPATH . WPINC . '/template-loader.php' ); - } catch( \Exception $e ) { - // If this was thrown by our do_action implementation, then we need to bail - if ( self::$exception_message === $e->getMessage() ) { - ob_get_clean(); - return; - } - // Otherwise, pass through. - } + require_once( ABSPATH . WPINC . '/template-loader.php' ); + ob_get_clean(); if ( isset( $this->loggers['wp_profile_last_hook'] ) && $this->loggers['wp_profile_last_hook']->running() ) { $this->loggers['wp_profile_last_hook']->stop(); } - ob_get_clean(); if ( ! $this->focus_stage && ! $this->focus_hook ) { $logger->stop(); $this->loggers[] = $logger; From 7721de219eedb865b41a1aa6a5711d6a232cb9da Mon Sep 17 00:00:00 2001 From: Daniel Bachhuber Date: Tue, 27 Sep 2016 08:01:12 -0700 Subject: [PATCH 2/3] Drop method that's no longer used --- inc/class-command.php | 52 ------------------------------------------- 1 file changed, 52 deletions(-) diff --git a/inc/class-command.php b/inc/class-command.php index 115b881..441364c 100644 --- a/inc/class-command.php +++ b/inc/class-command.php @@ -176,58 +176,6 @@ class Command { WP_CLI::add_wp_hook( $current_filter, array( $this, 'wp_hook_end' ), 999 ); } - /** - * Instrumented version of do_action() - */ - private function do_action( $tag, $arg = '' ) { - global $wp_actions, $merged_filters, $wp_current_filter; - $wp_filter = array(); - $wp_filter[ $tag ] = $this->current_filter_callbacks; - - if ( ! isset($wp_actions[$tag]) ) - $wp_actions[$tag] = 1; - else - ++$wp_actions[$tag]; - - if ( empty( $wp_filter[ $tag ] ) ) { - return; - } - - if ( !isset($wp_filter['all']) ) - $wp_current_filter[] = $tag; - - $args = array(); - if ( is_array($arg) && 1 == count($arg) && isset($arg[0]) && is_object($arg[0]) ) // array(&$this) - $args[] =& $arg[0]; - else - $args[] = $arg; - for ( $a = 2, $num = func_num_args(); $a < $num; $a++ ) - $args[] = func_get_arg($a); - - // Sort - if ( !isset( $merged_filters[ $tag ] ) ) { - ksort($wp_filter[$tag]); - $merged_filters[ $tag ] = true; - } - - reset( $wp_filter[ $tag ] ); - - do { - foreach ( (array) current($wp_filter[$tag]) as $i => $the_ ) - if ( !is_null($the_['function']) ) { - if ( ! isset( $this->loggers[ $i ] ) ) { - $this->loggers[ $i ] = new Logger( 'callback', self::get_name_from_callback( $the_['function'] ) ); - $this->loggers[ $i ]->start(); - } - call_user_func_array($the_['function'], array_slice($args, 0, (int) $the_['accepted_args'])); - $this->loggers[ $i ]->stop(); - } - - } while ( next($wp_filter[$tag]) !== false ); - - array_pop($wp_current_filter); - } - /** * Profiling verbosity at the end of every action and filter */ From 59579ccdea8306c8e2a9dabd0b52a4d7836bb518 Mon Sep 17 00:00:00 2001 From: Daniel Bachhuber Date: Tue, 27 Sep 2016 08:10:41 -0700 Subject: [PATCH 3/3] Properly handle an unset `$wp_filter` --- inc/class-command.php | 79 +++++++++++++++++++++++++------------------ 1 file changed, 47 insertions(+), 32 deletions(-) diff --git a/inc/class-command.php b/inc/class-command.php index 441364c..83f1f8d 100644 --- a/inc/class-command.php +++ b/inc/class-command.php @@ -140,41 +140,56 @@ class Command { } if ( $this->focus_hook && $current_filter === $this->focus_hook ) { - if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { - $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]->callbacks; - } else { - $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]; - } - - if ( is_array( $callbacks ) ) { - foreach( $callbacks as $priority => $priority_callbacks ) { - foreach( $priority_callbacks as $i => $the_ ) { - $callbacks[ $priority ][ $i ] = array( - 'function' => function() use( $the_, $i ) { - if ( ! isset( $this->loggers[ $i ] ) ) { - $this->loggers[ $i ] = new Logger( 'callback', self::get_name_from_callback( $the_['function'] ) ); - } - $this->loggers[ $i ]->start(); - $value = call_user_func_array( $the_['function'], func_get_args() ); - $this->loggers[ $i ]->stop(); - return $value; - }, - 'accepted_args' => $_the['accepted_args'], - ); - } - } - } - - if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { - $wp_filter[ $current_filter ]->callbacks = $callbacks; - } else { - $wp_filter[ $current_filter ] = $callbacks; - } - + $this->wrap_current_filter_callbacks( $current_filter ); } WP_CLI::add_wp_hook( $current_filter, array( $this, 'wp_hook_end' ), 999 ); } + + /** + * Wrap current filter callbacks with a timer + */ + private function wrap_current_filter_callbacks( $current_filter ) { + global $wp_filter; + $this->current_filter_callbacks = null; + + if ( ! isset( $wp_filter[ $current_filter ] ) ) { + return; + } + + if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { + $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]->callbacks; + } else { + $callbacks = $this->current_filter_callbacks = $wp_filter[ $current_filter ]; + } + + if ( ! is_array( $callbacks ) ) { + return; + } + + foreach( $callbacks as $priority => $priority_callbacks ) { + foreach( $priority_callbacks as $i => $the_ ) { + $callbacks[ $priority ][ $i ] = array( + 'function' => function() use( $the_, $i ) { + if ( ! isset( $this->loggers[ $i ] ) ) { + $this->loggers[ $i ] = new Logger( 'callback', self::get_name_from_callback( $the_['function'] ) ); + } + $this->loggers[ $i ]->start(); + $value = call_user_func_array( $the_['function'], func_get_args() ); + $this->loggers[ $i ]->stop(); + return $value; + }, + 'accepted_args' => $_the['accepted_args'], + ); + } + } + + if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { + $wp_filter[ $current_filter ]->callbacks = $callbacks; + } else { + $wp_filter[ $current_filter ] = $callbacks; + } + } /** * Profiling verbosity at the end of every action and filter @@ -201,7 +216,7 @@ class Command { } } - if ( $this->focus_hook && $current_filter === $this->focus_hook ) { + if ( $this->focus_hook && $current_filter === $this->focus_hook && ! is_null( $this->current_filter_callbacks ) ) { if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) { $wp_filter[ $current_filter ]->callbacks = $this->current_filter_callbacks; } else {