fix(serenity): check retryOnQuota's shared deadline before every attempt

src/support/serenity/allocation-metrics.js

@@ -58,8 +58,10 @@
  *   shared deadline), or `abandoned` (a genuinely non-quota error cut the cycle short before
  *   either of the above — distinct from `exhausted` so a dashboard summing
  *   `recovered + exhausted + abandoned` as "total recovery cycles" doesn't silently undercount,
- *   per Alicia Adriani's review). `Attempt` (the 1-based attempt the cycle ended on) and
- *   `CallSite` (a small closed set — `publishProject`, `createProject`, `createOnePrompt`,
+ *   per Alicia Adriani's review). `Attempt` (the 1-based poll attempt the cycle ended on, or `0`
+ *   if the shared deadline was already exhausted before any poll attempt could even be made — see
+ *   `retryOnQuota`'s pre-attempt deadline check, adobe/spacecat-api-service#2882) and `CallSite`
+ *   (a small closed set — `publishProject`, `createProject`, `createOnePrompt`,
  *   `createPromptsByIds`, ...) together give the attempt-to-recovery distribution per write path,
  *   without which a rising `exhausted` rate or a shift toward later attempts is invisible until it
  *   becomes an incident (round-2 SRE review).
@@ -168,13 +170,15 @@ export function recordMeteredQuotaClassifier(matched) {
 
 /**
  * @param {'recovered'|'exhausted'|'abandoned'} outcome
- * @param {{ attempt: number, callSite: string }} dims - `attempt` is the 1-based attempt the
- *   poll-retry cycle resolved (recovered), gave up on (exhausted), or was cut short on by a
- *   non-quota error (abandoned); `callSite` is a short closed-vocabulary label identifying which
- *   wrapped write/publish this recovery was for. `attempt` is a raw number, not pre-bucketed — it
- *   stays low-cardinality only because `retryOnQuota`'s `maxAttempts` is small (3 today); if
- *   `maxAttempts` is ever raised significantly, revisit whether `Attempt` should be capped/bucketed
- *   to hold the module's low-cardinality dimension contract (see the module doc above).
+ * @param {{ attempt: number, callSite: string }} dims - `attempt` is the 1-based poll attempt the
+ *   cycle resolved (recovered), gave up on (exhausted), or was cut short on by a non-quota error
+ *   (abandoned) — OR `0` for `exhausted` specifically when the shared deadline was already blown
+ *   before any poll attempt could be made (adobe/spacecat-api-service#2882). `callSite` is a short
+ *   closed-vocabulary label identifying which wrapped write/publish this recovery was for.
+ *   `attempt` is a raw number, not pre-bucketed — it stays low-cardinality only because
+ *   `retryOnQuota`'s `maxAttempts` is small (3 today); if `maxAttempts` is ever raised
+ *   significantly, revisit whether `Attempt` should be capped/bucketed to hold the module's
+ *   low-cardinality dimension contract (see the module doc above).
  * @returns {void}
  */
 export function recordQuotaRetryOutcome(outcome, { attempt, callSite }) {

src/support/serenity/dynamic-allocation-active.js

@@ -151,9 +151,13 @@ export function createHeadroomGuard(transport, {
     // per-child lock contention (round-2 SRE review) — so `ensure()` is called exactly ONCE, up
     // front, and the actual fix is the WAIT between retries, not a repeated top-up.
     //
-    // Bounded by whichever comes first: `maxAttempts`, or the shared `requestDeadline` above. A
-    // non-metered error (or a second/subsequent metered error once bounded) propagates untouched —
-    // this never masks a genuinely non-retryable failure, it only spans the known settle lag.
+    // Bounded by whichever comes first: `maxAttempts`, or the shared `requestDeadline` above — the
+    // deadline is checked BEFORE every attempt (including the first poll attempt, not only between
+    // retries), so a slow `ensure()` call (e.g. queued behind other same-child recoveries on
+    // `withResourceLock`'s own safety valve) can't silently blow past the shared budget before the
+    // budget is ever consulted. A non-metered error (or a second/subsequent metered error once
+    // bounded) propagates untouched — this never masks a genuinely non-retryable failure, it only
+    // spans the known settle lag.
     retryOnQuota: async (fn, { callSite = 'unknown' } = {}) => {
       try {
         return await fn();
@@ -174,30 +178,40 @@ export function createHeadroomGuard(transport, {
           subWorkspaceId: childId, callSite,
         });
         await ensure({}, { includeDrafted: true });
-        let attempt = 1;
+        let attempt = 0;
+        let lastError = e;
         for (;;) {
+          // Checked BEFORE every attempt, including the first — an already-blown deadline (e.g.
+          // `ensure()` itself ate the whole budget queued behind another same-child recovery) must
+          // not spend a further `fn()` call on top of it. See the header comment above for why.
+          if (now() >= requestDeadline) {
+            recordQuotaRetryOutcome('exhausted', { attempt, callSite });
+            throw lastError;
+          }
+          attempt += 1;
           try {
             // eslint-disable-next-line no-await-in-loop
             const result = await fn();
             recordQuotaRetryOutcome('recovered', { attempt, callSite });
             return result;
           } catch (e2) {
             if (!isMeteredQuota(e2)) {
-              // A non-quota error mid-recovery still ENDS this cycle (Alicia Adriani review):
-              // record it as `abandoned` so a dashboard built on `recovered + exhausted +
-              // abandoned` as "total recovery cycles" doesn't silently undercount cycles cut
-              // short by an unrelated failure — distinct from `exhausted` (which specifically
-              // means "still a metered 405 after every attempt").
+              // A non-quota error mid-recovery still ENDS this cycle — `abandoned` is distinct
+              // from `exhausted` (still a metered 405 after every attempt) so a dashboard summing
+              // recovered+exhausted+abandoned as "total cycles" doesn't undercount.
               recordQuotaRetryOutcome('abandoned', { attempt, callSite });
               throw e2;
             }
-            if (attempt >= maxAttempts || now() >= requestDeadline) {
+            lastError = e2;
+            // Bail here too, BEFORE sleeping, if the sleep would itself run past the deadline —
+            // an unconditional sleep could otherwise overshoot the budget by up to a full
+            // `backoffMs` doing nothing useful.
+            if (attempt >= maxAttempts || now() + backoffMs >= requestDeadline) {
               recordQuotaRetryOutcome('exhausted', { attempt, callSite });
               throw e2;
             }
             // eslint-disable-next-line no-await-in-loop
             await sleep(backoffMs);
-            attempt += 1;
           }
         }
       }

test/support/serenity/dynamic-allocation-active.test.js

@@ -351,20 +351,22 @@ describe('dynamic-allocation-active — createHeadroomGuard.retryOnQuota', () =>
     expect(fn).to.have.callCount(2);
   });
 
-  it('ON, the shared deadline (not the attempt cap) stops retrying: exhausts after the deadline passes even with attempts still available', async () => {
-    // maxAttempts is generous, but `now()` is stubbed to jump straight past totalBudgetMs after the
-    // first poll attempt — the deadline, not the attempt count, must be what ends the loop (round-2
-    // SRE review: this is the seam that bounds a stacked-call-site request, not per-call attempts).
+  it('ON, the deadline takes priority OVER the attempt cap: exhausts after one poll attempt even though maxAttempts allows many more', async () => {
+    // maxAttempts is generous, but `now()` is stubbed to jump past totalBudgetMs right after the
+    // FIRST poll attempt's own deadline check — the deadline, not the attempt count, must be what
+    // ends the loop (round-2 SRE review: this is the seam that bounds a stacked-call-site request,
+    // not per-call attempts). The deadline is checked BEFORE every attempt (self-review finding):
+    // 1st `now()` call = guard construction; 2nd = the deadline check before poll attempt 1 (still
+    // within budget, so attempt 1 runs and fails); 3rd = the deadline check before poll attempt 2
+    // (now past budget, so it never runs).
     const t = makeTransport({
       child: resources(dimObj(0, 0, 0), dimObj(0, 0, 0)),
       master: resources(dimObj(0, 0, 100), dimObj(0, 0, 800)),
     });
     let callCount = 0;
     const now = () => {
       callCount += 1;
-      // 1st call: guard construction (t0). 2nd+ calls: inside the loop's deadline check — jump
-      // straight past the budget so the very first deadline check already fails.
-      return callCount <= 1 ? 0 : 1_000_000;
+      return callCount <= 2 ? 0 : 1_000_000;
     };
     const guard = createHeadroomGuard(
       t,
@@ -391,6 +393,56 @@ describe('dynamic-allocation-active — createHeadroomGuard.retryOnQuota', () =>
     expect(fn).to.have.callCount(2);
   });
 
+  it('ON, the deadline is checked BEFORE the very first poll attempt, not only between retries: a budget already blown by ensure() skips the attempt entirely', async () => {
+    // Checking the deadline only inside the catch (i.e. only after a poll attempt already failed)
+    // meant the first attempt always ran regardless of how long `ensure()` itself took. Simulate
+    // `ensure()` alone having consumed the whole budget (e.g. queued behind other same-child
+    // recoveries) — `now()` is already past the deadline by the time the loop's first check runs,
+    // so `fn()` must NOT be called again at all, the ORIGINAL triggering error (not a fabricated
+    // new one) propagates, and the metric records the `attempt: 0` case this closes (MysticatBot
+    // review).
+    const recordQuotaRetryOutcome = sinon.stub();
+    const { createHeadroomGuard: mockedCreateHeadroomGuard } = await esmock(
+      '../../../src/support/serenity/dynamic-allocation-active.js',
+      { '../../../src/support/serenity/allocation-metrics.js': { recordQuotaRetryOutcome } },
+    );
+    const t = makeTransport({
+      child: resources(dimObj(0, 0, 0), dimObj(0, 0, 0)),
+      master: resources(dimObj(0, 0, 100), dimObj(0, 0, 800)),
+    });
+    let nowCallCount = 0;
+    const now = () => {
+      nowCallCount += 1;
+      // 1st call: guard construction (t0=0, so requestDeadline=9000). Every call after that
+      // (i.e. the loop's pre-attempt check) reports as already far past the budget.
+      return nowCallCount <= 1 ? 0 : 1_000_000;
+    };
+    const guard = mockedCreateHeadroomGuard(
+      t,
+      {
+        enabled: true,
+        subWorkspaceId: CHILD,
+        parentWorkspaceId: MASTER,
+        retryOnQuota: fastRetry({ maxAttempts: 10, totalBudgetMs: 9000, now }),
+      },
+      log,
+    );
+    const initialError = quota405();
+    const fn = sinon.stub().rejects(initialError);
+    let caught;
+    try {
+      await guard.retryOnQuota(fn);
+    } catch (e) {
+      caught = e;
+    }
+    expect(caught).to.equal(initialError);
+    expect(fn).to.have.been.calledOnce; // only the initial call — no poll attempt was ever made
+    expect(recordQuotaRetryOutcome).to.have.been.calledOnceWith(
+      'exhausted',
+      { attempt: 0, callSite: 'unknown' },
+    );
+  });
+
   it('ON, the deadline is SHARED across two sequential retryOnQuota calls on the SAME guard, not recomputed per call (MysticatBot review)', async () => {
     // This is the PR's key design intent: one guard is built per inbound request, and every wrap
     // site sharing that guard instance (e.g. createProject -> createPromptsByIds ->
@@ -429,22 +481,20 @@ describe('dynamic-allocation-active — createHeadroomGuard.retryOnQuota', () =>
     // guard's budget, even though `maxAttempts: 10` would otherwise allow many more poll attempts.
     clock = 150;
 
-    // Call site B: if the deadline were shared (correct), it's already past — B exhausts on its
-    // very first poll attempt despite `maxAttempts: 10`. If a regression recomputed the deadline
-    // fresh inside this call (bug), B would get a full new 100ms budget from clock=150 and NOT
-    // exhaust here.
-    const lastError = quota405();
-    const fnB = sinon.stub();
-    fnB.onFirstCall().rejects(quota405());
-    fnB.onSecondCall().rejects(lastError);
+    // Call site B: if the deadline were shared (correct), it's already past — the deadline check
+    // before B's first poll attempt fails immediately, so B never even gets a poll attempt, only
+    // its initial call. If a regression recomputed the deadline fresh inside this call (bug), B
+    // would get a full new 100ms budget from clock=150 and NOT exhaust here.
+    const initialErrorB = quota405();
+    const fnB = sinon.stub().rejects(initialErrorB);
     let caught;
     try {
       await guard.retryOnQuota(fnB, { callSite: 'B' });
     } catch (e) {
       caught = e;
     }
-    expect(caught).to.equal(lastError);
-    expect(fnB).to.have.callCount(2);
+    expect(caught).to.equal(initialErrorB);
+    expect(fnB).to.have.been.calledOnce;
   });
 
   it('ON, the recovery ensure() itself throws (e.g. org pool exhausted): that error propagates and fn is NOT retried', async () => {
@@ -625,6 +675,64 @@ describe('dynamic-allocation-active — retryOnQuota emits QuotaRetryOutcome (My
     );
   });
 
+  it('ON, a sleep that WOULD overshoot the deadline is skipped entirely: bails at the current attempt instead of sleeping uselessly (Alicia Adriani review)', async () => {
+    // Sequence of now() calls: 1st = construction (t0=0, budget=1000 => deadline=1000). 2nd = the
+    // pre-attempt check before poll attempt 1 (still within budget). 3rd = the pre-sleep check
+    // after poll attempt 1 fails: now()=950, backoffMs=3000 => 950+3000=3950 >= 1000 — sleeping
+    // would badly overshoot the deadline, so the fix must bail HERE, without ever calling sleep,
+    // rather than sleeping the full 3000ms only to bail at the next loop-top check anyway.
+    const recordQuotaRetryOutcome = sinon.stub();
+    const { createHeadroomGuard: mockedCreateHeadroomGuard } = await esmock(
+      '../../../src/support/serenity/dynamic-allocation-active.js',
+      { '../../../src/support/serenity/allocation-metrics.js': { recordQuotaRetryOutcome } },
+    );
+    const t = makeTransport({
+      child: resources(dimObj(0, 0, 0), dimObj(0, 0, 0)),
+      master: resources(dimObj(0, 0, 100), dimObj(0, 0, 800)),
+    });
+    let nowCallCount = 0;
+    const now = () => {
+      nowCallCount += 1;
+      if (nowCallCount === 1) {
+        return 0; // construction
+      }
+      if (nowCallCount === 2) {
+        return 100; // pre-attempt check before poll attempt 1
+      }
+      return 950; // pre-sleep check after poll attempt 1 fails
+    };
+    const sleep = sinon.stub().resolves();
+    const guard = mockedCreateHeadroomGuard(
+      t,
+      {
+        enabled: true,
+        subWorkspaceId: CHILD,
+        parentWorkspaceId: MASTER,
+        retryOnQuota: {
+          maxAttempts: 5, backoffMs: 3000, totalBudgetMs: 1000, now, sleep,
+        },
+      },
+      log,
+    );
+    const lastError = quota405();
+    const fn = sinon.stub();
+    fn.onCall(0).rejects(quota405());
+    fn.onCall(1).rejects(lastError);
+    let caught;
+    try {
+      await guard.retryOnQuota(fn, { callSite: 'publishProject' });
+    } catch (e) {
+      caught = e;
+    }
+    expect(caught).to.equal(lastError);
+    expect(fn).to.have.callCount(2); // initial call + exactly one poll attempt
+    expect(sleep).to.not.have.been.called;
+    expect(recordQuotaRetryOutcome).to.have.been.calledOnceWith(
+      'exhausted',
+      { attempt: 1, callSite: 'publishProject' },
+    );
+  });
+
   it('sleep(backoffMs) is actually invoked between poll attempts, not skipped — catches a regression that drops the await', async () => {
     const recordQuotaRetryOutcome = sinon.stub();
     const { createHeadroomGuard: mockedCreateHeadroomGuard } = await esmock(