Zend\Stdlib\ErrorHandler breaks custom error handlers #7497

lukasclausen · 2015-05-07T10:01:34Z

I know this issue has already been discussed, but it still exists. The Logger error handler only works for the first triggered error:

$logger = new Zend\Log\Logger();
$streamOrUrl = array('stream' => 'php://stdout');
$writer = new Zend\Log\Writer\Stream($streamOrUrl);
$logger->addWriter($writer);
Zend\Log\Logger::registerErrorHandler($logger);

trigger_error('Some notice');
trigger_error('Some other notice');

The second notice will not be logged. That's because of the Zend\Stdlib\ErroHandler::start/stop() call in the log writers. I know this error handler calls are there for good reason, but they break the main custom error handler. In more detail the nested set_error_handler calls inside Zend\Stdlib\ErroHandler breaks it. I found out that the second parameter of set_error_handler causes the error when used inside of an error_handler. I suppose that's a php bug. The following won't work for the second error:

$eh = function($level,$message) {
    $error_handler2 = function ($level,$message) {
        echo "Handle Error inside: $message \n";
    };
    set_error_handler($error_handler2,E_WARNING);
    echo "Handle Error: $message \n";
    strpos();
    restore_error_handler();
    return true;
};

 set_error_handler($eh);

 trigger_error('Some message',E_USER_NOTICE);
 trigger_error('Some other message',E_USER_NOTICE);

When changing set_error_handler($error_handler2,E_WARNING); to set_error_handler($error_handler2); the code works as expected. So removing the second argument of set_error_handler inside Zend\Stdlib\ErroHandler start for me also fixes my logger error handler problems. Is there a reason why Zend\Stdlib\ErroHandler::start is limited to E_WARNINGS by default?

The text was updated successfully, but these errors were encountered:

weierophinney · 2015-05-08T17:42:33Z

Is there a reason why Zend\Stdlib\ErroHandler::start is limited to E_WARNINGS by default?

Yes: because it's the most common use case.

ErrorHandler is used primarily within the framework in order to detect conditions that would prevent operations from success while preventing emission of the error. Typically, these are due to PHP internal function failures (e.g., fopen()), which typically will return a boolean false but also emit a E_WARNING. As such, ErrorHandler::start() defaults to passing E_WARNING in the $error_types flag, so that the developer does not have to explicitly pass it. Only if a different mask is desired does the developer need to pass an argument to start().

The specific problem you're seeing is due to the default behavior of Zend\Log\Logger::registerErrorHandler(). Let's recap:

The Logger error handler only works for the first triggered error:

By default, the error handler we register is using set_error_handler(), but not passing the second $error_types argument; in other words, Zend\Stdlib\ErrorHandler is not even in use here. So, why is only the first error triggering?

Let's look at the signature:

public static function registerErrorHandler(Logger $logger, $continueNativeHandler = false)

That second argument is a flag that determines the return value from the handler. Internally, we do this:

return !$continueNativeHandler;

The way PHP works, it only invokes other registered error handlers if the return value is boolean false:

If the function returns FALSE then the normal error handler continues. (http://php.net/set_error_handler)

So, by default, we return boolean true, which means subsequent error handlers are not triggered. Therefore, to get the behavior you want, you need to pass a boolean true value as the second argument to that method when you register it.

One point: If you are constructing Zend\Log\Logger and registering the error handler using configuration (i.e., the errorhandler configuration option), the error handler is registered with the default value. As such, you cannot get the behavior you desire if you do this via configuration. One option you have is to create a delegator factory for your logger instance, and have it do the following inside:

$logger = $callback();
\Zend\Log\Logger::registerErrorHandler($logger, true);
return $logger;

lukasclausen · 2015-05-08T20:36:31Z

Thank you for your answer. Maybe I wasn’t clear enough. I created my own error handler which makes use of the Logger and this error handler is only called for the first error. My error handler is very similar to the Logger error handler.
When I use the Logger error handler I have the same result.
What I do:

$logger = new Zend\Log\Logger();
$streamOrUrl = array('stream' => 'php://stdout');
$writer = new Zend\Log\Writer\Stream($streamOrUrl);
$logger->addWriter($writer);
Zend\Log\Logger::registerErrorHandler($logger, false);

trigger_error('Some notice');
trigger_error('Some other notice');

The output I expect:

2015-05-08T21:49:05+02:00 NOTICE (5): Some notice {"errno":1024,"file":"C:\\...\\index.php","line":38}
2015-05-08T21:49:05+02:00 NOTICE (5): Some other notice {"errno":1024,"file":"C:\\...\\index.php","line":39}

The output I get:

2015-05-08T21:50:25+02:00 NOTICE (5): Some notice {"errno":1024,"file":"C:\\...\\index.php","line":38}

Notice: Some other notice in C:\...\index.php on line 39
Call Stack:
    0.0000     127472   1. {main}() C:\...\index.php:0
    0.0140     568128   2. trigger_error() C:\...\index.php:39

When I change Zend\Log\Logger::registerErrorHandler($logger, false); to Zend\Log\Logger::registerErrorHandler($logger, true); I get:

2015-05-08T21:54:51+02:00 NOTICE (5): Some notice {"errno":1024,"file":"C:\\...\\index.php","line":38}

Notice: Some notice in C:\...\index.php on line 38
Call Stack:
    0.0005     127472   1. {main}() C:\...\index.php:0
    0.0130     567160   2. trigger_error() C:\...\index.php:38

Notice: Some other notice in C:\...\index.php on line 39
Call Stack:
    0.0005     127472   1. {main}() C:\...\index.php:0
    0.0235     568272   2. trigger_error() C:\...\index.php:39

Zf 2.4, php 5.5 / 5.6 tested on win7 and ubuntu

Whatever I do the Logger only logs the first error. In fact the Logger error handler is not even called for the second error but the native error handler is called.
So what normally happens if the Logger error handler is called as far as I know:

Logger::log is called
Logger goes through all writers and calls the write method
Inside AbstractWriter::write normally Stdlib\ErrorHandler::start is called
Stdlib\ErrorHandler::start registers a new error handler
Log is written
Stdlib\ErrorHandler::stop restores the former error handler which should be the closure defined in Logger::registerErrorHandler but it isn’t!

I suppose that’s because of some strange behaviour of set_error_handler and restore_error_handler, when the optional second parameter is used. When I modify the Zend\Stdlib\ErrorHandler:

-    public static function start($errorLevel = \E_WARNING)
+    public static function start()
     {
         if (!static::$stack) {
-            set_error_handler(array(get_called_class(), 'addError'),$errorLevel);
+            set_error_handler(array(get_called_class(), 'addError'));
         }

I get my expected result:

2015-05-08T21:49:05+02:00 NOTICE (5): Some notice {"errno":1024,"file":"C:\\...\\index.php","line":38}
2015-05-08T21:49:05+02:00 NOTICE (5): Some other notice {"errno":1024,"file":"C:\\...\\index.php","line":39}

By removing the $errorLevel the former error handler is later restored correctly. I really don’t know why it doesn’t work with $errorLevel. It should but it doesn’t.

weierophinney · 2015-05-11T13:29:34Z

That sounds like a PHP bug, then. It's always best to specify the error level when calling set_error_handler() to ensure it only triggers when errors of a specific priority are issued. If restore_error_handler() is not popping it off correctly, that's a bug in the PHP engine.

nicolas-grekas · 2016-01-11T17:26:11Z

@lukasclausen I was pointed out to this issue and I tried to reproduce your issue with as less code as possible. See e.g. https://3v4l.org/JdWWp
But I fail to reproduce the bug there. Can you manage to write such a script? Can you reproduce this with xdebug disabled/enabled?

lukasclausen · 2016-01-12T10:31:41Z

See for an example https://3v4l.org/6hW5O
Seems to work with hhvm.

The bug occurs when you have a nested error handler which is registered inside the current error handler and unregisterd before the original error handler finishes. It only occurs if the nested error handler is set for specific error types. The error handler the falls back to the php default error handler.

If the nested error handler is not limited (line 12) everythings fine:
https://3v4l.org/safbF

As a workaround I reset the main error handler at the end of each call:
https://3v4l.org/YijHT

I can reproduce it with both xdebug enabled and disabled.

nicolas-grekas · 2016-01-12T10:38:57Z

Understood, thanks for the explanations.
This is https://bugs.php.net/63206 then

falkenhawk · 2017-05-05T15:39:37Z

Okay, but the bug has not been fixed since then.

…/bugs.php.net/bug.php?id=63206

Ocramius · 2017-05-05T17:54:14Z

Needs to just be reported again then, ideally as failing test pr.

…

On 5 May 2017 5:39 p.m., "Maciej Holyszko" ***@***.***> wrote: Okay, but the bug has not been fixed since then. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#7497 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAJakCeqCxdC5vp8XJQEt-XGX9oc-MQ0ks5r20K9gaJpZM4ESRRc> .

weierophinney closed this as completed May 8, 2015

weierophinney added Log question labels May 8, 2015

csarrazi mentioned this issue Nov 11, 2015

Documentation for the new Ldap component symfony/symfony-docs#5756

Closed

heiglandreas mentioned this issue Nov 12, 2015

Removes default dependency to Zend\StdLib zendframework/zend-ldap#21

Merged

heiglandreas mentioned this issue Jan 14, 2016

Remove dependencies on external Libraries zendframework/zend-ldap#22

Closed

falkenhawk mentioned this issue May 5, 2017

Zend\Stdlib\ErrorHandler breaks custom error handlers zendframework/zend-stdlib#78

Closed

falkenhawk added a commit to ovos/zend-stdlib that referenced this issue May 5, 2017

a workaround for zendframework/zendframework#7497 and php bug https:/…

c76f2fa

…/bugs.php.net/bug.php?id=63206

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Zend\Stdlib\ErrorHandler breaks custom error handlers #7497

Zend\Stdlib\ErrorHandler breaks custom error handlers #7497

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Zend\Stdlib\ErrorHandler breaks custom error handlers #7497

Zend\Stdlib\ErrorHandler breaks custom error handlers #7497

Comments

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!