Skip to content

Commit

Permalink
feat(early expiry): added debug logs to help implement stale cache
Browse files Browse the repository at this point in the history
  • Loading branch information
shavounet committed Aug 10, 2022
1 parent 150fe28 commit 428c0cf
Show file tree
Hide file tree
Showing 7 changed files with 156 additions and 43 deletions.
6 changes: 4 additions & 2 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ bedrock_stale_cache:
stale_cache_service_id: # Desired id for this new stale cache instance
cache_pool: cache_pool_id # Cache pool on top of which stale cache will be used
max_stale: 3600 # Stale period duration, in seconds
enable_debug_logs: true # Optional (defaults to false), produce a bunch of debug logs
```
It will declare a `@stale_cache_service_id`, that you can use as an injected dependency.
Expand All @@ -37,9 +38,10 @@ The method `allowStaleCacheUsage` can be used for some custom logic, or you can

A `Bedrock\StaleCacheBundle\Event\StaleCacheUsage` event is sent on stale cache usage. It is strongly advised to log it, with the associated error.

### Remarks
### Logs

This bundle disables [the stampede prevention from Symfony Cache](https://symfony.com/doc/current/components/cache.html#stampede-prevention).
Debug logs can be enabled to ensure correct stale cache usage.
It should not be enabled in a production environment since it can cause performance issue.

## Contribute

Expand Down
1 change: 1 addition & 0 deletions composer.json
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@
"require": {
"php": "^7.4 || ^8.0",
"psr/event-dispatcher": "^1.0",
"psr/log": "^1 || ^2 || ^3",
"symfony/dependency-injection": "^4.4 || ^5.4 || ^6.0" ,
"symfony/http-kernel": "^4.4 || ^5.4 || ^6.0",
"symfony/cache-contracts": "^1.0 || ^2.0",
Expand Down
40 changes: 35 additions & 5 deletions src/Cache/Stale.php
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
use Bedrock\StaleCacheBundle\Event\StaleCacheUsage;
use Bedrock\StaleCacheBundle\Exception\UnavailableResourceException;
use Psr\EventDispatcher\EventDispatcherInterface;
use Psr\Log\LoggerInterface;
use Symfony\Component\Cache\CacheItem;
use Symfony\Contracts\Cache\CacheInterface;
use Symfony\Contracts\Cache\ItemInterface;
Expand All @@ -20,16 +21,20 @@ class Stale implements TagAwareCacheInterface

private int $maxStale;

private ?LoggerInterface $logger;

private ?int $defaultLifetime = null;

public function __construct(
CacheInterface $internalCache,
EventDispatcherInterface $dispatcher,
int $maxStale
int $maxStale,
?LoggerInterface $logger = null
) {
$this->internalCache = $internalCache;
$this->dispatcher = $dispatcher;
$this->maxStale = $maxStale;
$this->logger = $logger;
}

/**
Expand All @@ -53,18 +58,36 @@ public function get(string $key, callable $callback, float $beta = null, array &
// $beta = 0 to disable early recompute
$value = $this->internalCache->get($key, $callbackWithIncreasedCacheTime, 0, $metadata);

// If value is cached and we're in stale mode, try to force recomputing it
// Ignore correctly marked exceptions: this is where the stale mode should work as a fallback
if ($isHit && ($this->isStale($metadata) || $this->shouldTriggerEarlyCacheExpiry($metadata, $beta))) {
$recompute = false;
if ($this->isStale($metadata)) {
$this->logDebugMessage('Value is stale, try to recompute it', $key);
$recompute = true;
}

if (!$recompute && $this->shouldTriggerEarlyCacheExpiry($metadata, $beta)) {
$this->logDebugMessage('Value elected to early expiration, try to recompute it', $key);
$recompute = true;
}

if ($isHit && $recompute) {
try {
// $beta = \INF to force an early recompute
$value = $this->internalCache->get($key, $callbackWithIncreasedCacheTime, \INF, $metadata);
} catch (UnavailableResourceException $exception) {
if (!$exception->allowStaleCacheUsage()) {
$this->logDebugMessage('Cannot fallback to stale mode', $key, $exception);
throw $exception;
}

$this->dispatcher->dispatch(new StaleCacheUsage($exception));
$this->logDebugMessage('Fallback to stale mode', $key, $exception);
$this->dispatcher->dispatch(new StaleCacheUsage($exception, $key));
} catch (\Throwable $throwable) {
$this->logDebugMessage(
sprintf('Exception %s do not allow stale cache, it will be rethrown', get_class($throwable)),
$key, $throwable
);

throw $throwable;
}
}

Expand Down Expand Up @@ -140,4 +163,11 @@ private function shouldTriggerEarlyCacheExpiry(?array $metadata, ?float $beta):
// it should be triggered a few hundreds of ms before due time.
return ($expiry - $this->maxStale) <= microtime(true) - $ctime / 1000 * $beta * log(random_int(1, \PHP_INT_MAX) / \PHP_INT_MAX);
}

private function logDebugMessage(string $message, string $cacheKey, ?\Throwable $throwable = null): void
{
if ($this->logger) {
$this->logger->debug($message, ['cache_key' => $cacheKey, 'exception' => $throwable]);
}
}
}
2 changes: 1 addition & 1 deletion src/DependencyInjection/AddStaleCacheLifetime.php
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ public function process(ContainerBuilder $container): void
*/
private function findCachePoolDefaultLifetime(string $cachePool, array $cachePoolServices): ?int
{
foreach ($cachePoolServices as $serviceId => $tags) {
foreach ($cachePoolServices as $tags) {
foreach ($tags as $tag) {
if (array_key_exists('name', $tag) && $tag['name'] === $cachePool) {
return $tag['default_lifetime'] ?? null;
Expand Down
6 changes: 6 additions & 0 deletions src/DependencyInjection/BedrockStaleCacheExtension.php
Original file line number Diff line number Diff line change
Expand Up @@ -36,5 +36,11 @@ private function configureStaleCacheService(ContainerBuilder $container, string
$definition->setAutoconfigured(true);
$definition->setAutowired(true);
$definition->addTag('bedrock_stale_cache.stale_cache', $options);

// By default, disable debug logs
$enableDebugLogs = $options['enable_debug_logs'] ?? false;
if (!$enableDebugLogs) {
$definition->setArgument('$logger', null);
}
}
}
9 changes: 8 additions & 1 deletion src/Event/StaleCacheUsage.php
Original file line number Diff line number Diff line change
Expand Up @@ -10,14 +10,21 @@
class StaleCacheUsage extends Event
{
private UnavailableResourceException $exception;
private string $cacheKey;

public function __construct(UnavailableResourceException $exception)
public function __construct(UnavailableResourceException $exception, string $cacheKey)
{
$this->exception = $exception;
$this->cacheKey = $cacheKey;
}

public function getException(): UnavailableResourceException
{
return $this->exception;
}

public function getCacheKey(): string
{
return $this->cacheKey;
}
}
Loading

0 comments on commit 428c0cf

Please sign in to comment.