[Cache] add logs on early-recomputation and locking

Author: nicolas-grekas

CacheTrait.php

@@ -13,6 +13,7 @@
 
 use Psr\Cache\CacheItemPoolInterface;
 use Psr\Cache\InvalidArgumentException;
+use Psr\Log\LoggerInterface;
 
 /**
  * An implementation of CacheInterface for PSR-6 CacheItemPoolInterface classes.
@@ -37,7 +38,7 @@ public function delete(string $key): bool
         return $this->deleteItem($key);
     }
 
-    private function doGet(CacheItemPoolInterface $pool, string $key, callable $callback, ?float $beta, array &$metadata = null)
+    private function doGet(CacheItemPoolInterface $pool, string $key, callable $callback, ?float $beta, array &$metadata = null, LoggerInterface $logger = null)
     {
         if (0 > $beta = $beta ?? 1.0) {
             throw new class(sprintf('Argument "$beta" provided to "%s::get()" must be a positive number, %f given.', \get_class($this), $beta)) extends \InvalidArgumentException implements InvalidArgumentException {
@@ -52,9 +53,13 @@ private function doGet(CacheItemPoolInterface $pool, string $key, callable $call
             $expiry = $metadata[ItemInterface::METADATA_EXPIRY] ?? false;
             $ctime = $metadata[ItemInterface::METADATA_CTIME] ?? false;
 
-            if ($recompute = $ctime && $expiry && $expiry <= microtime(true) - $ctime / 1000 * $beta * log(random_int(1, PHP_INT_MAX) / PHP_INT_MAX)) {
+            if ($recompute = $ctime && $expiry && $expiry <= ($now = microtime(true)) - $ctime / 1000 * $beta * log(random_int(1, PHP_INT_MAX) / PHP_INT_MAX)) {
                 // force applying defaultLifetime to expiry
                 $item->expiresAt(null);
+                $this->logger && $this->logger->info('Item "{key}" elected for early recomputation {delta}s before its expiration', [
+                    'key' => $key,
+                    'delta' => sprintf('%.1f', $expiry - $now),
+                ]);
             }
         }