Improving monolog in the wake of trying to get Rollbar to work.

src/App.php

@@ -30,6 +30,7 @@ use Faker\Provider;
 use Middlewares\TrailingSlash;
 use Monolog\Formatter\LineFormatter;
 use Monolog\Handler\ErrorLogHandler;
+use Monolog\Handler\StreamHandler;
 use Monolog\Logger;
 use Monolog\Processor\PsrLogMessageProcessor;
 use Psr\Container\ContainerInterface;
@@ -63,6 +64,7 @@ class App
     private array $supportedLanguages = ['en_US'];
 
     private static bool $isInitialised = false;
+    protected ?CachePoolChain $cachePoolChain = null;
 
     public function __construct()
     {
@@ -134,6 +136,7 @@ class App
         //   $container->enableCompilation($this->getCachePath());
         //   $container->writeProxiesToFile(true, "{$this->getCachePath()}/injection-proxies");
         //}
+
         $container = $container->build();
 
         $container->set(Slim\Views\Twig::class, function (
@@ -254,23 +257,27 @@ class App
             return $faker;
         });
 
-        $container->set(CachePoolChain::class, function (Redis $redis) {
+        $container->set(CachePoolChain::class, function (Logger $logger, Redis $redis) {
-            $caches = [];
+            if (!$this->cachePoolChain) {
+                $caches = [];
+
+                // If apc/apcu present, add it to the pool
+                if (function_exists('apcu_add')) {
+                    $caches[] = new ApcuCachePool(true);
+                } elseif (function_exists('apc_add')) {
+                    $caches[] = new ApcCachePool(true);
+                }
+
+                // If Redis is configured, add it to the pool.
+                if ($redis->isAvailable()) {
+                    $caches[] = new RedisCachePool($redis->getUnderlyingRedis());
+                }
+                $caches[] = new ArrayCachePool();
+
+                $this->cachePoolChain = new CachePoolChain($caches);
 
-            // If apc/apcu present, add it to the pool
-            if (function_exists('apcu_add')) {
-                $caches[] = new ApcuCachePool();
-            } elseif (function_exists('apc_add')) {
-                $caches[] = new ApcCachePool();
             }
-
+            return $this->cachePoolChain;
-            // If Redis is configured, add it to the pool.
-            if ($redis->isAvailable()) {
-                $caches[] = new RedisCachePool($redis->getUnderlyingRedis());
-            }
-            $caches[] = new ArrayCachePool();
-
-            return new CachePoolChain($caches);
         });
 
         $container->set('MonologFormatter', function (EnvironmentService $environmentService) {
@@ -281,8 +288,11 @@ class App
             );
         });
 
-        $container->set(Logger::class, function (ConfigurationService $configurationService) {
+        $container->set(Logger::class, function (ConfigurationService $configurationService, EnvironmentService $environmentService) {
-            $monolog = new Logger($configurationService->get(ConfigurationService::KEY_APP_NAME));
+            $appName = $configurationService->get(ConfigurationService::KEY_APP_NAME);
+            $logName = $environmentService->has("REQUEST_URI") ? sprintf("%s(%s)", $appName, $environmentService->get("REQUEST_URI")) : $appName;
+            $monolog = new Logger($logName);
+            $monolog->pushHandler(new StreamHandler(sprintf("/var/log/%s.log", strtolower($appName))));
             $monolog->pushHandler(new ErrorLogHandler(), Logger::DEBUG);
             $monolog->pushProcessor(new PsrLogMessageProcessor());
 
@@ -339,6 +349,7 @@ class App
 
         $this->router = $container->get(Router::class);
 
+        #!\Kint::dump($this->environmentService->all());exit;
         return $container;
     }
 
@@ -482,7 +493,11 @@ class App
         $this->interrogateControllers();
         $this->debugBar['time']->stopMeasure('interrogateControllers');
 
-        $this->logger->debug(sprintf('Bootstrap complete in %sms', number_format((microtime(true) - $_SERVER['REQUEST_TIME_FLOAT']) * 1000, 2)));
+        $timeToBootstrapMs = (microtime(true) - $_SERVER['REQUEST_TIME_FLOAT']) * 1000;
+        $bootstrapTooLongThresholdMs = 300;
+        if($timeToBootstrapMs >= $bootstrapTooLongThresholdMs) {
+            $this->logger->warning(sprintf('Bootstrap complete in %sms which is more than the threshold of %sms', number_format($timeToBootstrapMs, 2), $bootstrapTooLongThresholdMs));
+        }
 
         $this->router->populateRoutes($this->getApp(), $request);
 
@@ -527,8 +542,6 @@ class App
 
         $this->router->cache();
 
-        $this->logger->debug(sprintf(
+        $this->logger->info('ROUTE_CACHE miss.');
-            'ROUTE_CACHE miss. Perhaps enable ROUTE_CACHE envvar.'
-        ));
     }
 }

src/Controllers/AbstractController.php

@@ -23,7 +23,7 @@ abstract class AbstractController
     public function __construct(Logger $logger, CacheProvider $cacheProvider)
     {
         $this->logger = $logger;
-        $this->logger->debug(sprintf('Entered Controller in %sms', number_format((microtime(true) - $_SERVER['REQUEST_TIME_FLOAT']) * 1000, 2)));
+        #$this->logger->debug(sprintf('Entered Controller in %sms', number_format((microtime(true) - $_SERVER['REQUEST_TIME_FLOAT']) * 1000, 2)));
         $this->cacheProvider = $cacheProvider;
     }
 

src/Controllers/AbstractHTMLController.php

@@ -51,11 +51,17 @@ abstract class AbstractHTMLController extends AbstractController
             $parameters
         )->withHeader('Content-Type', 'text/html');
 
-        $this->logger->debug(sprintf(
+        $renderTimeLimitMs = 500;
-            'Took %sms to render %s',
+        $renderTimeMs = (microtime(true) - $renderStart) * 1000;
-            number_format((microtime(true) - $renderStart) * 1000, 2),
+
-            $template
+        if($renderTimeMs >= $renderTimeLimitMs) {
-        ));
+            $this->logger->debug(sprintf(
+                'Took %sms to render %s, which is over %sms limit',
+                number_format($renderTimeMs, 2),
+                $template,
+                $renderTimeLimitMs
+            ));
+        }
         $this->debugBar['time']->stopMeasure('render');
 
         return $response;

src/Router/Route.php

@@ -34,13 +34,6 @@ class Route
     ];
     protected array $validDomains = [];
 
-    private Logger $logger;
-
-    public function __construct(Logger $logger)
-    {
-        $this->logger = $logger;
-    }
-
     public function getCallbackProperties(): array
     {
         return $this->callbackProperties;

src/Router/Router.php

@@ -71,7 +71,7 @@ class Router
                         }
 
                         foreach ($routeAnnotation->methods as $httpMethod) {
-                            $newRoute = new Route($this->logger);
+                            $newRoute = new Route();
 
                             $newRoute
                                 ->setHttpMethod($httpMethod)
@@ -141,7 +141,10 @@ class Router
         }
 
         $this->routes = $cacheItem->get();
-        $this->logger->debug(sprintf('Loaded routes from Cache in %sms', number_format((microtime(true) - $time) * 1000, 2)));
+        $timeToLoadFromCacheMs = (microtime(true) - $time) * 1000;
+        if($timeToLoadFromCacheMs >= 500) {
+            $this->logger->warning(sprintf('Loaded routes from Cache in %sms, which is slower than 500ms', number_format($timeToLoadFromCacheMs, 2)));
+        }
 
         return true;
     }
@@ -156,8 +159,9 @@ class Router
 
         try {
             $this->cachePoolChain->save($routeItem);
+            $this->logger->info("Cached router to cache pool");
         } catch (CachePoolException $cachePoolException) {
-            $this->logger->critical($cachePoolException->getMessage());
+            $this->logger->critical("Cache Pool Exception: " . $cachePoolException->getMessage());
         }
 
         return $this;