Skip to content
This repository has been archived by the owner on Jan 8, 2020. It is now read-only.

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

Merged
merged 4 commits into from
Mar 3, 2014

Conversation

weierophinney
Copy link
Member

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.

@weierophinney
Copy link
Member

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.

@jkavalik
Copy link
Author

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

@weierophinney
Copy link
Member

Can you write this as a unit test for us?

@jkavalik
Copy link
Author

jkavalik commented Nov 2, 2013

Not sure but I can try :)

@jkavalik
Copy link
Author

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

@weierophinney
Copy link
Member

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 added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013
- 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).
weierophinney added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013
@weierophinney
Copy link
Member

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

weierophinney added a commit to weierophinney/zendframework that referenced this pull request Dec 5, 2013
- 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.
@weierophinney
Copy link
Member

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
Copy link
Author

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

@weierophinney
Copy link
Member

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

@weierophinney
Copy link
Member

@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
Copy link
Author

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)

@weierophinney
Copy link
Member

@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
Copy link
Author

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
Copy link

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?

@marc-mabe
Copy link
Member

@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.

@Maks3w
Copy link
Member

Maks3w commented Feb 23, 2014

@weierophinney Please rebase the PR

jkavalik and others added 4 commits March 3, 2014 11:33
- 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).
- 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.
@weierophinney
Copy link
Member

@Maks3w rebased.

Maks3w added a commit that referenced this pull request Mar 3, 2014
Maks3w added a commit that referenced this pull request Mar 3, 2014
Maks3w added a commit that referenced this pull request Mar 3, 2014
@Maks3w Maks3w merged commit b8e5927 into zendframework:master Mar 3, 2014
weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015
- 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).
weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015
weierophinney added a commit to zendframework/zend-log that referenced this pull request May 15, 2015
- 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.
gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015
gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015
gianarb pushed a commit to zendframework/zend-log that referenced this pull request May 15, 2015
# for free to subscribe to this conversation on GitHub. Already have an account? #.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants