feat(billing): operational maturity — runbooks, stale cache, structured logs (Étape 4) (#3613)

* feat(billing): operational maturity — runbooks, stale cache, structured logs (Étape 4)

A — RUNBOOKS.md: 5 operational runbooks (dispute, dead-letter, meter mismatch,
    LIVE rollout checklist, Stripe API down fallback) with real endpoint refs.
B — STRIPE_SETUP.md: 10 webhook events, Smart Retries, extras forfeit policy,
    5-year FR retention, tax_id B2B EU setup.
C.1 — getPlans stale-while-revalidate: fresh TTL 5min, stale TTL 24h,
    emits billing.plans.stale on Stripe error fallback.
C.2 — Crons: replace console.* with structured logger in all 4 crons
    (dunningSweep, weeklyReset, extrasExpiration, reconcile) with
    entry/exit timing and contextual fields.
C.3 — billing.usage.service: replace console.warn/error with logger on
    hot path (extras debit failure, threshold mark failure, unsupported threshold)
    including organizationId + idempotencyKey for traceability.
Tests: +3 stale-while-revalidate unit tests; fix logger mock in 4 test files
    that transitively import billing.plans.service (billing.plans, billing.usage.service,
    billing.service.extras, billing.usageHeader); update console.warn spy →
    logger.warn in 2 existing tests.

* test(billing): cover extras debit unexpectedly-not-applied logger.error branch

Add test for the `debitResult.applied === false && reason !== 'duplicate_step'`
path in incrementMeter to bring patch coverage to 100% on new code.

* fix(billing): critical-review findings — TTL precision + mock isolation + runbook clarity

- billing.plans.service: use Date.now() inline in catch (not captured now)
  to account for Stripe round-trip latency at the 24h stale boundary
- billing.plans.unit.tests: wrap all Date.now manual mocks in try/finally
  so restore always runs even when an assertion fails (mock-leak fix)
- RUNBOOKS.md #4: smoke test must use TEST keys + test card; add warning
  that test cards are rejected against LIVE keys (false-pass prevention)

* fix(billing/crons): structured error serialization + applyJitter inside try

Per Copilot review:
- Replace `{ err }` (serializes to {}) with `{ err: err?.message, stack: err?.stack }`
  in all 4 cron fatal/per-item error log calls.
- Move `await applyJitter(...)` inside `try` block in weeklyReset + reconcile
  so jitter failures are caught by the structured `[cron.X] failed` handler.

Author: PierreBrisorgueil

modules/billing/RUNBOOKS.md

@@ -0,0 +1,140 @@
+# Billing Runbooks
+
+Operational runbooks for the billing module. Each runbook references real endpoints — see `modules/billing/routes/billing.admin.routes.js` for auth requirements (JWT admin token required for all `/api/admin/*` routes).
+
+---
+
+## 1 — Stripe Dispute
+
+**Context**: Stripe gives 7 calendar days from dispute creation to submit evidence. Missing the window results in an automatic loss. `billing.dispute.opened` fires an ntfy alert on day 1. The dispute funds are held by Stripe immediately on `charge.dispute.funds_withdrawn`.
+
+**Steps**:
+
+1. Confirm dispute in Stripe Dashboard → Radar → Disputes. Note the `charge_id` and `dispute_id`.
+2. Retrieve customer state to verify DB-side ledger matches Stripe:
+   ```
+   GET /api/admin/billing/customer/:orgId
+   ```
+   Confirm `stripeStatus` matches `subscription.status` in DB.
+3. If the dispute is fraudulent (stolen card), cancel the subscription immediately:
+   ```
+   POST /api/admin/billing/cancel/:orgId
+   ```
+4. Gather evidence in Stripe Dashboard: usage records, signup email, ToS acceptance timestamp, IP logs.
+5. Submit evidence before day 7 via Stripe Dashboard → Dispute → Submit evidence.
+6. If dispute won (`charge.dispute.funds_reinstated` received): verify the extras credit was re-applied by re-checking the ledger via `GET /api/admin/billing/customer/:orgId`.
+7. If dispute lost: extras balance debited by `charge.dispute.funds_withdrawn` is not refunded — log in incident tracker.
+
+---
+
+## 2 — Dead-Letter Investigation
+
+**Context**: Stripe webhook events that fail processing 3+ times (or where the idempotency guard fires on a poisoned payload) are marked `deadLetter: true` in `processedStripeEvents`. They accumulate and must be reviewed manually — partial TTL index excludes them from auto-expiry.
+
+**Steps**:
+
+1. List all dead-letter events:
+   ```
+   GET /api/admin/billing/dead-letters
+   ```
+   Response includes `eventId`, `type`, `createdAt`, `lastError` for each.
+
+2. For each suspicious event, attempt replay (re-fetches event from Stripe API, re-dispatches through the webhook pipeline):
+   ```
+   POST /api/admin/billing/webhook/replay
+   Body: { "eventId": "evt_xxx" }
+   ```
+   On success: the event is re-processed and the `deadLetter` flag cleared automatically.
+
+3. If replay succeeds but state is still inconsistent (e.g. subscription not updated), force a DB sync from Stripe:
+   ```
+   POST /api/admin/billing/sync/:orgId
+   ```
+
+4. If the event is stale/unrecoverable (e.g. the subscription no longer exists in Stripe), purge it:
+   ```
+   DELETE /api/admin/billing/dead-letters/:eventId
+   ```
+
+5. If the same event type keeps dead-lettering: check `lastError` for the root cause, open a fix issue, and monitor the next occurrence before purging.
+
+---
+
+## 3 — Meter Mismatch
+
+**Context**: `billing.reconcile` cron (Sundays 03:00 UTC) logs `billing.reconciliation.divergence` when Stripe subscription status or plan differs from the DB. Operations must investigate and resolve manually — no auto-fix to avoid masking bugs.
+
+**Steps**:
+
+1. Identify the divergence from the weekly reconciliation log:
+   ```
+   kubectl logs -n pierreb-projects job/billing-reconcile-<timestamp>
+   ```
+   Look for lines containing `divergence detected` — they include `orgId`, `stripeStatus`, `dbStatus`, `stripePlan`, `dbPlan`.
+
+2. Get the full customer state for the affected org:
+   ```
+   GET /api/admin/billing/customer/:orgId
+   ```
+   Compare `stripeSnapshot` (live from Stripe API) vs `dbSnapshot` (local DB) fields.
+
+3. If Stripe is authoritative (e.g. subscription renewed but DB missed the webhook), sync Stripe → DB:
+   ```
+   POST /api/admin/billing/sync/:orgId
+   ```
+
+4. If the plan needs manual correction (e.g. plan bump after payment confirmation):
+   ```
+   PATCH /api/admin/billing/plans/bump
+   Body: { "orgId": "...", "planId": "pro", "reason": "manual reconciliation post-mismatch" }
+   ```
+
+5. Re-run `GET /api/admin/billing/customer/:orgId` to confirm `stripeSnapshot` and `dbSnapshot` now match.
+
+6. If mismatch persists after sync: open an incident, check dead-letter queue (Runbook #2), replay missing events.
+
+---
+
+## 4 — Stripe LIVE Rollout
+
+**Context**: Pre-live checklist before switching `STRIPE_SECRET_KEY` from `sk_test_*` to `sk_live_*` in production.
+
+**Pre-live checklist** (complete all before toggling):
+
+- [ ] Stripe Dashboard (LIVE mode): 10 webhook events enabled (see `STRIPE_SETUP.md`)
+- [ ] Stripe Dashboard (LIVE mode): Smart Retries enabled (Billing settings → Smart Retries)
+- [ ] Stripe Dashboard (LIVE mode): `tax_id` collection enabled in Checkout (B2B EU)
+- [ ] `STRIPE_SECRET_KEY` = `sk_live_*` set in K8s secret `trawl-node-env`
+- [ ] `STRIPE_WEBHOOK_SECRET` = `whsec_*` (LIVE mode endpoint secret) updated in K8s secret
+- [ ] `STRIPE_PRICE_*` env vars point to LIVE price IDs (not test price IDs)
+- [ ] All 4 CronJob manifests deployed: `trawl-billing-dunning-sweep`, `trawl-billing-weekly-reset`, `trawl-billing-extras-expiration`, `trawl-billing-reconcile`
+- [ ] Dead-letter queue empty: `GET /api/admin/billing/dead-letters` → 0 entries
+- [ ] Test mode webhooks drained: Stripe Dashboard → Webhooks → no pending test deliveries
+- [ ] Smoke test: in staging pointed at **TEST** Stripe keys (not LIVE), create a checkout session using Stripe test card `4242 4242 4242 4242` — confirm `checkout.session.completed` webhook received + subscription created in DB. Do **not** use test cards against LIVE keys (they are rejected; use this step to validate the integration flow, then cut over to LIVE keys for production)
+- [ ] Rollback plan documented: toggling `STRIPE_SECRET_KEY` back to test key is sufficient for rollback (no DB migration required)
+
+**Go/no-go gate**: all checkboxes ticked + at least 1 successful end-to-end checkout in staging with LIVE keys.
+
+---
+
+## 5 — Stripe API Down
+
+**Context**: When Stripe's API is unavailable, the billing module degrades gracefully rather than erroring. No revenue-blocking occurs for existing subscribers.
+
+**Behavior during outage**:
+
+- `GET /api/billing/plans` (`getPlans`): returns stale cache (up to 24h old) + emits `billing.plans.stale` event. After 24h stale TTL, throws — clients see a 503 but cannot subscribe anyway (checkout would fail at Stripe).
+- Incoming webhooks: Stripe's retry queue accumulates events and delivers them when connectivity is restored. No action required — events replay automatically via Stripe's retry schedule.
+- `POST /api/admin/billing/sync/:orgId`: fails with Stripe error — do not retry in a loop; wait for Stripe status page to confirm recovery.
+- `POST /api/admin/billing/webhook/replay`: fails if Stripe API unreachable (event re-fetch fails). Queue replays until recovery.
+- Meter usage (`incrementMeter`): continues working — no Stripe call on the hot path. Extras debit is DB-only.
+- Admin operations (`adminBumpPlan`, `adminCancelSubscription`): `adminBumpPlan` is DB-only and continues working. `adminCancelSubscription` calls `stripe.subscriptions.cancel` — will fail; retry after recovery.
+
+**Steps during outage**:
+
+1. Confirm Stripe outage via https://status.stripe.com — check if it is API-wide or specific to Webhooks/Dashboard.
+2. No action required for existing subscribers — their access is unaffected.
+3. Disable any scheduled marketing emails that reference plan upgrade CTAs to avoid confusing users who cannot checkout.
+4. Monitor `billing.plans.stale` event frequency — if the stale cache is 24h+, alert the on-call to decide whether to take the plans endpoint down entirely or serve a static fallback.
+5. Once Stripe recovers: `POST /api/admin/billing/sync/:orgId` on any org that attempted a subscription change during the outage.
+6. Check dead-letter queue for events that exhausted retries during the outage window: `GET /api/admin/billing/dead-letters`.

modules/billing/STRIPE_SETUP.md

@@ -0,0 +1,72 @@
+# Stripe Dashboard Setup
+
+Configuration steps required in the Stripe Dashboard before going LIVE. All steps apply to both test mode (staging validation) and LIVE mode (production).
+
+---
+
+## 1 — Webhook Events to Enable
+
+Navigate to: **Stripe Dashboard → Developers → Webhooks → [your endpoint] → Update details**
+
+Enable exactly these 10 events:
+
+| Event | Trigger |
+|---|---|
+| `checkout.session.completed` | User completes a checkout → subscription created |
+| `customer.subscription.created` | Stripe creates a subscription (also fires on checkout) |
+| `customer.subscription.updated` | Plan change, renewal, status change |
+| `customer.subscription.deleted` | Subscription cancelled or expired |
+| `invoice.payment_succeeded` | Successful invoice payment → renews subscription |
+| `invoice.payment_failed` | Failed invoice → triggers dunning flow |
+| `charge.refunded` | Refund issued → credits extras ledger |
+| `charge.dispute.created` | Dispute opened → 7-day evidence window starts |
+| `charge.dispute.funds_withdrawn` | Dispute funds held → debits extras balance |
+| `charge.dispute.funds_reinstated` | Dispute won → re-credits extras balance |
+
+No other events are required. Adding extra events without handlers results in dead-letter accumulation.
+
+---
+
+## 2 — Smart Retries
+
+Navigate to: **Stripe Dashboard → Settings → Billing → Smart Retries**
+
+Enable **Smart Retries**. Stripe uses ML to schedule retry attempts at the optimal time for each card. This reduces involuntary churn without requiring a custom retry schedule in the dunning cron.
+
+The dunning cron (`billing.dunningSweep`) activates 14 days after `pastDueSince` — coordinated with the default Smart Retries window of 7 days. If you extend Smart Retries beyond 7 days, adjust `billing.dunningThresholdDays` accordingly.
+
+---
+
+## 3 — Extras Cancel Policy
+
+**Policy**: topup extras packs are forfeited without refund on subscription cancellation.
+
+This is consistent with the ToS (Section CGU — Extras packs). No proration or partial refund is owed.
+
+**Stripe configuration**: no dashboard setting needed — the `adminCancelSubscription` endpoint handles cancel at period end and the extras balance is NOT refunded. The DB ledger retains the history for audit.
+
+---
+
+## 4 — Billing Data Retention
+
+**Obligation légale FR (LCB-FT + RGPD)**: billing data must be retained for **5 years** from the last transaction date.
+
+**Implementation**:
+- `BillingSubscription`, `BillingExtraBalance`, `BillingUsage`, `ProcessedStripeEvent` collections have no TTL on production data.
+- The `processedStripeEvents` TTL index (`expireAfterSeconds: 2592000` = 30 days) applies only to non-dead-letter events — processed events are safe to expire (the authoritative record is in Stripe). The ledger (`BillingExtraBalance`) is permanent.
+- On account deletion: **anonymize, do not delete** billing records. Replace `organizationId` reference with a tombstone ID, remove PII from the org record, retain the financial ledger for 5 years.
+- Stripe customer data: use `stripe.customers.del()` to delete the Stripe customer on account deletion. This satisfies RGPD right-to-erasure for Stripe-side PII. The local ledger rows (amount, date, plan) are not PII and must be retained.
+
+---
+
+## 5 — Tax ID Collection (B2B EU / FR)
+
+Navigate to: **Stripe Dashboard → Settings → Checkout → Tax ID collection**
+
+Enable **Tax ID collection** in Checkout.
+
+This allows EU B2B customers to enter their VAT number (`FR12345678901`) during checkout. Stripe validates the VAT ID via VIES and attaches it to the customer record.
+
+**Effect**: invoices generated by Stripe include the customer's VAT ID, making them eligible for VAT reversal (autoliquidation) under EU B2B rules — required for French B2B invoice compliance.
+
+No code change required — `billing.service.js` passes `allow_promotion_codes: true` to Checkout; `tax_id_collection` is a Dashboard-level toggle that Stripe applies automatically to all Checkout sessions.

modules/billing/crons/billing.dunningSweep.js

@@ -22,20 +22,25 @@ process.env.NODE_ENV = process.env.NODE_ENV || 'development';
 const [
   { default: config },
   { default: mongooseService },
+  { default: logger },
   { applyJitter },
   { getCronJitterMaxMs, getDunningThresholdDays },
 ] = await Promise.all([
   import('../../../config/index.js'),
   import('../../../lib/services/mongoose.js'),
+  import('../../../lib/services/logger.js'),
   import('../lib/billing.cron-utils.js'),
   import('../lib/billing.constants.js'),
 ]);
 
 if (!config?.billing?.meterMode) {
-  console.log('[billing.dunningSweep] meterMode disabled — skipping.');
+  logger.info('[cron.dunningSweep] meterMode disabled — skipping.');
   process.exit(0);
 }
 
+const startMs = Date.now();
+logger.info('[cron.dunningSweep] start');
+
 try {
   await applyJitter(getCronJitterMaxMs());
   await mongooseService.connect();
@@ -49,7 +54,7 @@ try {
   const threshold = new Date(now.getTime() - getDunningThresholdDays() * 24 * 60 * 60 * 1000);
 
   const staleSubs = await BillingSubscriptionRepository.findStaleDunning(threshold);
-  console.log(`[billing.dunningSweep] ${staleSubs.length} stale past_due subscription(s) found`);
+  logger.info('[cron.dunningSweep] stale past_due subscriptions found', { count: staleSubs.length });
 
   let processed = 0;
   let errors = 0;
@@ -59,7 +64,7 @@ try {
     try {
       const subscription = await BillingSubscriptionRepository.markUnpaid(String(sub._id), threshold);
       if (!subscription) {
-        console.log(`[billing.dunningSweep] sub ${sub._id} skipped — already recovered`);
+        logger.info('[cron.dunningSweep] sub skipped — already recovered', { subId: String(sub._id) });
         continue;
       }
 
@@ -68,22 +73,30 @@ try {
       } catch (orgErr) {
         // Compensation: Subscription is now unpaid but Org.plan update failed.
         // Log for manual reconciliation — do not revert Subscription status.
-        console.error('[billing.dunningSweep] Org plan sync failed (manual reconciliation required):', orgErr);
+        logger.error('[cron.dunningSweep] Org plan sync failed (manual reconciliation required)', {
+          subId: String(sub._id),
+          orgId: String(sub.organization),
+          err: orgErr?.message,
+          stack: orgErr?.stack,
+        });
         desyncErrors += 1;
       }
 
-      console.log(`[billing.dunningSweep] sub ${sub._id} → unpaid, org ${sub.organization} → free`);
+      logger.info('[cron.dunningSweep] sub transitioned to unpaid', {
+        subId: String(sub._id),
+        orgId: String(sub.organization),
+      });
       processed += 1;
     } catch (err) {
       errors += 1;
-      console.error(`[billing.dunningSweep] failed for sub ${sub._id}:`, err);
+      logger.error('[cron.dunningSweep] failed for sub', { subId: String(sub._id), err: err?.message, stack: err?.stack });
     }
   }
 
-  console.log(`[billing.dunningSweep] done — processed: ${processed}, errors: ${errors}, desyncErrors: ${desyncErrors}`);
+  logger.info('[cron.dunningSweep] complete', { processed, errors, desyncErrors, durationMs: Date.now() - startMs });
   process.exitCode = errors > 0 ? 1 : 0;
 } catch (err) {
-  console.error('[billing.dunningSweep] fatal:', err);
+  logger.error('[cron.dunningSweep] failed', { err: err?.message, stack: err?.stack });
   process.exitCode = 1;
 } finally {
   await mongooseService.disconnect?.();

modules/billing/crons/billing.extrasExpiration.js

@@ -17,20 +17,25 @@ process.env.NODE_ENV = process.env.NODE_ENV || 'development';
 const [
   { default: config },
   { default: mongooseService },
+  { default: logger },
   { applyJitter },
   { getCronJitterMaxMs },
 ] = await Promise.all([
   import('../../../config/index.js'),
   import('../../../lib/services/mongoose.js'),
+  import('../../../lib/services/logger.js'),
   import('../lib/billing.cron-utils.js'),
   import('../lib/billing.constants.js'),
 ]);
 
 if (!config?.billing?.meterMode) {
-  console.log('[billing.extrasExpiration] meterMode disabled — skipping.');
+  logger.info('[cron.extrasExpiration] meterMode disabled — skipping.');
   process.exit(0);
 }
 
+const startMs = Date.now();
+logger.info('[cron.extrasExpiration] start');
+
 try {
   await applyJitter(getCronJitterMaxMs());
   await mongooseService.connect();
@@ -50,18 +55,18 @@ try {
   for (const orgId of orgIds) {
     try {
       const added = await BillingExtraService.expireOldEntries(orgId);
-      console.log(`[billing.extrasExpiration] org ${orgId}: ${added} expiration entries added`);
+      logger.info('[cron.extrasExpiration] org processed', { orgId: String(orgId), entriesAdded: added });
       processed += 1;
     } catch (err) {
       errors += 1;
-      console.error(`[billing.extrasExpiration] expireOldEntries failed for org ${orgId}:`, err);
+      logger.error('[cron.extrasExpiration] expireOldEntries failed', { orgId: String(orgId), err: err?.message, stack: err?.stack });
     }
   }
 
-  console.log(`[billing.extrasExpiration] done — processed: ${processed}, errors: ${errors}`);
+  logger.info('[cron.extrasExpiration] complete', { processed, errors, durationMs: Date.now() - startMs });
   process.exitCode = errors > 0 ? 1 : 0;
 } catch (err) {
-  console.error('[billing.extrasExpiration] fatal:', err);
+  logger.error('[cron.extrasExpiration] failed', { err: err?.message, stack: err?.stack });
   process.exitCode = 1;
 } finally {
   await mongooseService.disconnect?.();

modules/billing/crons/billing.reconcile.js

@@ -20,23 +20,27 @@ process.env.NODE_ENV = process.env.NODE_ENV || 'development';
 const [
   { default: config },
   { default: mongooseService },
+  { default: logger },
   { applyJitter },
   { getCronJitterMaxMs },
 ] = await Promise.all([
   import('../../../config/index.js'),
   import('../../../lib/services/mongoose.js'),
+  import('../../../lib/services/logger.js'),
   import('../lib/billing.cron-utils.js'),
   import('../lib/billing.constants.js'),
 ]);
 
 if (!config?.billing?.meterMode) {
-  console.log('[billing.reconcile] meterMode disabled — skipping.');
+  logger.info('[cron.reconcile] meterMode disabled — skipping.');
   process.exit(0);
 }
 
-await applyJitter(getCronJitterMaxMs());
+const startMs = Date.now();
+logger.info('[cron.reconcile] start');
 
 try {
+  await applyJitter(getCronJitterMaxMs());
   await mongooseService.loadModels();
   await mongooseService.connect();
 
@@ -47,12 +51,10 @@ try {
   ]);
 
   const result = await BillingReconcileService.runReconciliation();
-  console.log(
-    `[billing.reconcile] done — checked: ${result.checked}, divergences: ${result.divergences}, errors: ${result.errors}`,
-  );
+  logger.info('[cron.reconcile] complete', { checked: result.checked, divergences: result.divergences, errors: result.errors, durationMs: Date.now() - startMs });
   process.exitCode = result.errors > 0 ? 1 : 0;
 } catch (err) {
-  console.error('[billing.reconcile] fatal:', err);
+  logger.error('[cron.reconcile] failed', { err: err?.message, stack: err?.stack });
   process.exitCode = 1;
 } finally {
   await mongooseService.disconnect?.();