record. */ private $hooks = array(); /** @var array Hook name => probe closure still waiting to run. */ private $probes = array(); /** @var array spl_object_id => true for every closure Hooktrail added. */ private $own_closures = array(); /** @var array Hook names being traced. */ private $trace_hooks = array(); /** @var array Hook name => list of fires, each { input, steps[] }. */ private $traces = array(); /** @var array */ private $queries = array(); /** @var array */ private $errors = array(); /** @var array Removed callbacks found between checkpoints. */ private $removed = array(); /** @var array|null Registration snapshot at the previous checkpoint. */ private $checkpoint = null; /** @var string Name of the previous checkpoint. */ private $checkpoint_name = ''; /** @var string */ private $template = ''; /** @var float */ private $start_time; /** @var array Normalized path prefixes treated as "not the caller" when attributing queries. */ private $skip_paths = array(); public static function instance() { if ( null === self::$instance ) { self::$instance = new self(); } return self::$instance; } private function __construct() { global $timestart; $this->start_time = ! empty( $timestart ) ? (float) $timestart : microtime( true ); } public function start() { if ( $this->active ) { return; } $this->active = true; $abspath = trailingslashit( wp_normalize_path( ABSPATH ) ); $this->skip_paths = array( $abspath . WPINC . '/class-wpdb.php', $abspath . WPINC . '/wp-db.php', trailingslashit( wp_normalize_path( HOOKTRAIL_DIR ) ), ); add_action( 'all', array( $this, 'on_hook' ) ); add_filter( 'query', array( $this, 'on_query' ), PHP_INT_MAX ); add_filter( 'template_include', array( $this, 'on_template' ), PHP_INT_MAX ); if ( ! $this->handler_installed ) { // A debugging tool's core job: note each PHP warning and notice, // then pass it on unchanged to whatever handled it before. $this->previous_handler = set_error_handler( array( $this, 'on_error' ) ); // phpcs:ignore WordPress.PHP.DevelopmentFunctions.error_log_set_error_handler $this->handler_installed = true; } } public function stop() { if ( ! $this->active ) { return; } remove_action( 'all', array( $this, 'on_hook' ) ); remove_filter( 'query', array( $this, 'on_query' ), PHP_INT_MAX ); remove_filter( 'template_include', array( $this, 'on_template' ), PHP_INT_MAX ); foreach ( $this->probes as $hook => $probe ) { remove_filter( $hook, $probe, PHP_INT_MAX ); } $this->probes = array(); $this->checkpoint( 'end' ); $this->active = false; } /** * Stop and drop everything recorded so far. */ public function discard() { $this->stop(); $this->hooks = array(); $this->traces = array(); $this->queries = array(); $this->errors = array(); $this->removed = array(); } public function is_active() { return $this->active; } /** * Filters whose callbacks should be traced value by value. * * @param array $hooks Hook names. */ public function set_trace_hooks( array $hooks ) { $this->trace_hooks = array_slice( array_values( array_filter( array_map( 'strval', $hooks ) ) ), 0, self::MAX_TRACE_HOOKS ); } public function get_trace_hooks() { return $this->trace_hooks; } public function get_hooks() { return $this->hooks; } public function get_traces() { return $this->traces; } public function get_queries() { return $this->queries; } public function get_errors() { return $this->errors; } public function get_removed() { return $this->removed; } public function get_template() { return $this->template; } /** * Whether a callback is one Hooktrail added itself (probe or wrapper). * * @param mixed $callback Callback. * @return bool */ public function is_own_closure( $callback ) { return $callback instanceof Closure && isset( $this->own_closures[ spl_object_id( $callback ) ] ); } // ------------------------------------------------------------------ // Hooks // ------------------------------------------------------------------ /** * Called by WordPress before every hook runs. * * @param mixed ...$args The hook name, followed by the hook's arguments. */ public function on_hook( ...$args ) { $hook = isset( $args[0] ) && is_string( $args[0] ) ? $args[0] : ''; if ( '' === $hook || 'all' === $hook ) { return; } $is_traced = in_array( $hook, $this->trace_hooks, true ); if ( isset( $this->hooks[ $hook ] ) ) { ++$this->hooks[ $hook ]['count']; if ( $is_traced ) { $this->begin_trace_fire( $hook, $args ); } return; } global $wp_filter, $wp_current_filter; // WordPress has already pushed this hook onto $wp_current_filter, // so the entry before it is the hook that was running. $stack = is_array( $wp_current_filter ) ? $wp_current_filter : array(); $depth = max( 0, count( $stack ) - 1 ); $parent = $depth > 0 ? (string) $stack[ $depth - 1 ] : ''; $now = microtime( true ); $has_callbacks = isset( $wp_filter[ $hook ] ) && $wp_filter[ $hook ] instanceof WP_Hook && ! empty( $wp_filter[ $hook ]->callbacks ); $this->hooks[ $hook ] = array( 'count' => 1, 'depth' => $depth, 'parent' => $parent, 'time' => round( ( $now - $this->start_time ) * 1000, 2 ), 'dur' => $has_callbacks ? null : 0.0, 'callbacks' => ( $has_callbacks && count( $this->hooks ) < self::MAX_HOOKS ) ? $wp_filter[ $hook ]->callbacks : null, ); if ( in_array( $hook, self::PHASES, true ) ) { $this->checkpoint( $hook ); } if ( $has_callbacks ) { $this->add_probe( $hook, $now ); } if ( $is_traced ) { $this->begin_trace_fire( $hook, $args ); } } /** * Add a last-priority callback that records when the hook's first run * finishes, then removes itself. * * @param string $hook Hook name. * @param float $start Start time. */ private function add_probe( $hook, $start ) { $recorder = $this; $probe = null; $probe = function ( $value = null ) use ( $recorder, $hook, $start, &$probe ) { $recorder->end_probe( $hook, $start, $probe ); return $value; }; $this->own_closures[ spl_object_id( $probe ) ] = true; $this->probes[ $hook ] = $probe; add_filter( $hook, $probe, PHP_INT_MAX, 1 ); } /** * @param string $hook Hook name. * @param float $start Start time. * @param Closure $probe The probe itself. */ public function end_probe( $hook, $start, $probe ) { if ( isset( $this->hooks[ $hook ] ) && null === $this->hooks[ $hook ]['dur'] ) { $this->hooks[ $hook ]['dur'] = round( ( microtime( true ) - $start ) * 1000, 3 ); } remove_filter( $hook, $probe, PHP_INT_MAX ); unset( $this->probes[ $hook ] ); } // ------------------------------------------------------------------ // Filter trace // ------------------------------------------------------------------ /** * Start recording one run of a traced filter and make sure every * callback on it is wrapped. * * @param string $hook Hook name. * @param array $args Arguments passed to the "all" hook. */ private function begin_trace_fire( $hook, array $args ) { if ( did_action( $hook ) > 0 ) { return; // Actions return nothing, so there is no value to follow. } if ( ! isset( $this->traces[ $hook ] ) ) { $this->traces[ $hook ] = array(); } if ( count( $this->traces[ $hook ] ) < self::TRACE_FIRES ) { $this->traces[ $hook ][] = array( 'input' => self::to_text( array_key_exists( 1, $args ) ? $args[1] : null ), 'steps' => array(), ); } $this->wrap_callbacks( $hook ); } /** * Replace each callback on a traced filter with a wrapper that records * the value before and after it. The registration key stays the same. * * @param string $hook Hook name. */ private function wrap_callbacks( $hook ) { global $wp_filter; if ( ! isset( $wp_filter[ $hook ] ) || ! $wp_filter[ $hook ] instanceof WP_Hook ) { return; } $recorder = $this; foreach ( $wp_filter[ $hook ]->callbacks as $priority => $entries ) { foreach ( $entries as $key => $entry ) { if ( ! isset( $entry['function'] ) || $this->is_own_closure( $entry['function'] ) ) { continue; } $original = $entry['function']; $accepted = (int) $entry['accepted_args']; $wrapper = function ( ...$values ) use ( $recorder, $hook, $priority, $original, $accepted ) { $before = array_key_exists( 0, $values ) ? $values[0] : null; if ( 0 === $accepted ) { $after = call_user_func( $original ); } elseif ( $accepted >= count( $values ) ) { $after = call_user_func_array( $original, $values ); } else { $after = call_user_func_array( $original, array_slice( $values, 0, $accepted ) ); } $recorder->trace_step( $hook, $priority, $original, $before, $after ); return $after; }; $this->own_closures[ spl_object_id( $wrapper ) ] = true; // Pass every argument to the wrapper; it slices them back to // what the original callback asked for. $wp_filter[ $hook ]->callbacks[ $priority ][ $key ] = array( 'function' => $wrapper, 'accepted_args' => PHP_INT_MAX, ); } } } /** * Record one callback's effect on a traced filter. * * @param string $hook Hook name. * @param int $priority Priority. * @param mixed $callback Original callback. * @param mixed $before Value passed in. * @param mixed $after Value returned. */ public function trace_step( $hook, $priority, $callback, $before, $after ) { if ( empty( $this->traces[ $hook ] ) ) { return; } $fire = count( $this->traces[ $hook ] ) - 1; if ( count( $this->traces[ $hook ][ $fire ]['steps'] ) >= 200 ) { return; } $before_text = self::to_text( $before ); $after_text = self::to_text( $after ); $this->traces[ $hook ][ $fire ]['steps'][] = array( 'priority' => (int) $priority, 'callback' => $callback, 'changed' => $before_text !== $after_text || gettype( $before ) !== gettype( $after ), 'after' => $after_text, 'type' => gettype( $after ), ); } /** * Readable, size-limited text version of any value. * * @param mixed $value Value. * @return string */ public static function to_text( $value ) { if ( is_string( $value ) ) { $text = $value; } elseif ( null === $value ) { $text = 'null'; } elseif ( is_bool( $value ) ) { $text = $value ? 'true' : 'false'; } elseif ( is_scalar( $value ) ) { $text = (string) $value; } else { $json = wp_json_encode( $value, JSON_PRETTY_PRINT | JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE | JSON_PARTIAL_OUTPUT_ON_ERROR ); $text = ( is_object( $value ) ? get_class( $value ) . ' ' : '' ) . ( false === $json ? '' : $json ); } if ( strlen( $text ) > self::TRACE_VALUE_MAX ) { $text = substr( $text, 0, self::TRACE_VALUE_MAX ) . "\n[...]"; } return $text; } // ------------------------------------------------------------------ // Database queries // ------------------------------------------------------------------ /** * @param string $sql Query about to run. * @return string The same query, unchanged. */ public function on_query( $sql ) { if ( ! $this->active || count( $this->queries ) >= self::MAX_QUERIES ) { return $sql; } global $wp_current_filter; // The top of the stack is "query" itself; the hook below it is the // one that was running when the query was made. $stack = is_array( $wp_current_filter ) ? $wp_current_filter : array(); $count = count( $stack ); $hook = $count >= 2 ? (string) $stack[ $count - 2 ] : ''; list( $file, $line, $function ) = $this->find_caller(); $this->queries[] = array( 'sql' => strlen( (string) $sql ) > self::SQL_MAX ? substr( (string) $sql, 0, self::SQL_MAX ) . ' [...]' : (string) $sql, 'hook' => $hook, 'file' => $file, 'line' => $line, 'fn' => $function, 'ms' => round( ( microtime( true ) - $this->start_time ) * 1000, 2 ), ); return $sql; } /** * The code that caused the current query or error: the first stack frame * in a plugin or theme if there is one, otherwise the first frame * outside wpdb and Hooktrail. * * @return array { file, line, function } */ private function find_caller() { // Needed to attribute a query or warning to the plugin that caused it. $frames = debug_backtrace( DEBUG_BACKTRACE_IGNORE_ARGS, 40 ); // phpcs:ignore WordPress.PHP.DevelopmentFunctions.error_log_debug_backtrace $content = trailingslashit( wp_normalize_path( WP_CONTENT_DIR ) ); $fallback = array( '', 0, '' ); // Start at the outermost call into the database class ($wpdb->query, // get_var, ...). Its "file" is the code that asked for the query. // This also works for database drop-ins (HyperDB, SQLite, ...) whose // own files live in wp-content: everything inside them is skipped. $from = 0; foreach ( $frames as $i => $frame ) { if ( ! empty( $frame['class'] ) && is_a( $frame['class'], 'wpdb', true ) ) { $from = $i; } } foreach ( $frames as $i => $frame ) { if ( $i < $from || empty( $frame['file'] ) ) { continue; } $file = wp_normalize_path( $frame['file'] ); $skip = false; foreach ( $this->skip_paths as $prefix ) { if ( 0 === strpos( $file, $prefix ) ) { $skip = true; break; } } if ( $skip ) { continue; } // The function that contains this call is described by the next frame. $function = ''; if ( isset( $frames[ $i + 1 ]['function'] ) ) { $function = ( isset( $frames[ $i + 1 ]['class'] ) ? $frames[ $i + 1 ]['class'] . $frames[ $i + 1 ]['type'] : '' ) . $frames[ $i + 1 ]['function']; } $found = array( $file, isset( $frame['line'] ) ? (int) $frame['line'] : 0, $function ); if ( 0 === strpos( $file, $content ) ) { return $found; } if ( '' === $fallback[0] ) { $fallback = $found; } } return $fallback; } // ------------------------------------------------------------------ // PHP errors // ------------------------------------------------------------------ /** * @param int $errno Error level. * @param string $errstr Message. * @param string $errfile File. * @param int $errline Line. * @return bool */ public function on_error( $errno, $errstr, $errfile = '', $errline = 0 ) { // Respect error_reporting() and the @ operator, like PHP itself does. if ( $this->active && ( error_reporting() & $errno ) && count( $this->errors ) < self::MAX_ERRORS ) { // phpcs:ignore WordPress.PHP.DevelopmentFunctions.prevent_path_disclosure_error_reporting,WordPress.PHP.DiscouragedPHPFunctions.runtime_configuration_error_reporting global $wp_current_filter; $stack = is_array( $wp_current_filter ) ? $wp_current_filter : array(); list( $caller_file, $caller_line ) = $this->find_caller(); $this->errors[] = array( 'level' => self::error_level( $errno ), 'message' => substr( (string) $errstr, 0, 500 ), 'file' => wp_normalize_path( (string) $errfile ), 'line' => (int) $errline, 'hook' => $stack ? (string) end( $stack ) : '', 'caller' => $caller_file, 'cline' => $caller_line, 'ms' => round( ( microtime( true ) - $this->start_time ) * 1000, 2 ), ); } if ( is_callable( $this->previous_handler ) ) { return (bool) call_user_func( $this->previous_handler, $errno, $errstr, $errfile, $errline ); } // Let PHP's normal error handling continue. return false; } /** * @param int $errno Error level. * @return string */ private static function error_level( $errno ) { switch ( $errno ) { case E_WARNING: case E_USER_WARNING: return 'Warning'; case E_NOTICE: case E_USER_NOTICE: return 'Notice'; case E_DEPRECATED: case E_USER_DEPRECATED: return 'Deprecated'; case E_USER_ERROR: case E_RECOVERABLE_ERROR: return 'Error'; default: return 'PHP ' . (int) $errno; } } // ------------------------------------------------------------------ // Removed callbacks // ------------------------------------------------------------------ /** * Compare the registered callbacks with the previous checkpoint and * record any that were removed in between. * * @param string $name Checkpoint name (a loading-stage hook or "end"). */ private function checkpoint( $name ) { global $wp_filter; $current = array(); foreach ( (array) $wp_filter as $hook => $wp_hook ) { if ( 'all' === $hook || ! $wp_hook instanceof WP_Hook ) { continue; } foreach ( $wp_hook->callbacks as $priority => $entries ) { foreach ( $entries as $key => $entry ) { if ( isset( $entry['function'] ) && ! $this->is_own_closure( $entry['function'] ) ) { $current[ $hook . '|' . $priority . '|' . $key ] = $entry['function']; } } } } if ( null !== $this->checkpoint ) { foreach ( array_diff_key( $this->checkpoint, $current ) as $id => $function ) { list( $hook, $priority ) = explode( '|', $id, 3 ); if ( count( $this->removed ) < 500 ) { $this->removed[] = array( 'hook' => $hook, 'priority' => (int) $priority, 'callback' => $function, 'after' => $this->checkpoint_name, 'before' => $name, ); } } } $this->checkpoint = $current; $this->checkpoint_name = $name; } // ------------------------------------------------------------------ // Template // ------------------------------------------------------------------ /** * @param string $template Template path WordPress is about to load. * @return string Unchanged. */ public function on_template( $template ) { $this->template = is_string( $template ) ? wp_normalize_path( $template ) : ''; return $template; } }