diff --git a/CHANGELOG.md b/CHANGELOG.md new file mode 100644 index 0000000..c573bfc --- /dev/null +++ b/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). diff --git a/README.md b/README.md index ba727ff..165242a 100644 --- a/README.md +++ b/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 diff --git a/composer.json b/composer.json index b18456b..741b422 100644 --- a/composer.json +++ b/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" } } diff --git a/src/Api/Clock/SymfonyClockAdapter.php b/src/Api/Clock/SymfonyClockAdapter.php new file mode 100644 index 0000000..f30b68d --- /dev/null +++ b/src/Api/Clock/SymfonyClockAdapter.php @@ -0,0 +1,31 @@ +clock->now(); + } + + public function sleep(float $seconds): void + { + $this->clock->sleep($seconds); + } +} diff --git a/src/Api/Clock/SymfonyClockAdapterTest.php b/src/Api/Clock/SymfonyClockAdapterTest.php new file mode 100644 index 0000000..d3a3e39 --- /dev/null +++ b/src/Api/Clock/SymfonyClockAdapterTest.php @@ -0,0 +1,26 @@ +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()); + } +} diff --git a/src/Api/RetryClient.php b/src/Api/RetryClient.php index 3dd5164..bb3043d 100644 --- a/src/Api/RetryClient.php +++ b/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'); diff --git a/src/Api/RetryClientTest.php b/src/Api/RetryClientTest.php index 78ea772..3a1d4b8 100644 --- a/src/Api/RetryClientTest.php +++ b/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,7 +184,7 @@ 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, @@ -150,6 +192,24 @@ private function retryClient(MockClient $inner, int $maxRetries = 3, ?float $max $maxRetries, $maxDuration, $this->clock, + $logger ?? new RecordingLogger(), ); } } + +final class RecordingLogger extends AbstractLogger +{ + /** @var list}> */ + 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 $context + */ + public function log($level, $message, array $context = []): void + { + $this->records[] = [$level, (string) $message, $context]; + } +}