feat: restored retrying of rate-limited Leantime requests

.env

@@ -25,8 +25,6 @@ APP_INVOICE_SUPPLIER_ACCOUNT=APP_INVOICE_SUPPLIER_ACCOUNT
 APP_INVOICE_EXTERNAL_RECEIVER_ACCOUNT=
 APP_INVOICE_DESCRIPTION_TEMPLATE="Spørgsmål vedrørende fakturaen rettes til %name%, %email%."
 APP_PROJECT_BILLING_DEFAULT_DESCRIPTION=
-APP_HTTP_CLIENT_RETRY_DELAY_MS=1000
-APP_HTTP_CLIENT_MAX_RETRIES=3
 EMAIL_FROM_ADDRESS=
 
 ###> itk-dev/openid-connect-bundle ###

CHANGELOG.md

@@ -8,6 +8,40 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+* [PR-327](https://github.com/itk-dev/economics/pull/327)
+  * Recorded where the 429s came from, since nothing here did and the answer is not in the data-api plugin.
+    Leantime core rate-limits every request in `app/Core/Middleware/RequestRateLimiter.php` (v3.9.7): the API
+    bucket defaults to **100 requests per 60 seconds, keyed on client IP**, and the 429 carries `Retry-After`
+    plus three `X-RateLimit-*` headers. It reaches `/APIData/API/…` because `IncomingRequest::isApiRequest()`
+    lowercases the URI and prefix-matches `/api`. It is disabled outright when `app.debug` is true, which is
+    why development never saw it. **What resolved the 429s was raising `LEAN_RATELIMIT_API` to 10000 on the
+    Leantime side**, not anything in this repository — a full sync cannot approach that.
+  * Respaced the `async` transport's `retry_strategy`. Three attempts was never the problem; 1s/2s/4s was, being
+    over before anything transient has had time to end. Now 10s, 30s, 90s, so the last attempt lands 130s after
+    the first failure — past a Leantime restart, a database failover, or a 60s rate-limit window. No wider than
+    that, because a page only queues its successor once it succeeds: a page waiting to be retried is the whole
+    entity type's sync waiting with it, against an hourly cron. This applies to every message on the transport,
+    not only the Leantime ones. PR-325 and PR-326 already narrowed the handlers so only a failure describing the
+    message itself is unrecoverable, which is what lets a transient failure reach the queue at all.
+  * A 4xx other than 408/423/425/429 now fails the message immediately instead of being retried three times to
+    arrive at the same answer — the endpoint returns 400 for a missing `type` or the retired `deleted`
+    parameter, and the retry budget cannot rewrite the request. This is the delete sync's only cover:
+    `sync-deleted` dispatches on the `sync` transport, which has no retry strategy, and it has to stay there —
+    what keeps `DELETED_TYPES` in child-before-parent order is the handlers running inline.
+  * Bounded Leantime requests with `timeout: 5` and `max_duration: 30` on a client of their own rather than on
+    `framework.http_client.default_options`, so nothing else inherits them. Symfony caps neither by default and
+    an uncapped request holds the worker forever, since `messenger:consume` only checks `--time-limit` between
+    messages. A scoped client cannot express this: scopes key on `base_uri`, and the Leantime one comes from the
+    `DataProvider` entity at runtime.
+  * Dropped `--failure-limit=1` from the supervisor's `messenger:consume`. `StopWorkerOnFailureLimitListener`
+    counts every `WorkerMessageFailedEvent`, which the worker dispatches for retryable failures too, so with one
+    worker configured the first transient error stopped it — now that a retry ladder exists, that is the wrong
+    thing to count.
+  * Considered and rejected throttling the client with a `ThrottlingHttpClient` over a rate limiter. Against the
+    configured 10000/min it would guard nothing, and it pauses inside the message handler, so the single worker
+    stops draining the queue while it waits. Retrying is also the layer that cannot read the `Retry-After`
+    Leantime sends — a transport retry strategy never sees the response — but the ladder above outlasts a 60s
+    window by its third attempt, so the header would not change the outcome.
 * [PR-335](https://github.com/itk-dev/economics/pull/335)
   * Stopped `projectRemovedFromDataProvider()` hard-deleting a project that a version, a project billing or a
     service agreement still points at. Each of those points back with a non-nullable, non-cascading foreign key,

config/packages/messenger.yaml

@@ -8,6 +8,20 @@ framework:
             # @see https://symfony.com/doc/current/messenger.html#transport-configuration
             async:
                 dsn: "%env(MESSENGER_TRANSPORT_DSN)%"
+                # Symfony's three attempts are the right number; 1s/2s/4s is the wrong spacing, over
+                # before anything transient has had time to end. Widened to 10s, 30s, 90s, so the
+                # last attempt lands 130s after the first failure — past a Leantime restart, a
+                # database failover, or a 60s rate-limit window.
+                #
+                # Not widened further: a page only queues its successor once it succeeds, so a page
+                # waiting to be retried is the whole entity type's sync waiting with it, against an
+                # hourly cron. This applies to every message on the transport, not only the Leantime
+                # ones — the handlers mark a failure unrecoverable only when it describes the message
+                # itself, so anything transient reaches the transport.
+                retry_strategy:
+                    max_retries: 3
+                    delay: 10000
+                    multiplier: 3
             # @see https://symfony.com/doc/current/messenger.html#saving-retrying-failed-messages
             failed:
                 dsn: "%env(MESSENGER_TRANSPORT_DSN_FAILED)%"

config/services.yaml

@@ -64,3 +64,26 @@ services:
     App\Command\SyncCommand:
         arguments:
             $monitoringUrl: "%env(string:SYNC_MONITORING_URL)%"
+
+    # A full sync makes hundreds of paged requests to one host, so the Leantime caller gets bounds of
+    # its own; framework.http_client.default_options stays untouched so nothing else inherits them.
+    #
+    # A scoped client cannot express this: scopes key on base_uri, and the Leantime base URI comes
+    # from the DataProvider entity at runtime, not from config.
+    #
+    # Deliberately not a RetryableHttpClient. Every Leantime fetch is driven by a message the async
+    # transport already retries, and retrying underneath the queue only hides the failure from it.
+    app.leantime.http_client:
+        class: Symfony\Contracts\HttpClient\HttpClientInterface
+        factory: ["@http_client", withOptions]
+        arguments:
+            # timeout is the idle gap between chunks, not the whole request, so 5s is generous for an
+            # API that answers in milliseconds. max_duration bounds one page; if a page ever needs
+            # longer, lower LeantimeApiService::LIMIT rather than raising this. Symfony caps neither
+            # by default, and an uncapped request holds the worker forever: messenger:consume only
+            # checks --time-limit between messages, never during one.
+            - { timeout: 5, max_duration: 30 }
+
+    App\Service\LeantimeApiService:
+        arguments:
+            $httpClient: "@app.leantime.http_client"

docker-compose.server.override.yml

@@ -31,10 +31,15 @@ services:
     restart: unless-stopped
     stop_grace_period: 20s
     environment:
-      - APP_SUPERVISOR_COMMAND=/app/bin/console messenger:consume --env=prod --no-debug --time-limit=900 --failure-limit=1 async
+      # No --failure-limit: StopWorkerOnFailureLimitListener counts every WorkerMessageFailedEvent,
+      # which the worker dispatches for retryable failures too, so a limit of 1 stopped the only
+      # worker on the first transient error rather than on anything final. --time-limit still recycles
+      # the process, and a message that genuinely fails ends up in the failed transport either way.
+      - APP_SUPERVISOR_COMMAND=/app/bin/console messenger:consume --env=prod --no-debug --time-limit=900 async
       - APP_SUPERVISOR_WORKERS=1
       - APP_SUPERVISOR_USER=deploy
-      # Sync job is rate limited by LeanTime API so it will take some time to complete.
+      # A backstop only: --time-limit above ends the process first, and the Leantime client caps a
+      # single request at max_duration: 30s, so nothing inside one message runs anywhere near this.
       - PHP_MAX_EXECUTION_TIME=1800
       - PHP_MEMORY_LIMIT=512M
       - PHP_TIMEZONE=UTC

src/MessageHandler/LeantimeDeleteHandler.php

@@ -4,14 +4,18 @@
 
 use App\Exception\NotFoundException;
 use App\Message\LeantimeDeleteMessage;
+use App\MessageHandler\Trait\RethrowsTransientHttpFailuresTrait;
 use App\Service\LeantimeApiService;
 use Psr\Log\LoggerInterface;
 use Symfony\Component\Messenger\Attribute\AsMessageHandler;
 use Symfony\Component\Messenger\Exception\UnrecoverableMessageHandlingException;
+use Symfony\Contracts\HttpClient\Exception\ClientExceptionInterface;
 
 #[AsMessageHandler]
 readonly class LeantimeDeleteHandler
 {
+    use RethrowsTransientHttpFailuresTrait;
+
     public function __construct(
         private LoggerInterface $logger,
         private LeantimeApiService $leantimeApiService,
@@ -36,6 +40,8 @@ public function __invoke(LeantimeDeleteMessage $message): void
                 $message->asyncJobQueue,
                 $message->deletedAfter,
             );
+        } catch (ClientExceptionInterface $e) {
+            $this->rethrowUnlessPermanent($e, $this->logger);
         } catch (NotFoundException|\TypeError $e) {
             // Narrow on purpose: see UpsertIssueHandler. Infrastructure failures must propagate.
             $this->logger->error($e->getMessage());

src/MessageHandler/LeantimeUpdateHandler.php

@@ -4,14 +4,18 @@
 
 use App\Exception\NotFoundException;
 use App\Message\LeantimeUpdateMessage;
+use App\MessageHandler\Trait\RethrowsTransientHttpFailuresTrait;
 use App\Service\LeantimeApiService;
 use Psr\Log\LoggerInterface;
 use Symfony\Component\Messenger\Attribute\AsMessageHandler;
 use Symfony\Component\Messenger\Exception\UnrecoverableMessageHandlingException;
+use Symfony\Contracts\HttpClient\Exception\ClientExceptionInterface;
 
 #[AsMessageHandler]
 readonly class LeantimeUpdateHandler
 {
+    use RethrowsTransientHttpFailuresTrait;
+
     public function __construct(
         private LoggerInterface $logger,
         private LeantimeApiService $leantimeApiService,
@@ -33,6 +37,8 @@ public function __invoke(LeantimeUpdateMessage $message): void
                 $message->modifiedAfter,
                 $message->disableModifiedAtCheck,
             );
+        } catch (ClientExceptionInterface $e) {
+            $this->rethrowUnlessPermanent($e, $this->logger);
         } catch (NotFoundException|\TypeError $e) {
             // Narrow on purpose: see UpsertIssueHandler. A page that fails because Leantime or the
             // database is unavailable must be retried, not dropped along with the pages after it.

src/MessageHandler/Trait/RethrowsTransientHttpFailuresTrait.php

@@ -0,0 +1,36 @@
+<?php
+
+namespace App\MessageHandler\Trait;
+
+use Psr\Log\LoggerInterface;
+use Symfony\Component\Messenger\Exception\UnrecoverableMessageHandlingException;
+use Symfony\Contracts\HttpClient\Exception\ClientExceptionInterface;
+
+/**
+ * Shared by the handlers that call Leantime directly, so the two agree on which 4xx is worth
+ * another attempt.
+ */
+trait RethrowsTransientHttpFailuresTrait
+{
+    /**
+     * The 4xx codes that mean "later" rather than "no". Everything else in the range describes the
+     * request itself, and the retry budget cannot change the request.
+     */
+    private const RETRY_LATER_STATUS_CODES = [408, 423, 425, 429];
+
+    /**
+     * @throws ClientExceptionInterface              when the request is worth repeating, so the
+     *                                               transport's retry strategy picks it up
+     * @throws UnrecoverableMessageHandlingException when it is not
+     */
+    private function rethrowUnlessPermanent(ClientExceptionInterface $e, LoggerInterface $logger): never
+    {
+        if (in_array($e->getResponse()->getStatusCode(), self::RETRY_LATER_STATUS_CODES, true)) {
+            throw $e;
+        }
+
+        $logger->error($e->getMessage());
+
+        throw new UnrecoverableMessageHandlingException($e->getMessage());
+    }
+}

tests/Integration/Service/LeantimeApiClientTest.php

@@ -0,0 +1,71 @@
+<?php
+
+namespace App\Tests\Integration\Service;
+
+use App\Service\LeantimeApiService;
+use Symfony\Bundle\FrameworkBundle\Test\KernelTestCase;
+use Symfony\Contracts\HttpClient\HttpClientInterface;
+
+/**
+ * Leantime is called from the message worker, and Symfony bounds neither the idle gap between chunks
+ * nor the total duration of a request by default. `messenger:consume` only checks `--time-limit`
+ * between messages, so an unbounded request holds the worker for as long as the other end keeps the
+ * socket open.
+ *
+ * What is pinned here is that the service is wired to a client of its own carrying those bounds. The
+ * numbers live in config/services.yaml and are read back with `bin/console debug:container`.
+ */
+class LeantimeApiClientTest extends KernelTestCase
+{
+    public function testLeantimeApiServiceDoesNotUseTheSharedClient(): void
+    {
+        self::bootKernel();
+
+        $this->assertNotSame(
+            self::getContainer()->get('http_client'),
+            $this->leantimeHttpClient(),
+            'Drop the explicit $httpClient argument and the service autowires the unbounded shared client.',
+        );
+    }
+
+    public function testLeantimeClientIsBounded(): void
+    {
+        $options = $this->defaultOptions($this->leantimeHttpClient());
+
+        $this->assertSame(5.0, (float) $options['timeout'], 'Idle gap between chunks.');
+        $this->assertSame(30.0, (float) $options['max_duration'], 'Whole request, one page.');
+    }
+
+    private function leantimeHttpClient(): HttpClientInterface
+    {
+        self::bootKernel();
+
+        $service = self::getContainer()->get(LeantimeApiService::class);
+        $client = (new \ReflectionProperty($service, 'httpClient'))->getValue($service);
+
+        $this->assertInstanceOf(HttpClientInterface::class, $client);
+
+        return $client;
+    }
+
+    /**
+     * The options the client was built with. Symfony's clients keep them in a `defaultOptions`
+     * property and its decorators hold the one they wrap in `client`, so walking the stack finds
+     * whichever layer carries them — the profiler wraps this one in test.
+     *
+     * @return array<string, mixed>
+     */
+    private function defaultOptions(HttpClientInterface $client): array
+    {
+        while (!property_exists($client, 'defaultOptions')) {
+            $this->assertTrue(property_exists($client, 'client'), 'No layer of the client carries default options.');
+
+            $inner = (new \ReflectionProperty($client, 'client'))->getValue($client);
+            $this->assertInstanceOf(HttpClientInterface::class, $inner);
+
+            $client = $inner;
+        }
+
+        return (new \ReflectionProperty($client, 'defaultOptions'))->getValue($client);
+    }
+}

tests/Unit/MessageHandler/LeantimeDeleteHandlerTest.php

@@ -8,10 +8,58 @@
 use App\Service\LeantimeApiService;
 use PHPUnit\Framework\TestCase;
 use Psr\Log\LoggerInterface;
+use Symfony\Component\HttpClient\Exception\ClientException;
+use Symfony\Component\HttpClient\MockHttpClient;
+use Symfony\Component\HttpClient\Response\MockResponse;
 use Symfony\Component\Messenger\Exception\UnrecoverableMessageHandlingException;
 
 class LeantimeDeleteHandlerTest extends TestCase
 {
+    /**
+     * The endpoint answers 400 to a missing `type` or the retired `deleted` parameter, and no amount
+     * of retrying rewrites the request.
+     */
+    public function testInvokeOnPermanentClientErrorThrowsUnrecoverable(): void
+    {
+        $message = new LeantimeDeleteMessage(LeantimeApiService::TIMESHEETS, 0, 100, 1, false, null);
+
+        $service = $this->createMock(LeantimeApiService::class);
+        $service->method('deleteAsJob')->willThrowException($this->clientException(400));
+
+        $handler = new LeantimeDeleteHandler($this->createMock(LoggerInterface::class), $service);
+
+        $this->expectException(UnrecoverableMessageHandlingException::class);
+        $handler($message);
+    }
+
+    public function testInvokeOnRateLimitPropagates(): void
+    {
+        $message = new LeantimeDeleteMessage(LeantimeApiService::TIMESHEETS, 0, 100, 1, false, null);
+
+        $service = $this->createMock(LeantimeApiService::class);
+        $service->method('deleteAsJob')->willThrowException($this->clientException(429));
+
+        $handler = new LeantimeDeleteHandler($this->createMock(LoggerInterface::class), $service);
+
+        try {
+            $handler($message);
+            $this->fail('Expected the rate limit to propagate.');
+        } catch (ClientException $e) {
+            $this->assertSame(429, $e->getResponse()->getStatusCode());
+        }
+    }
+
+    private function clientException(int $statusCode): ClientException
+    {
+        $client = new MockHttpClient(new MockResponse('', ['http_code' => $statusCode]));
+        $response = $client->request('POST', 'https://leantime.example.com/APIData/API/deleted');
+
+        // Reading the code settles the mock, so ClientException finds the info it formats from.
+        $response->getStatusCode();
+
+        return new ClientException($response);
+    }
+
     public function testInvokeCallsDeleteAsJob(): void
     {
         $deletedAfter = new \DateTime('2024-01-01');