diff --git a/src/AccessLogHandler.php b/src/AccessLogHandler.php index 3b85505..30a86b8 100644 --- a/src/AccessLogHandler.php +++ b/src/AccessLogHandler.php @@ -5,6 +5,7 @@ use Psr\Http\Message\ResponseInterface; use Psr\Http\Message\ServerRequestInterface; use React\Promise\PromiseInterface; +use React\Stream\ReadableStreamInterface; /** * @internal @@ -28,27 +29,51 @@ public function __invoke(ServerRequestInterface $request, callable $next) if ($response instanceof PromiseInterface) { return $response->then(function (ResponseInterface $response) use ($request) { - $this->log($request, $response); + $this->logWhenClosed($request, $response); return $response; }); } elseif ($response instanceof \Generator) { return (function (\Generator $generator) use ($request) { $response = yield from $generator; - $this->log($request, $response); + $this->logWhenClosed($request, $response); return $response; })($response); } else { - $this->log($request, $response); + $this->logWhenClosed($request, $response); return $response; } } - private function log(ServerRequestInterface $request, ResponseInterface $response): void + /** + * checks if response body is closed (not streaming) before writing log message for response + */ + private function logWhenClosed(ServerRequestInterface $request, ResponseInterface $response): void + { + $body = $response->getBody(); + + if ($body instanceof ReadableStreamInterface && $body->isReadable()) { + $size = 0; + $body->on('data', function (string $chunk) use (&$size) { + $size += strlen($chunk); + }); + + $body->on('close', function () use (&$size, $request, $response) { + $this->log($request, $response, $size); + }); + } else { + $this->log($request, $response, $body->getSize() ?? strlen((string) $body)); + } + } + + /** + * writes log message for response after response body is closed (not streaming anymore) + */ + private function log(ServerRequestInterface $request, ResponseInterface $response, int $responseSize): void { $this->sapi->log( ($request->getServerParams()['REMOTE_ADDR'] ?? '-') . ' ' . '"' . $this->escape($request->getMethod()) . ' ' . $this->escape($request->getRequestTarget()) . ' HTTP/' . $request->getProtocolVersion() . '" ' . - $response->getStatusCode() . ' ' . $response->getBody()->getSize() + $response->getStatusCode() . ' ' . $responseSize ); } diff --git a/tests/AccessLogHandlerTest.php b/tests/AccessLogHandlerTest.php index 6560b23..69ae0f6 100644 --- a/tests/AccessLogHandlerTest.php +++ b/tests/AccessLogHandlerTest.php @@ -6,6 +6,7 @@ use PHPUnit\Framework\TestCase; use React\Http\Message\Response; use React\Http\Message\ServerRequest; +use React\Stream\ThroughStream; use function React\Promise\resolve; class AccessLogHandlerTest extends TestCase @@ -120,6 +121,48 @@ public function testInvokeWithCoroutineNextPrintsRequestLogWithCurrentDateAndTim $generator->next(); } + public function testInvokeWithStreamingResponsePrintsRequestLogWithCurrentDateAndTime() + { + $handler = new AccessLogHandler(); + + $stream = new ThroughStream(); + $request = new ServerRequest('GET', 'http://localhost:8080/users', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']); + $response = new Response(200, [], $stream); + + // 2021-01-29 12:22:01.717 127.0.0.1 "GET /users HTTP/1.1" 200 10\n + $this->expectOutputRegex("/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"GET \/users HTTP\/1\.1\" 200 10" . PHP_EOL . "$/"); + $handler($request, function () use ($response) { return $response; }); + $stream->write('hello'); + $stream->end('world'); + } + + public function testInvokeWithClosedStreamingResponsePrintsRequestLogWithCurrentDateAndTime() + { + $handler = new AccessLogHandler(); + + $stream = new ThroughStream(); + $stream->close(); + $request = new ServerRequest('GET', 'http://localhost:8080/users', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']); + $response = new Response(200, [], $stream); + + // 2021-01-29 12:22:01.717 127.0.0.1 "GET /users HTTP/1.1" 200 10\n + $this->expectOutputRegex("/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"GET \/users HTTP\/1\.1\" 200 0" . PHP_EOL . "$/"); + $handler($request, function () use ($response) { return $response; }); + } + + public function testInvokeWithStreamingResponsePrintsNothingIfStreamIsPending() + { + $handler = new AccessLogHandler(); + + $stream = new ThroughStream(); + $request = new ServerRequest('GET', 'http://localhost:8080/users', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']); + $response = new Response(200, [], $stream); + + $this->expectOutputString(''); + $handler($request, function () use ($response) { return $response; }); + $stream->write('hello'); + } + public function testInvokeWithoutRemoteAddressPrintsRequestLogWithDashAsPlaceholder() { $handler = new AccessLogHandler();