export-command/inc/class-command.php

403 lines
10 KiB
PHP
Raw Normal View History

2016-07-25 07:36:55 -07:00
<?php
2016-08-26 06:13:19 -07:00
namespace runcommand\Profile;
use WP_CLI;
use WP_CLI\Utils;
class Command {
2016-07-25 07:36:55 -07:00
private $loggers = array();
private $focus_stage = null;
2016-08-27 07:05:35 -07:00
private $stage_hooks = array();
private $focus_hook = null;
private $current_filter_callbacks = array();
private $focus_query_offset = 0;
private static $exception_message = "Need to bail, because can't restore the hooks";
2016-07-25 07:36:55 -07:00
/**
2016-10-04 06:49:18 -07:00
* Profile each stage of the WordPress load process (bootstrap, main_query, template).
2016-07-25 07:36:55 -07:00
*
* ## OPTIONS
*
* [<stage>]
2016-08-27 07:05:35 -07:00
* : Drill down into a specific stage.
*
* [--url=<url>]
* : Execute a request against a specified URL. Defaults to the home URL.
2016-08-25 07:00:39 -07:00
*
2016-07-25 10:17:10 -07:00
* [--fields=<fields>]
* : Display one or more fields.
2016-07-25 08:00:59 -07:00
*
* [--format=<format>]
* : Render output in a particular format.
* ---
* default: table
* options:
* - table
* - json
* - yaml
* - csv
* ---
*
2016-07-25 07:36:55 -07:00
* @when before_wp_load
*/
public function stage( $args, $assoc_args ) {
2016-07-25 08:10:43 -07:00
global $wpdb;
if ( isset( $args[0] ) ) {
$this->focus_stage = $args[0];
}
$valid_stages = array( 'bootstrap', 'main_query', 'template' );
if ( $this->focus_stage && ! in_array( $this->focus_stage, $valid_stages, true ) ) {
WP_CLI::error( 'Invalid stage. Must be one of: ' . implode( ', ', $valid_stages ) );
}
$this->run_profiler();
2016-08-27 07:05:35 -07:00
if ( $this->focus_stage ) {
2016-08-26 07:05:20 -07:00
$fields = array(
'hook',
2016-08-26 13:00:32 -07:00
'time',
2016-08-26 13:19:09 -07:00
'query_time',
'query_count',
2016-08-26 14:58:37 -07:00
'cache_ratio',
2016-08-26 13:19:09 -07:00
'cache_hits',
'cache_misses',
'request_time',
'request_count',
);
} else {
$fields = array(
2016-08-27 07:05:35 -07:00
'stage',
2016-08-26 13:00:32 -07:00
'time',
2016-08-26 13:19:09 -07:00
'query_time',
'query_count',
2016-08-26 14:58:37 -07:00
'cache_ratio',
2016-08-26 13:19:09 -07:00
'cache_hits',
'cache_misses',
'hook_time',
'hook_count',
'request_time',
'request_count',
);
2016-07-25 10:17:10 -07:00
}
2016-08-26 07:05:20 -07:00
$formatter = new Formatter( $assoc_args, $fields );
2016-08-26 09:57:28 -07:00
$formatter->display_items( $this->loggers );
}
/**
* Profile key metrics for a WordPress hook (action or filter).
*
* ## OPTIONS
*
* <hook>
* : WordPress hook (action or filter) to profile.
*
* [--url=<url>]
* : Execute a request against a specified URL. Defaults to the home URL.
*
* [--fields=<fields>]
* : Display one or more fields.
*
* [--format=<format>]
* : Render output in a particular format.
* ---
* default: table
* options:
* - table
* - json
* - yaml
* - csv
* ---
*
* @when before_wp_load
*/
public function hook( $args, $assoc_args ) {
$this->focus_hook = $args[0];
$this->run_profiler();
$fields = array(
'callback',
'time',
'query_time',
'query_count',
'cache_ratio',
'cache_hits',
'cache_misses',
'request_time',
'request_count',
);
$formatter = new Formatter( $assoc_args, $fields );
$formatter->display_items( $this->loggers );
}
/**
* Profiling verbosity at the beginning of every action and filter
*/
public function wp_hook_begin() {
2016-08-25 07:00:39 -07:00
global $wpdb, $wp_filter;
foreach( Logger::$active_loggers as $logger ) {
$logger->start_hook_timer();
}
$current_filter = current_filter();
2016-08-27 07:05:35 -07:00
if ( in_array( $current_filter, $this->stage_hooks ) ) {
2016-08-26 09:32:14 -07:00
$pseudo_hook = "before {$current_filter}";
if ( isset( $this->loggers[ $pseudo_hook ] ) ) {
$this->loggers[ $pseudo_hook ]->stop();
}
$this->loggers[ $current_filter ] = new Logger( 'hook', $current_filter );
$this->loggers[ $current_filter ]->start();
}
2016-08-25 07:00:39 -07:00
if ( $this->focus_hook && $current_filter === $this->focus_hook ) {
2016-09-27 08:10:41 -07:00
$this->wrap_current_filter_callbacks( $current_filter );
}
2016-09-28 05:27:58 -07:00
WP_CLI::add_wp_hook( $current_filter, array( $this, 'wp_hook_end' ), 9999 );
2016-09-27 08:10:41 -07:00
}
2016-09-27 08:10:41 -07:00
/**
* Wrap current filter callbacks with a timer
*/
private function wrap_current_filter_callbacks( $current_filter ) {
global $wp_filter;
$this->current_filter_callbacks = null;
2016-09-27 08:10:41 -07:00
if ( ! isset( $wp_filter[ $current_filter ] ) ) {
return;
}
2016-09-27 08:10:41 -07:00
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 ];
2016-08-25 07:00:39 -07:00
}
2016-09-27 08:10:41 -07:00
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;
},
2016-09-28 05:12:54 -07:00
'accepted_args' => $the_['accepted_args'],
2016-09-27 08:10:41 -07:00
);
}
}
if ( is_a( $wp_filter[ $current_filter ], 'WP_Hook' ) ) {
$wp_filter[ $current_filter ]->callbacks = $callbacks;
} else {
$wp_filter[ $current_filter ] = $callbacks;
}
2016-08-25 07:00:39 -07:00
}
/**
* Profiling verbosity at the end of every action and filter
*/
public function wp_hook_end( $filter_value = null ) {
2016-08-25 07:00:39 -07:00
global $wpdb, $wp_filter;
foreach( Logger::$active_loggers as $logger ) {
$logger->stop_hook_timer();
}
$current_filter = current_filter();
2016-08-27 07:05:35 -07:00
if ( in_array( $current_filter, $this->stage_hooks ) ) {
$this->loggers[ $current_filter ]->stop();
2016-08-27 07:05:35 -07:00
$key = array_search( $current_filter, $this->stage_hooks );
if ( false !== $key && isset( $this->stage_hooks[$key+1] ) ) {
$pseudo_hook = "before {$this->stage_hooks[$key+1]}";
2016-08-26 09:32:14 -07:00
$this->loggers[ $pseudo_hook ] = new Logger( 'hook', '' );
$this->loggers[ $pseudo_hook ]->start();
} else {
$pseudo_hook = 'wp_profile_last_hook';
$this->loggers[ $pseudo_hook ] = new Logger( 'hook', '' );
$this->loggers[ $pseudo_hook ]->start();
2016-08-26 09:32:14 -07:00
}
}
2016-09-27 08:10:41 -07:00
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 {
$wp_filter[ $current_filter ] = $this->current_filter_callbacks;
}
}
return $filter_value;
}
2016-08-26 08:26:42 -07:00
/**
* Profiling request time for any active Loggers
*/
public function wp_request_begin( $filter_value = null ) {
foreach( Logger::$active_loggers as $logger ) {
$logger->start_request_timer();
}
return $filter_value;
}
/**
* Profiling request time for any active Loggers
*/
public function wp_request_end( $filter_value = null ) {
foreach( Logger::$active_loggers as $logger ) {
$logger->stop_request_timer();
}
return $filter_value;
}
/**
* Run the profiler against WordPress
*/
private function run_profiler() {
WP_CLI::add_wp_hook( 'muplugins_loaded', function(){
if ( $url = WP_CLI::get_runner()->config['url'] ) {
WP_CLI::set_url( trailingslashit( $url ) );
} else {
WP_CLI::set_url( home_url( '/' ) );
}
});
WP_CLI::add_hook( 'after_wp_config_load', function() {
if ( defined( 'SAVEQUERIES' ) && ! SAVEQUERIES ) {
WP_CLI::error( "'SAVEQUERIES' is defined as false, and must be true. Please check your wp-config.php" );
}
if ( ! defined( 'SAVEQUERIES' ) ) {
define( 'SAVEQUERIES', true );
}
});
WP_CLI::add_wp_hook( 'all', array( $this, 'wp_hook_begin' ) );
WP_CLI::add_wp_hook( 'pre_http_request', array( $this, 'wp_request_begin' ) );
WP_CLI::add_wp_hook( 'http_api_debug', array( $this, 'wp_request_end' ) );
$this->load_wordpress_with_template();
}
/**
* Runs through the entirety of the WP bootstrap process
*/
private function load_wordpress_with_template() {
global $wp_query;
2016-08-27 07:05:35 -07:00
if ( 'bootstrap' === $this->focus_stage ) {
$this->set_stage_hooks( array(
'muplugins_loaded',
'plugins_loaded',
'setup_theme',
'after_setup_theme',
'init',
'wp_loaded',
2016-08-26 09:32:14 -07:00
) );
2016-08-27 07:05:35 -07:00
} else if ( ! $this->focus_stage && ! $this->focus_hook ) {
$logger = new Logger( 'stage', 'bootstrap' );
$logger->start();
}
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();
}
2016-08-27 07:05:35 -07:00
if ( ! $this->focus_stage && ! $this->focus_hook ) {
$logger->stop();
2016-08-26 09:57:28 -07:00
$this->loggers[] = $logger;
}
// Set up main_query main WordPress query.
2016-08-27 07:05:35 -07:00
if ( 'main_query' === $this->focus_stage ) {
$this->set_stage_hooks( array(
'parse_request',
'send_headers',
'pre_get_posts',
'the_posts',
'wp',
) );
2016-08-27 07:05:35 -07:00
} else if ( ! $this->focus_stage && ! $this->focus_hook ) {
$logger = new Logger( 'stage', 'main_query' );
$logger->start();
}
wp();
if ( isset( $this->loggers['wp_profile_last_hook'] ) && $this->loggers['wp_profile_last_hook']->running() ) {
$this->loggers['wp_profile_last_hook']->stop();
}
2016-08-27 07:05:35 -07:00
if ( ! $this->focus_stage && ! $this->focus_hook ) {
$logger->stop();
2016-08-26 09:57:28 -07:00
$this->loggers[] = $logger;
}
define( 'WP_USE_THEMES', true );
2016-08-27 07:05:35 -07:00
// Template is normally loaded in global stage, so we need to replicate
foreach( $GLOBALS as $key => $value ) {
global $$key;
}
// Load the theme template.
if ( 'template' === $this->focus_stage ) {
$this->set_stage_hooks( array(
'template_redirect',
'template_include',
'wp_head',
'loop_start',
'loop_end',
'wp_footer',
) );
} else if ( ! $this->focus_stage && ! $this->focus_hook ) {
2016-08-27 07:05:35 -07:00
$logger = new Logger( 'stage', 'template' );
$logger->start();
}
ob_start();
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();
}
2016-08-27 07:05:35 -07:00
if ( ! $this->focus_stage && ! $this->focus_hook ) {
$logger->stop();
2016-08-26 09:57:28 -07:00
$this->loggers[] = $logger;
}
}
2016-08-25 07:13:40 -07:00
/**
* Get a human-readable name from a callback
*/
private static function get_name_from_callback( $callback ) {
$name = '';
if ( is_array( $callback ) && is_object( $callback[0] ) ) {
$name = get_class( $callback[0] ) . '->' . $callback[1] . '()';
} elseif ( is_array( $callback ) && method_exists( $callback[0], $callback[1] ) ) {
$name = $callback[0] . '::' . $callback[1] . '()';
} elseif ( is_object( $callback ) && is_a( $callback, 'Closure' ) ) {
$name = 'function(){}';
} else if ( is_string( $callback ) ) {
$name = $callback . '()';
}
return $name;
}
2016-08-26 09:32:14 -07:00
/**
2016-08-27 07:05:35 -07:00
* Set the hooks for the current stage
2016-08-26 09:32:14 -07:00
*/
2016-08-27 07:05:35 -07:00
private function set_stage_hooks( $hooks ) {
$this->stage_hooks = $hooks;
2016-08-26 09:32:14 -07:00
$pseudo_hook = "before {$hooks[0]}";
2016-08-26 09:37:41 -07:00
$this->loggers[ $pseudo_hook ] = new Logger( 'hook', '' );
$this->loggers[ $pseudo_hook ]->start();
2016-08-26 09:32:14 -07:00
}
2016-07-25 07:36:55 -07:00
}