Follow-up to #2638140: Error logging should log a backtrace consistently

Problem/Motivation

Software has bugs, so errors are there and will be logged.
Sadly by default Drupal just puts the line of the broken code, which is already helpful, but on the other hand often now really helpful, because you need a full backtrace to figure something out.

Proposed resolution

Log a backtrace on top of the actual error message.
This will just make the backtrace available in the variables section, but won't be displayed as part of the watchdog site.

D7: Make the new setting opt-in and provide a way to get the value.

Remaining tasks

User interface changes

API changes

Data model changes

CommentFileSizeAuthor
#18 2777955-18.patch4.92 KBamontero
#14 interdiff-2777955-12-14.txt3.26 KBaerozeppelin
#14 2777955-14.patch4.51 KBaerozeppelin
#12 interdiff-2777955-8-12.txt1.98 KBaerozeppelin
#12 2777955-12.patch2.42 KBaerozeppelin
#8 interdiff-2777955-2-8.txt902 bytesrachel_norfolk
#8 2777955-8.patch2.38 KBrachel_norfolk
#2 2777955-2.patch2.33 KBaerozeppelin

Comments

Fabianx created an issue. See original summary.

aerozeppelin’s picture

aerozeppelin commented
Status: Patch (to be ported) » Needs review
StatusFileSize
new 2777955-2.patch2.33 KB

An initial attempt to port the patch to D7. Not sure if I am heading in the right direction. Any inputs would be helpful.

Status: Needs review » Needs work

The last submitted patch, 2: 2777955-2.patch, failed testing.

The last submitted patch, 2: 2777955-2.patch, failed testing.

The last submitted patch, 2: 2777955-2.patch, failed testing.

rachel_norfolk’s picture

rachel_norfolk
Primary language English
Location UK
commented 
+++ b/includes/errors.inc
@@ -72,7 +71,14 @@ function _drupal_error_handler_real($error_level, $message, $filename, $line, $c
+    if (variable_get('enable_backtrace', TRUE)) {
+      $error_details['@backtrace_string'] = (new \Exception())->getTraceAsString();
...
   }

@@ -121,6 +127,12 @@ function _drupal_decode_exception($exception) {
+    $error_details['@backtrace_string'] = (new \Exception())->getTraceAsString();

It seems the method here of creating the exception is not liked by php53.

Maybe need to be a little more long-handed about it?

fabianx’s picture

fabianx commented

Yes, a variable "$e = new Exception();" is fine to use here.

rachel_norfolk’s picture

rachel_norfolk
Primary language English
Location UK
commented
Status: Needs work » Needs review
StatusFileSize
new 2777955-8.patch2.38 KB
new interdiff-2777955-2-8.txt902 bytes

So, we should end up with something like the attached for php53 friendliness...

fabianx’s picture

fabianx commented 
  1. +++ b/includes/errors.inc
@@ -72,7 +71,15 @@ function _drupal_error_handler_real($error_level, $message, $filename, $line, $c
+    if (variable_get('enable_backtrace', TRUE)) {

@@ -121,6 +128,13 @@ function _drupal_decode_exception($exception) {
+  if (variable_get('enable_backtrace', TRUE)) {

    We need to document this variable and maybe rename it a little ore verbose:

    drupal_error_log_backtrace

    maybe? 

  2. +++ b/includes/errors.inc
@@ -211,6 +225,13 @@ function _drupal_log_error($error, $fatal = FALSE) {
+    if (array_key_exists('@backtrace_string', $error)) {
+      error_log(sprintf('%s: %s in %s on line %d %s', $error['%type'], $error['!message'], $error['%file'], $error['%line'], $error['@backtrace_string']));
+    }
+    else {
+      error_log(sprintf('%s: %s in %s on line %d', $error['%type'], $error['!message'], $error['%file'], $error['%line']));
+    }

    Are we sure we only want that for fatal errors?

rachel_norfolk’s picture

rachel_norfolk
Primary language English
Location UK
commented
Issue tags: +Drupalaton
rachel_norfolk’s picture

rachel_norfolk
Primary language English
Location UK
commented
Status: Needs review » Needs work
aerozeppelin’s picture

aerozeppelin commented
Status: Needs work » Needs review
StatusFileSize
new 2777955-12.patch2.42 KB
new interdiff-2777955-8-12.txt1.98 KB

Changes as per #9.

fabianx’s picture

fabianx commented
Status: Needs review » Needs work

Thank you for your work on this!

Some more things:

  1. +++ b/includes/errors.inc
@@ -72,7 +71,16 @@ function _drupal_error_handler_real($error_level, $message, $filename, $line, $c
+    if (variable_get('drupal_error_log_backtrace', TRUE)) {

@@ -121,6 +129,13 @@ function _drupal_decode_exception($exception) {
+  if (variable_get('drupal_error_log_backtrace', TRUE)) {

    For BC reasons, the default needs to be FALSE.

    And we need to document the new value in settings.php. 

  2. +++ b/includes/errors.inc
@@ -255,6 +270,13 @@ function _drupal_log_error($error, $fatal = FALSE) {
+  if (array_key_exists('@backtrace_string', $error)) {
+    error_log(sprintf('%s: %s in %s on line %d %s', $error['%type'], $error['!message'], $error['%file'], $error['%line'], $error['@backtrace_string']));
+  }
+  else {
+    error_log(sprintf('%s: %s in %s on line %d', $error['%type'], $error['!message'], $error['%file'], $error['%line']));
+  }

    Oh - I think I misread, that, yes we likely want to do this whole block only for fatal errors, but for both if and else.

aerozeppelin’s picture

aerozeppelin commented
Status: Needs work » Needs review
StatusFileSize
new 2777955-14.patch4.51 KB
new interdiff-2777955-12-14.txt3.26 KB

You're welcome. Thank you for reviewing my patch. I've updated my patch with the changes. Let's see what the test bot thinks.

Status: Needs review » Needs work

The last submitted patch, 14: 2777955-14.patch, failed testing.

David_Rothstein’s picture

David_Rothstein commented
Status: Needs work » Needs review
fabianx’s picture

fabianx commented

Looks pretty good to me, still unsure about the helper function.

amontero’s picture

amontero
Location Barcelona
commented
StatusFileSize
new 2777955-18.patch4.92 KB

Need this and wanting to work on it.
Stale patch, reroll, feed the testbot.

Status: Needs review » Needs work

The last submitted patch, 18: 2777955-18.patch, failed testing. View results

fabianx’s picture

fabianx commented
Issue tags: +Drupal 7.60 target

Moving into 7.60 sprint

joseph.olstad’s picture

joseph.olstad
Primary language French
commented

Please do not be alarmed by "composer Command Failed" - this is not an indication of a problem with the patch.
It occurs since approximately may 4th, there is a known testrunner issue. @mixologic (responsible for the testrunner) is on vacation
#2970950: D7 test runner not working since may 4th 2018 'Composer command failed'
Hopefully @mixologic gets back from his vacation soon.

joseph.olstad’s picture

joseph.olstad
Primary language French
commented
Status: Needs work » Needs review

re-trigger testbot

Status: Needs review » Needs work

The last submitted patch, 18: 2777955-18.patch, failed testing. View results

joseph.olstad’s picture

joseph.olstad
Primary language French
commented
Status: Needs work » Needs review
joseph.olstad’s picture

joseph.olstad
Primary language French
commented
Issue tags: -Drupal 7.60 target +Drupal 7.70 target

Bumping to 7.70. This didn't make it into 7.60

rcodina’s picture

rcodina
Primary language Catalan
Location Barcelona
commented

I've been testing patch on #18 and it works for me.

joseph.olstad’s picture

joseph.olstad
Primary language French
commented
Issue tags: -Drupal 7.70 target +Drupal 7.74 target

I like!

Status: Needs review » Closed (outdated)

Automatically closed because Drupal 7 security and bugfix support has ended as of 5 January 2025. If the issue verifiably applies to later versions, please reopen with details and update the version.