registerErrorHandler won't work unless you disable convertWriteErrorsToExceptions on the writer

[sg2002]

Bug Report

Q	A
Version(s)	2.12

Summary

Laminas\Log\Logger::registerErrorHandler wraps around set_error_handler. By default AbstractWriter starts Laminas\Stdlib\ErrorHandler before writing and stops it after. ErrorHandler's stop function in turn calls restore_error_handler. In practice this means that a very basic setup with a simple stream writer would not write any errors after the first one, since php error handler gets restored on the first write.

User can avoid this if he sets convertWriteErrorsToExceptions to false on the writer:

$writer->setConvertWriteErrorsToExceptions(false)

But this requires the user to first face this bug.

This bug is present since at least Zend 2.

Current behavior

Only one error gets written by the writer. After that Laminas\Log php error handler gets removed.

How to reproduce

Very basic one stream writer example would already suffer from this bug:

$logger = new Laminas\Log\Logger;
$writer = new Laminas\Log\Writer\Stream('/test.log');

$logger->addWriter($writer);
Laminas\Log\Logger::registerErrorHandler($logger);

$writer->setConvertWriteErrorsToExceptions(false);

trigger_error('test1');
trigger_error('test2');

Expected behavior

Ideally the ErrorHandler class should not call restore_error_handler and somehow remove only himself from the error handlers list. Unfortunately PHP does not have an API to do this. The easiest fix is probably setting convertWriteErrorsToExceptions to false by default, but this brings back the reason why it converts errors to exceptions: now user has no way of knowing that his logging has failed.

[weierophinney]

I think your diagnosis of the problem may be incorrect. From the php.net manual page for restore_error_handler():

Used after changing the error handler function using set_error_handler(), to revert to the previous error handler (which could be the built-in or a user defined function).

Calling restore_error_handler() pops off the last registered error handler (which PHP manages as a stack). Since this is only done when we have pushed on onto the error handler stack via set_error_handler(), this is likely not the root cause.

I'll see if I can reproduce with the steps you have provided, and diagnose from there.

[weierophinney]

I cannot reproduce.

I wrote the following unit test within the test/LoggerTest.php file:

    public function testTriggeringMoreThanOneErrorWhenLoggerIsRegisteredAsErrorHandlerShouldNotRestorePastOriginalHandler(): void
    {
        $stream = fopen('php://memory', 'w+');
        $writer = new StreamWriter($stream);
        $logger = new Logger();
        $logger->addWriter($writer);
        Logger::registerErrorHandler($logger);

        trigger_error('test1');
        trigger_error('test2');

        rewind($stream);
        $contents = stream_get_contents($stream);
        $this->assertStringContainsString('test1', $contents);
        $this->assertStringContainsString('test2', $contents);
    }

This test runs successfully. If I introspect the value of $contents, it has exactly what I would expect (two log lines, one containing "test1" as the message, another containing "test2"). If I trigger even more errors, they are all written to the stream correctly.

[sg2002]

Hi. Thanks for a quick reply.

Your test fails when I try it. I'm currently testing on a Windows machine running a simple xampp setup, that's pretty much left default, with php 7.2.32. If you want I can try reproducing on something else, e.g. some vagrant box. Originally I discovered this on a very old Ubuntu server running 5.3 and Zend 2, I can reliably reproduce it there too.

[sg2002]

Just tried another machine, this time it was Debian 9 with php 7.0.33, reproducible there.

[froschdesign]

I cannot reproduce. … This test runs successfully.

Same here, everything is fine.

[sg2002]

All right, I think I know why you can't reproduce it, restore_error_handler stacking was actually implemented quite recently - 2020-02-24, so this bug only affects php versions bellow 7.3. So I guess leaving this as is ok, but I'd suggest mentioning this bug in the documentation, since we all know how lazy the corporate world is at upgrading.

[froschdesign]

@sg2002

…but I'd suggest mentioning this bug in the documentation…

The current version of laminas-log supports PHP version 7.3 or higher and everything else is no longer supported. The problem may be annoying for you, but the component and the documentation is addressed to current versions.

Thanks for your understanding!