From f905a54dea278509c49aed1bd531966c08be5807 Mon Sep 17 00:00:00 2001 From: Robert Lemke Date: Mon, 5 Sep 2022 15:03:06 +0200 Subject: [PATCH 1/4] Log any errors in Redis Backend This change adds error logging to the Redis Backend and also provides a mechanism to de-duplicate errors (see README). --- Classes/RedisBackend.php | 259 ++++++++++++++++++++++++++------------- README.md | 25 +++- 2 files changed, 201 insertions(+), 83 deletions(-) diff --git a/Classes/RedisBackend.php b/Classes/RedisBackend.php index 5a602ea..d6559b5 100644 --- a/Classes/RedisBackend.php +++ b/Classes/RedisBackend.php @@ -23,8 +23,13 @@ use Neos\Cache\Backend\WithStatusInterface; use Neos\Cache\EnvironmentConfiguration; use Neos\Error\Messages\Result; +use Neos\Flow\Core\Bootstrap; +use Neos\Flow\Log\ThrowableStorageInterface; +use Neos\Flow\Log\Utility\LogEnvironment; +use Neos\Flow\ObjectManagement\ObjectManagerInterface; use Predis; use Predis\Collection\Iterator; +use Psr\Log\LoggerInterface; use RuntimeException; class RedisBackend extends IndependentAbstractBackend implements TaggableBackendInterface, IterableBackendInterface, FreezableBackendInterface, PhpCapableBackendInterface, WithStatusInterface @@ -34,6 +39,8 @@ class RedisBackend extends IndependentAbstractBackend implements TaggableBackend public const MIN_REDIS_VERSION = '5.0.0'; protected Predis\Client $client; + protected ?LoggerInterface $logger = null; + protected ?ThrowableStorageInterface $throwableStorage = null; protected ?bool $frozen = null; protected string $hostname = '127.0.0.1'; @@ -45,6 +52,9 @@ class RedisBackend extends IndependentAbstractBackend implements TaggableBackend protected int $compressionLevel = 0; protected ?Iterator\Keyspace $entryKeyspaceIterator = null; protected int $entryKeyspaceIteratorKeyPrefixLength = 0; + protected bool $deduplicateErrors = true; + + protected static array $loggedErrors = []; /** * @param EnvironmentConfiguration $environmentConfiguration @@ -54,6 +64,11 @@ public function __construct(EnvironmentConfiguration $environmentConfiguration, { parent::__construct($environmentConfiguration, $options); $this->client = $this->getRedisClient(); + + if (class_exists('Neos\Flow\Core\Bootstrap') && Bootstrap::$staticObjectManager instanceof ObjectManagerInterface) { + $this->logger = Bootstrap::$staticObjectManager->get(LoggerInterface::class); + $this->throwableStorage = Bootstrap::$staticObjectManager->get(ThrowableStorageInterface::class); + } } /** @@ -73,22 +88,26 @@ public function set(string $entryIdentifier, string $data, array $tags = [], int throw new RuntimeException(sprintf('Cannot add or modify cache entry because the backend of cache "%s" is frozen.', $this->cacheIdentifier), 1574776976); } - $this->client->multi(); - $lifetime = $lifetime ?? $this->defaultLifetime; - if ($lifetime > 0) { - $status = $this->client->set($this->getPrefixedIdentifier('entry:' . $entryIdentifier), $this->compress($data), 'ex', $lifetime); - } else { - $status = $this->client->set($this->getPrefixedIdentifier('entry:' . $entryIdentifier), $this->compress($data)); - } + try { + $this->client->multi(); + $lifetime = $lifetime ?? $this->defaultLifetime; + if ($lifetime > 0) { + $status = $this->client->set($this->getPrefixedIdentifier('entry:' . $entryIdentifier), $this->compress($data), 'ex', $lifetime); + } else { + $status = $this->client->set($this->getPrefixedIdentifier('entry:' . $entryIdentifier), $this->compress($data)); + } - $this->client->lRem($this->getPrefixedIdentifier('entries'), 0, $entryIdentifier); - $this->client->rPush($this->getPrefixedIdentifier('entries'), [$entryIdentifier]); + $this->client->lRem($this->getPrefixedIdentifier('entries'), 0, $entryIdentifier); + $this->client->rPush($this->getPrefixedIdentifier('entries'), [$entryIdentifier]); - foreach ($tags as $tag) { - $this->client->sAdd($this->getPrefixedIdentifier('tag:' . $tag), [$entryIdentifier]); - $this->client->sAdd($this->getPrefixedIdentifier('tags:' . $entryIdentifier), [$tag]); + foreach ($tags as $tag) { + $this->client->sAdd($this->getPrefixedIdentifier('tag:' . $tag), [$entryIdentifier]); + $this->client->sAdd($this->getPrefixedIdentifier('tags:' . $entryIdentifier), [$tag]); + } + $this->client->exec(); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); } - $this->client->exec(); } /** @@ -100,7 +119,11 @@ public function set(string $entryIdentifier, string $data, array $tags = [], int */ public function get(string $entryIdentifier) { - return $this->decompress($this->client->get($this->getPrefixedIdentifier('entry:' . $entryIdentifier))); + try { + return $this->decompress($this->client->get($this->getPrefixedIdentifier('entry:' . $entryIdentifier))); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -112,7 +135,11 @@ public function get(string $entryIdentifier) */ public function has(string $entryIdentifier): bool { - return (bool)$this->client->exists($this->getPrefixedIdentifier('entry:' . $entryIdentifier)); + try { + return (bool)$this->client->exists($this->getPrefixedIdentifier('entry:' . $entryIdentifier)); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -130,21 +157,25 @@ public function remove(string $entryIdentifier): bool if ($this->isFrozen()) { throw new RuntimeException(sprintf('Cannot remove cache entry because the backend of cache "%s" is frozen.', $this->cacheIdentifier), 1323344192); } - do { - $tagsKey = $this->getPrefixedIdentifier('tags:' . $entryIdentifier); - $this->client->watch($tagsKey); - $tags = $this->client->sMembers($tagsKey); - $this->client->multi(); - $this->client->del([$this->getPrefixedIdentifier('entry:' . $entryIdentifier)]); - foreach ($tags as $tag) { - $this->client->sRem($this->getPrefixedIdentifier('tag:' . $tag), $entryIdentifier); - } - $this->client->del([$this->getPrefixedIdentifier('tags:' . $entryIdentifier)]); - /** @var array|bool $result */ - $result = $this->client->exec(); - } while ($result === false); - - return true; + try { + do { + $tagsKey = $this->getPrefixedIdentifier('tags:' . $entryIdentifier); + $this->client->watch($tagsKey); + $tags = $this->client->sMembers($tagsKey); + $this->client->multi(); + $this->client->del([$this->getPrefixedIdentifier('entry:' . $entryIdentifier)]); + foreach ($tags as $tag) { + $this->client->sRem($this->getPrefixedIdentifier('tag:' . $tag), $entryIdentifier); + } + $this->client->del([$this->getPrefixedIdentifier('tags:' . $entryIdentifier)]); + /** @var array|bool $result */ + $result = $this->client->exec(); + } while ($result === false); + + return true; + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -173,14 +204,18 @@ public function flush(): void redis.call('DEL', KEYS[1]) "; - $this->client->eval( - $script, - 1, - $this->getPrefixedIdentifier('frozen'), - $this->getPrefixedIdentifier('*'), - $this->getPrefixedIdentifier('') - ); - $this->frozen = null; + try { + $this->client->eval( + $script, + 1, + $this->getPrefixedIdentifier('frozen'), + $this->getPrefixedIdentifier('*'), + $this->getPrefixedIdentifier('') + ); + $this->frozen = null; + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -221,12 +256,16 @@ public function flushByTag(string $tag): int return #entries "; - return $this->client->eval( - $script, - 1, - $this->getPrefixedIdentifier('tag:' . $tag), - $this->getPrefixedIdentifier('') - ); + try { + return $this->client->eval( + $script, + 1, + $this->getPrefixedIdentifier('tag:' . $tag), + $this->getPrefixedIdentifier('') + ); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -252,36 +291,60 @@ public function flushByTags(array $tags): int */ public function findIdentifiersByTag(string $tag): array { - return $this->client->sMembers($this->getPrefixedIdentifier('tag:' . $tag)); + try { + return $this->client->sMembers($this->getPrefixedIdentifier('tag:' . $tag)); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } #[\ReturnTypeWillChange] public function current() { - return $this->get(substr($this->getEntryKeyspaceIterator()->current(), $this->entryKeyspaceIteratorKeyPrefixLength)); + try { + return $this->get(substr($this->getEntryKeyspaceIterator()->current(), $this->entryKeyspaceIteratorKeyPrefixLength)); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } #[\ReturnTypeWillChange] public function next() { - $this->getEntryKeyspaceIterator()->next(); + try { + $this->getEntryKeyspaceIterator()->next(); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } #[\ReturnTypeWillChange] public function key() { - return substr($this->getEntryKeyspaceIterator()->current(), $this->entryKeyspaceIteratorKeyPrefixLength); + try { + return substr($this->getEntryKeyspaceIterator()->current(), $this->entryKeyspaceIteratorKeyPrefixLength); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } public function valid(): bool { - return $this->getEntryKeyspaceIterator()->valid(); + try { + return $this->getEntryKeyspaceIterator()->valid(); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } #[\ReturnTypeWillChange] public function rewind() { - $this->getEntryKeyspaceIterator()->rewind(); + try { + $this->getEntryKeyspaceIterator()->rewind(); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -301,19 +364,23 @@ public function freeze(): void if ($this->isFrozen()) { throw new RuntimeException(sprintf('Cannot add or modify cache entry because the backend of cache "%s" is frozen.', $this->cacheIdentifier), 1574777766); } - do { - $entriesKey = $this->getPrefixedIdentifier('entries'); - $this->client->watch($entriesKey); - $entries = $this->client->lRange($entriesKey, 0, -1); - $this->client->multi(); - foreach ($entries as $entryIdentifier) { - $this->client->persist($this->getPrefixedIdentifier('entry:' . $entryIdentifier)); - } - $this->client->set($this->getPrefixedIdentifier('frozen'), '1'); - /** @var array|bool $result */ - $result = $this->client->exec(); - } while ($result === false); - $this->frozen = true; + try { + do { + $entriesKey = $this->getPrefixedIdentifier('entries'); + $this->client->watch($entriesKey); + $entries = $this->client->lRange($entriesKey, 0, -1); + $this->client->multi(); + foreach ($entries as $entryIdentifier) { + $this->client->persist($this->getPrefixedIdentifier('entry:' . $entryIdentifier)); + } + $this->client->set($this->getPrefixedIdentifier('frozen'), '1'); + /** @var array|bool $result */ + $result = $this->client->exec(); + } while ($result === false); + $this->frozen = true; + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); + } } /** @@ -323,10 +390,14 @@ public function freeze(): void */ public function isFrozen(): bool { - if (null === $this->frozen) { - $this->frozen = (bool)$this->client->exists($this->getPrefixedIdentifier('frozen')); + try { + if (null === $this->frozen) { + $this->frozen = (bool)$this->client->exists($this->getPrefixedIdentifier('frozen')); + } + return $this->frozen; + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); } - return $this->frozen; } /** @@ -418,6 +489,14 @@ public function setClient(Predis\Client $client = null): void } } + /** + * @param bool $deduplicateErrors + */ + public function setDeduplicateErrors($deduplicateErrors): void + { + $this->deduplicateErrors = (bool)$deduplicateErrors; + } + /** * @param string|bool $value * @return string|bool @@ -464,24 +543,28 @@ public function getStatus(): Result */ private function getRedisClient(): \Predis\Client { - $options = [ - 'parameters' => [ - 'database' => $this->database - ] - ]; - - if (!empty($this->password)) { - $options['parameters']['password'] = $this->password; - } + try { + $options = [ + 'parameters' => [ + 'database' => $this->database + ] + ]; + + if (!empty($this->password)) { + $options['parameters']['password'] = $this->password; + } - if ($this->sentinels !== []) { - $connectionParameters = $this->sentinels; - $options['replication'] = 'sentinel'; - $options['service'] = $this->service; - } else { - $connectionParameters = 'tcp://' . $this->hostname . ':' . $this->port; + if ($this->sentinels !== []) { + $connectionParameters = $this->sentinels; + $options['replication'] = 'sentinel'; + $options['service'] = $this->service; + } else { + $connectionParameters = 'tcp://' . $this->hostname . ':' . $this->port; + } + return new Predis\Client($connectionParameters, $options); + } catch (\Throwable $throwable) { + $this->handleThrowable($throwable); } - return new Predis\Client($connectionParameters, $options); } private function getEntryKeyspaceIterator() @@ -493,4 +576,16 @@ private function getEntryKeyspaceIterator() return $this->entryKeyspaceIterator; } + /** + * @throws \Throwable + */ + private function handleThrowable(\Throwable|\Exception $throwable): void + { + $messageHash = md5($throwable->getMessage()); + if (!$this->deduplicateErrors || !array_key_exists($messageHash, static::$loggedErrors)) { + $this->logger && $this->logger->error($this->throwableStorage->logThrowable($throwable), LogEnvironment::fromMethodName(__METHOD__)); + static::$loggedErrors[$messageHash] = true; + } + throw $throwable; + } } diff --git a/README.md b/README.md index 6cef11b..dc613de 100644 --- a/README.md +++ b/README.md @@ -70,9 +70,32 @@ Flow_Mvc_Routing_Resolve: Note that "service" is the name of your Redis cluster (which is "mymaster" in most default configurations). +## Logging + +This cache backend will log errors, such as connection timeouts or other +problems while communicating with the Redis servers. + +If a connection error occurs during a request, it is likely, that more errors of +the same type will happen. Therfore, those messages will, by default, be +de-duplicated: If the messages of an error is identical with one which already +has been logged during the current CLI / web request, it will not be logged +another time. + +You can disable de-duplication logged errors for debugging purposes by +setting the respective backend option to false: + +```yaml +Flow_Mvc_Routing_Route: + backend: 'Flownative\RedisSentinel\RedisBackend' + backendOptions: + database: 0 + … + deduplicateErrors: false +``` + ## Tests -You can adjust the host and port used in the functional tests using the +You can adjust the host and port used in the functional tests using the environment variables `REDIS_HOST` and `REDIS_PORT`; ## Credits From a241a5e594a378cee724335ca8cdb29729c614a6 Mon Sep 17 00:00:00 2001 From: Robert Lemke Date: Mon, 5 Sep 2022 15:09:04 +0200 Subject: [PATCH 2/4] Fix type declaration for PHP 7.4 compatibility --- Classes/RedisBackend.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Classes/RedisBackend.php b/Classes/RedisBackend.php index d6559b5..92c9755 100644 --- a/Classes/RedisBackend.php +++ b/Classes/RedisBackend.php @@ -579,7 +579,7 @@ private function getEntryKeyspaceIterator() /** * @throws \Throwable */ - private function handleThrowable(\Throwable|\Exception $throwable): void + private function handleThrowable(\Throwable $throwable): void { $messageHash = md5($throwable->getMessage()); if (!$this->deduplicateErrors || !array_key_exists($messageHash, static::$loggedErrors)) { From 0d434df32df5f049dc60b2931984edb817f57467 Mon Sep 17 00:00:00 2001 From: Robert Lemke Date: Tue, 6 Sep 2022 13:59:41 +0200 Subject: [PATCH 3/4] Support Redis passwords in functional tests --- README.md | 4 ++-- Tests/Functional/RedisBackendTest.php | 4 +++- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index dc613de..9da514e 100644 --- a/README.md +++ b/README.md @@ -95,8 +95,8 @@ Flow_Mvc_Routing_Route: ## Tests -You can adjust the host and port used in the functional tests using the -environment variables `REDIS_HOST` and `REDIS_PORT`; +You can adjust the host, port and password used in the functional tests +using the environment variables `REDIS_HOST`, `REDIS_PORT` and `REDIS_PASSWORD`. ## Credits diff --git a/Tests/Functional/RedisBackendTest.php b/Tests/Functional/RedisBackendTest.php index 0c5d955..1afffbe 100644 --- a/Tests/Functional/RedisBackendTest.php +++ b/Tests/Functional/RedisBackendTest.php @@ -50,6 +50,7 @@ protected function setUp(): void { $redisHost = getenv('REDIS_HOST') !== false ? getenv('REDIS_HOST') : '127.0.0.1'; $redisPort = (int)(getenv('REDIS_PORT') !== false ? getenv('REDIS_PORT') : '6379'); + $redisPassword = getenv('REDIS_PASSWORD') !== false ? getenv('REDIS_PASSWORD') : ''; try { if (!@fsockopen($redisHost, $redisPort)) { @@ -63,7 +64,8 @@ protected function setUp(): void [ 'hostname' => $redisHost, 'port' => $redisPort, - 'database' => 0 + 'password' => $redisPassword, + 'database' => 0, ] ); $this->cache = $this->createMock(FrontendInterface::class); From 3b3c21012c6cc5776aa103fc6e476907c87344aa Mon Sep 17 00:00:00 2001 From: Robert Lemke Date: Tue, 6 Sep 2022 14:05:13 +0200 Subject: [PATCH 4/4] Make error logging configurable --- Classes/RedisBackend.php | 15 +++++++++++++-- README.md | 12 ++++++++++++ 2 files changed, 25 insertions(+), 2 deletions(-) diff --git a/Classes/RedisBackend.php b/Classes/RedisBackend.php index 92c9755..e07e7db 100644 --- a/Classes/RedisBackend.php +++ b/Classes/RedisBackend.php @@ -53,6 +53,7 @@ class RedisBackend extends IndependentAbstractBackend implements TaggableBackend protected ?Iterator\Keyspace $entryKeyspaceIterator = null; protected int $entryKeyspaceIteratorKeyPrefixLength = 0; protected bool $deduplicateErrors = true; + protected bool $logErrors = true; protected static array $loggedErrors = []; @@ -65,7 +66,7 @@ public function __construct(EnvironmentConfiguration $environmentConfiguration, parent::__construct($environmentConfiguration, $options); $this->client = $this->getRedisClient(); - if (class_exists('Neos\Flow\Core\Bootstrap') && Bootstrap::$staticObjectManager instanceof ObjectManagerInterface) { + if ($this->logErrors && class_exists(Bootstrap::class) && Bootstrap::$staticObjectManager instanceof ObjectManagerInterface) { $this->logger = Bootstrap::$staticObjectManager->get(LoggerInterface::class); $this->throwableStorage = Bootstrap::$staticObjectManager->get(ThrowableStorageInterface::class); } @@ -497,6 +498,14 @@ public function setDeduplicateErrors($deduplicateErrors): void $this->deduplicateErrors = (bool)$deduplicateErrors; } + /** + * @param bool $logErrors + */ + public function setLogErrors(bool $logErrors): void + { + $this->logErrors = $logErrors; + } + /** * @param string|bool $value * @return string|bool @@ -583,7 +592,9 @@ private function handleThrowable(\Throwable $throwable): void { $messageHash = md5($throwable->getMessage()); if (!$this->deduplicateErrors || !array_key_exists($messageHash, static::$loggedErrors)) { - $this->logger && $this->logger->error($this->throwableStorage->logThrowable($throwable), LogEnvironment::fromMethodName(__METHOD__)); + if ($this->logErrors && $this->logger && $this->throwableStorage) { + $this->logger && $this->logger->error($this->throwableStorage->logThrowable($throwable), LogEnvironment::fromMethodName(__METHOD__)); + } static::$loggedErrors[$messageHash] = true; } throw $throwable; diff --git a/README.md b/README.md index 9da514e..aec9b35 100644 --- a/README.md +++ b/README.md @@ -93,6 +93,18 @@ Flow_Mvc_Routing_Route: deduplicateErrors: false ``` +If you don't want errors being logged – for example, because you log errors via +the MultiBackend – you can turn off logging for this cache backend: + +```yaml +Flow_Mvc_Routing_Route: + backend: 'Flownative\RedisSentinel\RedisBackend' + backendOptions: + database: 0 + … + logErrors: false +``` + ## Tests You can adjust the host, port and password used in the functional tests