Merge pull request #248 from clue-labs/accesslog-null

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

src/AccessLogHandler.php

@@ -14,7 +14,7 @@
  */
 class AccessLogHandler
 {
-    /** @var LogStreamHandler */
+    /** @var ?LogStreamHandler */
     private $logger;
 
     /** @var bool */
@@ -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);
 
@@ -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() . '" ' .

src/App.php

@@ -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;
@@ -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);

src/Io/LogStreamHandler.php

@@ -7,7 +7,7 @@
  */
 class LogStreamHandler
 {
-    /** @var resource */
+    /** @var ?resource */
     private $stream;
 
     /**
@@ -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) {
@@ -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));
 

tests/AccessLogHandlerTest.php

@@ -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();

tests/AppTest.php

@@ -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);
@@ -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) { };

tests/Io/LogStreamHandlerCliIsDevNull.php

@@ -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);

tests/Io/LogStreamHandlerCliIsDevNullAfterClose.php

@@ -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);