Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
146 changes: 143 additions & 3 deletions features/profile-eval.feature
Original file line number Diff line number Diff line change
Expand Up @@ -10,10 +10,10 @@ Feature: Profile arbitary code execution
}
"""

When I run `wp profile eval 'wp_cli_do_nothing();' --fields=query_time,query_count,cache_ratio,cache_hits,cache_misses,request_time,request_count`
When I run `wp profile eval 'wp_cli_do_nothing();' --fields=query_time,query_count,cache_ratio,cache_hits,cache_misses,cache_calls,request_time,request_count`
Then STDOUT should be a table containing rows:
| query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
| 0s | 0 | | 0 | 0 | 0s | 0 |
| query_time | query_count | cache_ratio | cache_hits | cache_misses | cache_calls | request_time | request_count |
| 0s | 0 | | 0 | 0 | 0 | 0s | 0 |

Scenario: Profile a function that makes one HTTP request
Given a WP install
Expand Down Expand Up @@ -48,3 +48,143 @@ Feature: Profile arbitary code execution
Then STDOUT should be a table containing rows:
| callback | cache_hits | cache_misses |
| function(){} | 0 | 1 |

Scenario: cache_calls shows 0 when no persistent object cache is active
Given a WP install

When I run `wp profile eval 'wp_cache_get( "foo" );' --fields=cache_misses,cache_calls`
Then STDOUT should be a table containing rows:
| cache_misses | cache_calls |
| 1 | 0 |

Scenario: cache_calls tracks calls to a persistent object cache that exposes cache_calls
Given a WP install
And a wp-content/object-cache.php file:
"""
<?php
function wp_cache_init() {
global $wp_object_cache;
$wp_object_cache = new WP_Object_Cache_With_Cache_Calls();
}
function wp_cache_add( $key, $data, $group = '', $expire = 0 ) {
global $wp_object_cache;
return $wp_object_cache->add( $key, $data, $group, (int) $expire );
}
function wp_cache_add_global_groups( $groups ) {
global $wp_object_cache;
$wp_object_cache->add_global_groups( $groups );
}
function wp_cache_add_non_persistent_groups( $groups ) {}
function wp_cache_close() { return true; }
function wp_cache_decr( $key, $offset = 1, $group = '' ) {
global $wp_object_cache;
return $wp_object_cache->decr( $key, $offset, $group );
}
function wp_cache_delete( $key, $group = '' ) {
global $wp_object_cache;
return $wp_object_cache->delete( $key, $group );
}
function wp_cache_flush() {
global $wp_object_cache;
return $wp_object_cache->flush();
}
function wp_cache_get( $key, $group = '', $force = false, &$found = null ) {
global $wp_object_cache;
return $wp_object_cache->get( $key, $group, $force, $found );
}
function wp_cache_incr( $key, $offset = 1, $group = '' ) {
global $wp_object_cache;
return $wp_object_cache->incr( $key, $offset, $group );
}
function wp_cache_replace( $key, $data, $group = '', $expire = 0 ) {
global $wp_object_cache;
return $wp_object_cache->replace( $key, $data, $group, (int) $expire );
}
function wp_cache_set( $key, $data, $group = '', $expire = 0 ) {
global $wp_object_cache;
return $wp_object_cache->set( $key, $data, $group, (int) $expire );
}
function wp_cache_switch_to_blog( $blog_id ) {}
class WP_Object_Cache_With_Cache_Calls {
public $cache = array();
public $cache_hits = 0;
public $cache_misses = 0;
public $cache_calls = array();
private $global_groups = array();
private function cache_key( $key, $group ) {
return $group . ':' . $key;
}
private function track( $command ) {
$this->cache_calls[ $command ] = isset( $this->cache_calls[ $command ] ) ? $this->cache_calls[ $command ] + 1 : 1;
}
public function add( $key, $data, $group = 'default', $expire = 0 ) {
if ( isset( $this->cache[ $this->cache_key( $key, $group ) ] ) ) {
return false;
}
return $this->set( $key, $data, $group, $expire );
}
public function set( $key, $data, $group = 'default', $expire = 0 ) {
$this->cache[ $this->cache_key( $key, $group ) ] = $data;
$this->track( 'set' );
return true;
}
public function get( $key, $group = 'default', $force = false, &$found = null ) {
$this->track( 'get' );
if ( isset( $this->cache[ $this->cache_key( $key, $group ) ] ) ) {
$found = true;
$this->cache_hits++;
return $this->cache[ $this->cache_key( $key, $group ) ];
}
$found = false;
$this->cache_misses++;
return false;
}
public function delete( $key, $group = 'default' ) {
$cache_key = $this->cache_key( $key, $group );
if ( ! isset( $this->cache[ $cache_key ] ) ) {
return false;
}
unset( $this->cache[ $cache_key ] );
$this->track( 'del' );
return true;
}
public function flush() {
$this->cache = array();
return true;
}
public function decr( $key, $offset = 1, $group = 'default' ) {
$cache_key = $this->cache_key( $key, $group );
if ( ! isset( $this->cache[ $cache_key ] ) ) {
return false;
}
$this->cache[ $cache_key ] = max( 0, (int) $this->cache[ $cache_key ] - $offset );
$this->track( 'decrby' );
return $this->cache[ $cache_key ];
}
public function incr( $key, $offset = 1, $group = 'default' ) {
$cache_key = $this->cache_key( $key, $group );
if ( ! isset( $this->cache[ $cache_key ] ) ) {
return false;
}
$this->cache[ $cache_key ] = (int) $this->cache[ $cache_key ] + $offset;
$this->track( 'incrby' );
return $this->cache[ $cache_key ];
}
public function replace( $key, $data, $group = 'default', $expire = 0 ) {
if ( ! isset( $this->cache[ $this->cache_key( $key, $group ) ] ) ) {
return false;
}
return $this->set( $key, $data, $group, $expire );
}
public function add_global_groups( $groups ) {
foreach ( (array) $groups as $group ) {
$this->global_groups[ $group ] = true;
}
}
}
"""

When I run `wp profile eval 'wp_cache_set( "foo", "bar" ); wp_cache_get( "foo" ); wp_cache_get( "foo" );' --fields=cache_hits,cache_misses,cache_calls`
Then STDOUT should be a table containing rows:
| cache_hits | cache_misses | cache_calls |
| 2 | 0 | 3 |
4 changes: 4 additions & 0 deletions src/Command.php
Original file line number Diff line number Diff line change
Expand Up @@ -164,6 +164,7 @@ public function stage( $args, $assoc_args ) {
'cache_ratio',
'cache_hits',
'cache_misses',
'cache_calls',
'request_time',
'request_count',
);
Expand All @@ -178,6 +179,7 @@ public function stage( $args, $assoc_args ) {
'cache_ratio',
'cache_hits',
'cache_misses',
'cache_calls',
'hook_time',
'hook_count',
'request_time',
Expand Down Expand Up @@ -300,6 +302,7 @@ public function hook( $args, $assoc_args ) {
'cache_ratio',
'cache_hits',
'cache_misses',
'cache_calls',
'request_time',
'request_count',
);
Expand Down Expand Up @@ -522,6 +525,7 @@ private static function profile_eval_ish( $assoc_args, $profile_callback, $order
'cache_ratio',
'cache_hits',
'cache_misses',
'cache_calls',
'request_time',
'request_count',
)
Expand Down
56 changes: 51 additions & 5 deletions src/Logger.php
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@ class Logger {
/** @var string|null */
public $cache_ratio = null;
/** @var int */
public $cache_calls = 0;
/** @var int */
public $hook_count = 0;
/** @var float */
public $hook_time = 0;
Expand All @@ -44,6 +46,8 @@ class Logger {
private $cache_hit_offset = null;
/** @var int|null */
private $cache_miss_offset = null;
/** @var int|null */
private $cache_calls_offset = null;
/** @var float|null */
private $hook_start_time = null;
/** @var int */
Expand Down Expand Up @@ -119,6 +123,10 @@ public function start() {
}
$this->cache_hit_offset = ! empty( $wp_object_cache->cache_hits ) ? $wp_object_cache->cache_hits : 0;
$this->cache_miss_offset = ! empty( $wp_object_cache->cache_misses ) ? $wp_object_cache->cache_misses : 0;
$total = self::get_object_cache_calls( $wp_object_cache );
if ( ! is_null( $total ) ) {
$this->cache_calls_offset = $total;
}
}

/**
Expand Down Expand Up @@ -164,11 +172,19 @@ public function stop() {
}
}

$this->start_time = null;
$this->query_offset = null;
$this->cache_hit_offset = null;
$this->cache_miss_offset = null;
$key = array_search( $this, self::$active_loggers, true );
if ( ! is_null( $this->cache_calls_offset ) && isset( $wp_object_cache ) ) {
$total = self::get_object_cache_calls( $wp_object_cache );
if ( ! is_null( $total ) ) {
$this->cache_calls = $total - $this->cache_calls_offset;
}
}

$this->start_time = null;
$this->query_offset = null;
$this->cache_hit_offset = null;
$this->cache_miss_offset = null;
$this->cache_calls_offset = null;
$key = array_search( $this, self::$active_loggers, true );

if ( false !== $key ) {
unset( self::$active_loggers[ $key ] );
Expand Down Expand Up @@ -227,4 +243,34 @@ public function stop_request_timer() {
}
$this->request_start_time = null;
}

/**
* Get the total number of object cache backend calls from the active cache.
*
* Supports multiple implementations:
* - WP Redis: $wp_object_cache->redis_calls (array of command => count)
* - Redis Object Cache: $wp_object_cache->cache_calls (array of command => count)
* - Object Cache Pro: $wp_object_cache->metrics()->storeReads + storeWrites
*
* @param object|null $wp_object_cache
* @return int|null Total call count, or null if not supported.
*/
public static function get_object_cache_calls( $wp_object_cache ) {
if ( ! is_object( $wp_object_cache ) ) {
return null;
}
if ( isset( $wp_object_cache->redis_calls ) && is_array( $wp_object_cache->redis_calls ) ) {
return (int) array_sum( $wp_object_cache->redis_calls );
}
if ( isset( $wp_object_cache->cache_calls ) && is_array( $wp_object_cache->cache_calls ) ) {
return (int) array_sum( $wp_object_cache->cache_calls );
}
if ( method_exists( $wp_object_cache, 'metrics' ) ) {
$metrics = $wp_object_cache->metrics();
if ( is_object( $metrics ) && isset( $metrics->storeReads ) && isset( $metrics->storeWrites ) ) { // phpcs:ignore WordPress.NamingConventions.ValidVariableName.UsedPropertyNotSnakeCase
return (int) $metrics->storeReads + (int) $metrics->storeWrites; // phpcs:ignore WordPress.NamingConventions.ValidVariableName.UsedPropertyNotSnakeCase
}
}
return null;
}
}
25 changes: 19 additions & 6 deletions src/Profiler.php
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,8 @@ class Profiler {
private $tick_cache_hit_offset = null;
/** @var int|null */
private $tick_cache_miss_offset = null;
/** @var int|null */
private $tick_cache_calls_offset = null;

/** @var bool */
private $is_admin_request = false;
Expand Down Expand Up @@ -403,6 +405,7 @@ public function handle_function_tick() {
'cache_hits' => 0,
'cache_misses' => 0,
'cache_ratio' => null,
'cache_calls' => 0,
);
}

Expand Down Expand Up @@ -439,6 +442,15 @@ public function handle_function_tick() {
$ratio = ( $logger_data['cache_hits'] / $total ) * 100;
$logger_data['cache_ratio'] = round( $ratio, 2 ) . '%';
}

if ( ! is_null( $this->tick_cache_calls_offset ) ) {
$total = Logger::get_object_cache_calls( $wp_object_cache );
if ( ! is_null( $total ) ) {
$current_cache_calls = isset( $logger_data['cache_calls'] ) && is_numeric( $logger_data['cache_calls'] ) ? $logger_data['cache_calls'] : 0;
$delta = $total - $this->tick_cache_calls_offset;
$logger_data['cache_calls'] = $delta + (int) $current_cache_calls;
}
}
}
$this->loggers[ $callback_hash ] = $logger_data;
}
Expand Down Expand Up @@ -479,12 +491,13 @@ public function handle_function_tick() {
}
}

$this->tick_callback = $callback;
$this->tick_location = $location;
$this->tick_start_time = microtime( true );
$this->tick_query_offset = ! empty( $wpdb->queries ) ? count( $wpdb->queries ) : 0;
$this->tick_cache_hit_offset = ! empty( $wp_object_cache->cache_hits ) ? $wp_object_cache->cache_hits : 0;
$this->tick_cache_miss_offset = ! empty( $wp_object_cache->cache_misses ) ? $wp_object_cache->cache_misses : 0;
$this->tick_callback = $callback;
$this->tick_location = $location;
$this->tick_start_time = microtime( true );
$this->tick_query_offset = ! empty( $wpdb->queries ) ? count( $wpdb->queries ) : 0;
$this->tick_cache_hit_offset = ! empty( $wp_object_cache->cache_hits ) ? $wp_object_cache->cache_hits : 0;
$this->tick_cache_miss_offset = ! empty( $wp_object_cache->cache_misses ) ? $wp_object_cache->cache_misses : 0;
$this->tick_cache_calls_offset = Logger::get_object_cache_calls( $wp_object_cache );
}

/**
Expand Down
Loading