From 0648118cdb0087cca98bb0f9dea4625bd425ec16 Mon Sep 17 00:00:00 2001 From: Dread Date: Tue, 1 Sep 2026 13:56:55 -0700 Subject: [PATCH 1/4] fix(auth): never crash the api on an orphaned kratos identity; self-heal missing accounts MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit On 2026-09-01 every api replica crash-looped (restart count 10, CrashLoopBackOff 20:37–20:47Z) because of a single logged-in user. Root cause chain: - The Kratos after-registration web_hook runs with `response.parse: false`, so the identity is committed whether or not `/kratos/registration` managed to write the account. During the signup wave 26 registration writes failed with DuplicateKeyForPersistError and 13 with IbexError, leaving at least one identity (created 20:11:35Z) with a valid session and no Mongo account. - `sessionPublicContext` threw `mapError(CouldNotFindAccountFromKratosIdError)` for every request carrying that session. - `setGqlContext` is an async Express middleware with no error path, so the throw became an unhandled promise rejection, and Node 24 exits the process on those. The user's app retried on a timer, so all three replicas died within a second of each other, over and over. Changes: 1. `setGqlContext` moved to `servers/middlewares/gql-context.ts` and wrapped: an `AuthenticationError` from session resolution is answered as HTTP 200 with a GraphQL error (code NOT_AUTHENTICATED) because the federation router swallows non-2xx subgraph responses into SUBREQUEST_HTTP_ERROR; anything else is answered as a 500. The middleware never rejects. 2. `sessionPublicContext` repairs an orphaned identity in place: it loads the Kratos identity and re-runs `createAccountWithPhoneIdentifier` from its phone trait. If the identity has no phone or the write fails again, the original not-found error stands and is answered per (1). 3. `mapError` maps `CouldNotFindAccountFromKratosIdError` to `AuthenticationError` instead of the "unexpected error, please try again" catch-all, which invited the client to retry the request that crashed us. 4. The api entrypoint installs an `unhandledRejection` handler that logs and records the rejection instead of letting it end the process. 5. `parseRepositoryError` keeps the Mongo driver message on `DuplicateKeyForPersistError` so a failed write can be attributed to the index that collided (accounts.kratosUserId vs users.phone). Out of scope, follow-ups: switch the Kratos after-registration web_hook to `can_interrupt: true` (charts/flash values + deployments tf-module template) so a failed account write aborts the registration instead of committing an orphan; `ws-server` still calls `sessionPublicContext` unguarded. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01EtQzyzQ38thfC2F8BLK4u8 --- src/graphql/error-map.ts | 11 +- src/servers/graphql-main-server.ts | 71 ++----- src/servers/middlewares/gql-context.ts | 105 ++++++++++ src/servers/middlewares/session.ts | 69 ++++++- src/services/mongoose/utils.ts | 5 +- test/flash/unit/graphql/error-map.spec.ts | 16 +- .../servers/middlewares/gql-context.spec.ts | 139 +++++++++++++ .../unit/servers/middlewares/session.spec.ts | 193 ++++++++++++++++++ .../mongoose/parse-repository-error.spec.ts | 23 +++ 9 files changed, 572 insertions(+), 60 deletions(-) create mode 100644 src/servers/middlewares/gql-context.ts create mode 100644 test/flash/unit/servers/middlewares/gql-context.spec.ts create mode 100644 test/flash/unit/servers/middlewares/session.spec.ts create mode 100644 test/flash/unit/services/mongoose/parse-repository-error.spec.ts diff --git a/src/graphql/error-map.ts b/src/graphql/error-map.ts index 76c08a923..923085be6 100644 --- a/src/graphql/error-map.ts +++ b/src/graphql/error-map.ts @@ -1,5 +1,6 @@ import { ValidationError } from "@domain/shared" import { + AuthenticationError, TransactionRestrictedError, LightningPaymentError, NotFoundError, @@ -108,6 +109,15 @@ export const mapError = (error: ApplicationError): CustomApolloError => { message = `Account does not exist for id ${error.message}` return new NotFoundError({ message, logger: baseLogger }) + // A session whose Kratos identity has no account: the registration write + // failed after the identity was committed and could not be repaired. Not a + // transient fault the client should retry against — the session is + // unusable until an account exists, so it reads as unauthenticated rather + // than "unexpected error, please try again". + case "CouldNotFindAccountFromKratosIdError": + message = "No account is linked to this session" + return new AuthenticationError({ message, logger: baseLogger }) + case "CouldNotFindAccountFromUuidError": message = `Account does not exist for uuid ${error.message}` return new NotFoundError({ message, logger: baseLogger }) @@ -894,7 +904,6 @@ export const mapError = (error: ApplicationError): CustomApolloError => { case "InvalidCurrencyBaseAmountError": case "NoTransactionToUpdateError": case "BalanceLessThanZeroError": - case "CouldNotFindAccountFromKratosIdError": case "MissingPhoneError": case "InvalidUserId": case "InvalidLightningPaymentFlowBuilderStateError": diff --git a/src/servers/graphql-main-server.ts b/src/servers/graphql-main-server.ts index 697fe0bf6..61c76e080 100644 --- a/src/servers/graphql-main-server.ts +++ b/src/servers/graphql-main-server.ts @@ -1,6 +1,6 @@ import { applyMiddleware } from "graphql-middleware" -import { GALOY_API_PORT, UNSECURE_IP_FROM_REQUEST_OBJECT } from "@config" +import { GALOY_API_PORT } from "@config" import { AuthorizationError } from "@graphql/error" import { gqlMainSchema, mutationFields, queryFields } from "@graphql/public" @@ -10,17 +10,10 @@ import { baseLogger } from "@services/logger" import { setupMongoConnection } from "@services/mongodb" import { and, shield } from "graphql-shield" import { ShieldRule } from "graphql-shield/typings/types" -import { - ACCOUNT_USERNAME, - SemanticAttributes, - addAttributesToCurrentSpanAndPropagate, -} from "@services/tracing" - -import { NextFunction, Request, Response } from "express" +import { recordExceptionInCurrentSpan } from "@services/tracing" -import { parseIps } from "@domain/accounts-ips" import { apiKeyNestedFieldScopes } from "@domain/api-keys" -import { parseCashWalletClientCapabilities } from "@app/cash-wallet-cutover/client-capability" +import { ErrorLevel } from "@domain/shared" import { startApiKeyMetricsServer } from "./api-key-metrics" import { startApolloServerForAdminSchema } from "./graphql-admin-server" @@ -30,53 +23,9 @@ import { scopedApiKeyTypeField, startApolloServer, } from "./graphql-server" +import { setGqlContext } from "./middlewares/gql-context" import { walletIdMiddleware } from "./middlewares/wallet-id" -import { sessionPublicContext } from "./middlewares/session" - -const setGqlContext = async ( - req: Request, - res: Response, - next: NextFunction, -): Promise => { - const tokenPayload = req.token - - const ipString = UNSECURE_IP_FROM_REQUEST_OBJECT - ? req.ip - : req.headers["x-real-ip"] || req.headers["x-forwarded-for"] - - const ip = parseIps(ipString) - - const gqlContext = await sessionPublicContext({ - tokenPayload, - ip, - }) - const cashWalletClientCapabilities = parseCashWalletClientCapabilities(req.headers) - - req.gqlContext = { - ...gqlContext, - cashWalletClientCapabilities, - } - - return addAttributesToCurrentSpanAndPropagate( - { - "token.iss": tokenPayload?.iss, - "token.session_id": tokenPayload?.session_id, - "token.expires_at": tokenPayload?.expires_at, - [SemanticAttributes.HTTP_CLIENT_IP]: ip, - [SemanticAttributes.HTTP_USER_AGENT]: req.headers["user-agent"], - [ACCOUNT_USERNAME]: gqlContext?.domainAccount?.username, - [SemanticAttributes.ENDUSER_ID]: tokenPayload?.sub, - "cash_wallet.client_presentation": - cashWalletClientCapabilities.cashWalletPresentation, - "cash_wallet.client_usdt_supported": String( - cashWalletClientCapabilities.hasUsdtCashWalletSupport, - ), - }, - next, - ) -} - export async function startApolloServerForCoreSchema() { const authedQueryFields: { [key: string]: ShieldRule } = {} for (const key of Object.keys({ @@ -135,6 +84,18 @@ export async function startApolloServerForCoreSchema() { } if (require.main === module) { + // A rejected promise nobody awaits must be logged, not fatal: Node's default + // `--unhandled-rejections=throw` exits the whole api replica on one stray + // rejection (see setGqlContext for the 2026-09-01 crash loop). + process.on("unhandledRejection", (reason) => { + baseLogger.error({ reason }, "unhandledRejection") + recordExceptionInCurrentSpan({ + error: reason, + level: ErrorLevel.Critical, + fallbackMsg: "unhandledRejection", + }) + }) + setupMongoConnection(true) .then(async () => { // activateLndHealthCheck() diff --git a/src/servers/middlewares/gql-context.ts b/src/servers/middlewares/gql-context.ts new file mode 100644 index 000000000..a9927778e --- /dev/null +++ b/src/servers/middlewares/gql-context.ts @@ -0,0 +1,105 @@ +import { NextFunction, Request, Response } from "express" + +import { UNSECURE_IP_FROM_REQUEST_OBJECT } from "@config" + +import { parseCashWalletClientCapabilities } from "@app/cash-wallet-cutover/client-capability" +import { parseIps } from "@domain/accounts-ips" +import { ErrorLevel } from "@domain/shared" +import { AuthenticationError } from "@graphql/error" +import { baseLogger } from "@services/logger" +import { + ACCOUNT_USERNAME, + SemanticAttributes, + addAttributesToCurrentSpanAndPropagate, + recordExceptionInCurrentSpan, +} from "@services/tracing" + +import { sessionPublicContext } from "./session" + +// Express 4 does not catch a rejected async middleware. A throw while +// resolving the session used to surface as an unhandled rejection, and Node +// exits the process on those (`--unhandled-rejections=throw` is the default). +// On 2026-09-01 a single Kratos identity whose account write had failed was +// enough to crash every api replica on each request it made +// (CouldNotFindAccountFromKratosIdError out of sessionPublicContext). +// +// Nothing that happens while building the context may take the process down. +// A session that cannot be resolved is answered, not thrown. +// +// Response shape: same constraint as apiKeyRateLimitMiddleware — this /graphql +// server is a federation subgraph behind the Apollo router, which swallows any +// non-2xx subgraph response into an opaque SUBREQUEST_HTTP_ERROR. An +// unauthenticated session is therefore answered as HTTP 200 with a GraphQL +// error carrying a code the client can act on. Anything else is a genuine +// server fault and stays a 500. +export const setGqlContext = async ( + req: Request, + res: Response, + next: NextFunction, +): Promise => { + const tokenPayload = req.token + + const ipString = UNSECURE_IP_FROM_REQUEST_OBJECT + ? req.ip + : req.headers["x-real-ip"] || req.headers["x-forwarded-for"] + + const ip = parseIps(ipString) + + let gqlContext: Awaited> + try { + gqlContext = await sessionPublicContext({ + tokenPayload, + ip, + }) + } catch (err) { + const kratosUserId = tokenPayload?.sub + baseLogger.error({ err, kratosUserId }, "failed to build graphql context") + recordExceptionInCurrentSpan({ + error: err, + level: ErrorLevel.Critical, + attributes: { kratosUserId }, + fallbackMsg: "failed to build graphql context", + }) + + if (err instanceof AuthenticationError) { + res.status(200).json({ + data: null, + errors: [ + { + message: err.message, + extensions: { code: err.extensions.code }, + }, + ], + }) + return + } + + res.status(500).json({ error: "failed to build graphql context" }) + return + } + + const cashWalletClientCapabilities = parseCashWalletClientCapabilities(req.headers) + + req.gqlContext = { + ...gqlContext, + cashWalletClientCapabilities, + } + + return addAttributesToCurrentSpanAndPropagate( + { + "token.iss": tokenPayload?.iss, + "token.session_id": tokenPayload?.session_id, + "token.expires_at": tokenPayload?.expires_at, + [SemanticAttributes.HTTP_CLIENT_IP]: ip, + [SemanticAttributes.HTTP_USER_AGENT]: req.headers["user-agent"], + [ACCOUNT_USERNAME]: gqlContext?.domainAccount?.username, + [SemanticAttributes.ENDUSER_ID]: tokenPayload?.sub, + "cash_wallet.client_presentation": + cashWalletClientCapabilities.cashWalletPresentation, + "cash_wallet.client_usdt_supported": String( + cashWalletClientCapabilities.hasUsdtCashWalletSupport, + ), + }, + next, + ) +} diff --git a/src/servers/middlewares/session.ts b/src/servers/middlewares/session.ts index a7e7266db..61fad0135 100644 --- a/src/servers/middlewares/session.ts +++ b/src/servers/middlewares/session.ts @@ -5,15 +5,77 @@ import { DEFAULT_CASH_WALLET_CLIENT_CAPABILITIES } from "@app/cash-wallet-cutove import { recordExceptionInCurrentSpan } from "@services/tracing" import jsonwebtoken from "jsonwebtoken" +import { getDefaultAccountsConfig } from "@config" + import { mapError } from "@graphql/error-map" +import { createAccountWithPhoneIdentifier } from "@app/accounts" import { maybeExtendSession } from "@app/authentication" import { checkedToUserId } from "@domain/accounts" -import { ValidationError } from "@domain/shared" +import { CouldNotFindAccountFromKratosIdError } from "@domain/errors" +import { ErrorLevel, ValidationError } from "@domain/shared" +import { IdentityRepository } from "@services/kratos" import { baseLogger } from "@services/logger" import { UsersRepository } from "@services/mongoose" import { IbexError } from "@services/ibex/errors" +// The Kratos after-registration web_hook runs with `response.parse: false`: +// the identity is committed whether or not the api managed to write its +// account. A failed write (duplicate key, wallet provider down) therefore +// leaves a logged-in identity with no account, and every request it makes +// lands here. Re-run the registration write from the identity's own phone +// trait. If that is not possible the original not-found error stands and the +// caller answers it as "not authenticated" — it must never crash on it. +const repairOrphanedIdentity = async ({ + userId, + orphanError, + logger, +}: { + userId: UserId + orphanError: CouldNotFindAccountFromKratosIdError + logger: typeof baseLogger +}): Promise => { + const identity = await IdentityRepository().getIdentity(userId) + if (identity instanceof Error) { + logger.error( + { err: identity, kratosUserId: userId }, + "orphaned kratos identity: could not load identity", + ) + return orphanError + } + + if (!identity.phone) { + logger.error( + { kratosUserId: userId }, + "orphaned kratos identity: no phone trait to repair from", + ) + return orphanError + } + + const account = await createAccountWithPhoneIdentifier({ + newAccountInfo: { kratosUserId: userId, phone: identity.phone }, + config: getDefaultAccountsConfig(), + }) + if (account instanceof Error) { + recordExceptionInCurrentSpan({ + error: account, + level: ErrorLevel.Critical, + attributes: { kratosUserId: userId }, + }) + logger.error( + { err: account, kratosUserId: userId }, + "orphaned kratos identity: repair failed", + ) + return orphanError + } + + logger.warn( + { kratosUserId: userId, accountId: account.id }, + "orphaned kratos identity repaired", + ) + return account +} + export const sessionPublicContext = async ({ tokenPayload, ip, @@ -39,7 +101,10 @@ export const sessionPublicContext = async ({ if (!(maybeUserId instanceof ValidationError)) { const userId = maybeUserId - const account = await Accounts.getAccountFromUserId(userId) + let account = await Accounts.getAccountFromUserId(userId) + if (account instanceof CouldNotFindAccountFromKratosIdError) { + account = await repairOrphanedIdentity({ userId, orphanError: account, logger }) + } if (account instanceof Error) { throw mapError(account) } else { diff --git a/src/services/mongoose/utils.ts b/src/services/mongoose/utils.ts index 66ad1db3d..2410716b4 100644 --- a/src/services/mongoose/utils.ts +++ b/src/services/mongoose/utils.ts @@ -40,7 +40,10 @@ export const parseRepositoryError = (err: Error | string | unknown) => { return new InvalidDocumentIdForDbError() case match(KnownRepositoryErrorMessages.MongoDuplicateKeyForPersist): - return new DuplicateKeyForPersistError() + // Keep the driver message: it names the collection and index that + // collided, which is the only way to attribute a failed write after + // the fact (e.g. accounts.kratosUserId vs users.phone). + return new DuplicateKeyForPersistError(errMsg) default: return new UnknownRepositoryError(errMsg) diff --git a/test/flash/unit/graphql/error-map.spec.ts b/test/flash/unit/graphql/error-map.spec.ts index 85e8d37b2..dfa54467b 100644 --- a/test/flash/unit/graphql/error-map.spec.ts +++ b/test/flash/unit/graphql/error-map.spec.ts @@ -8,9 +8,23 @@ import { } from "@services/bridge/errors" import { IbexError, InsufficientIbexBalance } from "@services/ibex/errors" import { PhoneCountryNotAllowedError } from "@domain/users/errors" -import { InvalidPhoneNumber } from "@domain/errors" +import { CouldNotFindAccountFromKratosIdError, InvalidPhoneNumber } from "@domain/errors" describe("error-map", () => { + // A logged-in Kratos identity with no account (registration write failed + // after the identity was committed). It used to fall into the catch-all + // "unexpected error, please try again", which invites the client to retry + // the very request that crashed the api on 2026-09-01. + it("maps CouldNotFindAccountFromKratosIdError to NOT_AUTHENTICATED, not the catch-all", () => { + const result = mapError( + new CouldNotFindAccountFromKratosIdError("ebbe2b32-9a2e-4c77-80e4-5d7347c024bb"), + ) + + expect(result.extensions.code).toBe("NOT_AUTHENTICATED") + expect(result.message).toBe("No account is linked to this session") + expect(result.extensions.code).not.toBe("UNEXPECTED_CLIENT_ERROR") + }) + it("maps BridgeWithdrawalNotFoundError to BRIDGE_WITHDRAWAL_NOT_FOUND", () => { const result = mapError(new BridgeWithdrawalNotFoundError()) diff --git a/test/flash/unit/servers/middlewares/gql-context.spec.ts b/test/flash/unit/servers/middlewares/gql-context.spec.ts new file mode 100644 index 000000000..4c0bda8ff --- /dev/null +++ b/test/flash/unit/servers/middlewares/gql-context.spec.ts @@ -0,0 +1,139 @@ +import { NextFunction, Request, Response } from "express" + +import { AuthenticationError } from "@graphql/error" +import { setGqlContext } from "@servers/middlewares/gql-context" +import { sessionPublicContext } from "@servers/middlewares/session" +import { baseLogger } from "@services/logger" +import { recordExceptionInCurrentSpan } from "@services/tracing" + +jest.mock("@servers/middlewares/session", () => ({ + sessionPublicContext: jest.fn(), +})) + +jest.mock("@services/logger", () => ({ + baseLogger: { error: jest.fn(), warn: jest.fn(), info: jest.fn() }, +})) + +jest.mock("@services/tracing", () => ({ + ACCOUNT_USERNAME: "account.username", + SemanticAttributes: { + HTTP_CLIENT_IP: "http.client_ip", + HTTP_USER_AGENT: "http.user_agent", + ENDUSER_ID: "enduser.id", + }, + addAttributesToCurrentSpanAndPropagate: jest.fn((_attributes, fn) => fn()), + recordExceptionInCurrentSpan: jest.fn(), +})) + +const mockedSessionPublicContext = sessionPublicContext as jest.MockedFunction< + typeof sessionPublicContext +> +const mockedRecordException = recordExceptionInCurrentSpan as jest.MockedFunction< + typeof recordExceptionInCurrentSpan +> +const mockedLogger = baseLogger as unknown as { error: jest.Mock } + +const kratosUserId = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" + +const makeReq = () => + ({ + token: { sub: kratosUserId, iss: "galoy.io" }, + headers: { "x-real-ip": "203.0.113.7", "user-agent": "jest" }, + }) as unknown as Request & { gqlContext?: unknown } + +const makeRes = () => { + const res = { + status: jest.fn(), + json: jest.fn(), + } + res.status.mockReturnValue(res) + return res as unknown as Response & { status: jest.Mock; json: jest.Mock } +} + +describe("setGqlContext", () => { + let next: jest.MockedFunction + + beforeEach(() => { + mockedSessionPublicContext.mockReset() + mockedRecordException.mockReset() + mockedLogger.error.mockReset() + next = jest.fn() + }) + + it("attaches the resolved context and continues the chain", async () => { + const context = { + domainAccount: { username: "alice" }, + user: { id: kratosUserId }, + } + mockedSessionPublicContext.mockResolvedValue( + context as unknown as Awaited>, + ) + const req = makeReq() + const res = makeRes() + + await setGqlContext(req, res, next) + + expect(next).toHaveBeenCalled() + expect(req.gqlContext).toEqual( + expect.objectContaining({ + domainAccount: context.domainAccount, + cashWalletClientCapabilities: expect.any(Object), + }), + ) + expect(res.status).not.toHaveBeenCalled() + }) + + // The 2026-09-01 crash loop: one Kratos identity with no account rejected + // out of the async middleware, Express never caught it, and Node exited the + // replica on the unhandled rejection. The middleware must resolve — never + // reject — and answer the session as unauthenticated. + it("answers an unauthenticated session as a GraphQL error and does not reject", async () => { + const authError = new AuthenticationError({ + message: "No account is linked to this session", + logger: baseLogger, + }) + mockedSessionPublicContext.mockRejectedValue(authError) + const req = makeReq() + const res = makeRes() + + await expect(setGqlContext(req, res, next)).resolves.toBeUndefined() + + expect(next).not.toHaveBeenCalled() + expect(req.gqlContext).toBeUndefined() + // HTTP 200 + GraphQL error: the federation router swallows non-2xx + // subgraph responses into an opaque SUBREQUEST_HTTP_ERROR. + expect(res.status).toHaveBeenCalledWith(200) + expect(res.json).toHaveBeenCalledWith({ + data: null, + errors: [ + { + message: "No account is linked to this session", + extensions: { code: "NOT_AUTHENTICATED" }, + }, + ], + }) + expect(mockedLogger.error).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId }), + "failed to build graphql context", + ) + expect(mockedRecordException).toHaveBeenCalledWith( + expect.objectContaining({ error: authError }), + ) + }) + + it("answers any other failure as a 500 and does not reject", async () => { + const boom = new Error("kratos unreachable") + mockedSessionPublicContext.mockRejectedValue(boom) + const req = makeReq() + const res = makeRes() + + await expect(setGqlContext(req, res, next)).resolves.toBeUndefined() + + expect(next).not.toHaveBeenCalled() + expect(res.status).toHaveBeenCalledWith(500) + expect(res.json).toHaveBeenCalledWith({ error: "failed to build graphql context" }) + expect(mockedRecordException).toHaveBeenCalledWith( + expect.objectContaining({ error: boom }), + ) + }) +}) diff --git a/test/flash/unit/servers/middlewares/session.spec.ts b/test/flash/unit/servers/middlewares/session.spec.ts new file mode 100644 index 000000000..d21ca67a5 --- /dev/null +++ b/test/flash/unit/servers/middlewares/session.spec.ts @@ -0,0 +1,193 @@ +import { Accounts } from "@app" +import { createAccountWithPhoneIdentifier } from "@app/accounts" +import { + CouldNotFindAccountFromKratosIdError, + DuplicateKeyForPersistError, +} from "@domain/errors" +import { sessionPublicContext } from "@servers/middlewares/session" +import { IdentityRepository, UnknownKratosError } from "@services/kratos" +import { baseLogger } from "@services/logger" +import { UsersRepository } from "@services/mongoose" +import { recordExceptionInCurrentSpan } from "@services/tracing" + +jest.mock("@app", () => ({ + Accounts: { + getAccountFromUserId: jest.fn(), + updateAccountIPsInfo: jest.fn(), + }, + Transactions: { + getTransactionsMetadataByIds: jest.fn(), + }, +})) + +jest.mock("@app/accounts", () => ({ + createAccountWithPhoneIdentifier: jest.fn(), +})) + +jest.mock("@app/authentication", () => ({ + maybeExtendSession: jest.fn(), +})) + +jest.mock("@app/cash-wallet-cutover", () => ({ + DEFAULT_CASH_WALLET_CLIENT_CAPABILITIES: { + cashWalletPresentation: "legacy_compat", + hasUsdtCashWalletSupport: false, + }, +})) + +// Identity mapping is what is under test here, not the GraphQL error shape: +// pass domain errors through so the rejection can be asserted directly. +jest.mock("@graphql/error-map", () => ({ + mapError: jest.fn((err) => err), +})) + +jest.mock("@services/kratos", () => ({ + IdentityRepository: jest.fn(), + UnknownKratosError: class UnknownKratosError extends Error {}, +})) + +jest.mock("@services/mongoose", () => ({ + UsersRepository: jest.fn(), +})) + +jest.mock("@services/tracing", () => ({ + recordExceptionInCurrentSpan: jest.fn(), +})) + +jest.mock("@services/logger", () => { + const child = { error: jest.fn(), warn: jest.fn(), info: jest.fn() } + return { + baseLogger: { ...child, child: jest.fn(() => child) }, + } +}) + +const mockedGetAccount = Accounts.getAccountFromUserId as jest.MockedFunction< + typeof Accounts.getAccountFromUserId +> +const mockedCreateAccount = createAccountWithPhoneIdentifier as jest.MockedFunction< + typeof createAccountWithPhoneIdentifier +> +const mockedIdentityRepository = IdentityRepository as jest.MockedFunction< + typeof IdentityRepository +> +const mockedUsersRepository = UsersRepository as jest.MockedFunction< + typeof UsersRepository +> +const mockedRecordException = recordExceptionInCurrentSpan as jest.MockedFunction< + typeof recordExceptionInCurrentSpan +> +const childLogger = ( + baseLogger as unknown as { child: () => { warn: jest.Mock } } +).child() + +const kratosUserId = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" as UserId +const phone = "+2348012345678" as PhoneNumber +const ip = "203.0.113.7" as IpAddress + +const account = { + id: "6a972befef5ea964adc2548f", + kratosUserId, + username: "alice", +} as unknown as Account +const user = { id: kratosUserId, phone } as unknown as User + +const getIdentity = jest.fn() + +const tokenPayload = { sub: kratosUserId, session_id: "sess", expires_at: "later" } + +describe("sessionPublicContext", () => { + beforeEach(() => { + mockedGetAccount.mockReset() + mockedCreateAccount.mockReset() + mockedRecordException.mockReset() + getIdentity.mockReset() + childLogger.warn.mockReset() + mockedIdentityRepository.mockReturnValue({ + getIdentity, + } as unknown as ReturnType) + mockedUsersRepository.mockReturnValue({ + findById: jest.fn().mockResolvedValue(user), + } as unknown as ReturnType) + }) + + it("resolves an existing account without touching kratos", async () => { + mockedGetAccount.mockResolvedValue(account) + + const context = await sessionPublicContext({ tokenPayload, ip }) + + expect(context.domainAccount).toBe(account) + expect(context.user).toBe(user) + expect(mockedIdentityRepository).not.toHaveBeenCalled() + expect(mockedCreateAccount).not.toHaveBeenCalled() + }) + + it("leaves an anonymous subject without an account and without lookups", async () => { + const context = await sessionPublicContext({ + tokenPayload: { sub: "anon" }, + ip, + }) + + expect(context.domainAccount).toBeUndefined() + expect(context.user).toBeUndefined() + expect(mockedGetAccount).not.toHaveBeenCalled() + }) + + describe("orphaned kratos identity (identity committed, account write failed)", () => { + const orphan = new CouldNotFindAccountFromKratosIdError(kratosUserId) + + beforeEach(() => { + mockedGetAccount.mockResolvedValue(orphan) + }) + + it("repairs it from the identity's phone trait and continues as that account", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + mockedCreateAccount.mockResolvedValue(account) + + const context = await sessionPublicContext({ tokenPayload, ip }) + + expect(mockedCreateAccount).toHaveBeenCalledWith({ + newAccountInfo: { kratosUserId, phone }, + config: expect.any(Object), + }) + expect(context.domainAccount).toBe(account) + expect(context.user).toBe(user) + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId, accountId: account.id }), + "orphaned kratos identity repaired", + ) + }) + + it("re-raises the original error when the identity has no phone trait", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone: undefined }) + + await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + + expect(mockedCreateAccount).not.toHaveBeenCalled() + }) + + it("re-raises the original error when the identity cannot be loaded", async () => { + getIdentity.mockResolvedValue(new UnknownKratosError("kratos down")) + + await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + + expect(mockedCreateAccount).not.toHaveBeenCalled() + }) + + it("re-raises the original error when the repair write fails, and records it", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + const collision = new DuplicateKeyForPersistError( + "E11000 duplicate key error collection: galoy.users index: phone_1", + ) + mockedCreateAccount.mockResolvedValue(collision) + + await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + + expect(mockedRecordException).toHaveBeenCalledWith( + expect.objectContaining({ + error: collision, + attributes: { kratosUserId }, + }), + ) + }) + }) +}) diff --git a/test/flash/unit/services/mongoose/parse-repository-error.spec.ts b/test/flash/unit/services/mongoose/parse-repository-error.spec.ts new file mode 100644 index 000000000..29e0b6029 --- /dev/null +++ b/test/flash/unit/services/mongoose/parse-repository-error.spec.ts @@ -0,0 +1,23 @@ +import { DuplicateKeyForPersistError, UnknownRepositoryError } from "@domain/errors" +import { parseRepositoryError } from "@services/mongoose/utils" + +describe("parseRepositoryError", () => { + // The driver message is the only thing that names the collection and index + // that collided. Dropping it left 26 failed registration writes on + // 2026-09-01 unattributable between accounts.kratosUserId and users.phone. + it("keeps the driver message on a duplicate key error", () => { + const driverMessage = + 'E11000 duplicate key error collection: galoy.users index: phone_1 dup key: { phone: "+2348012345678" }' + + const result = parseRepositoryError(new Error(driverMessage)) + + expect(result).toBeInstanceOf(DuplicateKeyForPersistError) + expect(result.message).toContain("galoy.users index: phone_1") + }) + + it("still falls through to the unknown repository error otherwise", () => { + const result = parseRepositoryError(new Error("something else entirely")) + + expect(result).toBeInstanceOf(UnknownRepositoryError) + }) +}) From b4dd5e6c089492562c1d008e2d387ba35b3a6e51 Mon Sep 17 00:00:00 2001 From: Dread Date: Tue, 1 Sep 2026 16:13:58 -0700 Subject: [PATCH 2/4] fix(auth): scope orphan handling to the session, single-flight repairs, stop the unrepairable-orphan hot loop Review fixes for #499. - CouldNotFindAccountFromKratosIdError maps to NOT_FOUND like its id/uuid siblings. Only the session middleware, which knows the missing account is the caller's own, raises AuthenticationError ("No account is linked to this session"). Admin accountDetailsByUserPhone/ByUserEmail lookups of an orphan now get a not-found for that user instead of NOT_AUTHENTICATED. - Single-flight the repair per kratosUserId in-process so an orphan's parallel app-launch queries share one persistNew instead of all but one losing the unique-index race; on DuplicateKeyForPersistError re-read the account once to adopt a concurrent write from another replica. - Negative-cache failed repairs per kratosUserId (60s, replica-local): one Kratos/Mongo round trip per window instead of one per request. First failure logs error + Critical span, later failures warn. - gql-context: an AuthenticationError is answered with a warn log and no Critical span; the 500 branch keeps error + Critical. - DuplicateKeyForPersistError gets its own mapError case with a fixed client message; the retained Mongo driver text (collection, index, dup key) stays on the domain error for logs and spans only. Tests: session.spec covers the AuthenticationError shape, single-flight (create called once for two concurrent requests), cross-replica adoption, the retry window and warn-after-first; gql-context.spec asserts no span exception on the auth branch; error-map.spec asserts NOT_FOUND and no driver text; new admin account-details-by-phone.spec asserts NOT_FOUND on the admin path. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01EtQzyzQ38thfC2F8BLK4u8 --- src/graphql/error-map.ts | 24 +- src/servers/middlewares/gql-context.ts | 19 +- src/servers/middlewares/session.ts | 218 ++++++++++++++---- .../admin/account-details-by-phone.spec.ts | 108 +++++++++ test/flash/unit/graphql/error-map.spec.ts | 48 +++- .../servers/middlewares/gql-context.spec.ts | 23 +- .../unit/servers/middlewares/session.spec.ts | 216 +++++++++++++++-- 7 files changed, 558 insertions(+), 98 deletions(-) create mode 100644 test/flash/unit/graphql/admin/account-details-by-phone.spec.ts diff --git a/src/graphql/error-map.ts b/src/graphql/error-map.ts index 923085be6..cb702470b 100644 --- a/src/graphql/error-map.ts +++ b/src/graphql/error-map.ts @@ -1,6 +1,5 @@ import { ValidationError } from "@domain/shared" import { - AuthenticationError, TransactionRestrictedError, LightningPaymentError, NotFoundError, @@ -109,14 +108,15 @@ export const mapError = (error: ApplicationError): CustomApolloError => { message = `Account does not exist for id ${error.message}` return new NotFoundError({ message, logger: baseLogger }) - // A session whose Kratos identity has no account: the registration write - // failed after the identity was committed and could not be repaired. Not a - // transient fault the client should retry against — the session is - // unusable until an account exists, so it reads as unauthenticated rather - // than "unexpected error, please try again". + // Same shape as the id/uuid/username siblings: a not-found for whichever + // user the caller looked up. Admin lookups (accountDetailsByUserPhone, + // accountDetailsByUserEmail) resolve OTHER users through findByUserId, so + // this must never read as "your session is unauthenticated". The one site + // that knows the missing account is the caller's own is the session + // middleware, which raises AuthenticationError itself. case "CouldNotFindAccountFromKratosIdError": - message = "No account is linked to this session" - return new AuthenticationError({ message, logger: baseLogger }) + message = `Account does not exist for user id ${error.message}` + return new NotFoundError({ message, logger: baseLogger }) case "CouldNotFindAccountFromUuidError": message = `Account does not exist for uuid ${error.message}` @@ -865,7 +865,6 @@ export const mapError = (error: ApplicationError): CustomApolloError => { case "CouldNotFindTransactionMetadataError": case "CouldNotFindExpectedTransactionMetadataError": case "InvalidDocumentIdForDbError": - case "DuplicateKeyForPersistError": case "MismatchedResultForTransactionMetadataQuery": case "InvalidLedgerTransactionId": case "MultiplePendingPaymentsForHashError": @@ -984,6 +983,13 @@ export const mapError = (error: ApplicationError): CustomApolloError => { }${error.message ? ": " + error.message : ""})` return new UnexpectedClientError({ message, logger: baseLogger }) + // parseRepositoryError keeps the Mongo driver text on this error for logs + // and spans. It names internal collections, indexes and the colliding + // value, so unlike the catch-all above the message is not interpolated. + case "DuplicateKeyForPersistError": + message = `Unexpected error occurred, please try again or contact support if it persists (code: ${error.name})` + return new UnexpectedClientError({ message, logger: baseLogger }) + case "MissingSessionIdError": case "AuthTokenUserIdMismatchError": return new UnexpectedClientError({ diff --git a/src/servers/middlewares/gql-context.ts b/src/servers/middlewares/gql-context.ts index a9927778e..eb6796111 100644 --- a/src/servers/middlewares/gql-context.ts +++ b/src/servers/middlewares/gql-context.ts @@ -53,15 +53,13 @@ export const setGqlContext = async ( }) } catch (err) { const kratosUserId = tokenPayload?.sub - baseLogger.error({ err, kratosUserId }, "failed to build graphql context") - recordExceptionInCurrentSpan({ - error: err, - level: ErrorLevel.Critical, - attributes: { kratosUserId }, - fallbackMsg: "failed to build graphql context", - }) if (err instanceof AuthenticationError) { + // The session resolved; it just has no usable account. Not a server + // fault — whatever made it unrepairable was recorded where the repair + // ran — and an orphan's pollers hit this on every request, so no + // Critical span here. + baseLogger.warn({ err, kratosUserId }, "unauthenticated session") res.status(200).json({ data: null, errors: [ @@ -74,6 +72,13 @@ export const setGqlContext = async ( return } + baseLogger.error({ err, kratosUserId }, "failed to build graphql context") + recordExceptionInCurrentSpan({ + error: err, + level: ErrorLevel.Critical, + attributes: { kratosUserId }, + fallbackMsg: "failed to build graphql context", + }) res.status(500).json({ error: "failed to build graphql context" }) return } diff --git a/src/servers/middlewares/session.ts b/src/servers/middlewares/session.ts index 61fad0135..4fa0cba89 100644 --- a/src/servers/middlewares/session.ts +++ b/src/servers/middlewares/session.ts @@ -7,18 +7,30 @@ import jsonwebtoken from "jsonwebtoken" import { getDefaultAccountsConfig } from "@config" +import { AuthenticationError } from "@graphql/error" import { mapError } from "@graphql/error-map" import { createAccountWithPhoneIdentifier } from "@app/accounts" import { maybeExtendSession } from "@app/authentication" import { checkedToUserId } from "@domain/accounts" -import { CouldNotFindAccountFromKratosIdError } from "@domain/errors" +import { + CouldNotFindAccountFromKratosIdError, + DuplicateKeyForPersistError, +} from "@domain/errors" import { ErrorLevel, ValidationError } from "@domain/shared" import { IdentityRepository } from "@services/kratos" import { baseLogger } from "@services/logger" import { UsersRepository } from "@services/mongoose" import { IbexError } from "@services/ibex/errors" +type SessionLogger = typeof baseLogger + +type OrphanRepairArgs = { + userId: UserId + orphanError: CouldNotFindAccountFromKratosIdError + logger: SessionLogger +} + // The Kratos after-registration web_hook runs with `response.parse: false`: // the identity is committed whether or not the api managed to write its // account. A failed write (duplicate key, wallet provider down) therefore @@ -26,54 +38,159 @@ import { IbexError } from "@services/ibex/errors" // lands here. Re-run the registration write from the identity's own phone // trait. If that is not possible the original not-found error stands and the // caller answers it as "not authenticated" — it must never crash on it. -const repairOrphanedIdentity = async ({ +// +// Two pieces of replica-local state keep that from becoming a storm: +// +// - `inFlightRepairs` single-flights the repair per identity. An orphan +// opening the app fires several queries in parallel; `accounts.kratosUserId` +// is unique, so without this every request but one would lose the persistNew +// race and be answered NOT_AUTHENTICATED (with a Critical span) on the very +// launch that fixed the account. Requests landing mid-repair also never see +// the half-initialised account (no defaultWalletId yet) — they wait for the +// winner. A loser on ANOTHER replica is handled by re-reading the account +// after a duplicate-key failure. +// - `failedRepairs` negative-caches an identity that could not be repaired +// (phone collides on `users.phone`, no phone trait, Kratos unreachable). +// Without it every request from that identity costs a Kratos admin read plus +// two Mongo writes and emits a Critical span exception, and the mobile app's +// pollers keep firing on NOT_AUTHENTICATED. One attempt per window; the +// first failure is an error log with a Critical span, later ones warn. +const REPAIR_RETRY_WINDOW_MS = 60_000 + +const inFlightRepairs = new Map>() +const failedRepairs = new Map() + +// The maps above live for the process; specs reset them between cases. +export const clearOrphanRepairState = (): void => { + inFlightRepairs.clear() + failedRepairs.clear() +} + +const recordRepairFailure = ({ userId, + cause, + reason, orphanError, logger, -}: { - userId: UserId - orphanError: CouldNotFindAccountFromKratosIdError - logger: typeof baseLogger -}): Promise => { +}: OrphanRepairArgs & { + cause: Error | undefined + reason: string +}): CouldNotFindAccountFromKratosIdError => { + const failures = (failedRepairs.get(userId)?.failures ?? 0) + 1 + failedRepairs.set(userId, { + retryAfter: Date.now() + REPAIR_RETRY_WINDOW_MS, + failures, + }) + + const isFirstFailure = failures === 1 + const attributes = { kratosUserId: userId, repairFailures: failures } + recordExceptionInCurrentSpan({ + error: cause ?? orphanError, + level: isFirstFailure ? ErrorLevel.Critical : ErrorLevel.Warn, + attributes, + }) + + const details = { err: cause, ...attributes, retryAfterMs: REPAIR_RETRY_WINDOW_MS } + const msg = `orphaned kratos identity: ${reason}` + if (isFirstFailure) { + logger.error(details, msg) + } else { + logger.warn(details, msg) + } + + return orphanError +} + +const attemptRepair = async ({ + userId, + orphanError, + logger, +}: OrphanRepairArgs): Promise => { const identity = await IdentityRepository().getIdentity(userId) if (identity instanceof Error) { - logger.error( - { err: identity, kratosUserId: userId }, - "orphaned kratos identity: could not load identity", - ) - return orphanError + return recordRepairFailure({ + userId, + cause: identity, + reason: "could not load identity", + orphanError, + logger, + }) } if (!identity.phone) { - logger.error( - { kratosUserId: userId }, - "orphaned kratos identity: no phone trait to repair from", - ) - return orphanError + return recordRepairFailure({ + userId, + cause: undefined, + reason: "no phone trait to repair from", + orphanError, + logger, + }) } - const account = await createAccountWithPhoneIdentifier({ + const created = await createAccountWithPhoneIdentifier({ newAccountInfo: { kratosUserId: userId, phone: identity.phone }, config: getDefaultAccountsConfig(), }) - if (account instanceof Error) { - recordExceptionInCurrentSpan({ - error: account, - level: ErrorLevel.Critical, - attributes: { kratosUserId: userId }, + + if (created instanceof DuplicateKeyForPersistError) { + // Lost the persistNew race to a request on another replica: its account + // is the one to use. If the account is still missing the collision was + // on users.phone instead, and the failure stands. + const existing = await Accounts.getAccountFromUserId(userId) + if (!(existing instanceof Error)) { + failedRepairs.delete(userId) + logger.warn( + { kratosUserId: userId, accountId: existing.id }, + "orphaned kratos identity repaired by a concurrent request", + ) + return existing + } + } + + if (created instanceof Error) { + return recordRepairFailure({ + userId, + cause: created, + reason: "repair failed", + orphanError, + logger, }) - logger.error( - { err: account, kratosUserId: userId }, - "orphaned kratos identity: repair failed", - ) - return orphanError } + failedRepairs.delete(userId) logger.warn( - { kratosUserId: userId, accountId: account.id }, + { kratosUserId: userId, accountId: created.id }, "orphaned kratos identity repaired", ) - return account + return created +} + +const repairOrphanedIdentity = ({ + userId, + orphanError, + logger, +}: OrphanRepairArgs): Promise => { + const failed = failedRepairs.get(userId) + if (failed && Date.now() < failed.retryAfter) { + logger.debug( + { + kratosUserId: userId, + repairFailures: failed.failures, + retryAfter: new Date(failed.retryAfter), + }, + "orphaned kratos identity: repair skipped, last attempt failed recently", + ) + return Promise.resolve(orphanError) + } + + const inFlight = inFlightRepairs.get(userId) + if (inFlight) return inFlight + + const repair = attemptRepair({ userId, orphanError, logger }).finally(() => { + inFlightRepairs.delete(userId) + }) + inFlightRepairs.set(userId, repair) + return repair } export const sessionPublicContext = async ({ @@ -105,26 +222,37 @@ export const sessionPublicContext = async ({ if (account instanceof CouldNotFindAccountFromKratosIdError) { account = await repairOrphanedIdentity({ userId, orphanError: account, logger }) } - if (account instanceof Error) { - throw mapError(account) - } else { - domainAccount = account - // not awaiting on purpose. just updating metadata - // TODO: look if this can be a source of memory leaks - Accounts.updateAccountIPsInfo({ - accountId: account.id, - ip, + if (account instanceof CouldNotFindAccountFromKratosIdError) { + // Only here is the missing account known to be the caller's own. The + // session is unusable until one exists, which the client reads as + // NOT_AUTHENTICATED rather than "unexpected error, please try again". + // Anywhere else (admin lookups of other users) the same domain error + // is a plain not-found — see mapError. + throw new AuthenticationError({ + message: "No account is linked to this session", logger, }) + } + if (account instanceof Error) { + throw mapError(account) + } - if (sessionId && expiresAt) { - maybeExtendSession({ sessionId, expiresAt }) - } + domainAccount = account + // not awaiting on purpose. just updating metadata + // TODO: look if this can be a source of memory leaks + Accounts.updateAccountIPsInfo({ + accountId: account.id, + ip, + logger, + }) - const userRes = await UsersRepository().findById(account.kratosUserId) - if (userRes instanceof Error) throw mapError(userRes) - user = userRes + if (sessionId && expiresAt) { + maybeExtendSession({ sessionId, expiresAt }) } + + const userRes = await UsersRepository().findById(account.kratosUserId) + if (userRes instanceof Error) throw mapError(userRes) + user = userRes } const loaders = { diff --git a/test/flash/unit/graphql/admin/account-details-by-phone.spec.ts b/test/flash/unit/graphql/admin/account-details-by-phone.spec.ts new file mode 100644 index 000000000..2bb437d5b --- /dev/null +++ b/test/flash/unit/graphql/admin/account-details-by-phone.spec.ts @@ -0,0 +1,108 @@ +/** + * Schema-execution spec for the admin `accountDetailsByUserPhone` query, built + * the same way as account-details-by-npub.spec.ts: real field definition, real + * `Phone` scalar, real resolver, real error map; only the app layer mocked. + * + * The case that matters: an orphaned identity — `users` row written, `accounts` + * row missing — is exactly what an operator looks up by phone when reconciling + * a failed registration. The repository answers that lookup with + * CouldNotFindAccountFromKratosIdError, the same domain error the session + * middleware sees for the caller's OWN session. Here it must read as a + * not-found for the looked-up user, never as the operator's session being + * unauthenticated. + */ +const mockGetAccountByUserPhone = jest.fn() +const mockGetUser = jest.fn() + +jest.mock("@app", () => ({ + Admin: { + getAccountByUserPhone: (...args: unknown[]) => mockGetAccountByUserPhone(...args), + }, + Users: { + getUser: (...args: unknown[]) => mockGetUser(...args), + }, + Accounts: { getAccountCapabilities: jest.fn() }, + Wallets: { listWalletsByAccountId: jest.fn() }, + Merchants: { getMerchantsByUsername: jest.fn() }, +})) + +import { graphql, GraphQLSchema, GraphQLObjectType, GraphQLFieldConfig } from "graphql" + +import { CouldNotFindAccountFromKratosIdError } from "@domain/errors" +import AccountDetailsByUserPhoneQuery from "@graphql/admin/root/query/account-details-by-phone" + +const PHONE = "+18765550100" +const KRATOS_USER_ID = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" + +const LOOKUP_QUERY = ` + query accountDetailsByUserPhone($phone: Phone!) { + accountDetailsByUserPhone(phone: $phone) { + username + level + } + } +` + +const adminSchema = () => + new GraphQLSchema({ + query: new GraphQLObjectType({ + name: "Query", + fields: { + accountDetailsByUserPhone: + AccountDetailsByUserPhoneQuery as unknown as GraphQLFieldConfig< + unknown, + unknown + >, + }, + }), + }) + +const account = { + id: "account-id", + uuid: "5a9f6f45-0a3a-4b0a-9f3e-1e0f9b1b1b1b", + username: "jaceth2009", + level: 1, + kratosUserId: KRATOS_USER_ID, +} + +describe("admin accountDetailsByUserPhone", () => { + beforeEach(() => { + jest.clearAllMocks() + }) + + it("resolves an account by phone", async () => { + mockGetAccountByUserPhone.mockResolvedValue(account) + + const result = await graphql({ + schema: adminSchema(), + source: LOOKUP_QUERY, + variableValues: { phone: PHONE }, + }) + + expect(result.errors).toBeUndefined() + expect(mockGetAccountByUserPhone).toHaveBeenCalledWith(PHONE) + expect(result.data?.accountDetailsByUserPhone).toEqual({ + username: "jaceth2009", + level: "ONE", + }) + }) + + it("reports an orphaned identity as a not-found for that user, not as the operator's session", async () => { + mockGetAccountByUserPhone.mockResolvedValue( + new CouldNotFindAccountFromKratosIdError(KRATOS_USER_ID), + ) + + const result = await graphql({ + schema: adminSchema(), + source: LOOKUP_QUERY, + variableValues: { phone: PHONE }, + }) + + expect(result.errors?.[0].extensions?.code).toBe("NOT_FOUND") + expect(result.errors?.[0].extensions?.code).not.toBe("NOT_AUTHENTICATED") + expect(result.errors?.[0].message).toBe( + `Account does not exist for user id ${KRATOS_USER_ID}`, + ) + expect(result.errors?.[0].message).not.toContain("session") + }) +}) diff --git a/test/flash/unit/graphql/error-map.spec.ts b/test/flash/unit/graphql/error-map.spec.ts index dfa54467b..cd2f4d025 100644 --- a/test/flash/unit/graphql/error-map.spec.ts +++ b/test/flash/unit/graphql/error-map.spec.ts @@ -8,23 +8,47 @@ import { } from "@services/bridge/errors" import { IbexError, InsufficientIbexBalance } from "@services/ibex/errors" import { PhoneCountryNotAllowedError } from "@domain/users/errors" -import { CouldNotFindAccountFromKratosIdError, InvalidPhoneNumber } from "@domain/errors" +import { + CouldNotFindAccountFromKratosIdError, + DuplicateKeyForPersistError, + InvalidPhoneNumber, +} from "@domain/errors" describe("error-map", () => { - // A logged-in Kratos identity with no account (registration write failed - // after the identity was committed). It used to fall into the catch-all - // "unexpected error, please try again", which invites the client to retry - // the very request that crashed the api on 2026-09-01. - it("maps CouldNotFindAccountFromKratosIdError to NOT_AUTHENTICATED, not the catch-all", () => { - const result = mapError( - new CouldNotFindAccountFromKratosIdError("ebbe2b32-9a2e-4c77-80e4-5d7347c024bb"), - ) - - expect(result.extensions.code).toBe("NOT_AUTHENTICATED") - expect(result.message).toBe("No account is linked to this session") + // The same domain error reaches mapError from admin lookups of OTHER users + // (accountDetailsByUserPhone / accountDetailsByUserEmail → findByUserId) and + // from the caller's own session. Here it is a plain not-found like its + // id/uuid siblings. The session middleware is the one site that answers it + // as NOT_AUTHENTICATED, because only it knows the account is the caller's + // own — an operator reconciling an orphan must not be told their session is + // broken. + it("maps CouldNotFindAccountFromKratosIdError to NOT_FOUND, never NOT_AUTHENTICATED", () => { + const kratosUserId = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" + const result = mapError(new CouldNotFindAccountFromKratosIdError(kratosUserId)) + + expect(result.extensions.code).toBe("NOT_FOUND") + expect(result.message).toBe(`Account does not exist for user id ${kratosUserId}`) + expect(result.extensions.code).not.toBe("NOT_AUTHENTICATED") expect(result.extensions.code).not.toBe("UNEXPECTED_CLIENT_ERROR") }) + // parseRepositoryError keeps the Mongo driver text on the domain error for + // logs and spans. It names internal collections, indexes and the colliding + // value (a setUsername that loses the race after its availability check is + // the everyday case), so it must not reach the client. + it("maps DuplicateKeyForPersistError without leaking the driver message", () => { + const driverMessage = + 'E11000 duplicate key error collection: galoy.accounts index: username_1 dup key: { username: "alice" }' + const result = mapError(new DuplicateKeyForPersistError(driverMessage)) + + expect(result.extensions.code).toBe("UNEXPECTED_CLIENT_ERROR") + expect(result.message).toContain("code: DuplicateKeyForPersistError") + expect(result.message).not.toContain("E11000") + expect(result.message).not.toContain("galoy.accounts") + expect(result.message).not.toContain("username_1") + expect(result.message).not.toContain("alice") + }) + it("maps BridgeWithdrawalNotFoundError to BRIDGE_WITHDRAWAL_NOT_FOUND", () => { const result = mapError(new BridgeWithdrawalNotFoundError()) diff --git a/test/flash/unit/servers/middlewares/gql-context.spec.ts b/test/flash/unit/servers/middlewares/gql-context.spec.ts index 4c0bda8ff..9454a82a7 100644 --- a/test/flash/unit/servers/middlewares/gql-context.spec.ts +++ b/test/flash/unit/servers/middlewares/gql-context.spec.ts @@ -31,7 +31,7 @@ const mockedSessionPublicContext = sessionPublicContext as jest.MockedFunction< const mockedRecordException = recordExceptionInCurrentSpan as jest.MockedFunction< typeof recordExceptionInCurrentSpan > -const mockedLogger = baseLogger as unknown as { error: jest.Mock } +const mockedLogger = baseLogger as unknown as { error: jest.Mock; warn: jest.Mock } const kratosUserId = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" @@ -57,6 +57,7 @@ describe("setGqlContext", () => { mockedSessionPublicContext.mockReset() mockedRecordException.mockReset() mockedLogger.error.mockReset() + mockedLogger.warn.mockReset() next = jest.fn() }) @@ -112,13 +113,15 @@ describe("setGqlContext", () => { }, ], }) - expect(mockedLogger.error).toHaveBeenCalledWith( - expect.objectContaining({ kratosUserId }), - "failed to build graphql context", - ) - expect(mockedRecordException).toHaveBeenCalledWith( - expect.objectContaining({ error: authError }), + // Not a server fault: the repair site already recorded why the session + // has no account, and an orphan's pollers land here on every request. A + // warn line, no error line, no Critical span exception. + expect(mockedLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ err: authError, kratosUserId }), + "unauthenticated session", ) + expect(mockedLogger.error).not.toHaveBeenCalled() + expect(mockedRecordException).not.toHaveBeenCalled() }) it("answers any other failure as a 500 and does not reject", async () => { @@ -132,8 +135,12 @@ describe("setGqlContext", () => { expect(next).not.toHaveBeenCalled() expect(res.status).toHaveBeenCalledWith(500) expect(res.json).toHaveBeenCalledWith({ error: "failed to build graphql context" }) + expect(mockedLogger.error).toHaveBeenCalledWith( + expect.objectContaining({ err: boom, kratosUserId }), + "failed to build graphql context", + ) expect(mockedRecordException).toHaveBeenCalledWith( - expect.objectContaining({ error: boom }), + expect.objectContaining({ error: boom, level: "critical" }), ) }) }) diff --git a/test/flash/unit/servers/middlewares/session.spec.ts b/test/flash/unit/servers/middlewares/session.spec.ts index d21ca67a5..5085583a0 100644 --- a/test/flash/unit/servers/middlewares/session.spec.ts +++ b/test/flash/unit/servers/middlewares/session.spec.ts @@ -3,8 +3,14 @@ import { createAccountWithPhoneIdentifier } from "@app/accounts" import { CouldNotFindAccountFromKratosIdError, DuplicateKeyForPersistError, + UnknownRepositoryError, } from "@domain/errors" -import { sessionPublicContext } from "@servers/middlewares/session" +import { ErrorLevel } from "@domain/shared" +import { AuthenticationError } from "@graphql/error" +import { + clearOrphanRepairState, + sessionPublicContext, +} from "@servers/middlewares/session" import { IdentityRepository, UnknownKratosError } from "@services/kratos" import { baseLogger } from "@services/logger" import { UsersRepository } from "@services/mongoose" @@ -35,12 +41,6 @@ jest.mock("@app/cash-wallet-cutover", () => ({ }, })) -// Identity mapping is what is under test here, not the GraphQL error shape: -// pass domain errors through so the rejection can be asserted directly. -jest.mock("@graphql/error-map", () => ({ - mapError: jest.fn((err) => err), -})) - jest.mock("@services/kratos", () => ({ IdentityRepository: jest.fn(), UnknownKratosError: class UnknownKratosError extends Error {}, @@ -54,8 +54,18 @@ jest.mock("@services/tracing", () => ({ recordExceptionInCurrentSpan: jest.fn(), })) +// The real error map runs (no mock): what the client is answered with is part +// of what is under test. CustomApolloError binds `logger[level]`, so every +// pino level it can name has to exist on the mock. jest.mock("@services/logger", () => { - const child = { error: jest.fn(), warn: jest.fn(), info: jest.fn() } + const child = { + fatal: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + trace: jest.fn(), + } return { baseLogger: { ...child, child: jest.fn(() => child) }, } @@ -77,7 +87,9 @@ const mockedRecordException = recordExceptionInCurrentSpan as jest.MockedFunctio typeof recordExceptionInCurrentSpan > const childLogger = ( - baseLogger as unknown as { child: () => { warn: jest.Mock } } + baseLogger as unknown as { + child: () => { error: jest.Mock; warn: jest.Mock; debug: jest.Mock } + } ).child() const kratosUserId = "ebbe2b32-9a2e-4c77-80e4-5d7347c024bb" as UserId @@ -95,13 +107,31 @@ const getIdentity = jest.fn() const tokenPayload = { sub: kratosUserId, session_id: "sess", expires_at: "later" } +const flushMicrotasks = () => new Promise((resolve) => setImmediate(resolve)) + +// The caller's own session with no account is answered as NOT_AUTHENTICATED: +// the client must not retry it as a transient fault, and must not be told the +// account "does not exist for user id …" as an admin looking up someone else +// would be. +const expectNotAuthenticated = async (attempt: Promise) => { + await expect(attempt).rejects.toBeInstanceOf(AuthenticationError) + await expect(attempt).rejects.toMatchObject({ + message: "No account is linked to this session", + extensions: { code: "NOT_AUTHENTICATED" }, + }) +} + describe("sessionPublicContext", () => { beforeEach(() => { + clearOrphanRepairState() mockedGetAccount.mockReset() mockedCreateAccount.mockReset() mockedRecordException.mockReset() + mockedIdentityRepository.mockReset() getIdentity.mockReset() + childLogger.error.mockReset() childLogger.warn.mockReset() + childLogger.debug.mockReset() mockedIdentityRepository.mockReturnValue({ getIdentity, } as unknown as ReturnType) @@ -110,6 +140,10 @@ describe("sessionPublicContext", () => { } as unknown as ReturnType) }) + afterEach(() => { + jest.useRealTimers() + }) + it("resolves an existing account without touching kratos", async () => { mockedGetAccount.mockResolvedValue(account) @@ -132,6 +166,17 @@ describe("sessionPublicContext", () => { expect(mockedGetAccount).not.toHaveBeenCalled() }) + it("maps any other lookup failure through the error map and does not try to repair", async () => { + mockedGetAccount.mockResolvedValue(new UnknownRepositoryError("mongo unreachable")) + + const attempt = sessionPublicContext({ tokenPayload, ip }) + + await expect(attempt).rejects.not.toBeInstanceOf(AuthenticationError) + await expect(attempt).rejects.toMatchObject({ extensions: { code: "DB_ERROR" } }) + expect(mockedIdentityRepository).not.toHaveBeenCalled() + expect(mockedCreateAccount).not.toHaveBeenCalled() + }) + describe("orphaned kratos identity (identity committed, account write failed)", () => { const orphan = new CouldNotFindAccountFromKratosIdError(kratosUserId) @@ -155,39 +200,176 @@ describe("sessionPublicContext", () => { expect.objectContaining({ kratosUserId, accountId: account.id }), "orphaned kratos identity repaired", ) + expect(mockedRecordException).not.toHaveBeenCalled() }) - it("re-raises the original error when the identity has no phone trait", async () => { + it("answers NOT_AUTHENTICATED when the identity has no phone trait", async () => { getIdentity.mockResolvedValue({ id: kratosUserId, phone: undefined }) - await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) expect(mockedCreateAccount).not.toHaveBeenCalled() + expect(mockedRecordException).toHaveBeenCalledWith( + expect.objectContaining({ + error: orphan, + level: ErrorLevel.Critical, + attributes: expect.objectContaining({ kratosUserId }), + }), + ) }) - it("re-raises the original error when the identity cannot be loaded", async () => { - getIdentity.mockResolvedValue(new UnknownKratosError("kratos down")) + it("answers NOT_AUTHENTICATED when the identity cannot be loaded", async () => { + const kratosDown = new UnknownKratosError("kratos down") + getIdentity.mockResolvedValue(kratosDown) - await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) expect(mockedCreateAccount).not.toHaveBeenCalled() + expect(mockedRecordException).toHaveBeenCalledWith( + expect.objectContaining({ error: kratosDown, level: ErrorLevel.Critical }), + ) }) - it("re-raises the original error when the repair write fails, and records it", async () => { + it("answers NOT_AUTHENTICATED when the repair write fails, and records it as Critical", async () => { getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + // A collision on users.phone: the account is still missing afterwards, + // so this identity cannot be repaired by re-running registration. const collision = new DuplicateKeyForPersistError( "E11000 duplicate key error collection: galoy.users index: phone_1", ) mockedCreateAccount.mockResolvedValue(collision) - await expect(sessionPublicContext({ tokenPayload, ip })).rejects.toBe(orphan) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) expect(mockedRecordException).toHaveBeenCalledWith( expect.objectContaining({ error: collision, - attributes: { kratosUserId }, + level: ErrorLevel.Critical, + attributes: expect.objectContaining({ kratosUserId }), + }), + ) + expect(childLogger.error).toHaveBeenCalledWith( + expect.objectContaining({ err: collision, kratosUserId }), + "orphaned kratos identity: repair failed", + ) + }) + + // An orphan opening the app fires several queries at once. accounts. + // kratosUserId is unique, so without single-flighting every request but + // one would lose the persistNew race and be answered NOT_AUTHENTICATED on + // the very launch that fixed the account. + it("single-flights concurrent requests: one repair, every request gets the account", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + let releaseCreate: (value: Account) => void = () => undefined + mockedCreateAccount.mockReturnValue( + new Promise((resolve) => { + releaseCreate = resolve }), ) + + const first = sessionPublicContext({ tokenPayload, ip }) + const second = sessionPublicContext({ tokenPayload, ip }) + await flushMicrotasks() + + // Both requests are past the lookup and parked on the same repair. + expect(mockedCreateAccount).toHaveBeenCalledTimes(1) + expect(getIdentity).toHaveBeenCalledTimes(1) + + releaseCreate(account) + const [one, two] = await Promise.all([first, second]) + + expect(one.domainAccount).toBe(account) + expect(two.domainAccount).toBe(account) + expect(mockedCreateAccount).toHaveBeenCalledTimes(1) + expect(mockedRecordException).not.toHaveBeenCalled() + }) + + it("adopts the account a request on another replica wrote after losing the persistNew race", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + mockedCreateAccount.mockResolvedValue( + new DuplicateKeyForPersistError( + "E11000 duplicate key error collection: galoy.accounts index: kratosUserId_1", + ), + ) + mockedGetAccount.mockReset() + mockedGetAccount.mockResolvedValueOnce(orphan).mockResolvedValueOnce(account) + + const context = await sessionPublicContext({ tokenPayload, ip }) + + expect(context.domainAccount).toBe(account) + expect(context.user).toBe(user) + expect(mockedCreateAccount).toHaveBeenCalledTimes(1) + expect(mockedGetAccount).toHaveBeenCalledTimes(2) + expect(mockedRecordException).not.toHaveBeenCalled() + expect(childLogger.error).not.toHaveBeenCalled() + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId, accountId: account.id }), + "orphaned kratos identity repaired by a concurrent request", + ) + }) + + // An identity that cannot be repaired keeps making requests (the mobile + // app's pollers do not stop on NOT_AUTHENTICATED). Each one must not cost + // a Kratos admin read plus Mongo writes, nor page anyone again. + it("does not retry a failed repair within the retry window, and warns rather than errors on the next failure", async () => { + const start = new Date("2026-09-01T12:00:00Z").getTime() + jest.useFakeTimers({ now: start }) + const kratosDown = new UnknownKratosError("kratos down") + getIdentity.mockResolvedValue(kratosDown) + + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(getIdentity).toHaveBeenCalledTimes(1) + expect(childLogger.error).toHaveBeenCalledTimes(1) + expect(mockedRecordException).toHaveBeenCalledTimes(1) + + jest.setSystemTime(start + 30_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + + // Still one Kratos round trip, one error line, one Critical span. + expect(getIdentity).toHaveBeenCalledTimes(1) + expect(childLogger.error).toHaveBeenCalledTimes(1) + expect(mockedRecordException).toHaveBeenCalledTimes(1) + expect(childLogger.debug).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId, repairFailures: 1 }), + "orphaned kratos identity: repair skipped, last attempt failed recently", + ) + + jest.setSystemTime(start + 61_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + + // Window elapsed: one more attempt, reported at warn, not as Critical. + expect(getIdentity).toHaveBeenCalledTimes(2) + expect(childLogger.error).toHaveBeenCalledTimes(1) + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ err: kratosDown, kratosUserId, repairFailures: 2 }), + "orphaned kratos identity: could not load identity", + ) + expect(mockedRecordException).toHaveBeenCalledTimes(2) + expect(mockedRecordException).toHaveBeenLastCalledWith( + expect.objectContaining({ error: kratosDown, level: ErrorLevel.Warn }), + ) + }) + + it("retries after the window and forgets the failure once the repair succeeds", async () => { + const start = new Date("2026-09-01T12:00:00Z").getTime() + jest.useFakeTimers({ now: start }) + getIdentity.mockResolvedValueOnce(new UnknownKratosError("kratos down")) + + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + + jest.setSystemTime(start + 61_000) + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + mockedCreateAccount.mockResolvedValue(account) + + const context = await sessionPublicContext({ tokenPayload, ip }) + + expect(context.domainAccount).toBe(account) + expect(mockedCreateAccount).toHaveBeenCalledTimes(1) + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId, accountId: account.id }), + "orphaned kratos identity repaired", + ) }) }) }) From 1071a3852e37ca7cd0cc832e1d6e5f5282bfe436 Mon Sep 17 00:00:00 2001 From: Dread Date: Tue, 1 Sep 2026 16:31:21 -0700 Subject: [PATCH 3/4] fix(auth): store carrier metadata when repairing an orphaned identity MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The self-heal in sessionPublicContext re-ran the registration write without the Twilio carrier lookup the webhook path stores as users.phoneMetadata (login.ts → transient_payload → RegistrationPayloadValidator). Quiz rewards (add-earn → PhoneMetadataAuthorizer) fail closed on a missing phoneMetadata, so every repaired identity was permanently ineligible for rewards with nothing pointing at why. Look up the carrier before createAccountWithPhoneIdentifier and pass it through. Best effort, as on the webhook path: a failed lookup logs a warn line and repairs without metadata rather than failing the repair. Spec: asserts the metadata reaches createAccountWithPhoneIdentifier, that a failed lookup still repairs (no error line, no span exception), and that the billed carrier lookup is single-flighted with the rest of the repair. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01EtQzyzQ38thfC2F8BLK4u8 --- src/servers/middlewares/session.ts | 22 +++++- .../unit/servers/middlewares/session.spec.ts | 77 ++++++++++++++++++- 2 files changed, 96 insertions(+), 3 deletions(-) diff --git a/src/servers/middlewares/session.ts b/src/servers/middlewares/session.ts index 4fa0cba89..6738d6218 100644 --- a/src/servers/middlewares/session.ts +++ b/src/servers/middlewares/session.ts @@ -21,6 +21,7 @@ import { ErrorLevel, ValidationError } from "@domain/shared" import { IdentityRepository } from "@services/kratos" import { baseLogger } from "@services/logger" import { UsersRepository } from "@services/mongoose" +import { TwilioClient } from "@services/twilio" import { IbexError } from "@services/ibex/errors" type SessionLogger = typeof baseLogger @@ -36,8 +37,10 @@ type OrphanRepairArgs = { // account. A failed write (duplicate key, wallet provider down) therefore // leaves a logged-in identity with no account, and every request it makes // lands here. Re-run the registration write from the identity's own phone -// trait. If that is not possible the original not-found error stands and the -// caller answers it as "not authenticated" — it must never crash on it. +// trait, including the Twilio carrier lookup the webhook path stores as +// `users.phoneMetadata`. If that is not possible the original not-found error +// stands and the caller answers it as "not authenticated" — it must never +// crash on it. // // Two pieces of replica-local state keep that from becoming a storm: // @@ -127,9 +130,24 @@ const attemptRepair = async ({ }) } + // The webhook path stores the Twilio carrier lookup on the users row + // (login.ts → transient_payload → RegistrationPayloadValidator). Rewards + // (add-earn) fail closed on a missing phoneMetadata, so a repair without it + // would leave the account permanently ineligible with nothing pointing at + // why. Best effort, as on the webhook path: a lookup failure must not fail + // the repair, it just gets the warn line below so the gap is attributable. + const carrier = await TwilioClient().getCarrier(identity.phone) + if (carrier instanceof Error) { + logger.warn( + { err: carrier, kratosUserId: userId }, + "orphaned kratos identity: carrier lookup failed, repairing without phone metadata", + ) + } + const created = await createAccountWithPhoneIdentifier({ newAccountInfo: { kratosUserId: userId, phone: identity.phone }, config: getDefaultAccountsConfig(), + phoneMetadata: carrier instanceof Error ? undefined : carrier, }) if (created instanceof DuplicateKeyForPersistError) { diff --git a/test/flash/unit/servers/middlewares/session.spec.ts b/test/flash/unit/servers/middlewares/session.spec.ts index 5085583a0..01c110308 100644 --- a/test/flash/unit/servers/middlewares/session.spec.ts +++ b/test/flash/unit/servers/middlewares/session.spec.ts @@ -5,6 +5,7 @@ import { DuplicateKeyForPersistError, UnknownRepositoryError, } from "@domain/errors" +import { UnknownPhoneProviderServiceError } from "@domain/phone-provider" import { ErrorLevel } from "@domain/shared" import { AuthenticationError } from "@graphql/error" import { @@ -15,6 +16,7 @@ import { IdentityRepository, UnknownKratosError } from "@services/kratos" import { baseLogger } from "@services/logger" import { UsersRepository } from "@services/mongoose" import { recordExceptionInCurrentSpan } from "@services/tracing" +import { TwilioClient } from "@services/twilio" jest.mock("@app", () => ({ Accounts: { @@ -54,6 +56,10 @@ jest.mock("@services/tracing", () => ({ recordExceptionInCurrentSpan: jest.fn(), })) +jest.mock("@services/twilio", () => ({ + TwilioClient: jest.fn(), +})) + // The real error map runs (no mock): what the client is answered with is part // of what is under test. CustomApolloError binds `logger[level]`, so every // pino level it can name has to exist on the mock. @@ -86,6 +92,7 @@ const mockedUsersRepository = UsersRepository as jest.MockedFunction< const mockedRecordException = recordExceptionInCurrentSpan as jest.MockedFunction< typeof recordExceptionInCurrentSpan > +const mockedTwilioClient = TwilioClient as jest.MockedFunction const childLogger = ( baseLogger as unknown as { child: () => { error: jest.Mock; warn: jest.Mock; debug: jest.Mock } @@ -103,7 +110,21 @@ const account = { } as unknown as Account const user = { id: kratosUserId, phone } as unknown as User +// What the registration webhook stores on the users row from Twilio's carrier +// lookup (login.ts → transient_payload → RegistrationPayloadValidator). +const phoneMetadata = { + carrier: { + error_code: "", + mobile_country_code: "621", + mobile_network_code: "30", + name: "MTN Nigeria", + type: "mobile", + }, + countryCode: "NG", +} as PhoneMetadata + const getIdentity = jest.fn() +const getCarrier = jest.fn() const tokenPayload = { sub: kratosUserId, session_id: "sess", expires_at: "later" } @@ -128,13 +149,18 @@ describe("sessionPublicContext", () => { mockedCreateAccount.mockReset() mockedRecordException.mockReset() mockedIdentityRepository.mockReset() + mockedTwilioClient.mockReset() getIdentity.mockReset() + getCarrier.mockReset() childLogger.error.mockReset() childLogger.warn.mockReset() childLogger.debug.mockReset() mockedIdentityRepository.mockReturnValue({ getIdentity, } as unknown as ReturnType) + mockedTwilioClient.mockReturnValue({ + getCarrier, + } as unknown as ReturnType) mockedUsersRepository.mockReturnValue({ findById: jest.fn().mockResolvedValue(user), } as unknown as ReturnType) @@ -182,6 +208,7 @@ describe("sessionPublicContext", () => { beforeEach(() => { mockedGetAccount.mockResolvedValue(orphan) + getCarrier.mockResolvedValue(phoneMetadata) }) it("repairs it from the identity's phone trait and continues as that account", async () => { @@ -193,6 +220,7 @@ describe("sessionPublicContext", () => { expect(mockedCreateAccount).toHaveBeenCalledWith({ newAccountInfo: { kratosUserId, phone }, config: expect.any(Object), + phoneMetadata, }) expect(context.domainAccount).toBe(account) expect(context.user).toBe(user) @@ -203,6 +231,51 @@ describe("sessionPublicContext", () => { expect(mockedRecordException).not.toHaveBeenCalled() }) + // The webhook path stores Twilio's carrier lookup as users.phoneMetadata. + // Quiz rewards (add-earn → PhoneMetadataAuthorizer) fail closed when it is + // missing, so a repair that skipped the lookup would leave the account + // permanently ineligible for rewards with nothing pointing at why. + it("looks up the carrier and stores it with the repair, as the registration webhook would", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + mockedCreateAccount.mockResolvedValue(account) + + await sessionPublicContext({ tokenPayload, ip }) + + expect(getCarrier).toHaveBeenCalledTimes(1) + expect(getCarrier).toHaveBeenCalledWith(phone) + expect(mockedCreateAccount).toHaveBeenCalledWith( + expect.objectContaining({ phoneMetadata }), + ) + }) + + it("still repairs when the carrier lookup fails, just without phone metadata", async () => { + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + const lookupFailed = new UnknownPhoneProviderServiceError("twilio lookups down") + getCarrier.mockResolvedValue(lookupFailed) + mockedCreateAccount.mockResolvedValue(account) + + const context = await sessionPublicContext({ tokenPayload, ip }) + + expect(context.domainAccount).toBe(account) + expect(context.user).toBe(user) + expect(mockedCreateAccount).toHaveBeenCalledWith({ + newAccountInfo: { kratosUserId, phone }, + config: expect.any(Object), + phoneMetadata: undefined, + }) + // Attributable, but not a failure: no error line, no span exception. + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ err: lookupFailed, kratosUserId }), + "orphaned kratos identity: carrier lookup failed, repairing without phone metadata", + ) + expect(childLogger.warn).toHaveBeenCalledWith( + expect.objectContaining({ kratosUserId, accountId: account.id }), + "orphaned kratos identity repaired", + ) + expect(childLogger.error).not.toHaveBeenCalled() + expect(mockedRecordException).not.toHaveBeenCalled() + }) + it("answers NOT_AUTHENTICATED when the identity has no phone trait", async () => { getIdentity.mockResolvedValue({ id: kratosUserId, phone: undefined }) @@ -271,9 +344,11 @@ describe("sessionPublicContext", () => { const second = sessionPublicContext({ tokenPayload, ip }) await flushMicrotasks() - // Both requests are past the lookup and parked on the same repair. + // Both requests are past the lookup and parked on the same repair. The + // carrier lookup is a billed Twilio call, so it is single-flighted too. expect(mockedCreateAccount).toHaveBeenCalledTimes(1) expect(getIdentity).toHaveBeenCalledTimes(1) + expect(getCarrier).toHaveBeenCalledTimes(1) releaseCreate(account) const [one, two] = await Promise.all([first, second]) From 576209af450c9a7b60c252242f8489f556101fa6 Mon Sep 17 00:00:00 2001 From: Dread Date: Tue, 1 Sep 2026 16:40:50 -0700 Subject: [PATCH 4/4] fix(auth): back off unrepairable orphan repairs and cache the carrier lookup Round-3 review finding on #499: an identity that will never repair (phone collides on users.phone, no phone trait) re-ran the whole repair, including a billed Twilio carrier lookup, once every 60s per replica for as long as its app kept polling. - The negative-cache window now doubles on every consecutive failure (60s, 2m, 4m, ... capped at 1h), so a permanently broken identity costs one attempt an hour per replica instead of one a minute. - The carrier lookup is remembered per identity across attempts and dropped once the repair succeeds, so a retried repair never bills Twilio twice for the same number. Tests: pure backoff schedule, the doubled window holding between attempts, and a single getCarrier call across two failed attempts and the eventual success. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01EtQzyzQ38thfC2F8BLK4u8 --- src/servers/middlewares/session.ts | 29 +++++-- .../unit/servers/middlewares/session.spec.ts | 76 +++++++++++++++++++ 2 files changed, 99 insertions(+), 6 deletions(-) diff --git a/src/servers/middlewares/session.ts b/src/servers/middlewares/session.ts index 6738d6218..17c6466f6 100644 --- a/src/servers/middlewares/session.ts +++ b/src/servers/middlewares/session.ts @@ -56,17 +56,28 @@ type OrphanRepairArgs = { // (phone collides on `users.phone`, no phone trait, Kratos unreachable). // Without it every request from that identity costs a Kratos admin read plus // two Mongo writes and emits a Critical span exception, and the mobile app's -// pollers keep firing on NOT_AUTHENTICATED. One attempt per window; the -// first failure is an error log with a Critical span, later ones warn. -const REPAIR_RETRY_WINDOW_MS = 60_000 +// pollers keep firing on NOT_AUTHENTICATED. The window doubles on every +// consecutive failure (60s, 2m, 4m, ... capped at an hour) so an identity +// that will never repair costs one attempt an hour per replica, not one a +// minute. The first failure is an error log with a Critical span, later +// ones warn. +// - `carrierLookups` remembers the Twilio carrier lookup per identity so a +// retried repair does not bill Twilio again for the same number. +export const REPAIR_RETRY_WINDOW_MS = 60_000 +export const REPAIR_RETRY_MAX_MS = 60 * 60_000 const inFlightRepairs = new Map>() const failedRepairs = new Map() +const carrierLookups = new Map() + +export const repairRetryDelayMs = (failures: number): number => + Math.min(REPAIR_RETRY_MAX_MS, REPAIR_RETRY_WINDOW_MS * 2 ** Math.max(0, failures - 1)) // The maps above live for the process; specs reset them between cases. export const clearOrphanRepairState = (): void => { inFlightRepairs.clear() failedRepairs.clear() + carrierLookups.clear() } const recordRepairFailure = ({ @@ -80,8 +91,9 @@ const recordRepairFailure = ({ reason: string }): CouldNotFindAccountFromKratosIdError => { const failures = (failedRepairs.get(userId)?.failures ?? 0) + 1 + const retryAfterMs = repairRetryDelayMs(failures) failedRepairs.set(userId, { - retryAfter: Date.now() + REPAIR_RETRY_WINDOW_MS, + retryAfter: Date.now() + retryAfterMs, failures, }) @@ -93,7 +105,7 @@ const recordRepairFailure = ({ attributes, }) - const details = { err: cause, ...attributes, retryAfterMs: REPAIR_RETRY_WINDOW_MS } + const details = { err: cause, ...attributes, retryAfterMs } const msg = `orphaned kratos identity: ${reason}` if (isFirstFailure) { logger.error(details, msg) @@ -136,12 +148,15 @@ const attemptRepair = async ({ // would leave the account permanently ineligible with nothing pointing at // why. Best effort, as on the webhook path: a lookup failure must not fail // the repair, it just gets the warn line below so the gap is attributable. - const carrier = await TwilioClient().getCarrier(identity.phone) + const cachedCarrier = carrierLookups.get(userId) + const carrier = cachedCarrier ?? (await TwilioClient().getCarrier(identity.phone)) if (carrier instanceof Error) { logger.warn( { err: carrier, kratosUserId: userId }, "orphaned kratos identity: carrier lookup failed, repairing without phone metadata", ) + } else if (!cachedCarrier) { + carrierLookups.set(userId, carrier) } const created = await createAccountWithPhoneIdentifier({ @@ -157,6 +172,7 @@ const attemptRepair = async ({ const existing = await Accounts.getAccountFromUserId(userId) if (!(existing instanceof Error)) { failedRepairs.delete(userId) + carrierLookups.delete(userId) logger.warn( { kratosUserId: userId, accountId: existing.id }, "orphaned kratos identity repaired by a concurrent request", @@ -176,6 +192,7 @@ const attemptRepair = async ({ } failedRepairs.delete(userId) + carrierLookups.delete(userId) logger.warn( { kratosUserId: userId, accountId: created.id }, "orphaned kratos identity repaired", diff --git a/test/flash/unit/servers/middlewares/session.spec.ts b/test/flash/unit/servers/middlewares/session.spec.ts index 01c110308..3abfa85e8 100644 --- a/test/flash/unit/servers/middlewares/session.spec.ts +++ b/test/flash/unit/servers/middlewares/session.spec.ts @@ -10,6 +10,9 @@ import { ErrorLevel } from "@domain/shared" import { AuthenticationError } from "@graphql/error" import { clearOrphanRepairState, + REPAIR_RETRY_MAX_MS, + REPAIR_RETRY_WINDOW_MS, + repairRetryDelayMs, sessionPublicContext, } from "@servers/middlewares/session" import { IdentityRepository, UnknownKratosError } from "@services/kratos" @@ -446,5 +449,78 @@ describe("sessionPublicContext", () => { "orphaned kratos identity repaired", ) }) + + // An identity that will never repair (phone collides on users.phone, no + // phone trait) must not cost a Kratos read, two Mongo writes and a billed + // Twilio lookup every minute per replica for as long as its app polls. + it("doubles the retry window on every consecutive failure, capped at an hour", () => { + expect(repairRetryDelayMs(1)).toBe(REPAIR_RETRY_WINDOW_MS) + expect(repairRetryDelayMs(2)).toBe(REPAIR_RETRY_WINDOW_MS * 2) + expect(repairRetryDelayMs(3)).toBe(REPAIR_RETRY_WINDOW_MS * 4) + expect(repairRetryDelayMs(7)).toBe(REPAIR_RETRY_MAX_MS) // 64 min > cap + expect(repairRetryDelayMs(20)).toBe(REPAIR_RETRY_MAX_MS) + expect(repairRetryDelayMs(0)).toBe(REPAIR_RETRY_WINDOW_MS) + }) + + it("backs off: the second failure holds for two windows before the next attempt", async () => { + const start = new Date("2026-09-01T12:00:00Z").getTime() + jest.useFakeTimers({ now: start }) + getIdentity.mockResolvedValue(new UnknownKratosError("kratos down")) + + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + jest.setSystemTime(start + 61_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(getIdentity).toHaveBeenCalledTimes(2) + + // 90s after the second failure: inside its 120s window, no attempt. + jest.setSystemTime(start + 61_000 + 90_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(getIdentity).toHaveBeenCalledTimes(2) + expect(childLogger.debug).toHaveBeenLastCalledWith( + expect.objectContaining({ kratosUserId, repairFailures: 2 }), + "orphaned kratos identity: repair skipped, last attempt failed recently", + ) + + // 121s after the second failure: window elapsed, third attempt. + jest.setSystemTime(start + 61_000 + 121_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(getIdentity).toHaveBeenCalledTimes(3) + expect(childLogger.warn).toHaveBeenLastCalledWith( + expect.objectContaining({ + kratosUserId, + repairFailures: 3, + retryAfterMs: REPAIR_RETRY_WINDOW_MS * 4, + }), + "orphaned kratos identity: could not load identity", + ) + }) + + it("bills the carrier lookup once per identity across repair attempts", async () => { + const start = new Date("2026-09-01T12:00:00Z").getTime() + jest.useFakeTimers({ now: start }) + getIdentity.mockResolvedValue({ id: kratosUserId, phone }) + // users.phone collision: the account stays missing, so the repair fails. + mockedCreateAccount.mockResolvedValue( + new DuplicateKeyForPersistError("E11000 users.phone"), + ) + + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(getCarrier).toHaveBeenCalledTimes(1) + + jest.setSystemTime(start + 61_000) + await expectNotAuthenticated(sessionPublicContext({ tokenPayload, ip })) + expect(mockedCreateAccount).toHaveBeenCalledTimes(2) + expect(getCarrier).toHaveBeenCalledTimes(1) + expect(mockedCreateAccount).toHaveBeenLastCalledWith( + expect.objectContaining({ phoneMetadata }), + ) + + // Once the repair succeeds the cached lookup is dropped with the failure record. + jest.setSystemTime(start + 61_000 + 121_000) + mockedCreateAccount.mockResolvedValue(account) + const context = await sessionPublicContext({ tokenPayload, ip }) + expect(context.domainAccount).toBe(account) + expect(getCarrier).toHaveBeenCalledTimes(1) + }) }) })