Problem/Motivation
For exceptions, Drupal core passes the raw PHP backtrace to logger implementations. It does not do so for PHP errors, warnings, notices etc. so the logger must regenerate the backtrace if it needs one (as various third-party logging libraries such as Sentry do).
Proposed resolution
Include the backtrace in the $context array for errors, just like it is for exceptions.
Remaining tasks
Review change notice: https://www.drupal.org/node/2868845
User interface changes
None
API changes
Logger implementations will receive the backtrace for errors, in addition to exceptions.
Data model changes
None
Original report by mfb
Logger implementations could make use of the raw debug_backtrace() array, rather than having to regenerate it (which I'd assume uses extra memory and wastes CPU cycles).
I'm not clear why core unsets the backtrace - it may be doing so for no good reason - so testing out this patch to see if it passes tests.
Comment | File | Size | Author |
---|---|---|---|
#4 | backtrace-logger.patch | 796 bytes | mfb |
Comments
Comment #2
mfbComment #4
mfbOk now that I look at the code that couldn't possibly work.. $error is passed to various functions that expect an array of strings.
Comment #5
mfbComment #6
dawehnerThis was just recently changed in #2638140: Error logging should log a backtrace consistently
Why do you need the full backtrace when you already have the string available? I'm also wondering why its important to care about performance in this case. Things are already super bad, when an error is triggered, isn't it?
Comment #7
mfbdedicated logging systems like Sentry do a much better job displaying PHP backtraces than dblog or syslog. and they're often setup for centralized log aggregation across an organization. if it's not passed a backtrace, Sentry PHP library generates its own - including Drupal error logging functions which are not helpful.
Performance definitely matters because PHP notices and warnings are logged this way.
Comment #8
dawehnerOkay fair. My only worry is: When we include the backtrace some implementations might try to serialize it directly, which could cause issues, couldn't it?
Comment #9
mfbcontext already contains $context['user'] which is the user object - so I would expect there shouldn't be any problem passing other non-strings in the logger context
Comment #10
mfbComment #11
dawehnerI haven't read #9 yet, that is a good point.
Comment #12
dagmarThere is another call to the php logger here: DefaultExceptionHtmlSubscriber::makeSubrequest
Comment #13
mfb@dagmar in that method, $error array does include the raw backtrace courtesy of Error::decodeException
Comment #14
mfbalthough, I think we should pass the raw Exception object in the logger context, as well.. but I guess that could be a separate patch..
Comment #15
alexpottI think we need a change record here. To inform loggers that _drupal_log_error will be passing the entire backtrace in.
Also I think if the message contains the word @backtrace the following code might be a bit interesting...
I think having @backtrace atm would be a bug
Comment #16
mfbI think a change record is a bit superfluous, since loggers already receive the raw backtrace when logging exceptions, but I created a draft anyways, as I guess change records are also useful for spreading good news, not just scary breaking changes :)
Comment #17
mfbComment #18
mfbComment #19
mfbComment #20
mfbAnyone able to give this patch and change notice a review?
Comment #21
dawehnerI hope we don't let anyone control the actual message from outside :)
Comment #23
mfbthink that was a bogus test failure
Comment #27
catch#16 and #21 are both good answers. Committed/pushed to 8.5.x, thanks!
Comment #28
mfbwe have a draft change record @ https://www.drupal.org/node/2868845
Comment #29
dawehner@mfb
Thank you!
I just published it