fix for #4614 breaks error handler using Zend\Log #5383

Merged
merged 4 commits into from Mar 3, 2014

Conversation

Projects
None yet
5 participants

In #4616 problem was reintroduced with calling Zend\Stdlib\ErroHandler::start/stop() one level deeper than it was removed from in #2330 - when we tried to use default Zend\Log\Logger::registerErrorHandler() it only logs first php error.
We are using LogWriterStream and after some testing and searching even with $stream_writer->setConvertWriteErrorsToExceptions(false); but tracking showed, that another calls to Zend\Stdlib\ErrorHandler occurs in formatter which was added later.

Owner

weierophinney commented Oct 30, 2013

I fail to see how #4616 is related to #2330; they do not touch the same sets of code at all. Please provide:

  • a reproducible case (as succinct as possible)
  • expected results (my guess: log gets written)
  • actual results (my guess: error?)

and test with the code as it was when 2330 was committed to verify it works. If it does, use git bisect from that commit to head to determine the actual location where the bug was reintroduced. We can discuss solutions at that point.

We are working with ZendSkeletonApplication and 2330 is too old for that to work without big changes so I prepared fork in https://github.com/jkavalik/ZendSkeletonApplication with included logger and registered default logger error handler, and three notices generated in default index

expected results

  • no php errors on website and three "notice: undefined variable ..." in /tmp/zend_{current date}.log

actual results

  • when using branch "after", there is only one notice in log (first one), but two more on website shown from php default error handler
  • when using branch "before", results are as expected
Owner

weierophinney commented Nov 1, 2013

Can you write this as a unit test for us?

jkavalik commented Nov 2, 2013

Not sure but I can try :)

jkavalik commented Nov 2, 2013

Ok, I think I did - jkavalik/zf2@f121d22
Tested it with master/HEAD and with those two versions from ZendSkeletonApplication test, results are similar - only first notice is logged, second goes through default php handler and breaks test when I use code from 4616 or HEAD

Owner

weierophinney commented Dec 5, 2013

The test does indeed fail. Removing the start/stop calls in the fix from #4616 does indeed make it work again - and no new failures occur. I'm not entirely certain what the error handling was supposed to accomplish in that routine -- there are no functions called in there likely to raise an error, other than perhaps the calls for formatting DateTime objects -- so I think we're safe to remove it.

@weierophinney weierophinney added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013

@weierophinney weierophinney [#5383] Remove error handling calls
- The error handling calls pop the scope when already inside an error handler --
  such as when you use the Logger as an error handler. The only call inside the
  block that could be a potential problem is the one to format a DateTime object
  -- and then, only if the format is invalid (in which case you have bigger
  problems).
141c238

@weierophinney weierophinney added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013

@weierophinney weierophinney [#5383] Remove unused use statement a3ae850
Owner

weierophinney commented Dec 5, 2013

Turns out the issue is with recursion, which the error handling was taking care of. Checking into alternate ways to deal with this.

@weierophinney weierophinney added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013

@weierophinney weierophinney [#5383] Use error suppression *gulp*
- The only viable solution that (a) prevents recursion during serialization, and
  (b) allows the Logger to work as an error handler after a message has been
  formatted, is to use the error suppression operator. See the comment in the
  normalize method for details.
12e0f65
Owner

weierophinney commented Dec 5, 2013

Had to use error suppression; it is the only way for an error handler to suppress errors properly within the body of its work. Using another error handler does not work in this scope, as it essentially removes the current error handler when you pop it off the stack.

jkavalik commented Dec 5, 2013

I tried to find some recursion detection, but only which seem working is taking print_r of array and searching for "RECURSION", which would be probably performance killer and imho as ugly as error supression

Owner

weierophinney commented Dec 5, 2013

Test failure is on 5.5, and appears to be an unrelated segfault (log tests pass).

Owner

weierophinney commented Dec 5, 2013

@jkavalik any detection of recursion in this context is going to be bad on performance. The original solution was fine (ignore the error); the problem is it didn't take into account that it could be nested inside another error handler. Ugly situation.

jkavalik commented Dec 5, 2013

@weierophinney is there any possibility for that recursive array to come from error handler logging? if not, we could turn those start/stop off inside error handling (but I'm not sure if we can detect that it IS error handling)

Owner

weierophinney commented Dec 5, 2013

@jkavalik too difficult to manage -- it requires the formatter know the context in which it is called, which violates a whole slough of design principals.

jkavalik commented Dec 5, 2013

@weierophinney I was afraid of that. Would be nice to temporarily change formatter on the fly.. but again depending on some state..

Doev commented Jan 7, 2014

Hi,

I have the same Problem on the current dev-master. After the first logged error, the logger is disabled. I need the error logger for storing the errormessages to integrate them in my layout.

I found a workaround but I am not sure if there are side effects that cause errors in the future. Instead of using Zend\Log\Writer\AbstractWriter as a parentclass for the ErrorWriter, I create a own class that implements Zend\Log\Writer\WriterInterface with no other functionality, than storing the messages.

see this: http://pastebin.com/0XxPdT1M

Any comments on that?

Member

marc-mabe commented Jan 8, 2014

@weierophinney @jkavalik I really don't understand why this failure occurs but the JSON formatting is only to generate a good readable error message as a one-liner. It's not required to be valid JSON - it's required to be human readable, only. So in my opinion it makes sense to format with print_r but it needs post progressing to make it more readable and a one-liner.

PS: another issue with JSON formatting is the defined utf-8 encoding of the JSON spec were the logger doesn't define such encoding.

Member

Maks3w commented Feb 23, 2014

@weierophinney Please rebase the PR

jkavalik and others added some commits Nov 2, 2013

@weierophinney jkavalik test for using logger default errorhandler with streamwriter 6c5a085
@weierophinney weierophinney [#5383] Remove error handling calls
- The error handling calls pop the scope when already inside an error handler --
  such as when you use the Logger as an error handler. The only call inside the
  block that could be a potential problem is the one to format a DateTime object
  -- and then, only if the format is invalid (in which case you have bigger
  problems).
c94b611
@weierophinney weierophinney [#5383] Remove unused use statement 28e0d8f
@weierophinney weierophinney [#5383] Use error suppression *gulp*
- The only viable solution that (a) prevents recursion during serialization, and
  (b) allows the Logger to work as an error handler after a message has been
  formatted, is to use the error suppression operator. See the comment in the
  normalize method for details.
b8e5927
Owner

weierophinney commented Mar 3, 2014

@Maks3w rebased.

Maks3w was assigned by jkavalik Mar 3, 2014

@Maks3w Maks3w added a commit that referenced this pull request Mar 3, 2014

@Maks3w Maks3w Merge pull request #5383 60d4fae

@Maks3w Maks3w added a commit that referenced this pull request Mar 3, 2014

@Maks3w Maks3w Merge pull request #5383 in develop 8d1db7e

@Maks3w Maks3w added a commit that referenced this pull request Mar 3, 2014

@Maks3w Maks3w Merge pull request #5383 in master a55623d

@Maks3w Maks3w merged commit b8e5927 into zendframework:master Mar 3, 2014

1 check passed

default The Travis CI build passed
Details

@weierophinney weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@weierophinney weierophinney [zendframework/zendframework#5383] Remove error handling calls
- The error handling calls pop the scope when already inside an error handler --
  such as when you use the Logger as an error handler. The only call inside the
  block that could be a potential problem is the one to format a DateTime object
  -- and then, only if the format is invalid (in which case you have bigger
  problems).
c70ec68

@weierophinney weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@weierophinney weierophinney [zendframework/zendframework#5383] Remove unused use statement 3fbea69

@weierophinney weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@weierophinney weierophinney [zendframework/zendframework#5383] Use error suppression *gulp*
- The only viable solution that (a) prevents recursion during serialization, and
  (b) allows the Logger to work as an error handler after a message has been
  formatted, is to use the error suppression operator. See the comment in the
  normalize method for details.
2c365ec

@gianarb gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@Maks3w Maks3w Merge pull request zendframework/zendframework#5383 482c187

@gianarb gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@Maks3w Maks3w Merge pull request zendframework/zendframework#5383 in develop 5b0fa0d

@gianarb gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015

@Maks3w Maks3w Merge pull request zendframework/zendframework#5383 in master 49bc0b3
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment