Skip to content
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

RFC: Error Backtraces v2 #17056

Open
wants to merge 10 commits into
base: master
Choose a base branch
from
+157 −6
Open

RFC: Error Backtraces v2 #17056

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
3b9bd2f
rfc: error_backtraces_v2
ericnorris Jan 7, 2025
aa9c4f4
address second round of PR comments
ericnorris Jan 8, 2025
47148c1
use `eval` instead of `new_oom.inc`
ericnorris Jan 8, 2025
a44ac31
fix tests that invoke PHP and thus don't inherit run-tests.php INI se…
ericnorris Jan 8, 2025
e843e06
clear backtrace when throwing an exception
ericnorris Jan 8, 2025
2cd6c3f
address third round of PR comments
ericnorris Jan 8, 2025
aaa2443
move initialization of error_backtrace to handle NTS
ericnorris Jan 8, 2025
5fd14ee
move `error_get_last` w/ fatal to separate test
ericnorris Jan 13, 2025
b1db022
rename `error_backtrace` global to `fatal_error_backtrace`
ericnorris Jan 13, 2025
9f29e80
rename `fatal_error_backtrace` -> `last_fatal_error_backtrace`
ericnorris Jan 17, 2025
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
14 changes: 14 additions & 0 deletions Zend/tests/fatal_error_backtraces_001.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
--TEST--
Fatal error backtrace
--INI--
fatal_error_backtraces=On
--FILE--
<?php

eval("class Foo {}; class Foo {}");
?>
--EXPECTF--
Fatal error: Cannot redeclare class Foo (%s) in %s : eval()'d code on line %d
Stack trace:
#0 %sfatal_error_backtraces_001.php(%d): eval()
#1 {main}
19 changes: 19 additions & 0 deletions Zend/tests/fatal_error_backtraces_002.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
--TEST--
Fatal error backtrace w/ sensitive parameters
--INI--
fatal_error_backtraces=On
--FILE--
<?php

function trigger_fatal(#[\SensitiveParameter] $unused) {
eval("class Foo {}; class Foo {}");
}

trigger_fatal("bar");
?>
--EXPECTF--
Fatal error: Cannot redeclare class Foo (%s) in %s : eval()'d code on line %d
Stack trace:
#0 %sfatal_error_backtraces_002.php(%d): eval()
#1 %sfatal_error_backtraces_002.php(%d): trigger_fatal(Object(SensitiveParameterValue))
#2 {main}
20 changes: 20 additions & 0 deletions Zend/tests/fatal_error_backtraces_003.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
--TEST--
Fatal error backtrace w/ zend.exception_ignore_args
--INI--
fatal_error_backtraces=On
zend.exception_ignore_args=On
--FILE--
<?php

function trigger_fatal($unused) {
eval("class Foo {}; class Foo {}");
}

trigger_fatal("bar");
?>
--EXPECTF--
Fatal error: Cannot redeclare class Foo (%s) in %s : eval()'d code on line %d
Stack trace:
#0 %sfatal_error_backtraces_003.php(%d): eval()
#1 %sfatal_error_backtraces_003.php(%d): trigger_fatal()
#2 {main}
2 changes: 1 addition & 1 deletion Zend/tests/new_oom.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ $php = PHP_BINARY;

foreach (get_declared_classes() as $class) {
$output = shell_exec("$php --no-php-ini $file $class 2>&1");
if ($output && preg_match('(^\nFatal error: Allowed memory size of [0-9]+ bytes exhausted[^\r\n]* \(tried to allocate [0-9]+ bytes\) in [^\r\n]+ on line [0-9]+$)', $output) !== 1) {
if ($output && preg_match('(^\nFatal error: Allowed memory size of [0-9]+ bytes exhausted[^\r\n]* \(tried to allocate [0-9]+ bytes\) in [^\r\n]+ on line [0-9]+\nStack trace:\n(#[0-9]+ [^\r\n]+\n)+$)', $output) !== 1) {
echo "Class $class failed\n";
echo $output, "\n";
}
Expand Down
7 changes: 7 additions & 0 deletions Zend/zend.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -260,6 +260,7 @@ static ZEND_INI_MH(OnUpdateFiberStackSize) /* {{{ */

ZEND_INI_BEGIN()
ZEND_INI_ENTRY("error_reporting", NULL, ZEND_INI_ALL, OnUpdateErrorReporting)
STD_ZEND_INI_BOOLEAN("fatal_error_backtraces", "1", ZEND_INI_ALL, OnUpdateBool, fatal_error_backtrace_on, zend_executor_globals, executor_globals)
STD_ZEND_INI_ENTRY("zend.assertions", "1", ZEND_INI_ALL, OnUpdateAssertions, assertions, zend_executor_globals, executor_globals)
ZEND_INI_ENTRY3_EX("zend.enable_gc", "1", ZEND_INI_ALL, OnUpdateGCEnabled, NULL, NULL, NULL, zend_gc_enabled_displayer_cb)
STD_ZEND_INI_BOOLEAN("zend.multibyte", "0", ZEND_INI_PERDIR, OnUpdateBool, multibyte, zend_compiler_globals, compiler_globals)
Expand Down Expand Up @@ -1463,6 +1464,10 @@ ZEND_API ZEND_COLD void zend_error_zstr_at(
EG(errors)[EG(num_errors)-1] = info;
}

// Always clear the last backtrace.
zval_ptr_dtor(&EG(last_fatal_error_backtrace));
ZVAL_UNDEF(&EG(last_fatal_error_backtrace));

/* Report about uncaught exception in case of fatal errors */
if (EG(exception)) {
zend_execute_data *ex;
Expand All @@ -1484,6 +1489,8 @@ ZEND_API ZEND_COLD void zend_error_zstr_at(
ex->opline = opline;
}
}
} else if (EG(fatal_error_backtrace_on) && (type & E_FATAL_ERRORS)) {
zend_fetch_debug_backtrace(&EG(last_fatal_error_backtrace), 0, EG(exception_ignore_args) ? DEBUG_BACKTRACE_IGNORE_ARGS : 0, 0);
}

zend_observer_error_notify(type, error_filename, error_lineno, message);
Expand Down
4 changes: 4 additions & 0 deletions Zend/zend_exceptions.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -904,6 +904,10 @@ ZEND_API ZEND_COLD zend_result zend_exception_error(zend_object *ex, int severit
ZVAL_OBJ(&exception, ex);
ce_exception = ex->ce;
EG(exception) = NULL;

zval_ptr_dtor(&EG(last_fatal_error_backtrace));
ZVAL_UNDEF(&EG(last_fatal_error_backtrace));

if (ce_exception == zend_ce_parse_error || ce_exception == zend_ce_compile_error) {
zend_string *message = zval_get_string(GET_PROPERTY(&exception, ZEND_STR_MESSAGE));
zend_string *file = zval_get_string(GET_PROPERTY_SILENT(&exception, ZEND_STR_FILE));
Expand Down
5 changes: 5 additions & 0 deletions Zend/zend_execute_API.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -140,6 +140,8 @@ void init_executor(void) /* {{{ */
original_sigsegv_handler = signal(SIGSEGV, zend_handle_sigsegv);
#endif

ZVAL_UNDEF(&EG(last_fatal_error_backtrace));

EG(symtable_cache_ptr) = EG(symtable_cache);
EG(symtable_cache_limit) = EG(symtable_cache) + SYMTABLE_CACHE_SIZE;
EG(no_extensions) = 0;
Expand Down Expand Up @@ -307,6 +309,9 @@ ZEND_API void zend_shutdown_executor_values(bool fast_shutdown)
} ZEND_HASH_MAP_FOREACH_END_DEL();
}

zval_ptr_dtor(&EG(last_fatal_error_backtrace));
ZVAL_UNDEF(&EG(last_fatal_error_backtrace));

/* Release static properties and static variables prior to the final GC run,
* as they may hold GC roots. */
ZEND_HASH_MAP_REVERSE_FOREACH_VAL(EG(function_table), zv) {
Expand Down
4 changes: 4 additions & 0 deletions Zend/zend_globals.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -182,6 +182,10 @@ struct _zend_executor_globals {
JMP_BUF *bailout;

int error_reporting;

bool fatal_error_backtrace_on;
zval last_fatal_error_backtrace;

int exit_status;

HashTable *function_table; /* function symbol table */
Expand Down
3 changes: 3 additions & 0 deletions ext/opcache/tests/gh8846.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,9 @@ echo file_get_contents('http://' . PHP_CLI_SERVER_ADDRESS . '/gh8846-index.php?s
bool(true)
<br />
<b>Fatal error</b>: Cannot redeclare class Foo (previously declared in %sgh8846-1.inc:2) in <b>%sgh8846-2.inc</b> on line <b>%d</b><br />
Stack trace:
#0 %sgh8846-index.php(%d): include()
#1 {main}

bool(true)
Ok
8 changes: 8 additions & 0 deletions ext/standard/basic_functions.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1436,6 +1436,11 @@ PHP_FUNCTION(error_get_last)

ZVAL_LONG(&tmp, PG(last_error_lineno));
zend_hash_update(Z_ARR_P(return_value), ZSTR_KNOWN(ZEND_STR_LINE), &tmp);

if (!Z_ISUNDEF(EG(last_fatal_error_backtrace))) {
ZVAL_COPY(&tmp, &EG(last_fatal_error_backtrace));
zend_hash_update(Z_ARR_P(return_value), ZSTR_KNOWN(ZEND_STR_TRACE), &tmp);
}
}
}
/* }}} */
Expand All @@ -1457,6 +1462,9 @@ PHP_FUNCTION(error_clear_last)
PG(last_error_file) = NULL;
}
}

zval_ptr_dtor(&EG(last_fatal_error_backtrace));
ZVAL_UNDEF(&EG(last_fatal_error_backtrace));
}
/* }}} */

Expand Down
59 changes: 59 additions & 0 deletions ext/standard/tests/general_functions/error_get_last_002.phpt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,59 @@
--TEST--
error_get_last() w/ fatal error
--INI--
fatal_error_backtraces=On
--FILE--
<?php

function trigger_fatal_error_with_stacktrace() {
eval("class Foo {}; class Foo {}");
}

register_shutdown_function(function() {
var_dump(error_get_last());
echo "Done\n";
});

trigger_fatal_error_with_stacktrace();
?>
--EXPECTF--
Fatal error: Cannot redeclare class Foo (%s) in %s on line %d
Stack trace:
#0 %serror_get_last_002.php(%d): eval()
#1 %serror_get_last_002.php(%d): trigger_fatal_error_with_stacktrace()
#2 {main}
array(5) {
["type"]=>
int(64)
["message"]=>
string(%d) "Cannot redeclare class Foo %s"
["file"]=>
string(%d) "%serror_get_last_002.php(%d) : eval()'d code"
["line"]=>
int(%d)
["trace"]=>
array(2) {
[0]=>
array(3) {
["file"]=>
string(%d) "%serror_get_last_002.php"
["line"]=>
int(%d)
["function"]=>
string(%d) "eval"
}
[1]=>
array(4) {
["file"]=>
string(%d) "%serror_get_last_002.php"
["line"]=>
int(%d)
["function"]=>
string(%d) "trigger_fatal_error_with_stacktrace"
["args"]=>
array(0) {
}
}
}
}
Done
17 changes: 12 additions & 5 deletions main/main.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1282,6 +1282,7 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c
{
bool display;
int type = orig_type & E_ALL;
zend_string *backtrace = ZSTR_EMPTY_ALLOC();

/* check for repeated errors to be ignored */
if (PG(ignore_repeated_errors) && PG(last_error_message)) {
Expand Down Expand Up @@ -1321,6 +1322,10 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c
}
}

if (!Z_ISUNDEF(EG(last_fatal_error_backtrace))) {
backtrace = zend_trace_to_string(Z_ARRVAL(EG(last_fatal_error_backtrace)), /* include_main */ true);
}

/* store the error if it has changed */
if (display) {
clear_last_error();
Expand Down Expand Up @@ -1389,14 +1394,14 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c
syslog(LOG_ALERT, "PHP %s: %s (%s)", error_type_str, ZSTR_VAL(message), GetCommandLine());
}
#endif
spprintf(&log_buffer, 0, "PHP %s: %s in %s on line %" PRIu32, error_type_str, ZSTR_VAL(message), ZSTR_VAL(error_filename), error_lineno);
spprintf(&log_buffer, 0, "PHP %s: %s in %s on line %" PRIu32 "%s%s", error_type_str, ZSTR_VAL(message), ZSTR_VAL(error_filename), error_lineno, ZSTR_LEN(backtrace) ? "\nStack trace:\n" : "", ZSTR_VAL(backtrace));
php_log_err_with_severity(log_buffer, syslog_type_int);
efree(log_buffer);
}

if (PG(display_errors) && ((module_initialized && !PG(during_request_startup)) || (PG(display_startup_errors)))) {
if (PG(xmlrpc_errors)) {
php_printf("<?xml version=\"1.0\"?><methodResponse><fault><value><struct><member><name>faultCode</name><value><int>" ZEND_LONG_FMT "</int></value></member><member><name>faultString</name><value><string>%s:%s in %s on line %" PRIu32 "</string></value></member></struct></value></fault></methodResponse>", PG(xmlrpc_error_number), error_type_str, ZSTR_VAL(message), ZSTR_VAL(error_filename), error_lineno);
php_printf("<?xml version=\"1.0\"?><methodResponse><fault><value><struct><member><name>faultCode</name><value><int>" ZEND_LONG_FMT "</int></value></member><member><name>faultString</name><value><string>%s:%s in %s on line %" PRIu32 "%s%s</string></value></member></struct></value></fault></methodResponse>", PG(xmlrpc_error_number), error_type_str, ZSTR_VAL(message), ZSTR_VAL(error_filename), error_lineno, ZSTR_LEN(backtrace) ? "\nStack trace:\n" : "", ZSTR_VAL(backtrace));
} else {
char *prepend_string = INI_STR("error_prepend_string");
char *append_string = INI_STR("error_append_string");
Expand All @@ -1407,7 +1412,7 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c
php_printf("%s<br />\n<b>%s</b>: %s in <b>%s</b> on line <b>%" PRIu32 "</b><br />\n%s", STR_PRINT(prepend_string), error_type_str, ZSTR_VAL(buf), ZSTR_VAL(error_filename), error_lineno, STR_PRINT(append_string));
zend_string_free(buf);
} else {
php_printf_unchecked("%s<br />\n<b>%s</b>: %S in <b>%s</b> on line <b>%" PRIu32 "</b><br />\n%s", STR_PRINT(prepend_string), error_type_str, message, ZSTR_VAL(error_filename), error_lineno, STR_PRINT(append_string));
php_printf_unchecked("%s<br />\n<b>%s</b>: %S in <b>%s</b> on line <b>%" PRIu32 "</b><br />%s%s\n%s", STR_PRINT(prepend_string), error_type_str, message, ZSTR_VAL(error_filename), error_lineno, ZSTR_LEN(backtrace) ? "\nStack trace:\n" : "", ZSTR_VAL(backtrace), STR_PRINT(append_string));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is supposed to be readable in HTML, but I doubt the backtrace will be displayed in a readable manner. Perhaps, this should be wrapped in a <pre> tag or smth alike?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch, I'll look into that.

Semi-related tangent so feel free to disregard: Is it on anyone's radar to refactor this function at all? I saw "Deprecate the error_prepend_string and error_append_string INI directives" in https://wiki.php.net/rfc/deprecations_php_8_5, which would help make this a little more readable, but I wonder if there's more we could do simplify this logic. I acknowledge that is probably easier said than done, however.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I doubt refactoring this function is on someone's TODO list. There are indeed some outdated pieces (e.g. the ones you mentioned but also xmlrpc_errors imo). However, the question with refactoring is always how much it's worth spending time on this. This function likely is not on any hot code path and refactoring also brings in a risk of breaking things 🤷

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

would be also nice to break up those huge long lines when you are in it...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@nielsdos apologies, but what's the best way to wrap a zend_string in <pre>? strpprintf? Or would it be the worst thing to just change this to %s%s%s and then pass in ZSTR_LEN(backtrace) ? "<pre>Stack trace:\n" : "", ZSTR_VAL(backtrace), ZSTR_LEN(backtrace) ? "</pre>" : ""? We could also drop adding the pre at all since we already have some fatal errors with stack traces that do not have pre: /~https://github.com/search?q=repo%3Aphp%2Fphp-src+%22%3Cb%3EFatal+error%3C%2Fb%3E%22&type=code, e.g.

<br />
<b>Fatal error</b>:  Uncaught Error: Cannot access private property test::$pri in %s004.test.php:8
Stack trace:
#0 {main}
  thrown in <b>%s004.test.php</b> on line <b>8</b><br />

@bukka I received feedback elsewhere to not break up long lines, though maybe here is a good counterpoint. I'd personally like to err on keeping it as-is since I'd like to be able to merge this relatively soon, but if people feel strongly I could break this up. This is kind of what I was getting at with my earlier comment - this function could probably be simplified to make it more readable, besides just the long line length.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we wrap it with pre it should be done consistently.
If I were to write the code, I would go for the ZSTR_LEN() ternary trick.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we wrap it with pre it should be done consistently.

I'm not sure I follow - what I was saying was that we currently do not wrap it with <pre> (for errors that already have backtraces before my change), so if we wrap it with <pre> here we'd be inconsistent with existing errors like:

php-src/sapi/cgi/tests/004.phpt

Lines 43 to 46 in 72708f2

<b>Fatal error</b>: Uncaught Error: Cannot access private property test::$pri in %s004.test.php:8
Stack trace:
#0 {main}
thrown in <b>%s004.test.php</b> on line <b>8</b><br />

If I were to write the code, I would go for the ZSTR_LEN() ternary trick.

Thanks, I was leaning that way but I wanted your opinion. I'm still not convinced we should add the <pre> based on the above, but if you think we should I'll go the ZSTR_LEN route.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I received feedback elsewhere to not break up long lines,

In case you are referring to my remark here: #16937 (comment) - this case of a printf-style function is quite different and splitting it across multiple lines would be reasonable, because it accurately represents the complexity of the statement.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok let's not do the <pre> conversion.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@TimWolla I was! and when I said "maybe here is a good counterpoint", I meant that I could see that you might agree with splitting this up. My preference was to not do this myself though, since for consistency I should probably do that for all of them, and I was concerned with making it a topic for bikeshedding.

}
} else {
/* Write CLI/CGI errors to stderr if display_errors = "stderr" */
Expand All @@ -1416,18 +1421,20 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c
) {
fprintf(stderr, "%s: ", error_type_str);
fwrite(ZSTR_VAL(message), sizeof(char), ZSTR_LEN(message), stderr);
fprintf(stderr, " in %s on line %" PRIu32 "\n", ZSTR_VAL(error_filename), error_lineno);
fprintf(stderr, " in %s on line %" PRIu32 "%s%s\n", ZSTR_VAL(error_filename), error_lineno, ZSTR_LEN(backtrace) ? "\nStack trace:\n" : "", ZSTR_VAL(backtrace));
#ifdef PHP_WIN32
fflush(stderr);
#endif
} else {
php_printf_unchecked("%s\n%s: %S in %s on line %" PRIu32 "\n%s", STR_PRINT(prepend_string), error_type_str, message, ZSTR_VAL(error_filename), error_lineno, STR_PRINT(append_string));
php_printf_unchecked("%s\n%s: %S in %s on line %" PRIu32 "%s%s\n%s", STR_PRINT(prepend_string), error_type_str, message, ZSTR_VAL(error_filename), error_lineno, ZSTR_LEN(backtrace) ? "\nStack trace:\n" : "", ZSTR_VAL(backtrace), STR_PRINT(append_string));
}
}
}
}
}

zend_string_release(backtrace);

/* Bail out if we can't recover */
switch (type) {
case E_CORE_ERROR:
Expand Down
1 change: 1 addition & 0 deletions run-tests.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -272,6 +272,7 @@ function main(): void
'disable_functions=',
'output_buffering=Off',
'error_reporting=' . E_ALL,
'fatal_error_backtraces=Off',
'display_errors=1',
'display_startup_errors=1',
'log_errors=0',
Expand Down
Loading