From 6a848a2679f75f490c6eef4d22498ece50be66ad Mon Sep 17 00:00:00 2001 From: Ali Al Dallal Date: Wed, 12 Aug 2026 17:28:07 -0400 Subject: [PATCH] =?UTF-8?q?fix:=20e2e=20CI=20flake=20=E2=80=94=20goal-0017?= =?UTF-8?q?=20emit=20fanout=20raced=20canvas-live-sync=20(Standing=20#1)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Root cause, confirmed via real CI history (6/6 shard-1 failures, all after goal 0017 merged, zero before) and local reproduction (9/20 clean-canvas repeats failed with zero artificial load): goal 0017 gave every direct-mutation service its own dataevent.Emit call, so a single MCP update_workflow write now fires mill-data-changed TWICE (SnapshotDraft + UpdateWorkflow) plus a third echo from the test's own prior UI-driven CreateWorkflow. None carry payload content, so each handler independently refetches — three fetches racing meant whichever resolved last won unconditionally, letting a stale response beat an already-applied newer one and wrongly show the external-change banner on a clean canvas. Fixed in useCanvasLiveSync.ts with a monotonic request-sequence guard (the standard out-of-order-async-response fix): drop a fetch response once a newer mill-data-changed event has arrived since it was dispatched. Verified: 88 consecutive clean local repeats post-fix vs. 9/20 before it, same build. Also: canvas-live-sync.spec.ts's cleanup hardened into an outer try/finally (both tests) so a future assertion failure can't leave an undeleted workflow / unattended-MCP-writes settings for later tests in the same worker — defense-in-depth for the observed cascade, independent of the root-cause fix. resizable-table.spec.ts's one occurrence (PR #24, drag-handle bounding box) hardened with a condition-based expect.poll wait at the point of use, additive to the suite's existing retries: 1 (goal 0024 precedent, untouched). BACKLOG.md Standing #1 checked off with the full root-cause writeup; SPEC.md's realtime-lock section gets an Update note generalizing the lesson for future mill-data-changed consumers. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_018pkViCNAuZp2vBv2K9AbUh --- docs/SPEC.md | 19 +++- docs/goals/BACKLOG.md | 2 +- frontend/e2e/canvas-live-sync.spec.ts | 100 +++++++++++------- frontend/e2e/resizable-table.spec.ts | 11 ++ frontend/src/composition/useCanvasLiveSync.ts | 44 +++++++- 5 files changed, 133 insertions(+), 43 deletions(-) diff --git a/docs/SPEC.md b/docs/SPEC.md index ce54de2e..bdd1350e 100644 --- a/docs/SPEC.md +++ b/docs/SPEC.md @@ -126,7 +126,24 @@ an implicit `FINAL`. now round-trip through `localStorage` (`shared/store.ts`'s zustand `persist`, `shared/workTabs.ts`'s pure restore helpers) so a reload — deliberate or not — restores the same place instead of resetting - to Home. + to Home. **Update (2026-08-12, e2e CI flake investigation): goal + 0017's per-service `dataevent.Emit` fanout had a real race.** Giving + every direct-mutation service its own emit call means a single + logical write can now fire the SAME `mill-data-changed` event more + than once for the same entity (an MCP `update_workflow` write emits + from both `SnapshotDraft` and `UpdateWorkflow`; a canvas that just + created its own workflow can still be mid-flight on that emit when it + re-subscribes) — and since the event carries no payload, every + handler independently re-fetches, so several near-simultaneous + fetches can resolve out of order. `useCanvasLiveSync.ts` + (`frontend/src/composition/`) was the one caller sensitive to this + (its clean-vs-dirty decision), fixed with a monotonic per-hook + request-sequence guard that drops a response once a newer event has + arrived since it was dispatched — the general lesson for any FUTURE + `mill-data-changed` consumer that both reacts to the event AND + compares against locally-held state: assume the event can fire more + than once per logical change and can deliver out of order, don't + assume "one event in, one fetch, apply unconditionally" is safe. - **Scope filter, learned from the screenshot-to-clipboard tangent**: before any capability goes into Mill, check whether the OS (or an existing launcher like Alfred/Raycast) already does it simply and well. If yes, diff --git a/docs/goals/BACKLOG.md b/docs/goals/BACKLOG.md index 73e4ff3c..40278e74 100644 --- a/docs/goals/BACKLOG.md +++ b/docs/goals/BACKLOG.md @@ -184,7 +184,7 @@ live-review material, interleaved during owner reviews, not a lane.** contention flake, both confirmed transient on an isolated rerun). **Standing — ratified order (owner-delegated prioritization, 2026-08-12: "prioritize all work to line them up"; Dependabot majors pulled to the front same day per the deps-don't-linger policy and are IN FLIGHT as their own sequential wave, not listed here)** -1. [ ] E2e CI flake investigation (owner-directed 2026-08-12: "add to the backlog when problem found so that we prioritize to unblock us"; FIRST in queue because it taxes every subsequent PR with rerun cycles — `canvas-live-sync` alone flaked twice on 2026-08-12) — distinct e2e specs failing once on a shard then green on immediate rerun, across different PRs: `resizable-table.spec.ts` (drag-handle bounding-box), `canvas-live-sync.spec.ts` (MCP `update_workflow` live-redraw assertion, ×2), and (Go side, same class) `TestMillMCPService_RealClientRoundTrip` (already fixed — 2s `Shutdown` timeout too tight for a loaded runner, bumped to 10s, PR #21). Each individually diagnosed unrelated to its PR and confirmed transient by rerun — but the pattern deserves batch investigation: under-resourced shared runners vs a shared timing-sensitivity shape in these specs vs the general suite shape surfacing one spec at a time. DoR: pull actual CI run history for pass/fail/rerun rates over the last N runs before assuming root cause; DoD: a fix (shared wait pattern, strategic retries per goal 0024's e2e-retry precedent) or a documented accept-with-reasoning, never silence. +1. [x] E2e CI flake investigation — RESOLVED 2026-08-12 (`fix/e2e-flake-hardening`). Real CI history (last ~30 `ci.yml` runs) showed `canvas-live-sync.spec.ts` failing 6/6 times on shard 1, every single occurrence at the exact same assertion (`canvas-live-sync.spec.ts:151`, the `external-change-banner` count) and every single occurrence co-occurring with a `configure-lists.spec.ts` "list-search node" flake in the SAME run (recovered on Playwright's own retry every time) — zero occurrences before goal 0017 (PR #16) merged, all 6 after. Root cause: goal 0017 gave every direct-mutation Go service its own `dataevent.Emit("workflow", id)` call, so a single MCP `update_workflow` write now fires the SAME `mill-data-changed` event TWICE (`SnapshotDraft`'s own emit via `mutateWorkflow`, plus `UpdateWorkflow`'s own emit) — plus a THIRD echo from the test's own earlier UI-driven `CreateWorkflow`, still possibly in flight when the canvas mounts. None of the three carry payload content, so each independently re-fetches via `CompositionService.Workflows()`; three fetches racing meant whichever RESOLVED last won unconditionally regardless of dispatch order, so a stale response could occasionally win the live-sync decision against a baseline a different, already-applied response had advanced past — wrongly showing the external-change banner on a genuinely clean canvas. A REAL race, confirmed via local reproduction (9/20 clean-canvas repeats failed with zero artificial load, identical assertion/line to all 6 CI failures) and a temporary event-trace instrument. Fixed in `frontend/src/composition/useCanvasLiveSync.ts`: a monotonic per-hook request-sequence ref, bumped at event ARRIVAL time, drops any fetch response that's gone stale by the time it resolves (the standard out-of-order-async-response guard) — correct regardless of how many redundant emits fire in a burst or their resolution order. Verified: 88 consecutive clean local repeats post-fix (0 failures) vs. 9/20 before it, same build. `canvas-live-sync.spec.ts`'s own cleanup (both tests) hardened into an outer try/finally regardless, so a future assertion failure can never again leave an undeleted workflow / unattended-MCP-writes settings behind for later tests in the same worker. `resizable-table.spec.ts` (1 occurrence, PR #24, drag-handle bounding-box) hardened with a condition-based `expect.poll` wait at the point of use, additive to the suite's existing `retries: 1` (goal 0024's documented precedent, untouched). `TestMillMCPService_RealClientRoundTrip` was already fixed (PR #21). Full local suite green; both suspect specs run 5x locally with zero failures. 2. [ ] [0031 — AI node family](0031-ai-node-family.md) — research banked in the goal file (two adapters: openaicompat covers Ollama+BYO, anthropic native; AIProvider Configure entity; ai-completion + ai-extract-structured first). Effect-class LOCKED by owner delegation 2026-08-12 ("you're the boss"): static `ClassExternal` + `EffectForNode` downgrade to `ClassLocal` for loopback (localhost/127.0.0.1/::1) BaseURLs — remote asks by default, local Ollama frictionless. The flagship capability; conforms to node-standard.md from birth. 3. [ ] Copy-management migration ×4 (below, in order: `app/` → `composition/` → `configure/` → `views/`) then the `eslint-plugin-i18next` revisit — mechanical filler, interleaves between heavier waves when useful. 4. [ ] Workflow pins/favorites (tech debt, split from goal 0015's remainder 2026-08-12) — schema DECIDED at prioritization (orchestrator, 2026-08-12): a plain ordered workflow-ID list, store-owned (localStorage-tier alongside the frecency substrate; no per-workflow field, no new Go surface unless syncing matters later). Pinned rows sort above frecency in Quick Panel/⌘K. diff --git a/frontend/e2e/canvas-live-sync.spec.ts b/frontend/e2e/canvas-live-sync.spec.ts index 381a0dde..06094260 100644 --- a/frontend/e2e/canvas-live-sync.spec.ts +++ b/frontend/e2e/canvas-live-sync.spec.ts @@ -125,6 +125,26 @@ async function restoreMCPWriteDefaults(page: Page): Promise { } } +// Closes the open editor tab, deletes the named workflow row, and +// restores the shared MCP-write settings -- shared by both tests below, +// each wrapping this in an outer try/finally so it ALWAYS runs, even +// when an assertion above throws. Before this, both tests only ran +// their cleanup on the happy path: a failed assertion inside the MCP +// round-trip (this file's own live race, fixed in useCanvasLiveSync.ts) +// left "E2E live sync clean"/"dirty" undeleted AND unattended MCP +// writes still enabled for the rest of this worker's shard -- traced +// live as the mechanism behind a real cascade (this spec's own flake +// tripping configure-lists.spec.ts's "list-search node" test in the +// same shard-1 CI run, docs/goals/BACKLOG.md Standing #1). Kept as +// cleanup hardening regardless of the race fix -- any OTHER future +// assertion failure in either test would hit the exact same cascade +// without it. +async function cleanupWorkflow(page: Page, label: string): Promise { + await page.getByRole('button', { name: 'Close tab' }).last().click() + await clickRowAction(page, workflowRow(page, label), 'Delete') + await restoreMCPWriteDefaults(page) +} + test('clean canvas: an external MCP update_workflow redraws the open editor live, no reload', async ({ page }, testInfo) => { await enableUnattendedMCPWrites(page) @@ -138,24 +158,24 @@ test('clean canvas: an external MCP update_workflow redraws the open editor live await row.click() await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(1) - const client = await connectMCPClient(testInfo.parallelIndex) try { - const workflowId = await findWorkflowIdByLabel(client, 'E2E live sync clean') - await updateWorkflowViaMCP(client, workflowId, twoNodeDefinition('E2E live sync clean', 'clean-path marker')) - - // No page.reload(), no re-navigation -- the redraw has to happen - // purely from the `mill-data-changed` event this canvas subscribed - // to (useCanvasLiveSync.ts). - await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(2, { timeout: 10_000 }) - await expect(activePanel(page).locator('.react-flow__node').filter({ hasText: 'Process: Inject text' })).toBeVisible() - await expect(page.getByTestId('external-change-banner')).toHaveCount(0) + const client = await connectMCPClient(testInfo.parallelIndex) + try { + const workflowId = await findWorkflowIdByLabel(client, 'E2E live sync clean') + await updateWorkflowViaMCP(client, workflowId, twoNodeDefinition('E2E live sync clean', 'clean-path marker')) + + // No page.reload(), no re-navigation -- the redraw has to happen + // purely from the `mill-data-changed` event this canvas subscribed + // to (useCanvasLiveSync.ts). + await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(2, { timeout: 10_000 }) + await expect(activePanel(page).locator('.react-flow__node').filter({ hasText: 'Process: Inject text' })).toBeVisible() + await expect(page.getByTestId('external-change-banner')).toHaveCount(0) + } finally { + await client.close() + } } finally { - await client.close() + await cleanupWorkflow(page, 'E2E live sync clean') } - - await page.getByRole('button', { name: 'Close tab' }).last().click() - await clickRowAction(page, workflowRow(page, 'E2E live sync clean'), 'Delete') - await restoreMCPWriteDefaults(page) }) test('dirty canvas: external MCP edit shows a banner, keeps the local edit, and Reload applies the fresh definition', async ({ page }, testInfo) => { @@ -180,32 +200,32 @@ test('dirty canvas: external MCP edit shows a banner, keeps the local edit, and await activePanel(page).getByTestId('toggle-description').click() await activePanel(page).getByLabel('Description').fill('local unsaved edit') - const client = await connectMCPClient(testInfo.parallelIndex) try { - const workflowId = await findWorkflowIdByLabel(client, 'E2E live sync dirty') - await updateWorkflowViaMCP(client, workflowId, twoNodeDefinition('E2E live sync dirty', 'dirty-path marker')) - - const banner = page.getByTestId('external-change-banner') - await expect(banner).toBeVisible({ timeout: 10_000 }) - - // The local edit is untouched -- the external change was NOT - // applied automatically while dirty. - await expect(activePanel(page).getByLabel('Description')).toHaveValue('local unsaved edit') - await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(1) - - await banner.getByRole('button', { name: 'Reload' }).click() - - // Reload discards the local draft and loads the fresh (external) - // definition. - await expect(banner).toHaveCount(0) - await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(2) - await expect(activePanel(page).locator('.react-flow__node').filter({ hasText: 'Process: Inject text' })).toBeVisible() - await expect(activePanel(page).getByLabel('Description')).toHaveValue('') + const client = await connectMCPClient(testInfo.parallelIndex) + try { + const workflowId = await findWorkflowIdByLabel(client, 'E2E live sync dirty') + await updateWorkflowViaMCP(client, workflowId, twoNodeDefinition('E2E live sync dirty', 'dirty-path marker')) + + const banner = page.getByTestId('external-change-banner') + await expect(banner).toBeVisible({ timeout: 10_000 }) + + // The local edit is untouched -- the external change was NOT + // applied automatically while dirty. + await expect(activePanel(page).getByLabel('Description')).toHaveValue('local unsaved edit') + await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(1) + + await banner.getByRole('button', { name: 'Reload' }).click() + + // Reload discards the local draft and loads the fresh (external) + // definition. + await expect(banner).toHaveCount(0) + await expect(activePanel(page).locator('.react-flow__node')).toHaveCount(2) + await expect(activePanel(page).locator('.react-flow__node').filter({ hasText: 'Process: Inject text' })).toBeVisible() + await expect(activePanel(page).getByLabel('Description')).toHaveValue('') + } finally { + await client.close() + } } finally { - await client.close() + await cleanupWorkflow(page, 'E2E live sync dirty') } - - await page.getByRole('button', { name: 'Close tab' }).last().click() - await clickRowAction(page, workflowRow(page, 'E2E live sync dirty'), 'Delete') - await restoreMCPWriteDefaults(page) }) diff --git a/frontend/e2e/resizable-table.spec.ts b/frontend/e2e/resizable-table.spec.ts index 70cda3f3..b7c034c2 100644 --- a/frontend/e2e/resizable-table.spec.ts +++ b/frontend/e2e/resizable-table.spec.ts @@ -26,6 +26,17 @@ test('Table columns are drag-resizable and long cells truncate with a hover titl const firstTrack = () => table.evaluate((t) => parseFloat(getComputedStyle(t).gridTemplateColumns.split(' ')[0])) const before = await firstTrack() + // Condition-based wait, not a fixed-window one (docs/goals/BACKLOG.md + // Standing #1's CI flake investigation, 2026-08-12): a bare + // `boundingBox()` read right after the table becomes visible can still + // race the grid's own column-width layout pass under a loaded runner, + // occasionally returning null (PR #24's real flake -- the whole + // test's global `retries: 1`, playwright.config.ts, already masked + // it once; this polls for a stable box directly at the point of use + // instead of leaning on a full-test rerun to paper over layout timing). + await expect + .poll(() => handles.first().boundingBox().then((b) => b !== null), { timeout: 5_000 }) + .toBe(true) const box = await handles.first().boundingBox() if (!box) throw new Error('resize handle has no bounding box') const x = box.x + box.width / 2 diff --git a/frontend/src/composition/useCanvasLiveSync.ts b/frontend/src/composition/useCanvasLiveSync.ts index dfef47cf..172dd66c 100644 --- a/frontend/src/composition/useCanvasLiveSync.ts +++ b/frontend/src/composition/useCanvasLiveSync.ts @@ -100,14 +100,56 @@ export function useCanvasLiveSync(args: UseCanvasLiveSyncArgs): UseCanvasLiveSyn draftDescriptionRef.current = draftDescription }, [draftDescription]) + // Real bug found via CI flake investigation (docs/goals/BACKLOG.md + // Standing #1, 2026-08-12): goal 0017 gave every direct-mutation + // service its own `dataevent.Emit("workflow", id)` call -- but for a + // single MCP `update_workflow` write, that now fires the SAME + // `mill-data-changed` event TWICE: once from `SnapshotDraft` + // (compositionservice_versioning.go's `mutateWorkflow`, archiving the + // draft before the edit lands) and once from `UpdateWorkflow` itself + // (compositionservice.go) -- plus a THIRD, from this canvas's own + // `CreateWorkflow` moments earlier (canvas-live-sync.spec.ts's "clean + // canvas" test creates the workflow via the UI first), which can + // still be in flight when the canvas mounts and subscribes. All three + // carry no content of their own -- each handler independently calls + // CompositionService.Workflows() to refetch -- so three near- + // simultaneous events dispatch three independent fetches whose + // RESPONSES can resolve in a different order than they were + // dispatched. Before this fix, whichever resolved LAST won + // unconditionally, so a stale response could win the + // decideExternalSyncAction comparison against a baseline a different, + // already-applied response had advanced past, wrongly deciding + // "prompt" and showing the external-change banner on a genuinely + // clean canvas -- confirmed locally (traced via a temporary + // arrival/resolution/decision log): 9/20 repeats of the "clean + // canvas" test failed on exactly this assertion with zero artificial + // load, matching 6/6 real CI failures found in the last ~30 CI runs + // (canvas-live-sync.spec.ts:151, all after goal 0017 merged, zero + // occurrences before). requestSeqRef is the standard fix for + // out-of-order async responses: each event bumps the counter at + // ARRIVAL time (not resolution time), and a response is dropped + // unless it's still the most recently dispatched one when it resolves + // -- correct regardless of how many of these events fire in a burst + // or which of their fetches happens to resolve first. Verified fixed: + // 88 consecutive clean local runs (0 failures) after this change, vs. + // 9/20 before it, same build. + const requestSeqRef = useRef(0) + useEffect(() => { if (!workflowId) return return Events.On('mill-data-changed', (evt) => { const data = evt.data as { entity?: string; id?: string } if (data?.entity !== 'workflow' || data?.id !== workflowId) return + const seq = ++requestSeqRef.current CompositionService.Workflows() .then((all) => { - const fresh = (all ?? []).find((w) => w.ID === workflowId) + // A newer mill-data-changed event for this same workflow has + // already arrived and dispatched its own fetch since this one + // started -- this response is now stale (see the header + // comment above); applying or even just deciding on it would + // race the newer one. Drop it. + if (seq !== requestSeqRef.current) return + const fresh = (all ?? []).find((wf) => wf.ID === workflowId) // A concurrent external delete is out of this feature's scope // -- WorkTabShell's own once-lists-load tab-pruning handles a // since-deleted entity's open tab separately.