-
Notifications
You must be signed in to change notification settings - Fork 7.9k
RFC: Error Backtraces v2 #17056
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.
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
Changes from 5 commits
3b9bd2f
aa9c4f4
47148c1
a44ac31
e843e06
2cd6c3f
aaa2443
5fd14ee
b1db022
9f29e80
126a785
a6c9063
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,14 @@ | ||
--TEST-- | ||
Fatal error backtrace | ||
--FILE-- | ||
<?php | ||
|
||
ini_set('fatal_error_backtraces', true); | ||
|
||
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} |
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,20 @@ | ||
--TEST-- | ||
Fatal error backtrace w/ sensitive parameters | ||
--FILE-- | ||
<?php | ||
|
||
ini_set('fatal_error_backtraces', true); | ||
|
||
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} |
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,21 @@ | ||
--TEST-- | ||
Fatal error backtrace w/ zend.exception_ignore_args | ||
--FILE-- | ||
<?php | ||
|
||
ini_set('fatal_error_backtraces', true); | ||
ini_set('zend.exception_ignore_args', true); | ||
|
||
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} |
Original file line number | Diff line number | Diff line change | ||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|
|
@@ -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(error_backtrace)); | ||||||||||||
ZVAL_UNDEF(&EG(error_backtrace)); | ||||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm not 100% confident in this being the right fix, though it is similar to the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Seems correct, this will clear the message for the next error. Do you have a test for this? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
In a sense, yes, since the existing I'm concerned this (clearing the trace when throwing an exception) may not be enough and there may be other "weird" error handling things in extensions that may also end up having a double stack trace. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. It's hard to understand the problem exactly, it would be best to replicate in a new test. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm not exactly sure how to replicate it in a test, since it has something to do with how When I was debugging this, I noticed that Line 548 in a091e52
It's then kind of hard to follow, but roughly speaking it ends up in here: Lines 1868 to 1871 in a091e52
If I remember correctly, the backtrace exists at this point, and then calling There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Having dealt a tiny bit with ext/soap my guess is the following: SOAP Uses the bailout mechanisms (i.e. fatal errors) as its "exception" mechanism (as it predates exceptions existing in the language), and it now catches those to throw them as proper exceptions (although it sometimes also throws normal exceptions) which is probably the cause of this. Refactoring ext/soap so it stops doing this is a long term goal of mine, but the extension is quite complex. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Thanks, that makes sense. Do you think the above is an appropriate fix that might apply to other extensions doing stuff like this? I'm repeating myself, but I'm concerned that there might be other complex flows involving Would it make more sense to do backtrace fetching only in There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Frankly, the only other extensions I see overloading |
||||||||||||
|
||||||||||||
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)); | ||||||||||||
|
Original file line number | Diff line number | Diff line change | ||||||||
---|---|---|---|---|---|---|---|---|---|---|
|
@@ -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)) { | ||||||||||
|
@@ -1321,6 +1322,10 @@ static ZEND_COLD void php_error_cb(int orig_type, zend_string *error_filename, c | |||||||||
} | ||||||||||
} | ||||||||||
|
||||||||||
if (!Z_ISUNDEF(EG(error_backtrace))) { | ||||||||||
backtrace = zend_trace_to_string(Z_ARRVAL(EG(error_backtrace)), /* include_main */ true); | ||||||||||
} | ||||||||||
|
||||||||||
/* store the error if it has changed */ | ||||||||||
if (display) { | ||||||||||
clear_last_error(); | ||||||||||
|
@@ -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"); | ||||||||||
|
@@ -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)); | ||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe 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 There was a problem hiding this comment. Choose a reason for hiding this commentThe 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 There was a problem hiding this comment. Choose a reason for hiding this commentThe 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 🤷 There was a problem hiding this comment. Choose a reason for hiding this commentThe 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... There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. @nielsdos apologies, but what's the best way to wrap a
@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. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. If we wrap it with pre it should be done consistently. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
I'm not sure I follow - what I was saying was that we currently do not wrap it with php-src/sapi/cgi/tests/004.phpt Lines 43 to 46 in 72708f2
Thanks, I was leaning that way but I wanted your opinion. I'm still not convinced we should add the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
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. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Ok let's not do the There was a problem hiding this comment. Choose a reason for hiding this commentThe 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" */ | ||||||||||
|
@@ -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: | ||||||||||
|
Uh oh!
There was an error while loading. Please reload this page.