roadrunner-server / roadrunner

🤯 High-performance PHP application server, process manager written in Go and powered with plugins
https://docs.roadrunner.dev
MIT License
7.86k stars 409 forks source link

[RR2, BUG] On one of the windows machine, stderr messages showing inconsistent #467

Closed rustatian closed 3 years ago

rustatian commented 3 years ago

Take a look, that the messages separated randomly. OS Build: 10.0.18363.1256 test

rustatian commented 3 years ago

After discussion with @SerafimArts , we think, that the buffer instantiated in the PHP script (temporal-php-sdk) which flushes data to the stderr, should be set to the 10240 bytes (chunk size).

SerafimArts commented 3 years ago

Just in case, I will give an example of the current code, which restreams the output buffer to the stderr (to avoid getting extra data into the stdout, which breaks the goridge protocol over pipes):

    private function bootStdoutHandlers(): self
    {
        // symfony/var-dumper interceptor
        if (\class_exists(CliDumper::class)) {
            CliDumper::$defaultOutput = 'php://stderr';
        }

        // Intercept all output messages
        \ob_start(fn(string $chunk) => $this->write($chunk));

        // Intercept all exceptions
        \set_exception_handler(fn(\Throwable $e) => $this->writeException($e));

        // Intercept all errors
        \set_error_handler(function (int $code, string $message, string $file, int $line) {
            $this->writeException(
                new \ErrorException($message, $code, $code, $file, $line)
            );
        });

        return $this;
    }

    private function write(string $message): void
    {
        \file_put_contents('php://stderr', $message);
    }

    private function writeException(\Throwable $e): void
    {
        $this->write((string)$e);
    }

Possible cause of the problem is the output buffer (OB) redirection function ob_start without specifying the size of chunks (second argument of the function): https://www.php.net/manual/en/function.ob-start.php

wolfy-j commented 3 years ago

Sample code to reproduce.

<?php

use Spiral\RoadRunner;
use Nyholm\Psr7\Factory;

ini_set('display_errors', 'stderr');
include "vendor/autoload.php";

$worker = new RoadRunner\Http\PSR7Worker(
    RoadRunner\Worker::create(),
    new Factory\Psr17Factory(),
    new Factory\Psr17Factory(),
    new Factory\Psr17Factory()
);

while ($req = $worker->waitRequest()) {
    try {
        $rsp = new \Nyholm\Psr7\Response();
        $rsp->getBody()->write("hello world");
        error_log("hello");
        $worker->respond($rsp);
    } catch (\Throwable $e) {
        $worker->getWorker()->error((string)$e);
    }
}
rustatian commented 3 years ago

@wolfy-j Please, post here the link to the commit fixing that issue

wolfy-j commented 3 years ago

The actual bug is located in the error_log function. It can not be used for reliable logging purposes due to internal implementation. It's recommended to write directly to stderr, for example:

file_put_contents('php://stderr', 'message');