fix: migrate legacy tests, log silent catches, harden test config, fix TOCTOU in deductCredits

.env.test.example

@@ -1,3 +1,58 @@
+# ── Test environment variables ─────────────────────────────────────────────
+#
+# Copy the vars you need into a local .env before running `npm test`
+# locally (CI already sets these directly in .github/workflows/ci.yml).
+#
+# config/index.ts's test-mode fallback (loadConfig(), src/config/index.ts)
+# no longer hardcodes real-looking credential values for the vars below —
+# DATABASE_URL, JWT_SECRET, and STELLAR_PLATFORM_SECRET now throw a clear
+# error if missing in test mode, rather than silently substituting a fake
+# secret (#475). Every other var listed here has a safe, non-secret
+# in-code default and only needs to be set if you want to override it.
+#
+# None of the values below are real credentials — they are placeholders/
+# examples only.
+
+NODE_ENV=test
+
+# ── Database (REQUIRED — no fallback) ──────────────────────────────────────
+# Point this at a disposable local/test Postgres instance.
+DATABASE_URL=postgresql://chainlearn_test:test_password@localhost:5432/chainlearn_test
+
+# ── Redis (optional — defaults to redis://localhost:6379) ─────────────────
+REDIS_URL=redis://localhost:6379
+
+# ── JWT (REQUIRED — no fallback) ───────────────────────────────────────────
+# Must be at least 64 characters (256 bits) and not contain
+# "change-in-production" or equal "your-secret-key" (see envSchema).
+# This example string is exactly that shape and is safe to use verbatim
+# for local test runs — it is not used anywhere outside test mode.
+JWT_SECRET=test-secret-key-that-is-at-least-sixty-four-characters-long-for-tests
+
+# ── Stellar ─────────────────────────────────────────────────────────────
+STELLAR_NETWORK=testnet
+# Optional — defaults to the public Stellar testnet endpoints below.
+STELLAR_HORIZON_URL=https://horizon-testnet.stellar.org
+STELLAR_SOROBAN_RPC_URL=https://soroban-testnet.stellar.org
+
+# REQUIRED — no fallback. Must be a valid Stellar secret key
+# (starts with "S", 56 chars, base32). Generate a throwaway testnet keypair,
+# e.g. via `stellar keys generate` or the Stellar Laboratory — never reuse a
+# mainnet or otherwise real secret here.
+STELLAR_PLATFORM_SECRET=SAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
+
+# Optional — any non-empty string works for tests that don't assert on the
+# on-chain contract itself; defaults to "CHANGE_ME_IN_TEST_ENV" if unset.
+STELLAR_QUIZ_CONTRACT_ID=CHANGE_ME_IN_TEST_ENV
+STELLAR_REWARD_CONTRACT_ID=CHANGE_ME_IN_TEST_ENV
+STELLAR_CREDENTIAL_CONTRACT_ID=CHANGE_ME_IN_TEST_ENV
+
+# ── Request body limits (optional — see src/config/index.ts for defaults) ─
+# REQUEST_BODY_LIMIT_BYTES=1048576
+# MULTIPART_BODY_LIMIT_BYTES=5242880
+# AVATAR_UPLOAD_MAX_BYTES=2097152
+# AVATAR_UPLOAD_DIR=uploads/avatars
+# PUBLIC_BASE_URL=http://localhost:3000
 # Test-only environment variables (#475).
 #
 # Copy this to .env.test and it's picked up automatically when

src/config/index.ts

@@ -119,11 +119,51 @@
 
 let _config: Env | null = null;
 
+// Test-mode-only placeholders for non-critical vars (contract IDs, public
+// testnet URLs) whose exact value doesn't matter for most tests. These are
+// deliberately NOT secret-shaped — "CHANGE_ME_IN_TEST_ENV" can never be
+// mistaken for a real credential — unlike the old hardcoded fallbacks this
+// replaces (#475).
+const TEST_MODE_NON_SECRET_DEFAULTS = {
+  STELLAR_HORIZON_URL: "https://horizon-testnet.stellar.org",
+  STELLAR_SOROBAN_RPC_URL: "https://soroban-testnet.stellar.org",
+  STELLAR_QUIZ_CONTRACT_ID: "CHANGE_ME_IN_TEST_ENV",
+  STELLAR_REWARD_CONTRACT_ID: "CHANGE_ME_IN_TEST_ENV",
+  STELLAR_CREDENTIAL_CONTRACT_ID: "CHANGE_ME_IN_TEST_ENV",
+} as const;
+
+// Vars that must NEVER fall back to a hardcoded value, even a fake-looking
+// one, because a real value is required for the app/tests to behave
+// meaningfully (a real DB, a JWT secret whose length actually matters for
+// signing, a Stellar secret key whose format is validated and used to
+// derive a real keypair). Missing one of these in test mode is a config
+// error, not something to paper over — loadConfig throws a clear message
+// naming exactly which var(s) are missing (#475). See .env.test.example.
+const REQUIRED_IN_TEST_MODE = [
+  "DATABASE_URL",
+  "JWT_SECRET",
+  "STELLAR_PLATFORM_SECRET",
+] as const;
+
 function loadConfig(): Env {
   const result = envSchema.safeParse(process.env);
   if (!result.success) {
     if (process.env.NODE_ENV === "test") {
+      const missingRequired = REQUIRED_IN_TEST_MODE.filter(
+        (key) => !process.env[key],
+      );
+      if (missingRequired.length > 0) {
+        throw new Error(
+          `Missing required test environment variable(s): ${missingRequired.join(", ")}. ` +
+            "No hardcoded fallback is used for these, even in test mode, so tests never " +
+            "silently run against a fake-but-real-looking secret. Copy the matching " +
+            "entries from .env.test.example into your local .env with real test values.",
+        );
+      }
+
       // In test mode, warn but don't exit — tests mock what they need.
+      // Merge with process.env so CI-provided values (DATABASE_URL, REDIS_URL, etc.)
+      // are preserved; only non-critical vars get obviously-fake test defaults.
       // Every field is passed through from process.env (populated above by
       // real environment variables, then .env.test, in that precedence)
       // consistently, not just the ones that happened to need a fallback —
@@ -135,6 +175,31 @@
         result.error.flatten().fieldErrors
       );
       return envSchema.parse({
+        DATABASE_URL: process.env.DATABASE_URL,
+        REDIS_URL: process.env.REDIS_URL || "redis://localhost:6379",
+        CORS_ORIGINS: process.env.CORS_ORIGINS,
+        JWT_SECRET: process.env.JWT_SECRET,
+        STELLAR_HORIZON_URL:
+          process.env.STELLAR_HORIZON_URL ||
+          TEST_MODE_NON_SECRET_DEFAULTS.STELLAR_HORIZON_URL,
+        STELLAR_SOROBAN_RPC_URL:
+          process.env.STELLAR_SOROBAN_RPC_URL ||
+          TEST_MODE_NON_SECRET_DEFAULTS.STELLAR_SOROBAN_RPC_URL,
+        STELLAR_PLATFORM_SECRET: process.env.STELLAR_PLATFORM_SECRET,
+        STELLAR_QUIZ_CONTRACT_ID:
+          process.env.STELLAR_QUIZ_CONTRACT_ID ||
+          TEST_MODE_NON_SECRET_DEFAULTS.STELLAR_QUIZ_CONTRACT_ID,
+        STELLAR_REWARD_CONTRACT_ID:
+          process.env.STELLAR_REWARD_CONTRACT_ID ||
+          TEST_MODE_NON_SECRET_DEFAULTS.STELLAR_REWARD_CONTRACT_ID,
+        STELLAR_CREDENTIAL_CONTRACT_ID:
+          process.env.STELLAR_CREDENTIAL_CONTRACT_ID ||
+          TEST_MODE_NON_SECRET_DEFAULTS.STELLAR_CREDENTIAL_CONTRACT_ID,
+        REQUEST_BODY_LIMIT_BYTES: process.env.REQUEST_BODY_LIMIT_BYTES,
+        MULTIPART_BODY_LIMIT_BYTES: process.env.MULTIPART_BODY_LIMIT_BYTES,
+        AVATAR_UPLOAD_MAX_BYTES: process.env.AVATAR_UPLOAD_MAX_BYTES,
+        AVATAR_UPLOAD_DIR: process.env.AVATAR_UPLOAD_DIR,
+        PUBLIC_BASE_URL: process.env.PUBLIC_BASE_URL,
         ...process.env,
         NODE_ENV: "test",
         DATABASE_URL: process.env.DATABASE_URL || TEST_FALLBACKS.DATABASE_URL,

src/modules/admin/admin-users.service.ts

@@ -175,6 +175,33 @@ export class AdminUsersService {
   /**
    * Deduct credits from a user — penalties, corrections, abuse prevention.
    *
+   * #476: this used to be a SELECT-then-UPDATE — read `credits`, check
+   * `credits >= amount` in application code, then a separate UPDATE wrote
+   * `credits - amount`. Between the SELECT and the UPDATE, a concurrent
+   * writer (another deduction, or a reward/grant credit) could change the
+   * balance, so by the time the UPDATE ran the check was stale: the UPDATE's
+   * WHERE clause didn't re-enforce sufficiency, so two concurrent deductions
+   * could both pass their (now-stale) check and together drive credits
+   * negative.
+   *
+   * Fixed the same way grantCredits already avoids the analogous race: one
+   * atomic UPDATE. The WHERE clause enforces `credits >= amount` at the
+   * database level (in addition to the id/not-deleted match), so Postgres's
+   * row lock for the UPDATE is what actually serializes concurrent
+   * deductions — there's no window between "check" and "act" because they're
+   * the same statement. If two deductions race for a balance that can only
+   * afford one of them, exactly one UPDATE matches the WHERE and returns a
+   * row; the other matches nothing and `returning` comes back empty.
+   *
+   * An empty `returning` is then ambiguous between "user doesn't exist /
+   * already soft-deleted" and "balance was insufficient" — the WHERE clause
+   * can't distinguish them, since both make zero rows match. Existence
+   * itself isn't racy the way the balance check was (nothing turns a valid
+   * userId into an invalid one mid-request, short of an admin racing this
+   * same call with a delete), so a preliminary `SELECT id` is safe and lets
+   * the error message be precise without reintroducing the TOCTOU: it can
+   * only ever make this method THROW SOONER on a case that would have
+   * failed anyway, never allow an over-deduction to slip through.
    * The balance check and the deduction are a single atomic UPDATE (#476):
    * `WHERE credits >= amount` guards the row itself, so a concurrent grant or
    * deduction between "check" and "act" can no longer let credits go
@@ -193,6 +220,21 @@ export class AdminUsersService {
     reference?: string,
     actorId?: string,
   ): Promise<CreditDeductResult> {
+    // Existence check only — not racy, see the note above. Deliberately
+    // does NOT read `credits` here: any balance read here would be exactly
+    // the stale value the atomic UPDATE below is written to not depend on.
+    const [existing] = await db
+      .select({ id: users.id })
+      .from(users)
+      .where(and(eq(users.id, userId), isNull(users.deletedAt)));
+
+    if (!existing) {
+      throw new NotFoundError("User");
+    }
+
+    // Single atomic UPDATE: the WHERE clause's `credits >= amount` guard is
+    // enforced by Postgres under the row lock the UPDATE takes, so there is
+    // no gap between checking the balance and acting on it.
     const [updated] = await db
       .update(users)
       .set({
@@ -203,6 +245,7 @@ export class AdminUsersService {
         and(
           eq(users.id, userId),
           isNull(users.deletedAt),
+          sql`${users.credits} >= ${amount}`,
           gte(users.credits, amount),
         ),
       )
@@ -212,6 +255,23 @@ export class AdminUsersService {
       });
 
     if (!updated) {
+      // The preliminary existence check above passed, so getting here means
+      // the WHERE guard's balance condition is what didn't match: the
+      // balance dropped below `amount` sometime between the existence check
+      // and this UPDATE (concurrent deduction) or was already insufficient.
+      // Re-read the current balance only for the error message — this read
+      // has no bearing on the deduction decision itself, which the atomic
+      // UPDATE above already made.
+      const [current] = await db
+        .select({ credits: users.credits })
+        .from(users)
+        .where(eq(users.id, userId));
+
+      throw new ValidationError({
+        amount: [
+          current
+            ? `Insufficient credits. User has ${current.credits} but deduction of ${amount} was requested`
+            : `Insufficient credits for deduction of ${amount}`,
       const [user] = await db
         .select({ credits: users.credits })
         .from(users)

src/modules/auth/auth.service.ts

@@ -147,6 +147,12 @@ export class AuthService {
     try {
       storedChallenge = JSON.parse(challengeData);
     } catch (err) {
+      // This is the server's own Redis-stored value, not client input, so
+      // a parse failure here is an internal anomaly worth tracking.
+      logger.warn(
+        { err, stellarAddress, challengeId },
+        "Corrupt stored SEP-10 challenge record",
+      );
       logger.debug({ err, stellarAddress }, "Stored challenge is not valid JSON");
       throw new UnauthorizedError("Corrupt stored challenge");
     }
@@ -163,6 +169,12 @@ export class AuthService {
         getNetworkPassphrase()
       ) as StellarSdk.Transaction;
     } catch (err) {
+      // Same as above — this decodes the server's own issued envelope, not
+      // client input, so a decode failure here is an internal anomaly.
+      logger.warn(
+        { err, stellarAddress, challengeId },
+        "Failed to decode server-issued SEP-10 challenge envelope",
+      );
       logger.debug({ err, stellarAddress }, "Stored challenge envelope failed to decode from XDR");
       throw new UnauthorizedError("Corrupt stored challenge");
     }

src/modules/auth/refresh-token.service.ts

@@ -188,6 +188,13 @@ export async function revokeRefreshToken(token: string): Promise<void> {
     await revokeRefreshFamily(record.familyId, "logout");
   } catch (err) {
     // Corrupt record — nothing more we can do, and logout still succeeds.
+    // Logged because a corrupt Redis record is an anomaly worth tracking
+    // (e.g. a serialization bug or bit rot), not an expected outcome. Not
+    // logging `raw` itself since it's a serialized auth record.
+    logger.warn(
+      { err, hash },
+      "Corrupt refresh token record encountered during logout revoke",
+    );
     logger.debug({ err }, "Could not revoke refresh token family on logout — corrupt record");
   }
 }

src/modules/courses/course.service.ts

@@ -750,6 +750,15 @@ export class CourseService {
             : "Enrolled successfully",
         });
       } catch (err) {
+        // Reported back to the caller in `results` below, so this isn't a
+        // silent swallow from the client's perspective — but it's still
+        // worth a warn here for operational visibility into which
+        // courses/reasons show up across batch requests (e.g. spotting a
+        // course that's failing for everyone).
+        logger.warn(
+          { err, userId, courseId },
+          "Batch enrollment: failed to enroll in one course",
+        );
         results.push({
           courseId,
           success: false,

src/modules/credentials/credential.service.ts

@@ -245,6 +245,14 @@ export class CredentialService {
           data,
         });
       } catch (err) {
+        // Reported back to the caller in `results` below, so this isn't a
+        // silent swallow from the client's perspective — but it's still
+        // worth a warn here for operational visibility into which
+        // courses/reasons show up across batch requests.
+        logger.warn(
+          { err, userId, courseId: submission.courseId, submissionId: submission.submissionId },
+          "Batch credential mint: failed to mint one credential",
+        );
         results.push({
           ...submission,
           success: false,

src/modules/rewards/reward.service.ts

@@ -77,6 +77,14 @@ async function handleBadSeqError(submissionId: string, stellarAddress: string):
     const account = await stellarClient.getAccount(stellarAddress);
     accountSeq = account.sequence;
   } catch (err) {
+    // Intentionally swallow error: sequence fetch is for debugging only —
+    // if Horizon is unavailable, we still want to mark the transaction as
+    // pending. Logged at warn (not error) since this is a best-effort
+    // diagnostic lookup, not the failure itself — the bad_seq warning below
+    // still fires either way.
+    logger.warn(
+      { err, submissionId },
+      "Could not fetch account sequence while handling bad_seq (debugging aid only)",
     // Intentionally swallow error: sequence fetch is for debugging only
     // If Horizon is unavailable, we still want to mark the transaction as pending
     logger.debug(
@@ -130,6 +138,10 @@ async function _executeStellarRewardClaim(claimData: RewardClaimData): Promise<s
     ) {
       return handleBadSeqError(claimData.submissionId, claimData.stellarAddress);
     }
+    logger.error(
+      { err, submissionId: claimData.submissionId, userId: claimData.userId },
+      "Stellar reward claim transaction failed",
+    );
     throw err;
   }
 }
@@ -224,6 +236,10 @@ export async function processRewardClaim(
     try {
       txHash = await _executeStellarRewardClaim(claimData);
     } catch (err: unknown) {
+      logger.error(
+        { err, submissionId, userId },
+        "Reward claim failed — marking submission as rewardFailed",
+      );
       await db
         .update(quizSubmissions)
         .set({ rewardPending: false, rewardFailed: true })

src/services/retry-queue.ts

@@ -244,6 +244,10 @@ export async function getQueuedRewardJobs(): Promise<QueuedRewardJob[]> {
       });
     } catch (err) {
       // Malformed entry — dequeueReadyBatch handles moving it to the DLQ;
+      // this is just a read-only introspection path so it skips rather
+      // than throwing. Still logged here since a malformed queue entry is
+      // an anomaly worth tracking even though it self-heals elsewhere.
+      logger.warn({ err }, "Skipped malformed reward retry queue entry");
       // this read-only view just can't render it, so log rather than
       // silently omitting it from what the caller sees.
       logger.warn({ err, index: i / 2 }, "Skipping malformed queue entry in getQueuedRewardJobs");

src/utils/resilience.ts

@@ -154,6 +154,11 @@ export function createCircuitBreaker(options: CircuitBreakerOptions): CircuitBre
       // or not — otherwise a persistent non-transient error (e.g. a 400 from
       // a corrupted account) would let unlimited probes through.
       if (state === CircuitState.HalfOpen || (err instanceof Error && isTransientError(err))) {
+        // recordFailure() itself logs when this pushes the circuit to Open
+        // (threshold reached, or the HalfOpen probe failed); this warn
+        // captures the underlying error for every failure, including the
+        // ones below threshold that recordFailure() doesn't log on its own.
+        logger.warn({ err, label, state }, "Circuit breaker recorded a failure");
         recordFailure();
       } else {
         halfOpenProbeInFlight = false;