Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve performance by skipping AccessLogHandler if it writes to /dev/null #248

Merged
merged 2 commits into from
Mar 4, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 26 additions & 2 deletions src/AccessLogHandler.php
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@
*/
class AccessLogHandler
{
/** @var LogStreamHandler */
/** @var ?LogStreamHandler */
private $logger;

/** @var bool */
Expand All @@ -31,15 +31,38 @@ public function __construct(?string $path = null)
$path = \PHP_SAPI === 'cli' ? 'php://output' : 'php://stderr';
}

$this->logger = new LogStreamHandler($path);
$logger = new LogStreamHandler($path);
if (!$logger->isDevNull()) {
// only assign logger if we're not logging to /dev/null (which would discard any logs)
$this->logger = $logger;
}

$this->hasHighResolution = \function_exists('hrtime'); // PHP 7.3+
}

/**
* [Internal] Returns whether we're writing to /dev/null (which will discard any logs)
*
* @internal
* @return bool
*/
public function isDevNull(): bool
{
return $this->logger === null;
}

/**
* @return ResponseInterface|PromiseInterface<ResponseInterface>|\Generator
*/
public function __invoke(ServerRequestInterface $request, callable $next)
{
if ($this->logger === null) {
// Skip if we're logging to /dev/null (which will discard any logs).
// As an additional optimization, the `App` will automatically
// detect we no longer need to invoke this instance at all.
return $next($request); // @codeCoverageIgnore
}

$now = $this->now();
$response = $next($request);

Expand Down Expand Up @@ -95,6 +118,7 @@ private function log(ServerRequestInterface $request, ResponseInterface $respons
$responseSize = 0;
}

\assert($this->logger instanceof LogStreamHandler);
$this->logger->log(
($request->getAttribute('remote_addr') ?? $request->getServerParams()['REMOTE_ADDR'] ?? '-') . ' ' .
'"' . $this->escape($method) . ' ' . $this->escape($request->getRequestTarget()) . ' HTTP/' . $request->getProtocolVersion() . '" ' .
Expand Down
12 changes: 10 additions & 2 deletions src/App.php
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,12 @@ public function __construct(...$middleware)
if ($needsErrorHandler && ($handler instanceof ErrorHandler || $handler instanceof AccessLogHandler) && !$handlers) {
$needsErrorHandler = null;
}
$handlers[] = $handler;

// only add to list of handlers if this is not a NOOP
if (!$handler instanceof AccessLogHandler || !$handler->isDevNull()) {
$handlers[] = $handler;
}

if ($handler instanceof AccessLogHandler) {
$needsAccessLog = null;
$needsErrorHandlerNext = true;
Expand All @@ -99,7 +104,10 @@ public function __construct(...$middleware)

// only log for built-in webserver and PHP development webserver by default, others have their own access log
if ($needsAccessLog instanceof Container) {
\array_unshift($handlers, $needsAccessLog->getAccessLogHandler());
$handler = $needsAccessLog->getAccessLogHandler();
if (!$handler->isDevNull()) {
\array_unshift($handlers, $handler);
}
}

$this->router = new RouteHandler($container);
Expand Down
37 changes: 36 additions & 1 deletion src/Io/LogStreamHandler.php
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
*/
class LogStreamHandler
{
/** @var resource */
/** @var ?resource */
private $stream;

/**
Expand All @@ -33,6 +33,31 @@ public function __construct(string $path)
});

$stream = \fopen($path, 'ae');

// try to fstat($stream) to see if this points to /dev/null (skip on Windows)
// @codeCoverageIgnoreStart
$stat = false;
if ($stream !== false && \DIRECTORY_SEPARATOR !== '\\') {
if (\strtolower($path) === 'php://output') {
// php://output doesn't support stat, so assume php://output will go to php://stdout
$stdout = \defined('STDOUT') ? \STDOUT : \fopen('php://stdout', 'w');
if (\is_resource($stdout)) {
$stat = \fstat($stdout);
} else {
// STDOUT can not be opened => assume piping to /dev/null
$stream = null;
}
} else {
$stat = \fstat($stream);
}

// close stream if it points to /dev/null
if ($stat !== false && $stat === \stat('/dev/null')) {
$stream = null;
}
}
// @codeCoverageIgnoreEnd

\restore_error_handler();

if ($stream === false) {
Expand All @@ -44,8 +69,18 @@ public function __construct(string $path)
$this->stream = $stream;
}

public function isDevNull(): bool
{
return $this->stream === null;
}

public function log(string $message): void
{
// nothing to do if we're writing to /dev/null
if ($this->stream === null) {
return; // @codeCoverageIgnore
}

$time = \microtime(true);
$prefix = \date('Y-m-d H:i:s', (int) $time) . \sprintf('.%03d ', (int) (($time - (int) $time) * 1e3));

Expand Down
18 changes: 18 additions & 0 deletions tests/AccessLogHandlerTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,24 @@ public function testCtorWithPathToNewFileWillCreateNewFile(): void
unlink($path);
}

public function testIsDevNullReturnsFalseForDefaultPath(): void
{
$handler = new AccessLogHandler();

$this->assertFalse($handler->isDevNull());
}

public function testIsDevNullReturnsTrueForDevNull(): void
{
if (DIRECTORY_SEPARATOR === '\\') {
$this->markTestSkipped('Not supported on Windows');
}

$handler = new AccessLogHandler('/dev/null');

$this->assertTrue($handler->isDevNull());
}

public function testInvokeWithDefaultPathWillLogMessageToConsole(): void
{
$handler = new AccessLogHandler();
Expand Down
54 changes: 54 additions & 0 deletions tests/AppTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -362,6 +362,31 @@ public function testConstructWithAccessLogHandlerAndErrorHandlerAssignsHandlersA
$this->assertInstanceOf(RouteHandler::class, $handlers[2]);
}

public function testConstructWithAccessLogHandlerToDevNullAndErrorHandlerWillRemoveAccessLogHandler(): void
{
$accessLogHandler = $this->createMock(AccessLogHandler::class);
$accessLogHandler->expects($this->once())->method('isDevNull')->willReturn(true);
assert(is_callable($accessLogHandler));

$errorHandler = new ErrorHandler();

$app = new App($accessLogHandler, $errorHandler);

$ref = new ReflectionProperty($app, 'handler');
$ref->setAccessible(true);
$handler = $ref->getValue($app);
assert($handler instanceof MiddlewareHandler);

$ref = new ReflectionProperty($handler, 'handlers');
$ref->setAccessible(true);
$handlers = $ref->getValue($handler);
assert(is_array($handlers));

$this->assertCount(2, $handlers);
$this->assertSame($errorHandler, $handlers[0]);
$this->assertInstanceOf(RouteHandler::class, $handlers[1]);
}

public function testConstructWithAccessLogHandlerClassAndErrorHandlerClassAssignsDefaultHandlers(): void
{
$app = new App(AccessLogHandler::class, ErrorHandler::class);
Expand Down Expand Up @@ -410,6 +435,35 @@ public function testConstructWithContainerAndAccessLogHandlerClassAndErrorHandle
$this->assertInstanceOf(RouteHandler::class, $handlers[2]);
}

public function testConstructWithContainerAndAccessLogHandlerClassAndErrorHandlerClassWillUseContainerToGetAccessLogHandlerAndWillSkipAccessLogHandlerToDevNull(): void
{
$accessLogHandler = $this->createMock(AccessLogHandler::class);
$accessLogHandler->expects($this->once())->method('isDevNull')->willReturn(true);

$errorHandler = new ErrorHandler();

$container = $this->createMock(Container::class);
$container->expects($this->once())->method('getAccessLogHandler')->willReturn($accessLogHandler);
$container->expects($this->once())->method('getErrorHandler')->willReturn($errorHandler);

assert($container instanceof Container);
$app = new App($container, AccessLogHandler::class, ErrorHandler::class);

$ref = new ReflectionProperty($app, 'handler');
$ref->setAccessible(true);
$handler = $ref->getValue($app);
assert($handler instanceof MiddlewareHandler);

$ref = new ReflectionProperty($handler, 'handlers');
$ref->setAccessible(true);
$handlers = $ref->getValue($handler);
assert(is_array($handlers));

$this->assertCount(2, $handlers);
$this->assertSame($errorHandler, $handlers[0]);
$this->assertInstanceOf(RouteHandler::class, $handlers[1]);
}

public function testConstructWithMiddlewareBeforeAccessLogHandlerAndErrorHandlerAssignsDefaultErrorHandlerAsFirstHandlerFollowedByGivenHandlers(): void
{
$middleware = static function (ServerRequestInterface $request, callable $next) { };
Expand Down
11 changes: 11 additions & 0 deletions tests/Io/LogStreamHandlerCliIsDevNull.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
<?php

use FrameworkX\Io\LogStreamHandler;

require __DIR__ . '/../../vendor/autoload.php';

$log = new LogStreamHandler($argv[1] ?? 'php://stdout');

$buffer = var_export($log->isDevNull(), true) . PHP_EOL;

file_put_contents($argv[2] ?? 'php://stdout', $buffer);
18 changes: 18 additions & 0 deletions tests/Io/LogStreamHandlerCliIsDevNullAfterClose.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
<?php

use FrameworkX\Io\LogStreamHandler;

require __DIR__ . '/../../vendor/autoload.php';

fclose(STDOUT);

try {
$log = new LogStreamHandler($argv[1] ?? 'php://stdout');
} catch (\Exception $e) {
fwrite(STDERR, get_class($e) . ': ' . $e->getMessage() . PHP_EOL);
exit(1);
}

$buffer = var_export($log->isDevNull(), true) . PHP_EOL;

file_put_contents($argv[2] ?? 'php://stdout', $buffer);
Loading