Extend drupal_error_handler to manage exceptions
Damien Tournoud - September 6, 2008 - 22:37
| Project: | Drupal |
| Version: | 7.x-dev |
| Component: | base system |
| Category: | task |
| Priority: | normal |
| Assigned: | Unassigned |
| Status: | closed |
Description
drupal_error_handler was in need of a lifting. This patch does three things:
- Add supports for uncaught exceptions and reimplement a mechanism we had in the pre-DB:TNG-time: get the true caller of the database function that failed. As uncaught exceptions are fatal in PHP (ie: WSOD), we also implement a small error message.
- Add supports for SimpleTest: we can now pull errors and assertions from the tested site. That means that errors and exceptions that occurs during the processing of a page we get by drupalGet or drupalPost are now logged in the test log, in the 'Exceptions' class.
| Attachment | Size |
|---|---|
| error-handler-needs-love.patch | 8.65 KB |
#1
Test results with this patch: we have hidden failures (ie. errors or exceptions that occurs during the test but are not caught by assertions)
Remove feed item functionality 28 passes, 0 fails, 1 exceptionCategorize feed item functionality 29 passes, 0 fails, 1 exception
Update feed item functionality 36 passes, 0 fails, 1 exception
Import feeds from OPML functionality 49 passes, 0 fails, 1 exception
Comment functionality 471 passes, 0 fails, 1 exception
Session tests 82 passes, 0 fails, 7 exceptions
#2
A while(true) loop made chx cringe. Here is a refactoring (thanks, chx).
#3
Doing a quick visual patch review - this looks odd to me:
if (func_num_args() == 5) {Also looks like debug code left in index.php:
+db_delete('test')->execute();#4
@pwolanin: the same function is used as both and error_handler() and an exception_handler(). The signature of those function are different but most of the processing is common.
#5
The same patch without the
if (func_num_args() == 5)and the debugging code.#6
I'm marking this as postponed, until #305077: Rework simpletest backend is in.
#7
#8
This is a patch based on #305077: Rework simpletest backend, that draft how this could look like. DrupalTestBod will be angry, but I don't care :p
#9
Patch failed to apply. More information can be found at http://testing.drupal.org/node/14169. If you need help with creating patches please look at http://drupal.org/patch/create
#10
Patch failed to apply. More information can be found at http://testing.drupal.org/node/14169. If you need help with creating patches please look at http://drupal.org/patch/create
#11
#12
Here is a first patch for the exception handler. I separated the simpletest part in another patch to ease review.
This patch refactors drupal_error_handler, implements an exception handler and reimplement the backtracing feature we had for database functions.
Also fixes a small bug in _drupal_get_last_caller(): if PHP generates an error in an internal function (like strpos, for example), no line information is available for the last call of the stack.
#13
Installed this on a clean HEAD. Tested by going to admin/content/taxonomy/edit/term/ which handily produces many different notices and warnings at the moment, then messed with a couple of db_query() to add syntax errors. Seems pretty good to me, and I like the way the eventual simpletest handling will go to. I also did a visual review of the patch, and although there's one existing long array of error codes which could be split across lines, that was the only thing I could find to gripe about. And no test breakage.
Could do with another look over it, but nice work.
#14
While catch is right about that array needig better indents it's more important to use PHP E_ constants. Speaking of constants, there are more and more with every PHP release, so $types[$errno] can be nothing. This needs handling.
"Errors that occurs" that's "occur".
#15
Reroll, addressing chx' concerns.
#16
Subscribe.
#17
Rerolled following #308399: The simpletest error handler is broken for PHP functions.
#18
patch at #17 applies cleanly, and all tests pass. looks RTBC to me.
Catch notices, warnings, errors and fatal errors from the tested side is now waiting on this patch.
#19
- $types = array(1 => 'error', 2 => 'warning', 4 => 'parse error', 8 => 'notice', 16 => 'core error', 32 => 'core warning', 64 => 'compile error', 128 => 'compile warning', 256 => 'user error', 512 => 'user warning', 1024 => 'user notice', 2048 => 'strict warning', 4096 => 'recoverable fatal error');+ $types = array(
+ E_ERROR => 'Error',
...
1. Yay for replacing obscure numbers with actual error constants. But let's add a comment that explains where these come from.
2. Should we add in an update function for this? It seems that changing the case will affect the ability to filter log messages, no?
3. These are not wrapped in t(). Is that by design?
+function drupal_exception_handler($exception) {@param $exception needs documentation. What type of exception is that? Is that coming from PHP or us?
+ while (($caller = $backtrace[1]) &&+ ((isset($caller['class']) && (strpos($caller['class'], 'Query') !== FALSE || strpos($caller['class'], 'Database') !== FALSE)) ||
+ in_array($caller['function'], $db_functions))) {
Dear, sweet, merciful crap! ;) Is there any way to break that up and make it more legible? I'd be more in favour of 3-level nesting than a 15-condition while statement.
+ _drupal_log_error('uncaught exception', $exception->getMessage(), $backtrace);1. Capital U on uncaught, for consistency with the rest.
2. Comment above here to explain how we get here. Is this normal, or is it weird?
+function _drupal_log_error($type, $message, $backtrace) {PHPDoc please.
#20
1. Done
2. Not needed.
<?phpwatchdog('php', '%error: %message in %function (line %line of %file).', array('%error' => $type, '%message' => $message, '%function' => $caller['function'], '%file' => $caller['file'], '%line' => $caller['line']), WATCHDOG_ERROR);
?>
The "Type" is always "php". We always considered PHP errors to be of severity WATCHDOG_ERROR. The patch doesn't change this.
3. This is by design. The error message itself can't be translated (it comes from PHP), and I don't like the idea of half-translated messages.
Moreover implementing this cleanly (ie. messages output to the users have to be translated, but not those going to the watchdog that should be dynamic, etc.) would probably add lots of ugly lines of code to the patch (ie. one watchdog call per $type, *sigh*).
I documented both _drupal_error_handler and _drupal_exception_handler, and marked those as private.
While grepping through the core, I also found a DB:TNG left-over in database.inc.
This is not for everyone's eyes. It took time to cleanly engineer this one. It would make no real sense to break the condition out of the where (the loop is guaranteed to terminate only because of the array_shift inside it). Why and what is done is clearly documented above the loop, so I'm no willing to touch this again.
1. Well caught (:p).
2. I augmented the documentation of _drupal_exception_handler to clearly indicate that it is always fatal to have uncaught exceptions.
Done.
#21
subscribing. ran all the tests and this doesn't affect them (there's two problem with node tests regardless of this patch). visually it looks good to me.
#22
The term "error_reporting" is currently used to for specifying whether errors should be displayed to the user (0 = Hide errors, 1 = Show errors - see system_error_reporting_settings()). The patch uses the same term in name of the variable that contains the PHP error level (i.e. one of the E_xxx constants). I think one of these should be renamed in order to avoid confusion between the two unrelated concepts. I suggest renaming the existing setting to "display_errors" to be in sync with the corresponding php.ini setting.
+ _drupal_log_error(isset($types[$errno]) ? $types[$error_level] : 'Unknown error', $message, $backtrace);$errno is not defined at this point. Looks like a left-over from the renaming of $errno to $error_level.
if ($errno & (E_ALL)) {+ $types = array(
...
+ E_STRICT => 'Strict warning',
+ );
E_STRICT is not part of E_ALL (only in PHP ≥ 6), so AFAICT the string is never used, so I think it should be omitted.
How about changing
if ($errno & (E_ALL)) {toif ($errno & error_reporting()) {to allow users use more verbose error reporting than E_ALL (e.g. E_ALL ¦ E_STRICT)? If we do that, we should probably reseterror_reportingto E_ALL in .htaccess and/or in bootstrap.inc - but before settings.php is included.In preparation for PHP 5.3, we might want to add E_DEPRECATED and E_USER_DEPRECATED as well (I have heard about early adopters running their own builds of PHP 5.3 or even PHP 6). The constants are not defined in PHP 5.2.x, so if we choose to support them, we should either use their numerical values or define them using define().
+ watchdog('php', '%error: %message in %function (line %line of %file).', array('%error' => $type, '%message' => $message, '%function' => $caller['function'], '%file' => $caller['file'], '%line' => $caller['line']), WATCHDOG_ERROR);For greater readability I suggest replacing
%errorwith%type. There is no need to introduce another word for the same concept.The error handler appears to assume that the error message, $message, is plain text. But if the
html_errorsPHP ini setting is enabled,$messagecontains HTML tags that are check_plain'ed before being output, making the messages hard to read. I don't mind dropping support forhtml_errors, i.e. making Drupal callini_set('html_errors', '0')somewhere, but I don't know whether anybody would miss this feature. Comment #7 on issue 313902 includes a patch that disabledhtml_errors.The PHP manual says:
It is not specific about when it is necessary, but I assume they refer to E_USER_ERROR and E_RECOVERABLE_ERROR errors (there are other fatal error types, but these cannot be caught using a custom error handler). I suggest handling these like uncaught exceptions.
If an exception is somehow thrown during bootstrapping (e.g. try to insert
throw new Exception('foo');in common.inc right after the exception handler has been set), the exception handler dies with this error:Fatal error: Call to undefined function user_access() in /home/c960657/www/drupal/includes/theme.inc on line 1752I don't know whether exceptions are likely to be raised during phase of the bootstrap, though.
+ if (variable_get('error_level', 1) == 1 || strstr($_SERVER['SCRIPT_NAME'], 'update.php')) {Wouldn't it be better to use the MAINTENANCE_MODE constant?
I know many of the issues mentioned are also present in the existing code. But now that we are touching the code, I think it is a good time to discuss them.
#23
Here is a new version, addressing most of c960657's concerns:
- corrected typo with $errno
- complied with error_reporting level, a sane default is now set in settings.php, but could be overridden by the user
- added an ini_set('html_errors', 0) to settings.php
- output an error page in case of an RECOVERABLE_ERROR (poor choice of name for fatal errors that can still launch an error handler), for consistency with exceptions
- fix the output of the error page in probably pretty much every case (including during the bootstrap), do not show blocks on the error page for consistency with 404/403 pages.
#24
The default.settings.php chunk didn't make it inside the patch... Anyway it makes much more sense to set sane default in drupal_initialize_variables(), before settings.php is called.
#25
@c960657: your other suggestions (especially adding E_DEPRECATED) are to big for this, and could be discussed in another issue.
#26
What is the best way to test that this is working as designed?
#27
Yeah, I'd like to know that as well.
+ // Set sane error reporting level.+ if (error_reporting() < E_ALL) {
+ error_reporting(E_ALL);
+ }
+ // Disable HTML errors.
+ ini_set('html_errors', 0);
If you're going to force E_ALL at all times, why bother with the if()? And if you're bothering with the if() do you need one around ini_set() too?
I'm kinda -1 this code generally, but I'm fine putting it in until we can do better at #291026: change E_NOTICE to warning and allow selection of error level.
I understand renaming drupal_error_handler and _drupal_exception_handler to make them private, since that's very unlikely to be called outside of common.inc. However is _drupal_log_error() also an internal-only function, or is that something other modules might trigger?
Finally, I would really like to see some tests for at least that tweaky PDOException stuff. That seems like the perfect example of something someone well meaning is going to easily break somewhere along the line trying to "fix" it. Also, then Moshe wouldn't have to ask questions like "What is the best way to test that this is working as designed?" ;)
Nitpick time!
+ * @param $error_level+ * The level of the error raised.
a) there should be a newline between the description and the param list.
b) The description here and others in this docblock need to be indented one space.
+ * Custom PHP exception handler: log uncaught exceptions and output a meaningful error message to the user.Please rephrase so it fits in < 80 characters.
Overall though, this patch is a huge improvement, and I can't wait to press the big green button on it. :D
#28
Personally, I don't like the fact that we have to threat PDOExceptions special. Where will this end? We can't special-case for every possible exception.
+ // Disable HTML errors.+ ini_set('html_errors', 0);
I didn't remember what html_errors was for so I had to look it up. Would be great if you could improve that code-comment a bit.
#29
I now changed that logic to a clearer (and saner):
<?php+ error_reporting(E_ALL | error_reporting());
?>
There is now an unit test.
(That's such a pain to write, I hate you guys.)
Sincerely, me neither. But (1) we did that before for database errors, (2) we have no other choice (because PHP is limited).
I would rather keep that private. Do you have an use case for calling that directly?
#30
@damien : in function testErrorHandler(),
+ $this->assertErrorLogged('Warning', 'common.test', 'DrupalErrorHandlerUnitTest->testErrorHandler()', 'Division by zero');+ $this->assertErrorLogged('Warning', 'common.test', 'DrupalErrorHandlerUnitTest->testErrorHandler()', 'Division by zero');
#31
Removed the redundant assertion, thanks lilou.
#32
For the record, I hate the special case handling for database errors. I'm very open to better handling of that, although probably in a separate patch.
#33
Tests ran without error. On a brief code review it looks good. I agree with Dries and Crell on the PDOexception special case. It's not pretty.
#34
This patch was very helpful to me when debugging a PDO Exception. Without it, I had no meaningfull error message at all. I can't really comment on the particulars, but I can say that we need something like this. It appears to me that the PDO handling just restores what we have in D6 and thus should not hold up the patch.
#35
A new version, with a cleaner test (we no longer need to instrument _drupal_log_error, and we can remove a lot of lines of code).
#36
I can't get all tests to run with or without this patch, which is a shame. I ran the exception tests though, and manually generated some errors (notices in eval()ed code, fatal errors in node.module etc.) and it caught them all nicely. Also reviewed comments and stuff with Damien in irc.
While the crazy while loop and PDO specific stuff aren't nice, nor's not being able to show exceptions etc. in simpletests.
#37
all tests pass for me with patch #35 on a fresh HEAD - looks RTBC.
#38
@damien: I'm hardly in a position to offer an authoritative opinion, but looks a great patch to me. :D
@all: Also for the record (and a separate patch) - is it time to add support for error/exception handling in hook_boot/exit after a cached response? In the case of hook_exit() you may never see the error, unless you keep an eye on the Apache error log. moshe's comment #34 emphasises the potential value of this.
#39
After another review of this patch, I committed it to CVS HEAD. I do get one exception and one error when running the tests, but it does not seem related to this patch itself. I'll investigate that separately. Thanks Damien.
#40
Automatically closed -- issue fixed for two weeks with no activity.