From 66a777f8636e84103003ff46ac1ea3e6da6d61b0 Mon Sep 17 00:00:00 2001 From: Bob Qiu Date: Tue, 29 Sep 2026 16:13:58 +0800 Subject: [PATCH] debug(project): add temporary timing diagnostics for create-project hang MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two prior fixes (lock acquire timeout, bounded team-projects fetch timeout) targeted the wrong bottleneck — the mock API's team-projects endpoint responds instantly with no artificial delay, so the CI hang is coming from somewhere else. Add console.log timing around lock wait/hold time, NeDB project creation, and the team-projects fetch/sync so the next CI failure's console-log attachment shows exactly which step is slow. Co-Authored-By: Claude Sonnet 5 --- .../insomnia-data/node-src/services/project.ts | 10 ++++++++++ packages/insomnia/src/common/project.ts | 14 +++++++++++++- .../organization.$organizationId.project.new.tsx | 6 ++++++ 3 files changed, 29 insertions(+), 1 deletion(-) diff --git a/packages/insomnia-data/node-src/services/project.ts b/packages/insomnia-data/node-src/services/project.ts index 5567ca0054..8d4b437a44 100644 --- a/packages/insomnia-data/node-src/services/project.ts +++ b/packages/insomnia-data/node-src/services/project.ts @@ -75,6 +75,8 @@ export async function getFirstProjectOfOrganization(organizationId: string) { const TEAM_PROJECTS_FETCH_TIMEOUT_MS = 8000; export async function getAllTeamProjects(organizationId: string) { + // TEMP DIAGNOSTIC: see matching note in insomnia/src/common/project.ts's wrapWithLock. + const diagStart = Date.now(); const { id: sessionId } = await userSessionService.get(); if (!sessionId) { return []; @@ -82,6 +84,7 @@ export async function getAllTeamProjects(organizationId: string) { console.log('[project] Fetching', organizationId); const response = await fetchTeamProjects({ sessionId, organizationId, timeout: TEAM_PROJECTS_FETCH_TIMEOUT_MS }); + console.log(`[create-project-timing] fetchTeamProjects done after ${Date.now() - diagStart}ms`); return response.data; } @@ -157,14 +160,21 @@ export async function syncTeamProjects({ } export async function syncProjects(organizationId: string) { + // TEMP DIAGNOSTIC: see matching note in insomnia/src/common/project.ts's wrapWithLock. + const diagStart = Date.now(); + console.log(`[create-project-timing] syncProjects(${organizationId}) start`); // Local-only organizations have no team projects to fetch, so bail out before the request. if (models.organization.isLocalOrganizationId(organizationId)) { + console.log('[create-project-timing] syncProjects bailed out (local-only organization)'); return; } const user = await userSessionService.get(); const teamProjects = await getAllTeamProjects(organizationId); // ensure we don't sync projects in the wrong place if (Array.isArray(teamProjects) && user.id) { + const syncStart = Date.now(); await syncTeamProjects({ teamProjects, organizationId }); + console.log(`[create-project-timing] syncTeamProjects() done after ${Date.now() - syncStart}ms`); } + console.log(`[create-project-timing] syncProjects total ${Date.now() - diagStart}ms`); } diff --git a/packages/insomnia/src/common/project.ts b/packages/insomnia/src/common/project.ts index 18c48c953d..0a412c566b 100644 --- a/packages/insomnia/src/common/project.ts +++ b/packages/insomnia/src/common/project.ts @@ -87,11 +87,23 @@ const lockGenerator = () => { const wrapWithLock = Promise>(fn: T): T => { const wrappedFn = async (...args: Parameters): Promise> => { + // TEMP DIAGNOSTIC: timing breakdown to root-cause the intermittent + // "Create project" hang seen in CI (see insomnia PR #10556). Remove + // once the real bottleneck is identified from CI console-log output. + const callId = Math.random().toString(36).slice(2, 8); + const waitStart = Date.now(); + console.log(`[lock-timing] ${callId} waiting for lock`); await lock(); + const waitMs = Date.now() - waitStart; + console.log(`[lock-timing] ${callId} acquired lock after ${waitMs}ms`); try { - return await fn(...args); + const runStart = Date.now(); + const result = await fn(...args); + console.log(`[lock-timing] ${callId} fn() finished after ${Date.now() - runStart}ms (holding lock)`); + return result; } finally { await unlock(); + console.log(`[lock-timing] ${callId} released lock`); } }; return wrappedFn as T; diff --git a/packages/insomnia/src/routes/organization.$organizationId.project.new.tsx b/packages/insomnia/src/routes/organization.$organizationId.project.new.tsx index 5610971e02..16bf47b1c2 100644 --- a/packages/insomnia/src/routes/organization.$organizationId.project.new.tsx +++ b/packages/insomnia/src/routes/organization.$organizationId.project.new.tsx @@ -60,7 +60,11 @@ export const reportGitProjectCount = async (organizationId: string, sessionId: s }; const createProjectImpl = async (organizationId: string, newProjectData: CreateProjectData) => { + // TEMP DIAGNOSTIC: see matching note in ~/common/project.ts's wrapWithLock. + const diagStart = Date.now(); + console.log(`[create-project-timing] createProjectImpl start (storageType=${newProjectData.storageType})`); const user = await services.userSession.get(); + console.log(`[create-project-timing] userSession.get() done after ${Date.now() - diagStart}ms`); const sessionId = user.id; invariant(sessionId, 'User must be logged in to create a project'); invariant( @@ -69,10 +73,12 @@ const createProjectImpl = async (organizationId: string, newProjectData: CreateP ); if (newProjectData.storageType === 'local') { + const dbStart = Date.now(); const project = await services.project.create({ name: newProjectData.name, parentId: organizationId, }); + console.log(`[create-project-timing] services.project.create() done after ${Date.now() - dbStart}ms (total ${Date.now() - diagStart}ms)`); return project._id; }