From 27cf00985d99c2d81e0e04153c6ce9545f55a3a1 Mon Sep 17 00:00:00 2001 From: Nathan Flurry Date: Thu, 12 Mar 2026 23:49:50 -0700 Subject: [PATCH] Make GitHub OAuth callback idempotent against duplicate requests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Clear oauthState before exchangeCode so duplicate callback requests fail the state check instead of hitting GitHub with a consumed code. Marked as HACK — root cause of duplicate HTTP requests is unknown. Co-Authored-By: Claude Opus 4.6 --- .../backend/src/actors/workspace/app-shell.ts | 71 +++++++++++++++++-- foundry/research/friction/general.mdx | 23 ++++++ 2 files changed, 88 insertions(+), 6 deletions(-) diff --git a/foundry/packages/backend/src/actors/workspace/app-shell.ts b/foundry/packages/backend/src/actors/workspace/app-shell.ts index b2f259e..01b4289 100644 --- a/foundry/packages/backend/src/actors/workspace/app-shell.ts +++ b/foundry/packages/backend/src/actors/workspace/app-shell.ts @@ -14,10 +14,15 @@ import { getActorRuntimeContext } from "../context.js"; import { getOrCreateWorkspace } from "../handles.js"; import { GitHubAppError } from "../../services/app-github.js"; import { repoIdFromRemote, repoLabelFromRemote } from "../../services/repo.js"; +import { logger } from "../../logging.js"; import { appSessions, invoices, organizationMembers, organizationProfile, repos, seatAssignments, stripeLookup } from "./db/schema.js"; export const APP_SHELL_WORKSPACE_ID = "app"; +const githubWebhookLogger = logger.child({ + scope: "github-webhook", +}); + const PROFILE_ROW_ID = "profile"; const OAUTH_TTL_MS = 10 * 60_000; @@ -621,6 +626,20 @@ export const workspaceAppActions = { throw new Error("GitHub OAuth state is invalid or expired"); } + // HACK: Clear the oauth state before exchangeCode so that duplicate + // callback requests (e.g. user refresh during the slow sync) fail the + // state check above instead of attempting a second code exchange. + // GitHub OAuth codes are single-use; a second exchangeCode always + // returns bad_verification_code. The root cause of duplicate requests + // is unknown — actor RPCs serialize, appWorkspaceAction does not retry, + // yet production logs show two HTTP requests with different request IDs + // hitting /v1/auth/github/callback with the same code+state ~9s apart. + // See research/friction/general.mdx 2026-03-13 entry. + await updateAppSession(c, session.id, { + oauthState: null, + oauthStateExpiresAt: null, + }); + const token = await appShell.github.exchangeCode(input.code); await updateAppSession(c, session.id, { githubScope: token.scopes.join(","), @@ -1014,7 +1033,14 @@ export const workspaceAppActions = { const accountLogin = body.installation?.account?.login; const accountType = body.installation?.account?.type; if (!accountLogin) { - console.log(`[github-webhook] Ignoring ${event}.${body.action ?? ""}: no installation account`); + githubWebhookLogger.info( + { + event, + action: body.action ?? null, + reason: "missing_installation_account", + }, + "ignored", + ); return { ok: true }; } @@ -1022,7 +1048,15 @@ export const workspaceAppActions = { const organizationId = organizationWorkspaceId(kind, accountLogin); if (event === "installation" && (body.action === "created" || body.action === "deleted" || body.action === "suspend" || body.action === "unsuspend")) { - console.log(`[github-webhook] ${event}.${body.action} for ${accountLogin} (org=${organizationId})`); + githubWebhookLogger.info( + { + event, + action: body.action, + accountLogin, + organizationId, + }, + "installation_event", + ); if (body.action === "deleted") { const workspace = await getOrCreateWorkspace(c, organizationId); await workspace.applyGithubInstallationRemoved({}); @@ -1036,8 +1070,16 @@ export const workspaceAppActions = { } if (event === "installation_repositories") { - console.log( - `[github-webhook] ${event}.${body.action} for ${accountLogin}: +${body.repositories_added?.length ?? 0} -${body.repositories_removed?.length ?? 0}`, + githubWebhookLogger.info( + { + event, + action: body.action ?? null, + accountLogin, + organizationId, + repositoriesAdded: body.repositories_added?.length ?? 0, + repositoriesRemoved: body.repositories_removed?.length ?? 0, + }, + "repository_membership_changed", ); const workspace = await getOrCreateWorkspace(c, organizationId); await workspace.applyGithubRepositoryChanges({ @@ -1063,13 +1105,30 @@ export const workspaceAppActions = { ) { const repoFullName = body.repository?.full_name; if (repoFullName) { - console.log(`[github-webhook] ${event}.${body.action ?? ""} for ${repoFullName}`); + githubWebhookLogger.info( + { + event, + action: body.action ?? null, + accountLogin, + organizationId, + repoFullName, + }, + "repository_event", + ); // TODO: Dispatch to GitHubStateActor / downstream actors } return { ok: true }; } - console.log(`[github-webhook] Unhandled event: ${event}.${body.action ?? ""}`); + githubWebhookLogger.info( + { + event, + action: body.action ?? null, + accountLogin, + organizationId, + }, + "unhandled_event", + ); return { ok: true }; }, diff --git a/foundry/research/friction/general.mdx b/foundry/research/friction/general.mdx index 6535897..de19cab 100644 --- a/foundry/research/friction/general.mdx +++ b/foundry/research/friction/general.mdx @@ -1,5 +1,28 @@ # General Friction Log +## 2026-03-13 - uncommitted + +### What I Was Working On + +Debugging slow GitHub OAuth sign-in in production after deploying backend request logging (d0ed0a4). + +### Friction / Issue + +Production logs showed two separate HTTP requests (different request IDs, ~9s apart) hitting `GET /v1/auth/github/callback` with the same `code` and `state` parameters. The first request succeeded (`exchangeCode` returned a token) but took ~18s total due to `syncGithubSessionFromToken` making multiple sequential GitHub API calls. The second request arrived while the first was still syncing, passed the oauth state validation (state was never cleared), and attempted `exchangeCode` with the already-consumed code, which GitHub rejected with `bad_verification_code`. + +The root cause of the duplicate HTTP request is unknown. It is not `appWorkspaceAction` (no retry logic in the current version), not Railway proxy retry (no such config), and not a frontend double-navigation (the SPA is not involved during the OAuth redirect chain). Best hypothesis is the user refreshing during the ~18s blank page wait, but unconfirmed. + +### Attempted Fix / Workaround + +1. Made `completeAppGithubAuth` clear `oauthState`/`oauthStateExpiresAt` immediately after validation and before `exchangeCode`, so any duplicate request fails the state check instead of hitting GitHub with a consumed code. +2. Marked the fix as a HACK since the root cause of the duplicate request is not identified. + +### Outcome + +- Duplicate callback requests now fail fast with "GitHub OAuth state is invalid or expired" instead of producing a `bad_verification_code` error from GitHub. +- The first request completes normally and the user lands on `/organizations`. +- Root cause of the duplicate HTTP request remains uninvestigated. + ## 2026-03-05 - uncommitted ### What I Was Working On