Skip to content

REST API: Log suppressed diagnostic messages to the debug log #12531

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
deepakpra wants to merge 1 commit into from
Closed

REST API: Log suppressed diagnostic messages to the debug log #12531

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
94 changes: 88 additions & 6 deletions src/wp-includes/rest-api.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -706,6 +706,76 @@ function rest_ensure_response( $response ) {
return new WP_REST_Response( $response );
}

/**
* Returns the caller location for a REST API debug log entry.
*
* @since 7.1.0
* @access private
*
* @return string The formatted caller location, or an empty string when unavailable.
*/
function _rest_get_debug_backtrace_caller(): string {
$backtrace = debug_backtrace( DEBUG_BACKTRACE_IGNORE_ARGS );
$normalized_content_dir = trailingslashit( wp_normalize_path( WP_CONTENT_DIR ) );

foreach ( $backtrace as $index => $frame ) {
if ( ! isset( $frame['file'] ) ) {
continue;
}

$normalized_file = wp_normalize_path( $frame['file'] );
if ( ! str_starts_with( $normalized_file, $normalized_content_dir ) ) {
continue;
}

$location = ' in ' . $normalized_file;
if ( isset( $frame['line'] ) ) {
$location .= ' on line ' . $frame['line'];
}

$caller = $backtrace[ $index + 1 ] ?? null;
if ( ! $caller ) {
return $location;
}

if ( str_starts_with( $caller['function'], '{' ) ) {
return ' called from (anonymous function)' . $location;
}

if ( in_array( $caller['function'], array( 'require', 'require_once', 'include', 'include_once' ), true ) ) {
return $location;
}

$function = $caller['function'];
if ( isset( $caller['class'] ) ) {
$function = $caller['class'] . $caller['type'] . $function;
}

return ' called from ' . $function . '()' . $location;
}

return '';
}

/**
* Writes a REST API diagnostic message to the PHP error log.
*
* @since 7.1.0
* @access private
*
* @param string $message The diagnostic message.
* @param int $error_level The `E_USER_*` error level.
* @param bool $debug_log_enabled Whether debug logging is enabled.
*/
function _rest_log_debug_message( string $message, int $error_level, bool $debug_log_enabled ): void {
if ( ! $debug_log_enabled || ! ( error_reporting() & $error_level ) ) {
return;
}

$prefix = E_USER_DEPRECATED === $error_level ? 'PHP Deprecated: ' : 'PHP Notice: ';
error_log( $prefix . wp_strip_all_tags( $message ) . _rest_get_debug_backtrace_caller() );
}

/**
* Handles _deprecated_function() errors.
*
Expand All @@ -716,7 +786,7 @@ function rest_ensure_response( $response ) {
* @param string $version Version.
*/
function rest_handle_deprecated_function( $function_name, $replacement, $version ) {
if ( ! WP_DEBUG || headers_sent() ) {
if ( ! WP_DEBUG ) {
return;
}
if ( ! empty( $replacement ) ) {
Expand All @@ -727,7 +797,11 @@ function rest_handle_deprecated_function( $function_name, $replacement, $version
$string = sprintf( __( '%1$s (since %2$s; no alternative available)' ), $function_name, $version );
}

header( sprintf( 'X-WP-DeprecatedFunction: %s', $string ) );
if ( ! headers_sent() ) {
header( sprintf( 'X-WP-DeprecatedFunction: %s', $string ) );
}

_rest_log_debug_message( $string, E_USER_DEPRECATED, (bool) WP_DEBUG_LOG );
}

/**
Expand All @@ -740,7 +814,7 @@ function rest_handle_deprecated_function( $function_name, $replacement, $version
* @param string $version Version.
*/
function rest_handle_deprecated_argument( $function_name, $message, $version ) {
if ( ! WP_DEBUG || headers_sent() ) {
if ( ! WP_DEBUG ) {
return;
}
if ( $message ) {
Expand All @@ -751,7 +825,11 @@ function rest_handle_deprecated_argument( $function_name, $message, $version ) {
$string = sprintf( __( '%1$s (since %2$s; no alternative available)' ), $function_name, $version );
}

header( sprintf( 'X-WP-DeprecatedParam: %s', $string ) );
if ( ! headers_sent() ) {
header( sprintf( 'X-WP-DeprecatedParam: %s', $string ) );
}

_rest_log_debug_message( $string, E_USER_DEPRECATED, (bool) WP_DEBUG_LOG );
}

/**
Expand All @@ -764,7 +842,7 @@ function rest_handle_deprecated_argument( $function_name, $message, $version ) {
* @param string|null $version The version of WordPress where the message was added.
*/
function rest_handle_doing_it_wrong( $function_name, $message, $version ) {
if ( ! WP_DEBUG || headers_sent() ) {
if ( ! WP_DEBUG ) {
return;
}

Expand All @@ -778,7 +856,11 @@ function rest_handle_doing_it_wrong( $function_name, $message, $version ) {
$string = sprintf( $string, $function_name, $message );
}

header( sprintf( 'X-WP-DoingItWrong: %s', $string ) );
if ( ! headers_sent() ) {
header( sprintf( 'X-WP-DoingItWrong: %s', $string ) );
}

_rest_log_debug_message( $string, E_USER_NOTICE, (bool) WP_DEBUG_LOG );
}

/**
Expand Down
156 changes: 156 additions & 0 deletions tests/phpunit/tests/rest-api.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,14 @@
* @group restapi
*/
class Tests_REST_API extends WP_UnitTestCase {
private $rest_debug_log_file;

private $rest_debug_log_original_error_log;

private $rest_debug_log_original_error_reporting;

private $rest_debug_log_fixture;

public function set_up() {
parent::set_up();

Expand All @@ -24,9 +32,157 @@ public function set_up() {

public function tear_down() {
remove_filter( 'wp_rest_server_class', array( $this, 'filter_wp_rest_server_class' ) );

if ( null !== $this->rest_debug_log_original_error_log ) {
ini_set( 'error_log', $this->rest_debug_log_original_error_log );
}

if ( null !== $this->rest_debug_log_original_error_reporting ) {
error_reporting( $this->rest_debug_log_original_error_reporting );
}

if ( $this->rest_debug_log_fixture && file_exists( $this->rest_debug_log_fixture ) ) {
unlink( $this->rest_debug_log_fixture );
}

unset( $GLOBALS['wp_test_rest_debug_log_closure'] );

parent::tear_down();
}

private function start_rest_debug_log_capture() {
$this->rest_debug_log_file = $this->temp_filename();
$this->rest_debug_log_original_error_log = ini_get( 'error_log' );
$this->rest_debug_log_original_error_reporting = error_reporting();

ini_set( 'error_log', $this->rest_debug_log_file );
error_reporting( E_ALL );
}

private function get_rest_debug_log() {
if ( ! file_exists( $this->rest_debug_log_file ) ) {
return '';
}

return preg_replace( '/^\[.+?\] /m', '', file_get_contents( $this->rest_debug_log_file ) );
}

/**
* @ticket 64260
*
* @covers ::_rest_log_debug_message
*
* @dataProvider data_rest_debug_log_messages
*/
public function test_rest_debug_log_message( $error_level, $expected_prefix ) {
$this->start_rest_debug_log_capture();

_rest_log_debug_message( 'Message with <code>markup</code>.', $error_level, true );

$this->assertSame( $expected_prefix . 'Message with markup.' . PHP_EOL, $this->get_rest_debug_log() );
}

public function data_rest_debug_log_messages() {
return array(
'doing it wrong notice' => array( E_USER_NOTICE, 'PHP Notice: ' ),
'deprecation' => array( E_USER_DEPRECATED, 'PHP Deprecated: ' ),
);
}

/**
* @ticket 64260
*
* @covers ::_rest_log_debug_message
*/
public function test_rest_debug_log_message_is_not_logged_when_disabled() {
$this->start_rest_debug_log_capture();

_rest_log_debug_message( 'Disabled message.', E_USER_NOTICE, false );

$this->assertSame( '', $this->get_rest_debug_log() );
}

/**
* @ticket 64260
*
* @covers ::_rest_log_debug_message
*/
public function test_rest_debug_log_message_respects_error_reporting() {
$this->start_rest_debug_log_capture();
error_reporting( E_ALL & ~E_USER_DEPRECATED );

_rest_log_debug_message( 'Masked deprecation.', E_USER_DEPRECATED, true );

$this->assertSame( '', $this->get_rest_debug_log() );
}

/**
* @ticket 64260
*
* @covers ::_rest_get_debug_backtrace_caller
*/
public function test_rest_debug_log_includes_content_caller() {
$this->start_rest_debug_log_capture();
$this->rest_debug_log_fixture = WP_CONTENT_DIR . '/plugins/rest-api-debug-log-test.php';

file_put_contents(
$this->rest_debug_log_fixture,
"<?php\nfunction wp_test_rest_debug_log_caller() {\n\t_rest_log_debug_message( 'Caller message.', E_USER_NOTICE, true );\n}\n"
);
require $this->rest_debug_log_fixture;

wp_test_rest_debug_log_caller();

$this->assertMatchesRegularExpression(
'#^PHP Notice: Caller message\. called from wp_test_rest_debug_log_caller\(\) in .+/wp-content/plugins/rest-api-debug-log-test\.php on line 3' . preg_quote( PHP_EOL, '#' ) . '$#',
$this->get_rest_debug_log()
);
}

/**
* @ticket 64260
*
* @covers ::_rest_get_debug_backtrace_caller
*/
public function test_rest_debug_log_identifies_anonymous_function_caller() {
$this->start_rest_debug_log_capture();
$this->rest_debug_log_fixture = WP_CONTENT_DIR . '/plugins/rest-api-debug-log-test.php';

file_put_contents(
$this->rest_debug_log_fixture,
"<?php\n\$GLOBALS['wp_test_rest_debug_log_closure'] = static function () {\n\t_rest_log_debug_message( 'Closure message.', E_USER_NOTICE, true );\n};\n"
);
require $this->rest_debug_log_fixture;

$GLOBALS['wp_test_rest_debug_log_closure']();

$this->assertMatchesRegularExpression(
'#^PHP Notice: Closure message\. called from \(anonymous function\) in .+/wp-content/plugins/rest-api-debug-log-test\.php on line 3' . preg_quote( PHP_EOL, '#' ) . '$#',
$this->get_rest_debug_log()
);
}

/**
* @ticket 64260
*
* @covers ::_rest_get_debug_backtrace_caller
*/
public function test_rest_debug_log_omits_include_pseudo_function_for_global_scope_caller() {
$this->start_rest_debug_log_capture();
$this->rest_debug_log_fixture = WP_CONTENT_DIR . '/plugins/rest-api-debug-log-test.php';

file_put_contents(
$this->rest_debug_log_fixture,
"<?php\n_rest_log_debug_message( 'Global scope message.', E_USER_NOTICE, true );\n"
);
require $this->rest_debug_log_fixture;

$this->assertMatchesRegularExpression(
'#^PHP Notice: Global scope message\. in .+/wp-content/plugins/rest-api-debug-log-test\.php on line 2' . preg_quote( PHP_EOL, '#' ) . '$#',
$this->get_rest_debug_log()
);
}

public function filter_wp_rest_server_class( $class_name ) {
return 'Spy_REST_Server';
}
Expand Down
Loading