Reverb\Http\Server dispatches requests without request body (intermittently)

[stephenfrank]

Reverb Version

1.0.0-beta9

Laravel Version

11.6.0

PHP Version

8.2.9

Description

I have an issue where requests are intermittently dispatched without the request body.

I've tracked it down to the React PHP connection $connection->on('data' receiving the data in two chunks. eg. the headers in the first chunk and the body in the second chunk.

        $connection->on('data', function ($data) use ($connection, &$_data) {
            echo ">>>".$data."<<<\n";
        });

Gives this output (edited for brevity)

>>>POST /apps/952923/events?auth_key=votduorcbb09oywvlctt&auth_timestamp=1715074672&auth_version=1.0&body_md5=65358e7a3a5e5ba3aad9091d974ea924&auth_signature=20adcb3ba9d85f0a60b979f48667536f6ae8c0761f74c2ddbb19be5646ebd431 HTTP/1.1
Host: mysite.ddev.site:9080
User-Agent: GuzzleHttp/7
Content-Length: 363
[...]

{"name":"chat.message"}<<<

>>>POST /apps/952923/events?auth_key=votduorcbb09oywvlctt&auth_timestamp=1715074673&auth_version=1.0&body_md5=65358e7a3a5e5ba3aad9091d974ea924&auth_signature=d357bab3cb9310867b430cd2c72dff4675a5763a9ad4c121771faa90a85b6064 HTTP/1.1
Host: mysite.ddev.site:9080
User-Agent: GuzzleHttp/7
Content-Length: 363
[...]

<<<
>>>{"name":"chat.message"}<<<

I've hacked together a solution that solves this issue for me... essentially parsing the Content-Length header and waiting for the complete body before proceeding (it's just a proof of concept)

The ReactPHP HTTP server implementation has similar buffering to handle the full request body:
https://github.com/reactphp/http/blob/1.x/src/Middleware/RequestBodyBufferMiddleware.php

    $_data = "";
    $connection->on('data', function ($data) use ($connection, &$_data) {
        $_data .= $data;

        // parse content-length header
        if (preg_match('/Content-Length: (\d+)/', $_data, $matches)) {
            $contentLength = (int) $matches[1];

            // extract body
            if (preg_match('/\r\n\r\n(.*)/', $_data, $matches)) {
                $body = $matches[1];
                if (strlen($body) < $contentLength) {
                    return;
                } else {
                    $this->handleRequest($_data, $connection);
                    $_data = "";
                }
            }
        } else {
            $this->handleRequest($_data, $connection);
            $_data = "";
        }
    });
    

Steps To Reproduce

I'm only running this on my local development environment so can't say for sure how to reproduce.

[joedixon]

Are you sure you're running the latest version as we resolved a very similar issue a few weeks back: https://github.com/laravel/reverb/pull/87/files

[stephenfrank]

Hi Joe, I'm using v1.0.0-beta9 which includes these updates.

I've sent a pull request where I believe there is an error:
https://github.com/laravel/reverb/blob/main/src/Servers/Reverb/Http/Request.php#L36

 if ($connection->bufferLength() < $contentLength[0] ?? 0)

should be

 if ($request->getBody()->getSize() < $contentLength[0] ?? 0)

Content-Length should be compared to the length of the body only since the length of the buffer also includes the headers.

After this, the incomplete requests are rejected as null. The behaviour seems to work for me because the connection is held open and the missing data is appended to the buffer (at least, that's how I think it works) after which the request gets through and is broadcast

15:07:41.6876 Request Content-Length> 362
15:07:41.6876 Request Body> 0
-
15:07:41.6878 Request Content-Length> 362
15:07:41.6878 Request Body> 362

[joedixon]

@stephenfrank Your assumption is correct about how the buffer will continue to be filled until the end of body symbol is received.

Your logic makes sense to me, but I'm not sure how this is the first time it has been raised.

Assuming the values in your last messages are from log statements, could you also include the value of $connection->bufferLength()?

[stephenfrank]

I agree, seems like something that would have come up.

Here is the same logging with the buffers length:

1715094296.4642 | Connection Buffer> 948
1715094296.4642 | Request Content-Length> 362
1715094296.4642 | Request Body> 362
1715094297.982 | ->
1715094297.982 | Connection Buffer> 586
1715094297.982 | Request Content-Length> 362
1715094297.982 | Request Body> 0
1715094297.9822 | ->
1715094297.9822 | Connection Buffer> 948
1715094297.9822 | Request Content-Length> 362
1715094297.9822 | Request Body> 362

Running in Request.php

public static function from(string $message, Connection $connection, int $maxRequestSize): ?RequestInterface
    {
        $connection->appendToBuffer($message);

        if ($connection->bufferLength() > $maxRequestSize) {
            throw new OverflowException('Maximum HTTP buffer size of '.$maxRequestSize.'exceeded.');
        }

        if (static::isEndOfMessage($buffer = $connection->buffer())) {
            $request = Message::parseRequest($buffer);

            $t = microtime(true);
            echo "$t | ->\n";
            echo "$t | Connection Buffer> {$connection->bufferLength()}\n";
            echo "$t | Request Content-Length> {$request->getHeader('Content-Length')[0]}\n";
            echo "$t | Request Body> {$request->getBody()->getSize()}\n";

            if (! $contentLength = $request->getHeader('Content-Length')) {
                return $request;
            }

            if ($request->getBody()->getSize() < $contentLength[0] ?? 0) {
                return null;
            }

            $connection->clearBuffer();

            return $request;
        }

        return null;
    }

Running on Docker / Macbook / ARM64:

php -v
PHP 8.2.9 (cli) (built: Aug 29 2023 10:48:25) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.2.9, Copyright (c) Zend Technologies
    with Zend OPcache v8.2.9, Copyright (c), by Zend Technologies
    with Xdebug v3.2.1, Copyright (c) 2002-2023, by Derick Rethans

[joedixon]

Do the second and third logs comprise a single request?

[stephenfrank]

Yes, sorry maybe I could explain better...

Request 1) $connection->on('data' receives header and body in a single chunk

1715094296.4642 | Connection Buffer> 948
1715094296.4642 | Request Content-Length> 362
1715094296.4642 | Request Body> 362

Request 2) $connection->on('data' is fired twice and receives header in first chunk and body in the second chunk

1715094297.982 | ->
1715094297.982 | Connection Buffer> 586
1715094297.982 | Request Content-Length> 362
1715094297.982 | Request Body> 0
1715094297.9822 | ->
1715094297.9822 | Connection Buffer> 948
1715094297.9822 | Request Content-Length> 362
1715094297.9822 | Request Body> 362

[joedixon]

I'm still intrigued to know why your requests are getting split up like that, but I've tested your PR and all looks good so going to recommend this gets merged. Thanks for digging into this one 👍