Starting with Drupal 7, the system has become extremely modular. Generic functions are re-used in many places, so it's a horrible job to figure out where exactly an error originates from.

Issues like #1067750: Let Field API fail in a tale-telling way on invalid $entity only underline the problem space.

The proposal is to show a simplified backtrace for all error messages, so one is able to see the root of a problem.

Files: 
CommentFileSizeAuthor
#165 1158322-error_backtrace-161.patch28.44 KBReg
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch 1158322-error_backtrace-161_0.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]
#161 1158322-error_backtrace-161.patch0 bytesReg
FAILED: [[SimpleTest]]: [MySQL] 58,135 pass(es), 1 fail(s), and 0 exception(s).
[ View ]
#158 1158322-error_backtrace-158.patch28.16 KBReg
PASSED: [[SimpleTest]]: [MySQL] 58,072 pass(es).
[ View ]
#152 1158322-error_backtrace-151.patch29.06 KBReg
PASSED: [[SimpleTest]]: [MySQL] 57,703 pass(es).
[ View ]
#147 1158322-error_backtrace-147-D8.patch21.67 KBReg
FAILED: [[SimpleTest]]: [MySQL] 57,979 pass(es), 4 fail(s), and 1 exception(s).
[ View ]
#141 1158322-error_backtrace-141-D8.patch13.27 KBReg
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch 1158322-error_backtrace-141-D8.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]
#138 1158322-error_backtrace-138-D7.patch10.62 KBReg
PASSED: [[SimpleTest]]: [MySQL] 39,942 pass(es).
[ View ]
#137 1158322-error_backtrace-137-D7.patch9.87 KBReg
PASSED: [[SimpleTest]]: [MySQL] 39,749 pass(es).
[ View ]
#129 1158322-error_backtrace-129-D7.patch9.8 KBReg
PASSED: [[SimpleTest]]: [MySQL] 39,745 pass(es).
[ View ]
#127 1158322-error_backtrace-127-with_test-D7-do-not-test.patch7.33 KBmrfelton
#126 1158322-error_backtrace-126-with_test.patch6.92 KBdas-peter
PASSED: [[SimpleTest]]: [MySQL] 50,541 pass(es).
[ View ]
#126 1158322-patch-diff-112-126.txt1.97 KBdas-peter
#122 fix-errors-1158322-122.patch2.2 KBbeejeebus
PASSED: [[SimpleTest]]: [MySQL] 49,754 pass(es).
[ View ]
#114 1158322_114-do-not-test.patch1.69 KBchx
#112 1158322-error_backtrace-112-with_test.patch7.99 KBdas-peter
PASSED: [[SimpleTest]]: [MySQL] 49,312 pass(es).
[ View ]
#111 1158322-error_backtrace-109-test_only.patch3.51 KBolli
FAILED: [[SimpleTest]]: [MySQL] 48,776 pass(es), 2 fail(s), and 0 exception(s).
[ View ]
#111 1158322-error_backtrace-109-with_test.patch6.92 KBolli
PASSED: [[SimpleTest]]: [MySQL] 48,773 pass(es).
[ View ]
#109 drupal8.error-backtrace.109.patch3.41 KBsun
FAILED: [[SimpleTest]]: [MySQL] Repository checkout: failed to checkout from [git://git.drupal.org/project/drupal.git].
[ View ]
#100 1158322-error_backtrace-100.patch375 bytesolli
PASSED: [[SimpleTest]]: [MySQL] 48,309 pass(es).
[ View ]
#96 testbot-fail.png72.35 KBmikeytown2
#92 drupal8.error-backtrace.92.patch1.19 KBsun
PASSED: [[SimpleTest]]: [MySQL] 39,977 pass(es).
[ View ]
#82 drupal-1158322-82-add-backtrace-to-errors-D7.patch7.05 KBmikeytown2
PASSED: [[SimpleTest]]: [MySQL] 39,257 pass(es).
[ View ]
#77 drupal8.error-backtrace.77.patch7.09 KBsun
PASSED: [[SimpleTest]]: [MySQL] 37,026 pass(es).
[ View ]
#77 interdiff.txt1.08 KBsun
#72 drupal7.error-backtrace.1158322.72.D7-do-not-test.patch7.08 KBmrfelton
#71 drupal8.error-backtrace.1158322.71.patch7.11 KBsalvis
PASSED: [[SimpleTest]]: [MySQL] 36,835 pass(es).
[ View ]
#68 drupal8.error-backtrace.68.patch6.14 KBsun
PASSED: [[SimpleTest]]: [MySQL] 36,693 pass(es).
[ View ]
#59 drupal-1158322-59.patch5.91 KBamateescu
PASSED: [[SimpleTest]]: [MySQL] 36,692 pass(es).
[ View ]
#56 drupal-1158322-56.patch5.91 KBtim.plunkett
PASSED: [[SimpleTest]]: [MySQL] 36,684 pass(es).
[ View ]
#53 patch-1158322-53.patch5.87 KBartfulrobot
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch patch-1158322-53.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]
#50 exception.png92.41 KBwapnik
#43 Screen shot 2011-09-08 at 20.24.40.png102.02 KBsteinmb
#42 1158322-42-error-backtrace.patch5.91 KBjhedstrom
PASSED: [[SimpleTest]]: [MySQL] 32,928 pass(es).
[ View ]
#34 Screen shot 2011-06-07 at 17.01.13.png128.52 KBsteinmb
#19 drupal.error-backtrace.19.patch4.4 KBsun
FAILED: [[SimpleTest]]: [MySQL] 29,643 pass(es), 35 fail(s), and 6,656 exception(es).
[ View ]
#19 error-backtrace.19.png13.84 KBsun
#1 error-backtrace.1.png13.76 KBsun
drupal.error-backtrace.0.patch4.07 KBsun
FAILED: [[SimpleTest]]: [MySQL] 29,629 pass(es), 29 fail(s), and 6,665 exception(es).
[ View ]

Comments

StatusFileSize
new13.76 KB

error-backtrace.1.png

You forgot probably the most important, exception stack trace. While PHP fatal errors will make you unable to get to this, and while common warnings can be catched and probably need this exact backtrace, most of the work should focus on loosy exception catching that core does and should probably push a "production mode" concept into core for development and testing sites.

Status:Needs review» Needs work

The last submitted patch, drupal.error-backtrace.0.patch, failed testing.

@pounard - Could elaborate on what you meant by 'loosy exception catching' and a 'production mode concept'?

Are you suggesting that core should respond if a different way to a variable indicating whether a site is development/staging/production (best practices BTW)?

@#4, For the later, yes totally what you said: most frameworks and piece of software allows to configure, at least, a production and a devel mode. ZF allows user to set as many "modes" as they can via configuration override (through the Zend_Config API). Each "mode" is (for the most, outside the site configuration) a set of variables such as error display, error logging, etc..

Drupal has the error level variable, but it's pretty much all that you can have, having finer granularity over "development" mode could be better to somehow force modules to use that in order to do their own different processing depending on the runtime mode (and development mode could mean different things among different sites, so it's basically a pure set of variables). For the most, the core isn't design to have a devel mode, and the error display handler is totally unable to display back trace. I'm actually fed off switching 10 variables to // comments each time I need to this while a single named parameter in the settings.php file (or even as environment variable inside the HTTPd configuration) would be more than enough to trigger a packaged set of variable overrides).

For the first part, about exception, there is something that is actually really anoying with D7, is that when you raise some exceptions, the sites goes to fallback maintenance theme (which is a good fallback mode actually) but doesn't display the exceptions stack trace (which imposes the developer to go to watchdog screen). While some errors can sometime prevent any page to be displayed (including watchdog screen, known as recent log entries), the devel mode should always trigger the full trace to be displayed by the error handler whatever happens.

I did this exact patch on a development site once, I should have kept it (trashed it actually). The actual functions in error.inc file are absolutely not designed to do this (they only keep the error message, that should actually not get to the end user when in production mode btw) so the patch was kinda tricky. I should be able to restore it somehow.

Status:Needs work» Needs review

@pounard: Any discussion pertaining to a "production mode concept" belongs into a separate issue, not this one. Thanks.

And yes, the current patch only focuses on errors, not exceptions. For exceptions, we'd have to introduce a DrupalException class, which overrides PHP's default ->getMessage() method to append a similar backtrace, leveraging the ->getTrace() provided by PHP.

Additionally, built-in + bootstrap-safe handling for t() messages and arguments would be highly beneficial to have.

Also, just now I recognize that the function in the actual error message does not contain argument values like the functions in the backtrace.

This is cool, but I would prefer a table.

dsm(debug_backtrace()); provides a lot more information.

@jbrown: A table for what? And why?

Also, to make one thing crystal clear:

The next time someone proposes a full backtrace output, this issue will immediately won't fix.

@#6

And yes, the current patch only focuses on errors, not exceptions. For exceptions, we'd have to introduce a DrupalException class, which overrides PHP's default ->getMessage() method to append a similar backtrace, leveraging the ->getTrace() provided by PHP.

FOUTAISES! (French word for "bullshits"). Creating a specific exception specialization for Drupal is certainly a good idea, for finer error handling, while doing it for display purposes doesn't make any sense (current display is good enough, and if you want a custom one, please just build using the raw stack trace you can get as an array).
EDIT: Let me explain a bit more: Each time you override code by creating a layer over an existing one only because the API doesn't fit you what you like, you create what we call code indirection. Code indirection often leads to spagetti code and pretty much fucks up any framework. OOP inheritance is a good thing, when you use it for business reasons, exception's business is to have a granular error handling mecanism, and changing exception display IS NOT exception's business, please, NEVER ever override exception only for this kind of display purpose, you will create code indirection that may impact performances even when not running in devel mode.

Further more, this patch is useless without talking before of a framework-wide error handling strategy. All it will provide in the long term is a lot code indirection (other use case of code indirection here, split up code, then attempt to glue back pieces, only provides headaches and useless glue code) and will make everybody's life harder when it will come to unify already existing code for implementing a common solution in the end.
EDIT: Pretty much rewrote the full paragraph, better english and typo.

Status:Needs review» Closed (duplicate)

This is a duplicate of #1157850: Provide detailed backtrace in the log for Drupal fatal errors, please keep this discussion in one place, please.

Thanks Damien.

Status:Closed (duplicate)» Needs review

Actually, this patch seems superior. Marked the other issue as duplicate.

Status:Needs review» Needs work

This patch looks good to me. There is only one thing to do: extend it to exceptions by passing the 'backtrace' key into _drupal_decode_exception(); there is no reason not to output a simplified backtrace for exceptions too (and the current patch introduced a notice in the exception handling code path).

#13 Damien+1 It would be a good thing to do.

Status:Needs work» Needs review

Wow, great stuff. Thanks for your work on this, @sun. I guess great minds think alike... or are annoyed by the same old thing over and over again. In commerce, we're seeing fatals show up in the issue queue and we have absolutely no way to get context on them.

I do like showing more information, and would appreciate you saying *why* that would make this a won't fix. Also would like to make sure we display information from exceptions, as an uncaught exception is just another kind of error.

Key differences in #1157850: Provide detailed backtrace in the log for Drupal fatal errors:
* There only fatals get a backtrace. Some sites exist with so many ongoing non-fatals that it may not be worth providing the backtrace for those. But I'm certainly open on this.
* There, exceptions get a backtrace and it seems to work just fine.
* There's a complete backtrace rather than a simplified one
* It only goes into the log. I don't really like taking an already scary fatal page and adding a stack trace to it and presenting that to the user.

I'm fine with the current amount of information. Displaying more gets things tricky fast (do we want the full path of the files, or just the basename? something in between? do we want to display objects? how to handle that? etc.).

Also, I'm fine displaying the backtrace by default when the error is displayed. We might consider making the display of the backtrace optional, but I don't really see the point (error display is already optional).

Looks good to me.

StatusFileSize
new13.84 KB
new4.4 KB
FAILED: [[SimpleTest]]: [MySQL] 29,643 pass(es), 35 fail(s), and 6,656 exception(es).
[ View ]

No progress on exceptions yet, but

- removed removal of error source in the backtrace (so function arguments are visible for that, too)
- added safe attempt to not expose DRUPAL_ROOT

error-backtrace.19.png

Status:Needs review» Needs work

The last submitted patch, drupal.error-backtrace.19.patch, failed testing.

Status:Needs work» Needs review

Since we're working on this class of things, shameless plug for #1159422: Death to WSOD: Output information about what caused a fatal error

#19: drupal.error-backtrace.19.patch queued for re-testing.

I think we should restrict this to just www requests and not CLI.

Status:Needs review» Needs work

The last submitted patch, drupal.error-backtrace.19.patch, failed testing.

If you're testing: I created an error-creating fatal module for testing.

This would be absolutely awesome to something like this in the simpletest module as well, especially because you can't get a debug manually when running simpletest (ie. using something like dpm(debug_backtrace())).

Dunno if that should be part of this bug, or a separate issue?

+++ b/modules/field/modules/text/text.moduleundefined
@@ -9,6 +9,7 @@
+  $foo = $bar;

I don't think anything is wrong with this patch, it is this line (testing line) that is breaking the testbot.

Powered by Dreditor.

Let's also move that algorithm generating a simplified/prettified backtrace output into a separate function. Would be useful for Devel and custom/other code. A full backtrace is often too heavy, especially for on-issue communication (just ran into this in another issue).

Including line numbers might be helpful as well. Sometimes functions are called several times in a function, and you might not know which on is at fault.

I agree; I copied this code to commerce_devel and was immediately forced to add file and line number. I used just basename($trace['file']) and $trace['line']

big plus one from me! may even be able to retire some of the debug code i've been using for longer than i can remember.

also, i really like #30, because i often want to look at cleaned up backtraces while developing, and it has nothing to do with errors.

StatusFileSize
new128.52 KB

+1 from me too!
Running my dev. sandbox with patch #19

Would it be possible to put those errors in a collapsed fieldset? it's not uncommon that if you get one, you get a lot, and the messages could end up being quite long.

Very useful and well done -- but I am hesitant a little. Do we want this on screen or watchdog only? We could amend the watchdog hook so that the modules logging can provide a link if they want (dblog and mongodb will, syslog won't) . One problem here is that sometimes errors come by the dozens or even the hundreds. Not to mention that I do not want to consider all the possible security implications. Should you leave error display on? No. But, should we make that mistake so much worse?

Also, since know the file path can we link the core functions (if it does not start with profiles or sites it's core) to api.drupal.org for convinience?

Finally, the part where we ucfirst(gettype()) -- if it's not scalar, then it's a resource, an object or an array. For arrays we could display a count like Array (20), for objects we could show the class like Object (NegativeDentry) and finally for resources: ob_start(); var_dump($x); ob_get_clean(). Because this shows the type of resource and even the internal identifier which can be used to discern between two resources of the same type.

We have agreed to scrap the watchdog idea but instead create a new ERROR_REPORTING_VERBOSE level.

What would be handy is just to backtrace to the first (last?) non-core function in the call stack. It doesn't help me to know that there was a problem in form_execute_handlers(), but if it at least goes back to whatever last non-core function is in the call stack, that'd be a big help. Any PHP error that drupal reports to me is way too generic. You might as well get rid of them for what they're presently worth.

Q: are most/all errors going to originate in non-core functions? In other words, would this work/be useful in most cases? I don't know.

Status:Needs work» Needs review

Here's the patch from 19 without the $foo = $bar line, so the tests should pass. I also added the ERROR_REPORTING_DISPLAY_VERBOSE constant, the change to the error form, and the logic of whether to display the backtrace or not.

Subscribe - I think this will at least give some people better clues about where to look for and/or report bugs.

@jhedstrom - #39 is missing the patch you mention

One thing to watch for is large strings... drupal_render_page() for instance can be passed a VERY large string value.

The following will need to include some kind of trimming.

<?php
$call
['args'][] = is_string($arg) ? "'$arg'" : $arg;
?>

StatusFileSize
new5.91 KB
PASSED: [[SimpleTest]]: [MySQL] 32,928 pass(es).
[ View ]

Oops. Here's the patch I forgot to actually upload in #39.

StatusFileSize
new102.02 KB

Attached screenshot with running with #42

subscribe

Is there really much point having a backtrace with no line numbers or filenames?

Tend to agree, line and file helps a lot. Problems don't always stem from the last call in the stack (obviously). Objects can have overridden methods, so determining which class contains the actual called code is problematic without filename. Line number is useful when a function is called more than once from the originating function.

I too think we need filenames and line numbers for each function call in the stack.

Do this patch also add a backtrace field to watchdog database table and hook signature documentation so that those trace will always be present when logged?

Status:Needs review» Needs work

Will need reroll after the /core patch went in.

StatusFileSize
new92.41 KB

What about displaying more information, like for example symfony does too. Few lines of code around the error, request info, ... What you think about adding Symfony\Component\HttpKernel\Debug\ErrorHandler and Symfony\Component\HttpKernel\Debug\ExceptionHandler to Drupal?

I like #50 suggestion, and because those two components are parts of the HttpKernel Synfony component, it's tied to what WSCCI is doing and will probably be included as a part of HttpKernel. I would definitely cleanup core error handling code.

Speaking of design, we could easily extend those two and raise events (using Synfony's EventDispatcher package) on errors so modules could act on those (we can keep a hook for registering module listeners though at first).

I definitely +1 wapnik suggestion.

EDIT: The event listener doesn't seems like a good pattern here, my opinion is that it should never exist more than one error listener; But, in order to reproduce the actual core hook_watchdog() behavior, we can do as I described upper easily.

(Off topic) Could we get permissions added while this is being refactored? The function / method signatures could be used to see what modules and versions are enabled, allowing easy discovery of possible security vulnerabilities. Maybe a new permission "view on-screen errors and warnings" or something?

StatusFileSize
new5.87 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch patch-1158322-53.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

Patch from #42 did not apply cleanly on 7.14 for me. Here's one that did.

Status:Needs work» Needs review

Status:Needs review» Needs work

The last submitted patch, patch-1158322-53.patch, failed testing.

Issue tags:+needs backport to D7
StatusFileSize
new5.91 KB
PASSED: [[SimpleTest]]: [MySQL] 36,684 pass(es).
[ View ]

Rerolling #53 for D8.

Status:Needs work» Needs review

Status:Needs review» Reviewed & tested by the community

The purpose of this patch is to provide a short backtrace to give some clue. Those needing more are welcome to install devel. I for myself like this.

StatusFileSize
new5.91 KB
PASSED: [[SimpleTest]]: [MySQL] 36,692 pass(es).
[ View ]

+++ b/core/includes/errors.inc
@@ -21,6 +21,11 @@ const ERROR_REPORTING_DISPLAY_SOME = 1;
const ERROR_REPORTING_DISPLAY_ALL = 2;
/**
+ * Error reporting level: display all messages, plus backtrace information.
+ */
+define('ERROR_REPORTING_DISPLAY_VERBOSE', 3);

Fixed in the attached patch. This is only a minor change so leaving at RTBC.

Trying not to sound like a broken record, can we slip in a permission check here for the screen errors?

I've used this code on a custom D7 module that is happy spitting out backtraces all over the place (Fields and Panels are generate so many warnings), but our clients is blissfully unaware and we are resolving these bugs much faster because of the code replicated from here and the fact that we get an instant backtrace.

<?php
+  global $user;
$detail_access = (!empty($user) && $user->uid == 1) || (function_exists('user_access') ? user_access('view screen errors') : 0);
?>

And then in all of the corresponding locations:

<?php
 
if (drupal_is_cli()) {
    if (
$fatal) {
     
// When called from CLI, simply output a plain text message.
-      print html_entity_decode(strip_tags(t('%type: !message in %function (line %line of %file).', $error))). "\n";
+      if (
$detail_access) {
+       
$message = t('%type: !message in %function (line %line of %file).', $error);
+      }
+      else {
+       
$message = t('The website encountered an unexpected error. Please try again later.');
+      }
+      print
html_entity_decode(strip_tags($message)) . "\n";
      exit;
    }
  }
  if (isset(
$_SERVER['HTTP_X_REQUESTED_WITH']) && $_SERVER['HTTP_X_REQUESTED_WITH'] == 'XMLHttpRequest') {
    if (
$fatal) {
     
// When called from JavaScript, simply output the error message.
-      print t('%type: !message in %function (line %line of %file).', $error);
+      if (
$detail_access) {
+        print
t('%type: !message in %function (line %line of %file).', $error);
+      }
+      else {
+        print
t('The website encountered an unexpected error. Please try again later.');
+      }
      exit;
    }
-    if (
error_displayable($error)) {
+    if (
$detail_access && error_displayable($error)) {
?>

Can we do #60 in a follow-up / separate issue?!
Seems like that needs some more discussion and this has been lingering for so long already.

Agreed with #61. I'm tired of installing commerce_devel just to get this important piece of DX.

I'm tired of installing commerce_devel just to get this important piece of DX.

I was on the brink of adding the commerce_devel code to devel, but it requires duplicating an awful lot of core code to get it right, because core is so uncooperative.

Let me look into this to see what it would take to provide a reasonable integration point.

because core is so uncooperative.

. Hrm. What is missing? Please file an issue for any missing hooks, alters etc

Yes, I'll open a new issue. We'll need a new hook.

devel_commerce duplicates the entire 76-line _drupal_log_error() function just to customize two lines.


+++ b/core/includes/errors.inc
@@ -241,13 +253,55 @@ function _drupal_log_error($error, $fatal = FALSE) {
+      // Do not expose DRUPAL_ROOT, if possible.
+      $root_length = strlen(DRUPAL_ROOT);
+      if (substr($error['%file'], 0, $root_length) == DRUPAL_ROOT) {
+        $error['%file'] = substr($error['%file'], $root_length + 1);
+      }

We could and maybe should do more here. I have found that if Drupal is symlinked into the webroot directory (for easy sharing among multiple sites), then DRUPAL_ROOT will contain the path in the webroot, but PHP delivers the resolved paths in the file system. This means there is no match and the file system path is exposed.

Status:Reviewed & tested by the community» Needs work

I'm not sure we should add the DRUPAL_ROOT check at all here, see http://groups.drupal.org/node/230373 for example.

If we add it, but it doesn't work all the time, we'll get more 'full path disclosure vulnerability!?!!!!" crap.

If we don't do it at all, then we might still get that but we can just say we don't care at all.

I can maybe see an argument for shortening the filenames just to reduce verbosity, but then is that the right place?

Status:Needs work» Needs review
StatusFileSize
new6.14 KB
PASSED: [[SimpleTest]]: [MySQL] 36,693 pass(es).
[ View ]

The paths are shortened to reduce verbosity only. At no point in time I considered "security" to be a reason for the shortening.

To account for that, for now, I'd recommend to implant the verbosity reason into code comments, because - yes, the code does not explain why this is done, so anyone reading it might mistakenly believe that this is a (poor) security "feature".

I'd suggest to enhance both the constant definition as well as the inline comment above the code block that performs the stripping:

+++ b/core/includes/errors.inc
@@ -21,6 +21,11 @@ const ERROR_REPORTING_DISPLAY_SOME = 1;
/**
+ * Error reporting level: display all messages, plus backtrace information.
+ */
+const ERROR_REPORTING_DISPLAY_VERBOSE = 3;
@@ -241,13 +253,55 @@ function _drupal_log_error($error, $fatal = FALSE) {
+      // Do not expose DRUPAL_ROOT, if possible.

Done so.

I'd prefer a separate follow-up issue for #66 to improve the symlink case. We might be able to use realpath(DRUPAL_ROOT), but as usual, I guess that needs a lot of dedicated testing on its own.

Status:Needs review» Needs work

EDIT: Ignore this comment!

+++ b/core/includes/errors.inc
@@ -193,6 +201,10 @@ function _drupal_log_error($error, $fatal = FALSE) {
+  // Backtrace array is not a valid replacement value for t().
+  $backtrace = $error['backtrace'];
+  unset($error['backtrace']);
+

'backtrace' is not '!backtrace', and thus no replacement candidate value; 'severity_level' is not intended for t() either.

Once this patch has landed, I'd like to propose a new hook_log_error($error) that passes $error for any module that wants to display/log/whatever the message in an alternative way. It would be nice to pass the backtrace, too. This could be an additional parameter, but why not just leave it in $error and pass $error unchanged?

(didn't mean to change the status)

Status:Needs work» Needs review
StatusFileSize
new7.11 KB
PASSED: [[SimpleTest]]: [MySQL] 36,835 pass(es).
[ View ]

+++ b/core/includes/errors.inc
@@ -21,6 +21,14 @@ const ERROR_REPORTING_DISPLAY_SOME = 1;
+ * Error reporting level: display all messages, plus backtrace information.
+ *
+ * DRUPAL_ROOT is attempted to be stripped from file paths in the backtrace to
+ * reduce verbosity only, not for (false) security reasons.

Actually, the stripping is not related to the "backtrace information" -- it's about the path in the error message. Drop the second paragraph.

+++ b/core/includes/errors.inc
@@ -193,6 +204,10 @@ function _drupal_log_error($error, $fatal = FALSE) {
+  // Backtrace array is not a valid replacement value for t().
+  $backtrace = $error['backtrace'];
+  unset($error['backtrace']);
+

t() does not like having additional stuff in its $variables argument, especially non-scalars. So this is needed — ignore my comment in #69.

+++ b/core/includes/errors.inc
@@ -241,13 +256,56 @@ function _drupal_log_error($error, $fatal = FALSE) {
+      // Attempt to reduce verbosity by removing DRUPAL_ROOT from file paths in
+      // the backtrace. This does not happen for (false) security.

Fix the comment to not mislead.

In addition to the items above, I've made the following changes:

Fixed the docblock of _drupal_log_error() to document the new 'backtrace' key.

Moved the formatting of the backtrace to a separate _drupal_format_backtrace() function. This improves the code structure, and the function can be useful for contribs.

Added passing string arguments through filter_xss().

Nice. Here it is for those that want in their D7 make files.

Thanks for working on the Drupal 7 backport. However, it's premature -- we only backport once the patch is committed.

I must say I hate with a fiery passion when people post patches for drush make! It typically makes the queue harder to follow and flies straight against http://drupal.org/best-practices/do-not-hack-core .

Status:Needs review» Reviewed & tested by the community

#67 is addressed so back to green. Perhaps we could salvage #72 as well as if this goes in.

Sorry chx, but it's a very useful patch wether for Drupal 8 or Drupal 7. I tested #71 on D8, it did the job, it passed all the tests, so I backported it. This issue was tagged as "needs backport to Drupal 7" back in comment #56. I marked the patch clearly as a D7 patch, and one that the testbot should ignore. I don't know how you can possibly call that hacking core.

I thought #73 was quite clear on what my problem was -- and sorry for lashing out at you. In this case it's not that bad -- but often we see these drush make patches in very long, convoluted issues and even on those that have zero chance of getting in. I expressed my hopes in fact that your patch can be used, after all.

StatusFileSize
new1.08 KB
new7.09 KB
PASSED: [[SimpleTest]]: [MySQL] 37,026 pass(es).
[ View ]

Moved the formatting of the backtrace to a separate _drupal_format_backtrace() function. This improves the code structure, and the function can be useful for contribs.

_ denotes a private function though, which shouldn't be used by anything else. I agree with the intention and general usefulness, so here's a quick fix for that.

_ denotes a private function though, which shouldn't be used by anything else.

Agreed, but no scope prefix, i.e. format_backtrace()? There are certainly other ways to format a backtrace.

I modeled the docblock after the one for _drupal_get_last_caller(), but I agree with sun's improvements in #71. Should we improve the _drupal_get_last_caller($backtrace) docblock accordingly (and add the type hint)? Can/should we remove that underline, too?

I only adjusted the phpDoc of the newly added function. Fixing phpDoc of existing functions is left for dedicated general code clean-up issues.

Category:task» feature

This seems like a nice useful feature, but it's a feature, not a task. I'll get back to this again when I'm through the rest of the major/critical tasks/bugs.

Version:8.x-dev» 7.x-dev
Status:Reviewed & tested by the community» Patch (to be ported)

Committed/pushed to 8.x, moving to 7.x for backport.

Status:Patch (to be ported)» Needs review
StatusFileSize
new7.05 KB
PASSED: [[SimpleTest]]: [MySQL] 39,257 pass(es).
[ View ]

Pretty much a straight port from #77 to D7.

Status:Needs review» Reviewed & tested by the community

I think this is good to go , I do not see any string changes only a single addition t('All messages, with backtrace information')

Looking good, RTBC.

OMG YES. This will make it a zillion times easier for contrib modules to debug things (because many non-technical users don't know the kind of information we need). Thanks to all of you who made this happen!

And just in case this is forgotten about: #1608034: Permissions on display of errors

Live sites have errors too and errors shouldn't show to non-admins / developers!

So this has 8.x and 7.x RTBC patches.
Will this get attention as 7.x issue?

#82 appears to have the go ahead to commit into 7.x - it is already in 8.x

#86 is to allow developers to alter the settings in the settings.php file without resorting to meaningless numbers like 32767 or 30719 for E_ALL (PHP version dependent)

#87 is to allow site builders to run this on live sites without exposing the internals to the entire world

Sorry, the combination of string addition, UI change, and form structure change makes me not want to commit this right before the Drupal 7.15 release. Let's hold off and discuss again after that.

I think as long as we provide some advanced notice (and commit this towards the beginning of a release cycle) it's OK, though.

But..... why does this patch not have tests (for either Drupal 7 or Drupal 8)? There's a DrupalErrorHandlerTestCase in the codebase that attempts to test each of the 'error_level' options, but now it doesn't have any tests for the new option being added.

Version:7.x-dev» 8.x-dev
Status:Reviewed & tested by the community» Needs work

Sorry to do this, but there is a flaw somewhere in the code, so it's probably not that bad that we didn't commit the backport yet.

For certain errors/exceptions, an additional error/exception is thrown. I wasn't able to identify yet what exact kind of errors/exceptions are triggering the additional one.

Manually dumping a debug_backtrace() yields this:

  [1]=>
  array(4) {
    ["file"]=>
    string(54) "core\includes\errors.inc"
    ["line"]=>
    int(253)
    ["function"]=>
    string(17) "error_displayable"
    ["args"]=>
    array(1) {
      [0]=>
      &array(6) {
        ["%type"]=>
        string(6) "Notice"
        ["!message"]=>
        string(26) "Undefined index: backtrace"
        ["%function"]=>
        string(19) "_drupal_log_error()"
        ["%file"]=>
        string(54) "core\includes\errors.inc"
        ["%line"]=>
        int(208)
        ["severity_level"]=>
        int(5)
      }
    }

So it looks like some errors/exceptions do not have a backtrace, and/or _drupal_log_error() might be called from another place, which didn't pass the error/exception through _drupal_error_handler_real().

Status:Needs work» Needs review
StatusFileSize
new1.19 KB
PASSED: [[SimpleTest]]: [MySQL] 39,977 pass(es).
[ View ]

This would be the obvious "quick fix", but I don't think that's the proper thing to do.

Currently, backtraces are not added to watchdog loggings. Is there a reason not add them to watchdog loggings?

Backtraces in watchdog entries would be useful on production sites, especially since UI logging is normally disabled on production sites.

@scito:

I'm guessing you haven't read any of this issue.

Got testbot to throw "Undefined index: backtrace Notice".
http://qa.drupal.org/pifr/test/329463

StatusFileSize
new72.35 KB

Looks like that went away, so here is a screenshot of it. More info on what failed... http://drupal.org/node/818818#comment-6417664

Assigned:sun» Unassigned

Thanks @mikeytown2, that seems to be exactly the same nested exception I'm frequently encountering, too. I won't have time to look further into this, so I hope someone else can take over.

I am currently having an error which triggers the "Undefined index: backtrace" notice, related to #1798732: Convert install_task, install_time and install_current_batch to use the state system.

I'm not sure if this of any use, but I thought I would at least make a note of it here - hopefully it helps to narrow things down.

Starting Drupal installation. This takes a few seconds ...                                                                          [ok]
Undefined index: backtrace errors.inc:188                                                                                              [notice]
WD php: Symfony\Component\DependencyInjection\Exception\InvalidArgumentException: The service definition "keyvalue" does not exist. [error]
in Symfony\Component\DependencyInjection\ContainerBuilder->getDefinition() (line 690 of
/Users/cam8001/Sites/drupal/core/vendor/symfony/dependency-injection/Symfony/Component/DependencyInjection/ContainerBuilder.php).
Symfony\Component\DependencyInjection\Exception\InvalidArgumentException: The service definition "keyvalue" does not exist. in Symfony\Component\DependencyInjection\ContainerBuilder->getDefinition() (line 690 of /Users/cam8001/Sites/drupal/core/vendor/symfony/dependency-injection/Symfony/Component/DependencyInjection/ContainerBuilder.php).

$error is

<?php
array (
 
'%type' => 'Symfony\\Component\\DependencyInjection\\Exception\\InvalidArgumentException',
 
'!message' => 'The service definition &quot;keyvalue&quot; does not exist.',
 
'%function' => 'Symfony\\Component\\DependencyInjection\\ContainerBuilder->getDefinition()',
 
'%file' => '/Users/cam8001/Sites/drupal/core/vendor/symfony/dependency-injection/Symfony/Component/DependencyInjection/ContainerBuilder.php',
 
'%line' => 690,
 
'severity_level' => 3,
)
?>

Heres a gist with a backtrace. https://gist.github.com/3956062

It is possible that #1536868: No trace when database is down fixed the PHP notice about the missing 'backtrace'. I did not verify this, only saw that commit in the log.

StatusFileSize
new375 bytes
PASSED: [[SimpleTest]]: [MySQL] 48,309 pass(es).
[ View ]

Here is one missing line.

Status:Needs review» Reviewed & tested by the community

Well, that totally looks more like it. Thanks! :)

Heh, what a lovely patch :)

Version:8.x-dev» 7.x-dev
Status:Reviewed & tested by the community» Patch (to be ported)

Great catch! :)

Committed and pushed to 8.x. Back to 7.x for porting as per the tags, though I'm not sure if David's into that idea or not.

Getting the following now when an exception is thrown, I think that is caused by this patch:

htmlspecialchars() expects parameter 1 to be string, array given
htmlspecialchars(Array, 3, 'UTF-8')
check_plain(Array)
drupal_placeholder(Array)
format_string('%type: !message in %function (line %line of %file). !backtrace', Array)
Drupal\simpletest\TestBase->exceptionHandler(Object)
Drupal\simpletest\TestBase->run()
_simpletest_batch_operation(Array, '208', Array)
call_user_func_array('_simpletest_batch_operation', Array)
_batch_process()
_batch_do()
_batch_page()
system_batch_page()
call_user_func_array('system_batch_page', Array)
Drupal\Core\EventSubscriber\LegacyControllerSubscriber->Drupal\Core\EventSubscriber\{closure}()
call_user_func_array(Object, Array)
Symfony\Component\HttpKernel\HttpKernel->handleRaw(Object, 1)
Symfony\Component\HttpKernel\HttpKernel->handle(Object, 1, 1)
Drupal\Core\HttpKernel->handle(Object, 1, 1)
Symfony\Component\HttpKernel\Kernel->handle(Object)

Which is because of:

<?php
   
// The exception message is run through check_plain() by _drupal_decode_exception().
   
$message = format_string('%type: !message in %function (line %line of %file). <pre class="backtrace">!backtrace</pre>', _drupal_decode_exception($exception) + array(
     
'!backtrace' => format_backtrace($verbose_backtrace),
?>

So the backtrace array is passed to format_string(), which tries to check_plain() it.

Version:7.x-dev» 8.x-dev
Status:Patch (to be ported)» Needs work

Here we go again...

Additionally, the entire code of errors.inc has been duplicated into ExceptionController...

None of the code that has been added by this issue exists in there.

I don't know in which situations the functions in errors.inc are triggered in HEAD — they're still registered early in the bootstrap, and I've seen verbose error messages including backtrace in HEAD up until very recently, but we completely changed the bootstrap to boot DrupalKernel instead (as of yesterday) and the Symfony Kernel is known to overload the environment.

I was under the assumption that we disabled that by overriding Kernel::init() in DrupalKernel, but in trying to debug an exception to debug some other functionality, I factually don't see any function in errors.inc getting invoked (except error_displayable(), which is weird on its own...) — instead, the entire thing runs through Drupal\Core\ExceptionController::on500Html(), which still calls into various procedural functions, but I'm not able to make sense of it.

Category:feature» task
Status:Needs work» Active

This essentially means that the entire patch in #77 needs to be redone. (plus the follow-up fix from #100)

Category:task» bug

Status:Active» Needs review
StatusFileSize
new3.41 KB
FAILED: [[SimpleTest]]: [MySQL] Repository checkout: failed to checkout from [git://git.drupal.org/project/drupal.git].
[ View ]

Attached patch re-implements #77 and #100 in ExceptionController.

I'm getting a formatted backtrace with this again.

Status:Needs review» Needs work

The last submitted patch, drupal8.error-backtrace.109.patch, failed testing.

Status:Needs work» Needs review
StatusFileSize
new6.92 KB
PASSED: [[SimpleTest]]: [MySQL] 48,773 pass(es).
[ View ]
new3.51 KB
FAILED: [[SimpleTest]]: [MySQL] 48,776 pass(es), 2 fail(s), and 0 exception(s).
[ View ]

Attached a simple test.

StatusFileSize
new7.99 KB
PASSED: [[SimpleTest]]: [MySQL] 49,312 pass(es).
[ View ]

Updated patch, fixes the mentioned issue in #104 from berdir.

Status:Needs review» Needs work

The last submitted patch, 1158322-error_backtrace-112-with_test.patch, failed testing.

StatusFileSize
new1.69 KB

Here's some patch from the other end of the problem. It nukes the backtrace before format_stringing it from update or testbase. Not sure how helpful it is, but it's written and maybe it helps.

Status:Needs work» Needs review

+++ b/core/modules/system/lib/Drupal/system/Tests/System/ErrorHandlerTest.phpundefined
@@ -121,6 +123,24 @@ function testExceptionHandler() {
+    // We cannot use assertErrorMessage() since the extact error reported
+    // varies from database to database. Check that the SQL string is displayed.

extact => exact.

Status:Needs review» Needs work
Issue tags:-DX (Developer Experience), -needs backport to D7

The last submitted patch, 1158322-error_backtrace-112-with_test.patch, failed testing.

Status:Needs work» Needs review
Issue tags:+DX (Developer Experience), +needs backport to D7

37ea2e09c90fd4ee6deb22040d0eae9bc06b5ef8 breaks callers of _drupal_decode_exception(). i just wasted a bunch of time trying to figure out a heisenbug over in #1331486: Move module_invoke_*() and friends to an Extensions class because of this.

please can we rollback?

if we're not going to rollback, can we commit something along the lines of #114 to stop the bleeding?

Can you review it and mark it RTBC if it fixes your problem? :)

StatusFileSize
new2.2 KB
PASSED: [[SimpleTest]]: [MySQL] 49,754 pass(es).
[ View ]

attaching #114 so the bot runs it. i think it's RTBC, looked at usage of _drupal_decode_exception() and this covers the cases that were broken by the 'backtrace' array in it's output.

i've added on doc fix to #114 - we had a reference to drupal_decode_exception instead of _drupal_decode_exception.

so if this comes back green, i'm going to RTBC - no commit credit, the patch is chx's work.

Status:Needs review» Reviewed & tested by the community

yay.

Version:8.x-dev» 7.x-dev
Category:bug» feature
Status:Reviewed & tested by the community» Patch (to be ported)

Have we finally seen the end of this perma-major? Tune in tomorrow! ;)

Committed and pushed to 8.x.

Oh-so-tentatively marking down to 7.x for backport, but I recommend waiting awhile to see how the dust settles first.

Version:7.x-dev» 8.x-dev
Status:Patch (to be ported)» Needs work

I think not.

I'm not sure why #114 was committed and not #112, which I think contained a fix for the problem as well + other improvements and test coverage.

What #112 did not contain is the update.inc change, so let's not roll back (I'm glad at least the ugly exception in case of test exceptions was fixed) but #112 will need a re-roll now.

Status:Needs work» Needs review
StatusFileSize
new1.97 KB
new6.92 KB
PASSED: [[SimpleTest]]: [MySQL] 50,541 pass(es).
[ View ]

I hope this is re-rolled properly.

Really need something that works for Drupal 7 too. Attached is a backport of the patch in #126.

Also, can we update watchdog_exception() to include the backtrace as well while we're at it? Because that's the one where it would be *really* useful.

Status:Needs work» Needs review
StatusFileSize
new9.8 KB
PASSED: [[SimpleTest]]: [MySQL] 39,745 pass(es).
[ View ]

This patch is against drupal 7.18. Since this is an issue for Drupal 8 this will probably fail testing.

Also, I added a couple of features, namely:

  • You can choose whether the output goes to the page and/or the log
  • You can choose to display either with scalar variables as before and/or a stack trace. I find the stack trace option more useful in most cases since if I need to start looking at variables being passed I'll probably be using a real IDE/debugger for the job. A simple stack trace on the otherhand has helped me countless times determining where an error is originating without resorting to a debugger.

In any case, the prime goal here is to add flexibility. If anyone else has other outputs they find useful it would be very easy to copy the methodology I used to add another format. I mention this because I noticed earlier in the issue much debate over what should be displayed. There's never going to be one best display of information so some choices should help.

Status:Needs review» Needs work

The last submitted patch, 1158322-error_backtrace-129-D7.patch, failed testing.

Status:Needs review» Needs work

Thank you, but we need to get the D8 version committed first.

Well, it's there for anyone using D7 that wants it.

I wouldn't mind doing it for D8 but my time is limited and I checked the error that was generated "Detect a non-applicable patch". I really don't know what that means or how I would go about finding exactly what it's complaining about. I'm a little shy of jumping in trying pass all the tests for a version I've never used when I can't really figure out the line(s) the tester is complaining about.

Perhaps you could give me some insight on where the detail of what created that message is? I looked around and couldn't find anything to give any extra detail.

@Reg, I think you already answered your own question above :)

This patch is against drupal 7.18. Since this is an issue for Drupal 8 this will probably fail testing.

So yeah, that's all that's happening really; the testbot is trying to apply the patch to Drupal 8 and it doesn't apply there since it was written for Drupal 7.

Most likely there are several reasons why the patch won't apply, but the main one is that in Drupal 8 all the modules and such have been moved into the top-level core/ directory...

Ok, I appreciate that however what I still want to know is how do I "see" that in the test results.

This is one thing: "Detect a non-applicable patch". What I would expect to see is: "File referenced in patch .../xyz not found." ...anything that's not a cryptic response.

What's concerning me is if I tackle creating a patch for a version I don't yet know that passes testing am I going to be spending all my time trying to decode what the tester is saying because that's only one error but I when I looked at the results saw dozens of checks, perhaps close to a 100... that's a lot to go wrong and spend time scratching your head over what it's telling you.

Version:8.x-dev» 7.x-dev
Status:Needs work» Needs review

Going to retest #129 under D7

#129: 1158322-error_backtrace-129-D7.patch queued for re-testing.

Once this test is done, we can switch the issue back to 8.x

StatusFileSize
new9.87 KB
PASSED: [[SimpleTest]]: [MySQL] 39,749 pass(es).
[ View ]

Very cool and thank you so much. If I wasn't so tapped out for time I would tackle the D8 version but I just can't right now so I really appreciate this!

I've been using this over the last couple of days and made a couple of tweaks (changed a label and removed a couple of "notices" that came up under certain circumstances). I've attached the update here.

One thing that I know should be changed is there is a very tiny bit of styling added for a table that is generated in the PHP. I'm sure someone who knows the drupal system CSS well could remove that (it's only a couple of lines) and just hard code in some existing CSS classes. I added a TODO in there to that effect.

StatusFileSize
new10.62 KB
PASSED: [[SimpleTest]]: [MySQL] 39,942 pass(es).
[ View ]

This has one change only. Occasionally a PDOException will get through and if you have it set to send to watchdog the PDO will reject the exception since you can't send errors from using the PDO back though the PDO. This is a restriction by PHP, and it makes perfect sense so no complaints here.

This addition checks for such an error and if you have it set to go to watchdog it simply won't thus preventing a cascade of errors. The danger here is that the error could get "thrown away" if you don't have it set to display errors as well.

I'm in two minds about this, it would easy enough to force the error to the display if we don't allow to go to watchdog however there are user settings to control that and I don't necessarily want to ignore the user settings.

I could make an argument to force to show the error or equally well to leave it up to the user. If anyone wants to chime in, please do.

Version:7.x-dev» 8.x-dev
Category:feature» task
Status:Needs review» Needs work
Issue tags:-needs backport to D7

Friends, this issue is getting completely out of hands again. This is still not working correctly in HEAD, since we magically skipped over an essential follow-up patch. I'm removing the backport tags and everything else. This needs to be fixed in HEAD first.

The D8 patch that is still required is #109/#126.

Also noteworthy: The committed follow-up patch from #122 added manual unset($variables['backtrace']) calls to various places, but that is not sufficient; hook_watchdog() implementations still get a backtrace that may contain data that cannot be serialized: #1934738: Exception: Serialization of 'Closure' is not allowed in serialize() (line 154 of dblog.module)

@sun:#139 The error you are referring to I just came across and fixed. I believe it is the very last bug in the code (although you never know for sure).

Anyway, the code is here: http://drupal.org/node/1937832.

If you look for the function "array_has_PDOException" and the two calls to it and incorporate it into your D8 code you will have removed that error. Sorry I couldn't do this directly on D8 yet but at least there is a fix you can adopt easily enough for whomever is working in this problem.

StatusFileSize
new13.27 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch 1158322-error_backtrace-141-D8.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

I don't have a running copy of D8 however the code is so similar to D7 (for the parts that relate to this) it wasn't hard to manually splice the D7 code into the D8 code.

Of course there is more than a decent chance I made a mistake along the way so I would very much appreciate anyone who's actively running D8 to test this and let me know of anything that comes up. I'll fix it quickly so we can finally get better error reporting officially integrated into Drupal.

This is meant to be identical to the latest patch for D7 I did that's seems to be working perfectly (at http://drupal.org/node/1937832#comment-7154472 so you can use that as well for a reference if you want to do a little debugging yourself).

One thing I avoided is adding 2 tests. I think you really want a running copy for that however I did add a TODO where they should go.

Thanks for working on this, here is a quick review. Don't try to do too much in here.

+++ b/core/includes/bootstrap.incundefined
@@ -57,10 +57,15 @@
+ * Error reporting type of debug information: Add stacktrace or backtrace information to logs.
...
+ * Error reporting type of debug information: Add stacktrace or backtrace information to messages on page.

Comment shouldn't be longer than 80 characters.

+++ b/core/includes/bootstrap.incundefined
@@ -57,10 +57,15 @@
+const ERROR_REPORTING_DISPLAY_LOGS = 1;  // Do not start at zero.

Comments shouldn't be appended to code but always be on their own line. Also, why is this not using a stringe like the other constants?

+++ b/core/includes/errors.incundefined
@@ -186,8 +185,11 @@
+    $backtrace = debug_backtrace(TRUE);

As of PHP 5.3.6, which we now require, the arguments to that function have changed, see http://php.net/debug_backtrace

+++ b/core/includes/errors.incundefined
@@ -209,7 +211,29 @@
+  $st_opts=variable_get('error_stacktrace_display', array());
...
+  $bt_opts=variable_get('error_backtrace_display', array());

Needs spaces around the =. And it shouldn't use variable_get() but config()

+++ b/core/includes/errors.incundefined
@@ -209,7 +211,29 @@
+  if (!array_has_PDOException($error)) { // If it was a DB error don't write to the DB.
+    watchdog('php', $message_line, $error, $error['severity_level']);

That should a) be handled by dblog.module, for which there is a specific issue and b) we actually should never pass a backtrace array through to watchdog, only the generated string. Then this wouldn't be a problem.

+++ b/core/includes/errors.incundefined
@@ -357,5 +408,64 @@
     $return .= $call['function'] . '(' . implode(', ', $call['args']) . ")\n";
...
-  return $return;
+  return '<br/><br/>BACKTRACE:<br/>' . $return;

I don't think this should be changed. As you can see in the line above, this function currently doesn't assume that it returns HTML and is returned in a HTML response.

On all but the last two points: First, it's less than I thought it would be given a manual splicing of code and having never run D8 so I'm not feeling too bad about it but it is going to be difficult to get it right since none of my work involves working on D8. Is there any chance you could tweak those few and give it whirl? That would be big help!

On the last two points:

That should a) be handled by dblog.module, for which there is a specific issue and b) we actually should never pass a backtrace array through to watchdog, only the generated string. Then this wouldn't be a problem.

a) Agreed, I hadn't got around to moving it but it was in the plan.

b) Agreed, and I already thought this one through a bit and the reasoning goes a little beyond what "should be". The reality is that you just don't know what people are going to do with contributed modules (or for that matter even a core bug could cause the same problem) and this PDOException getting through to watchdog is such a showstopper that's it's worth throwing in extra protection like this. You will also see a similar check right in watchdog for the same reason (they both need to be in place to work). If you don't then what can happen is you "lose" the error that caused the problem and the only problem you see is that "cannot pass PDOExecption to..." (I've experienced this first hand it's not fun to deal with) which then defeats what we are trying to achieve which is easier debugging. So, in this case, being overly careful and protective is not a bad thing at all so from already having experienced the problems that can otherwise happen, it's a good thing to keep it as is.

return '<br/><br/>BACKTRACE:<br/>' . $return;
I don't think this should be changed.

It's changed for a very good reason. You should test it before setting yourself on this conclusion. It is complimentary to:
return '...STACKTRACE:..'
I've been using these two quite a bit in D7 and they report well together the way I have done them. It also sets up a precedence for if/when someone may add other reporting styles, i.e., we've given each type a header to distinguish them.

Coming here from #1872690: Exception: Serialization of 'Closure' is not allowed in serialize.

Why exactly do we need to serialize a backtrace that in many cases is not serializable, because this is PHP and not everything is serializable?

And if we need to log exceptions, have a look at Symfony's FlattenException that is intended to address the same issue.

I'm not sure where backtrace is getting serialized. It's certainly not in any of the code that I created to have the backtrace so I could only assume it's built into a function that gets called along the way I've not fully looked at, if at all. The full backtrace isn't used anyway, for the purpose of readability it's stripped down and summarized in two different forms, each of which you can choose to use or not. (patch at #141 above).

Regarding using symphony, right now we simply pass the error to the screen and don't let it go to the DB (most recent code #141). Given that the error was in the database that seems like a very sensible course of action to me so I'm not sure if there's any benefit in doing extra work just to see if you can send it back into the DB.

StatusFileSize
new21.67 KB
FAILED: [[SimpleTest]]: [MySQL] 57,979 pass(es), 4 fail(s), and 1 exception(s).
[ View ]

Finally had some time to do this some justice.

This is a fairly significant rework so I'll probably have to iterate a couple of times but I have D8 running now which of course makes all the difference.

This will probably speed up development so it would be nice to get it into D8 ASAP.

It says status ignore on the patch. How do you make it run or not run tests on a patch?

Status:Needs work» Needs review

Is that what causes a patch to be tested, setting the status to needs review? - Never mind, found: https://drupal.org/node/332678

Status:Needs review» Needs work

The last submitted patch, 1158322-error_backtrace-147-D8.patch, failed testing.

Status:Needs work» Needs review
StatusFileSize
new29.06 KB
PASSED: [[SimpleTest]]: [MySQL] 57,703 pass(es).
[ View ]

The only errors that patch produced was from the simpletest. I had a look and it was something that was there and I hadn't really worked on. Looking through it I only got so far and then came to an impasse and could use some advice from people who work in that area more.

Here's what I have found and where I am up to. I've reworked the test so that all combinations of conditions can be tested. However, I do not know how to effect an error in the context of a webtest that will inject the results of that triggered error into the HTML that's tested when you use the "assert" functions.

What won't work is you can't use set_error_handler() and then trigger_error() as the results won't go into the HTML that we want it to. I tried adding a hook so that I could create an error in the hook (using page_alter) so that I could create an error condition there but couldn't get the hook to take. I don't know if that's because the test modules won't get picked up by hooks or if I need to do something to make D8 realize the hook is there.

Another tact I was looking at was that CronRunTest:testCronExceptions() seems to create an exception so I figured there must be a way to trigger an error to do what I want but I don't really know enough to figure it out. Also I've never seen this syntax (from CronRunTest):

    \Drupal::state()->set('system.cron_last', $cron_last);

Does anyone know what that prepended slash does?

For now I just bypass the tests with a return at the top of the function until someone can give me enough info to know how to go about finishing it off.

Thanks.

Copying from the related #2063303: A Drupal 8 AjaxResponse that must return a 403, returns a 403 and prints "A fatal error occurred: "

I know Symfony and Silex have very good debug output in case of uncaught exceptions. Symfony also has a nice debug toolbar. We should perhaps look into both of them and see if there's code we can borrow, or at least concepts.

@Reg: the Drupal class exists to support legacy code that cannot be dependency injected. When you use it in a class you need to use the fully-qualified namespace, which is \Drupal (rather than Drupal). When it is used in procedural code (such as a hook), it can just be called like Drupal::state.

I'm working on a solution. In the meantime does anyone know why this function:

function _drupal_error_handler_real($error_level, $message, $filename, $line, $context) {

has this passed $context variable even though it's not used in the function?

I'm not sure, but frankly all exception handling in errors.inc needs to be removed in favor of the existing handling in the kernel, which will catch it anyway.

Drupal is not an OS, what do you do call a kernel in drupal?

StatusFileSize
new28.16 KB
PASSED: [[SimpleTest]]: [MySQL] 58,072 pass(es).
[ View ]

This has testing of all the admin options and select error types however it's just looking for errors to be thrown so unit testing rather than functional testing.

Error trapping is a bit of a special case and I don't know if it makes sense to do functional testing with error trapping. However, if someone knows a trick to make the error trapping work with functional tests, terrific. I would like to see how it's done.

Also, could someone have a look at the error output and admin. options. I would like to know what people think of it over the previous way.

The HttpKernel class, provided by Symfony in the HttpKernel component. I strongly recommend reading through that and understanding it before working on error handling, because what you're doing here appears to be Drupal 7-era architecture. You're adding a bunch of new functions and global constants to support error handling code that is *almost* never called, and when it is it probably shouldn't be. There's an entirely different error handling model provided by HttpKernel that we should be moving more toward, not continuing to develop the legacy, ugly one that still assumes PHP 4 is a viable language. :-)

Good point.

I looked at the error handling as is and right now this is the error trapping in Drupal so when an error happens this will *always* be called so this at the moment is anything but code that is almost never called. That is, no other error trap is set (unless running tests).

Symphony does have a set_error_handler() statement but at least through normal page loads without add-in modules I don't see it ever being run.

I'm happy to change this code over to Symphony integration, if in fact after study that is the way to go, however like almost everyone else I'm a volunteer so time is needed. The best steps forward I suggest are for now to use what I have written as it makes troubleshooting far better than anything previously so it should speed up development.

I'll dig into Symphony when I can next block out a chunk of time to study it and refactor this code accordingly.

StatusFileSize
new0 bytes
FAILED: [[SimpleTest]]: [MySQL] 58,135 pass(es), 1 fail(s), and 0 exception(s).
[ View ]

A small improvement.

Status:Needs review» Needs work

The last submitted patch, 1158322-error_backtrace-161.patch, failed testing.

Well, that's impressive, a patch without changes has failed tests :D

Probably has something to do with it being 0 bytes :)

StatusFileSize
new28.44 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch 1158322-error_backtrace-161_0.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

LOL, that is bizarre. I was about to make some excuses about working until daylight and such but it's a full patch on my system so I have no idea what happened. Maybe a slight update delay on my LAN with my NFS share ...who knows.

Status:Needs work» Needs review

Status:Needs review» Needs work

The last submitted patch, 1158322-error_backtrace-161.patch, failed testing.

There's been an update to the git repo. which is why the last patch failed. I updated my local repo to build a new patch but even though I have the patch I can't test it before uploading because this update is throwing an exception (nothing to do with my code as far as I can see).

What's the coarse of action here? Just wait a while until whoever is working on that area fixes it?

The interesting thing here is it is a Symfony error so that's an opportunity for me to look at that part of the error handling although sooner than I really have time for.

Symfony\Component\DependencyInjection\Exception\ServiceNotFoundException:  You have requested a non-existent service "csrf_token". in .../core/vendor/symfony/dependency-injection/Symfony/Component/DependencyInjection/Container.php on line 289
Stack trace:
   1. {main}() .../index.php:0
   2. drupal_handle_request() .../index.php:13
   3. Drupal\Core\DrupalKernel->handle() .../core/includes/bootstrap.inc:1902
   4. Drupal\Core\HttpKernel->handle() .../core/lib/Drupal/Core/DrupalKernel.php:296
   5. Symfony\Component\HttpKernel\HttpKernel->handle() .../core/lib/Drupal/Core/HttpKernel.php:52
   6. Symfony\Component\HttpKernel\HttpKernel->handleRaw() .../core/vendor/symfony/http-kernel/Symfony/Component/HttpKernel/HttpKernel.php:61
   7. call_user_func_array() .../core/vendor/symfony/http-kernel/Symfony/Component/HttpKernel/HttpKernel.php:117
   8. Drupal\views\Routing\ViewPageController->handle() .../core/vendor/symfony/http-kernel/Symfony/Component/HttpKernel/HttpKernel.php:117
   9. Drupal\views\ViewExecutable->executeDisplay() .../core/modules/views/lib/Drupal/views/Routing/ViewPageController.php:82
  10. Drupal\views\Plugin\views\display\Page->execute() .../core/modules/views/lib/Drupal/views/ViewExecutable.php:1397
  11. drupal_render_page() .../core/modules/views/lib/Drupal/views/Plugin/views/display/Page.php:97
  12. block_page_build() .../core/includes/common.inc:3660
  13. block_get_blocks_by_region() .../core/modules/block/block.module:224
  14. _block_get_renderable_region() .../core/modules/block/block.module:272
  15. entity_view() .../core/modules/block/block.module:303
  16. Drupal\block\BlockRenderController->view() .../core/includes/entity.inc:632
  17. Drupal\block\BlockRenderController->viewMultiple() .../core/modules/block/lib/Drupal/block/BlockRenderController.php:29
  18. Drupal\search\Plugin\Block\SearchBlock->build() .../core/modules/block/lib/Drupal/block/BlockRenderController.php:42
  19. drupal_get_form() .../core/modules/search/lib/Drupal/search/Plugin/Block/SearchBlock.php:57
  20. drupal_build_form() .../core/includes/form.inc:175
  21. drupal_prepare_form() .../core/includes/form.inc:385
  22. drupal_get_token() .../core/includes/form.inc:1085
  23. Drupal::csrfToken() .../core/includes/common.inc:3063
  24. Symfony\Component\DependencyInjection\Container->get() .../core/lib/Drupal.php:401

What's the coarse of action here? Just wait a while until whoever is working on that area fixes it?

Did you re-install Drupal to test it? This sounds like an artefact in the configuration files. Ensure the config files are deleted before you reinstall the system.
I use this script to automate that whole thing:
rm sites/default/files/* -Rf && drush si standard --sites-subdir=default --account-pass=admin -y && drush dis overlay -y && drush en devel simpletest devel_generate -y && drush uli -l http://d8.localhost

Interesting thanks! I will definitely do that later however I'm actually going to leave it as is for now because I don't want the Symfony error to go away.

The reason being I read a little on the error handling in Symfony and they say that the error handling there is limited and that the best error handling can be done by using a custom error handler. I figure this is an opportunity to figure out how to take it over through their configuration files and use ours so I'm looking at this is an "opportunity in disguise".

Of course part of that might mean moving the code over to classes as Symfony is very (if not entirely, I haven't looked that far yet) class oriented. If that's the case I'll probably do the transition in two steps, first take it over and then later do class conversion as my time is way over on what I allocated already but it would be very nice to get at least an initial Symfony integration going with the error handling.

Issue summary:View changes
Status:Needs work» Fixed

I'm not sure what happened here. The latest patches contain completely different changes. The original change was still not completed for D8 (see #109 ... #139)

In order to get this back under control, I've created #2188523: ExceptionController does not respect configured system.logging:error_level (verbose backtrace) for the necessary follow-up fixes in D8 now.

We could consider to backport the original change here as a minor feature addition to D7, but doing so will require a very careful and cautious backport and review, since multiple patches were committed (to fix regressions of the original patch). For now, I'm tentatively marking this fixed.

I'm still using #138 in D7 so getting this backported to D7 would be ideal.

Status:Fixed» Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.

Version:8.x-dev» 7.x-dev
Status:Closed (fixed)» Active
Issue tags:+Needs backport to 7.x

Reopening this for 7.x. Close it if this is the wrong place and I will create a new issue.