Merge pull request #129 from alleyinteractive/feature/condense-trace-do-action

Reduce backtrace display of hooks

Author: srtfisher

.phpunit-watcher.yml

@@ -0,0 +1,7 @@
+watch:
+  directories:
+    - tests
+    - inc
+  fileMask: '*.php'
+phpunit:
+  timeout: 300

CHANGELOG.md

@@ -3,6 +3,10 @@
 This library adheres to [Semantic Versioning](https://semver.org/) and [Keep a
 CHANGELOG](https://keepachangelog.com/en/1.0.0/).
 
+## 2.6.0 - 2024-12-19
+
+- Collapse internal calls to `do_action` and `apply_filters` in the log backtrace.
+
 ## 2.5.0 - 2024-09-03
 
 - Change the garbage collector to schedule a single recurring event to clean up logs instead of `wp_schedule_single_event`.

inc/backtrace/class-frame.php

@@ -8,13 +8,21 @@
 namespace AI_Logger\Backtrace;
 
 use Spatie\Backtrace\Frame as SpatieFrame;
+use WP_Hook;
 
 /**
  * Frame extension class.
  *
  * Stores the frame's code snippet in the frame itself for serialization and storage.
  */
 class Frame extends SpatieFrame {
+	/**
+	 * Hook methods to ignore.
+	 *
+	 * @var array<string>
+	 */
+	const HOOK_METHODS = [ 'do_action', 'do_action_ref_array', 'apply_filters', 'apply_filters_ref_array' ];
+
 	/**
 	 * Code snippet.
 	 *
@@ -56,6 +64,16 @@ public static function from_base( SpatieFrame $frame ): self {
 	 * @param int $line_count Number of lines to load.
 	 */
 	public function load_snippet( int $line_count ): void {
+		// Prevent snippet from being loaded for specific internal frames which
+		// don't make sense to store (such as do_action).
+		if ( WP_Hook::class === $this->class ) {
+			return;
+		}
+
+		if ( ! $this->class && in_array( $this->method, self::HOOK_METHODS, true ) ) {
+			return;
+		}
+
 		$this->snippet = $this->getSnippet( $line_count );
 	}
 }

inc/handler/class-post-handler.php

@@ -113,8 +113,7 @@ protected function write( array $record ): void {
 					],
 					true
 				)
-			)
-				->frames();
+			)->frames();
 
 			$record['extra']['backtrace'] = array_map(
 				fn ( SpatieFrame $frame ) => Frame::from_base( $frame ),

template-parts/log-display.php

@@ -5,6 +5,7 @@
  * @package AI_Logger
  */
 
+use AI_Logger\Backtrace\Frame;
 use AI_Logger\Data_Structures;
 
 use function Mantle\Support\Helpers\str;
@@ -47,12 +48,60 @@ function ai_logger_render_legacy_backtrace( array $backtrace ): void {
 	<?php
 }
 
+/**
+ * Collapse do_action/do_action_ref_array/apply_filters/apply_filters_ref_array
+ * calls in the backtrace. This is to prevent the backtrace from being
+ * cluttered with calls to these internal WordPress functions.
+ *
+ * @param array<\AI_Logger\Backtrace\Frame> $backtrace Backtrace to collapse.
+ * @return array<\AI_Logger\Backtrace\Frame> Collapsed backtrace.
+ */
+function ai_logger_collapse_hook_calls( array $backtrace ): array {
+	// Prevent compression if the query parameter is set.
+	if ( ! empty( $_GET['ai_logger_dont_compress'] ) ) { // phpcs:ignore WordPress.Security.NonceVerification.Recommended
+		return $backtrace;
+	}
+
+	for ( $i = 0; $i < count( $backtrace ) - 1; $i++ ) { // phpcs:ignore Generic.CodeAnalysis.ForLoopShouldBeWhileLoop.ForLoop, Squiz.PHP.DisallowSizeFunctionsInLoops.Found, Generic.CodeAnalysis.ForLoopWithTestFunctionCall.NotAllowed
+		$current = $backtrace[ $i ];
+
+		if ( \WP_Hook::class !== $current->class ) {
+			continue;
+		}
+
+		if ( ! in_array( $current->method, Frame::HOOK_METHODS, true ) ) {
+			continue;
+		}
+
+		// Determine where the backtrace exits from WP_Hook. Find all the frames and
+		// remove them. This could be in 2 frames or 5.
+		for ( $si = $i + 1; $si < count( $backtrace ); $si++ ) { // phpcs:ignore Generic.CodeAnalysis.ForLoopShouldBeWhileLoop.ForLoop, Squiz.PHP.DisallowSizeFunctionsInLoops.Found, Generic.CodeAnalysis.ForLoopWithTestFunctionCall.NotAllowed
+			$next = $backtrace[ $si ];
+
+			if ( \WP_Hook::class === $next->class ) {
+				continue;
+			}
+
+			if ( in_array( $next->method, Frame::HOOK_METHODS, true ) ) {
+				continue;
+			}
+
+			array_splice( $backtrace, $i, $si - $i, [] );
+
+			break;
+		}
+	}
+
+	return $backtrace;
+}
+
 /**
  * Render the backtrace powered by spatie/backtrace.
  *
  * @param array<\AI_Logger\Backtrace\Frame> $backtrace Backtrace to render.
  */
 function ai_logger_render_backtrace( array $backtrace ): void {
+	$backtrace = ai_logger_collapse_hook_calls( $backtrace );
 	?>
 	<div class="ai-log-backtrace">
 		<?php

tests/Handler/PostHandlerTest.php

@@ -0,0 +1,43 @@
+<?php
+namespace AI_Logger\Tests\Handler;
+
+use AI_Logger\Backtrace\Frame;
+use AI_Logger\Handler\Post_Handler;
+use Mantle\Testkit\Test_Case;
+use Monolog\Logger;
+use WP_Post;
+
+class PostHandlerTest extends Test_Case {
+	protected Logger $logger;
+
+	protected function setUp(): void {
+		parent::setUp();
+
+		$this->logger = new Logger( 'test', [
+			new Post_Handler(),
+		] );
+
+		// Prevent logging on shutdown by default.
+		remove_action( 'shutdown', 'wp_ob_end_flush_all', 1 );
+		add_filter( 'ai_logger_should_write_on_shutdown', '__return_false' );
+	}
+
+	public function test_generates_a_backtrace(): void {
+		$this->logger->info( 'a message to log' );
+
+		$log = $this->get_last_log();
+
+		$this->assertNotNull( $log );
+
+		$record = get_post_meta( $log->ID, '_logger_record', true );
+
+		$this->assertNotEmpty( $record['extra']['backtrace'] );
+		$this->assertContainsOnlyInstancesOf( Frame::class, $record['extra']['backtrace'] );
+	}
+
+	protected function get_last_log(): ?WP_Post {
+		$logs = get_posts( [ 'post_type' => 'ai_log', 'numberposts' => 1, 'orderby' => 'ID', 'order' => 'DESC' ] );
+
+		return array_shift( $logs );
+	}
+}