Produce a more comprehensive summary

This commit is contained in:
Daniel Bachhuber 2016-07-25 10:17:10 -07:00
parent f2c529011e
commit cd6e40a6f8
2 changed files with 111 additions and 17 deletions

View file

@ -10,16 +10,31 @@ Quick links: [Using](#using) | [Installing](#installing) | [Contributing](#contr
## Using ## Using
~~~ ~~~
wp profile [--url=<url>] [--field=<field>] [--format=<format>] wp profile [--url=<url>] [--fields=<fields>] [--format=<format>]
~~~ ~~~
Monitors aspects of the WordPress execution process to display key
performance indicators for audit.
```
$ wp profile
+------------+----------------+-------------+------------+------------+-----------+--------------+
| scope | execution_time | query_count | query_time | hook_count | hook_time | memory_usage |
+------------+----------------+-------------+------------+------------+-----------+--------------+
| total | 2.68269s | 192 | 0.02165s | 10737 | 0.19395s | 49.25mb |
| bootstrap | 2.34255s | 15 | 0.00386s | 2835 | 0.11172s | 45mb |
| main_query | 0.01155s | 3 | 0.0004s | 78 | 0.00117s | 45.75mb |
| template | 0.32768s | 174 | 0.0174s | 7824 | 0.08106s | 49.25mb |
+------------+----------------+-------------+------------+------------+-----------+--------------+
```
**OPTIONS** **OPTIONS**
[--url=<url>] [--url=<url>]
Execute a request against a specified URL. Defaults to the home URL. Execute a request against a specified URL. Defaults to the home URL.
[--field=<field>] [--fields=<fields>]
Display a specific field. Display one or more fields.
[--format=<format>] [--format=<format>]
Render output in a particular format. Render output in a particular format.

View file

@ -5,21 +5,38 @@
*/ */
class Profile_Command { class Profile_Command {
private $start_time; private $hook_start_time = 0;
private $hook_count = 0; private $hook_time = 0;
private $hook_start_time; private $scope_log;
private $hook_time; private $current_scope;
private $query_offset = 0;
private $hook_offset = 0;
/** /**
* Profile the performance of a WordPress request. * Profile the performance of a WordPress request.
* *
* Monitors aspects of the WordPress execution process to display key
* performance indicators for audit.
*
* ```
* $ wp profile
* +------------+----------------+-------------+------------+------------+-----------+--------------+
* | scope | execution_time | query_count | query_time | hook_count | hook_time | memory_usage |
* +------------+----------------+-------------+------------+------------+-----------+--------------+
* | total | 2.68269s | 192 | 0.02165s | 10737 | 0.19395s | 49.25mb |
* | bootstrap | 2.34255s | 15 | 0.00386s | 2835 | 0.11172s | 45mb |
* | main_query | 0.01155s | 3 | 0.0004s | 78 | 0.00117s | 45.75mb |
* | template | 0.32768s | 174 | 0.0174s | 7824 | 0.08106s | 49.25mb |
* +------------+----------------+-------------+------------+------------+-----------+--------------+
* ```
*
* ## OPTIONS * ## OPTIONS
* *
* [--url=<url>] * [--url=<url>]
* : Execute a request against a specified URL. Defaults to the home URL. * : Execute a request against a specified URL. Defaults to the home URL.
* *
* [--field=<field>] * [--fields=<fields>]
* : Display a specific field. * : Display one or more fields.
* *
* [--format=<format>] * [--format=<format>]
* : Render output in a particular format. * : Render output in a particular format.
@ -37,41 +54,66 @@ class Profile_Command {
public function __invoke( $args, $assoc_args ) { public function __invoke( $args, $assoc_args ) {
global $wpdb; global $wpdb;
$this->scope_log = array();
$scope_fields = array(
'scope',
'execution_time',
'query_count',
'query_time',
'hook_count',
'hook_time',
'memory_usage',
);
foreach( array( 'total', 'bootstrap', 'main_query', 'template' ) as $scope ) {
$this->scope_log[ $scope ] = array();
foreach( $scope_fields as $field ) {
if ( 'scope' === $field ) {
$this->scope_log[ $scope ][ $field ] = $scope;
} else {
$this->scope_log[ $scope ][ $field ] = 0;
}
}
}
if ( ! isset( \WP_CLI::get_runner()->config['url'] ) ) { if ( ! isset( \WP_CLI::get_runner()->config['url'] ) ) {
$this->add_wp_hook( 'muplugins_loaded', function(){ $this->add_wp_hook( 'muplugins_loaded', function(){
WP_CLI::set_url( home_url( '/' ) ); WP_CLI::set_url( home_url( '/' ) );
}); });
} }
if ( ! defined( 'SAVEQUERIES' ) ) { if ( ! defined( 'SAVEQUERIES' ) ) {
define( 'SAVEQUERIES', true ); define( 'SAVEQUERIES', true );
} }
$this->add_wp_hook( 'all', array( $this, 'wp_hook_begin' ) ); $this->add_wp_hook( 'all', array( $this, 'wp_hook_begin' ) );
$this->start_time = microtime( true );
$this->load_wordpress_with_template(); $this->load_wordpress_with_template();
$end_time = microtime( true );
$total_query_time = 0; $total_query_time = 0;
foreach( $wpdb->queries as $query ) { foreach( $wpdb->queries as $query ) {
$total_query_time += $query[1]; $total_query_time += $query[1];
} }
$profile = array( $profile = array(
'hook_count' => $this->hook_count,
'hook_time' => $this->hook_time, 'hook_time' => $this->hook_time,
'execution_time' => round( $end_time - $this->start_time, 3 ) . 's',
'memory_usage' => self::convert_size( memory_get_usage( true ) ), 'memory_usage' => self::convert_size( memory_get_usage( true ) ),
'query_count' => count( $wpdb->queries ), 'query_count' => count( $wpdb->queries ),
'query_time' => round( $total_query_time, 3 ) . 's', 'query_time' => round( $total_query_time, 3 ) . 's',
'template_time' => round( $this->template_time, 3 ) . 's',
); );
$formatter = new \WP_CLI\Formatter( $assoc_args, array_keys( $profile ) ); foreach( $this->scope_log as $scope => $data ) {
$formatter->display_item( $profile ); foreach( $data as $key => $value ) {
if ( stripos( $key,'_time' ) ) {
$this->scope_log[ $scope ][ $key ] = round( $value, 5 ) . 's';
}
}
}
$formatter = new \WP_CLI\Formatter( $assoc_args, $scope_fields );
$formatter->display_items( $this->scope_log );
} }
/** /**
* Profiling verbosity at the beginning of every action and filter * Profiling verbosity at the beginning of every action and filter
*/ */
public function wp_hook_begin() { public function wp_hook_begin() {
$this->hook_count++; $this->scope_log['total']['hook_count']++;
$this->scope_log[ $this->current_scope ]['hook_count']++;
$this->hook_start_time = microtime( true ); $this->hook_start_time = microtime( true );
$this->add_wp_hook( current_filter(), array( $this, 'wp_hook_end' ), 999 ); $this->add_wp_hook( current_filter(), array( $this, 'wp_hook_end' ), 999 );
} }
@ -91,10 +133,16 @@ class Profile_Command {
private function load_wordpress_with_template() { private function load_wordpress_with_template() {
global $wp_query; global $wp_query;
$this->scope_track_begin( 'total' );
$this->scope_track_begin( 'bootstrap' );
WP_CLI::get_runner()->load_wordpress(); WP_CLI::get_runner()->load_wordpress();
$this->scope_track_end( 'bootstrap' );
// Set up the main WordPress query. // Set up the main WordPress query.
$this->current_scope = 'main_query';
$this->scope_track_begin( 'main_query' );
wp(); wp();
$this->scope_track_end( 'main_query' );
define( 'WP_USE_THEMES', true ); define( 'WP_USE_THEMES', true );
@ -104,9 +152,40 @@ class Profile_Command {
} }
// Load the theme template. // Load the theme template.
$this->scope_track_begin( 'template' );
ob_start(); ob_start();
require_once( ABSPATH . WPINC . '/template-loader.php' ); require_once( ABSPATH . WPINC . '/template-loader.php' );
ob_get_clean(); ob_get_clean();
$this->scope_track_end( 'template' );
$this->scope_track_end( 'total' );
}
/**
* Start tracking the current scope
*/
private function scope_track_begin( $scope ) {
if ( 'total' !== $scope ) {
$this->current_scope = $scope;
}
$this->scope_log[ $scope ]['execution_time'] = microtime( true );
$this->hook_offset = $this->hook_time;
}
/**
* End tracking the current scope
*/
private function scope_track_end( $scope ) {
global $wpdb;
$this->scope_log[ $scope ]['memory_usage'] = self::convert_size( memory_get_usage( true ) );
$this->scope_log[ $scope ]['execution_time'] = microtime( true ) - $this->scope_log[ $scope ]['execution_time'];
$query_offset = 'total' === $scope ? 0 : $this->query_offset;
for ( $i = $query_offset; $i < count( $wpdb->queries ); $i++ ) {
$this->scope_log[ $scope ]['query_time'] += $wpdb->queries[ $i ][1];
$this->scope_log[ $scope ]['query_count']++;
}
$this->query_offset = count( $wpdb->queries );
$hook_time = 'total' === $scope ? $this->hook_time : $this->hook_time - $this->hook_offset;
$this->scope_log[ $scope ]['hook_time'] = $hook_time;
} }
/** /**