Add retry logging and Symfony clock support, allow webmozart/assert 2 (0.1.1)

CHANGELOG.md

@@ -0,0 +1,15 @@
+# Changelog
+
+## 0.1.1
+
+- Allow `webmozart/assert` 2.x (`^1.11||^2.0`).
+- `RetryClient` takes an optional PSR-3 logger (`psr/log` is now required) and logs every retry,
+  and every retry prevented by `maxDuration`, at info level. Entries never contain the query
+  string or a body.
+- `Clock\SymfonyClockAdapter` lets `RetryClient` and `GenericRetryStrategy` use a Symfony clock
+  (requires `symfony/clock`).
+
+## 0.1.0
+
+PHP 8.2 to 8.5, method-aware retries, exceptions with status code and cause, string bodies,
+per-request encoders, lazy response decoding and test doubles. See [UPGRADE-0.1.md](UPGRADE-0.1.md).

README.md

@@ -193,9 +193,25 @@ $client = new RetryClient(
     ),
     maxRetries: 3,
     maxDuration: 70.0,
+    logger: $logger,
 );
 ```
 
+Pass a PSR-3 `logger` to have every retry logged at info level (and every retry the deadline
+prevents). Entries name method and path only, never the query string or a body; status code,
+retry count and delay are in the context.
+
+Waiting and the deadline go through `Api\Clock\ClockInterface` (`NativeClock` by default). To use
+a Symfony clock, e.g. the framework's `clock` service, wrap it in `SymfonyClockAdapter`:
+
+```php
+use Api\Clock\SymfonyClockAdapter;
+
+$clock = new SymfonyClockAdapter($symfonyClock); // requires symfony/clock
+
+new RetryClient($client, new GenericRetryStrategy(clock: $clock), clock: $clock);
+```
+
 ### Testing with Mocks
 
 `Api\Testing\MockClient` answers requests from a queue and records them, which is handy for
@@ -213,7 +229,7 @@ $client = new MockClient([
 self::assertCount(2, $client->requests());
 ```
 
-`Api\Clock\MockClock` advances its time on `sleep()` instead of waiting. Pass it to `RetryClient`
+`Api\Clock\MockClock` (or Symfony's `MockClock` through `SymfonyClockAdapter`) advances its time on `sleep()` instead of waiting. Pass it to `RetryClient`
 and `GenericRetryStrategy` to test retries without delays; `sleeps()` returns the waits.
 
 To test the `Client` itself without network access, wrap Symfony's `MockHttpClient` in a

composer.json

@@ -33,7 +33,8 @@
     "psr/http-client": "^1.0",
     "psr/http-factory": "^1.1",
     "psr/http-message": "^1.1||^2.0",
-    "webmozart/assert": "^1.11"
+    "psr/log": "^1.1||^2.0||^3.0",
+    "webmozart/assert": "^1.11||^2.0"
   },
   "require-dev": {
     "brianium/paratest": "^7.8.5",
@@ -45,6 +46,7 @@
     "phpstan/phpstan-phpunit": "^2.0",
     "phpunit/phpunit": "^11.5",
     "rector/rector": "^2.0",
+    "symfony/clock": "^6.4.13||^7.1",
     "symfony/http-client": "^6.4||^7.0",
     "tomasvotruba/cognitive-complexity": "^1.0",
     "tomasvotruba/type-coverage": "^2.0"
@@ -53,6 +55,7 @@
     "php-http/client-implementation": "*"
   },
   "suggest": {
-    "symfony/http-client": "PSR-18 client (Psr18Client) that also implements the PSR-17 factories"
+    "symfony/http-client": "PSR-18 client (Psr18Client) that also implements the PSR-17 factories",
+    "symfony/clock": "To use the Symfony clock (and its MockClock) for retry delays via SymfonyClockAdapter"
   }
 }

src/Api/Clock/SymfonyClockAdapter.php

@@ -0,0 +1,31 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Api\Clock;
+
+use Symfony\Component\Clock\ClockInterface as SymfonyClockInterface;
+
+/**
+ * Lets RetryClient and GenericRetryStrategy use a Symfony clock, e.g. the app's `clock`
+ * service, so retry delays follow Symfony's MockClock in tests. Requires symfony/clock.
+ *
+ * @see SymfonyClockAdapterTest
+ */
+final readonly class SymfonyClockAdapter implements ClockInterface
+{
+    public function __construct(
+        private SymfonyClockInterface $clock,
+    ) {
+    }
+
+    public function now(): \DateTimeImmutable
+    {
+        return $this->clock->now();
+    }
+
+    public function sleep(float $seconds): void
+    {
+        $this->clock->sleep($seconds);
+    }
+}

src/Api/Clock/SymfonyClockAdapterTest.php

@@ -0,0 +1,26 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Api\Clock;
+
+use PHPUnit\Framework\Attributes\CoversClass;
+use PHPUnit\Framework\Attributes\Group;
+use PHPUnit\Framework\TestCase;
+use Symfony\Component\Clock\MockClock as SymfonyMockClock;
+
+#[CoversClass(SymfonyClockAdapter::class)]
+#[Group('unit')]
+final class SymfonyClockAdapterTest extends TestCase
+{
+    public function test_it_delegates_to_the_symfony_clock(): void
+    {
+        $symfonyClock = new SymfonyMockClock('2026-10-25 12:00:00');
+        $clock = new SymfonyClockAdapter($symfonyClock);
+
+        $clock->sleep(1.5);
+
+        self::assertSame('2026-10-25 12:00:01.500000', $clock->now()->format('Y-m-d H:i:s.u'));
+        self::assertEquals($symfonyClock->now(), $clock->now());
+    }
+}

src/Api/RetryClient.php

@@ -6,12 +6,15 @@
 
 use Api\Clock\ClockInterface;
 use Api\Clock\NativeClock;
+use Api\Exception\RequestDescription;
 use Api\Exception\ResponseException;
 use Api\Exception\TransportException;
 use Api\Request\RequestInterface;
 use Api\Response\ResponseInterface;
 use Api\Retry\GenericRetryStrategy;
 use Api\Retry\RetryStrategyInterface;
+use Psr\Log\LoggerInterface;
+use Psr\Log\NullLogger;
 use Webmozart\Assert\Assert;
 
 /**
@@ -24,6 +27,9 @@
  * the deadline is not attempted and the last failure is thrown instead. Each single attempt
  * is bounded by the timeout of the underlying PSR-18 client.
  *
+ * Every retry, and every retry the deadline prevents, is logged at info level. Log entries
+ * name the method and path only, never the query string or a body.
+ *
  * @see RetryClientTest
  */
 final readonly class RetryClient implements ClientInterface
@@ -34,6 +40,7 @@ public function __construct(
         private int $maxRetries = 3,
         private ?float $maxDuration = null,
         private ClockInterface $clock = new NativeClock(),
+        private LoggerInterface $logger = new NullLogger(),
     ) {
         Assert::greaterThanEq($maxRetries, 0, 'maxRetries cannot be negative, %s given.');
         Assert::nullOrGreaterThan($maxDuration, 0.0, 'maxDuration must be greater than 0, %s given.');
@@ -48,13 +55,9 @@ public function request(RequestInterface $request): ResponseInterface
             try {
                 return $this->client->request($request);
             } catch (ResponseException|TransportException $failure) {
-                if ($retryCount >= $this->maxRetries) {
-                    throw $failure;
-                }
+                $delay = $this->delayBeforeRetry($request, $failure, ++$retryCount, $deadline);
 
-                $delay = $this->strategy->getDelay($request, $failure, ++$retryCount);
-
-                if (null === $delay || (null !== $deadline && $this->now() + $delay >= $deadline)) {
+                if (null === $delay) {
                     throw $failure;
                 }
 
@@ -63,6 +66,47 @@ public function request(RequestInterface $request): ResponseInterface
         }
     }
 
+    /**
+     * @return float|null seconds to wait, null when the failure must be thrown
+     */
+    private function delayBeforeRetry(RequestInterface $request, ResponseException|TransportException $failure, int $retryCount, ?float $deadline): ?float
+    {
+        if ($retryCount > $this->maxRetries) {
+            return null;
+        }
+
+        $delay = $this->strategy->getDelay($request, $failure, $retryCount);
+
+        if (null === $delay) {
+            return null;
+        }
+
+        if (null !== $deadline && $this->now() + $delay >= $deadline) {
+            $this->log('Not retrying "{request}" after {failure}: waiting {delay}s would pass the {max_duration}s deadline.', $request, $failure, $retryCount, $delay);
+
+            return null;
+        }
+
+        $this->log('Retrying "{request}" after {failure} in {delay}s (retry {retry} of {max_retries}).', $request, $failure, $retryCount, $delay);
+
+        return $delay;
+    }
+
+    private function log(string $message, RequestInterface $request, ResponseException|TransportException $failure, int $retryCount, float $delay): void
+    {
+        $statusCode = $failure instanceof ResponseException ? $failure->statusCode() : null;
+
+        $this->logger->info($message, [
+            'request' => RequestDescription::of($request),
+            'failure' => null === $statusCode ? 'a network error' : sprintf('HTTP %d', $statusCode),
+            'status_code' => $statusCode,
+            'retry' => $retryCount,
+            'max_retries' => $this->maxRetries,
+            'delay' => round($delay, 3),
+            'max_duration' => $this->maxDuration,
+        ]);
+    }
+
     private function now(): float
     {
         return (float) $this->clock->now()->format('U.u');

src/Api/RetryClientTest.php

@@ -17,6 +17,7 @@
 use PHPUnit\Framework\Attributes\Group;
 use PHPUnit\Framework\Attributes\UsesClass;
 use PHPUnit\Framework\TestCase;
+use Psr\Log\AbstractLogger;
 
 #[CoversClass(RetryClient::class)]
 #[UsesClass(GenericRetryStrategy::class)]
@@ -125,6 +126,47 @@ public function test_no_retry_is_attempted_past_the_deadline(): void
         }
     }
 
+    public function test_retries_are_logged_without_the_query_string(): void
+    {
+        $logger = new RecordingLogger();
+        $inner = new MockClient([new Response('', 503), new TransportException(new Request(Method::GET, 'items'), new \RuntimeException()), new Response('ok', 200)]);
+
+        $this->retryClient($inner, logger: $logger)->request(new Request(Method::GET, 'items?token=secret'));
+
+        self::assertSame([
+            ['info', 'Retrying "{request}" after {failure} in {delay}s (retry {retry} of {max_retries}).', ['request' => 'GET items', 'failure' => 'HTTP 503', 'status_code' => 503, 'retry' => 1, 'max_retries' => 3, 'delay' => 1.0, 'max_duration' => null]],
+            ['info', 'Retrying "{request}" after {failure} in {delay}s (retry {retry} of {max_retries}).', ['request' => 'GET items', 'failure' => 'a network error', 'status_code' => null, 'retry' => 2, 'max_retries' => 3, 'delay' => 2.0, 'max_duration' => null]],
+        ], $logger->records);
+    }
+
+    public function test_a_retry_prevented_by_the_deadline_is_logged(): void
+    {
+        $logger = new RecordingLogger();
+        $inner = new MockClient([new Response('', 503), new Response('', 503)]);
+
+        try {
+            $this->retryClient($inner, maxDuration: 2.5, logger: $logger)->request(new Request(Method::GET, 'items'));
+            self::fail('No exception thrown.');
+        } catch (ServerException) {
+            self::assertCount(2, $logger->records);
+            self::assertSame('Not retrying "{request}" after {failure}: waiting {delay}s would pass the {max_duration}s deadline.', $logger->records[1][1]);
+            self::assertSame(2.5, $logger->records[1][2]['max_duration']);
+        }
+    }
+
+    public function test_requests_that_are_not_retried_are_not_logged(): void
+    {
+        $logger = new RecordingLogger();
+        $inner = new MockClient([new Response('', 503)]);
+
+        try {
+            $this->retryClient($inner, logger: $logger)->request(new Request(Method::POST, 'items', ['a' => 1]));
+            self::fail('No exception thrown.');
+        } catch (ServerException) {
+            self::assertSame([], $logger->records);
+        }
+    }
+
     public function test_other_exceptions_are_not_retried(): void
     {
         $inner = new MockClient([new \LogicException('bug'), new Response('ok', 200)]);
@@ -142,14 +184,32 @@ public function test_negative_max_retries_are_rejected(): void
         $this->retryClient(new MockClient(), maxRetries: -1);
     }
 
-    private function retryClient(MockClient $inner, int $maxRetries = 3, ?float $maxDuration = null): RetryClient
+    private function retryClient(MockClient $inner, int $maxRetries = 3, ?float $maxDuration = null, ?RecordingLogger $logger = null): RetryClient
     {
         return new RetryClient(
             $inner,
             new GenericRetryStrategy(jitter: 0.0, clock: $this->clock),
             $maxRetries,
             $maxDuration,
             $this->clock,
+            $logger ?? new RecordingLogger(),
         );
     }
 }
+
+final class RecordingLogger extends AbstractLogger
+{
+    /** @var list<array{mixed, string, array<mixed>}> */
+    public array $records = [];
+
+    /**
+     * $message stays untyped: psr/log 1.x declares it without a type, and a typed override would be incompatible.
+     *
+     * @param string|\Stringable $message
+     * @param array<mixed>       $context
+     */
+    public function log($level, $message, array $context = []): void
+    {
+        $this->records[] = [$level, (string) $message, $context];
+    }
+}