Picker/page test suites are pathologically slow under real timers; testTimeout: 60000 is masking it

[steilerDev]

Summary

@testing-library/user-event tests that drive a debounced component under real timers have become extremely slow, to the point of exceeding a 60s per-test limit. The current mitigation is a global testTimeout: 60000 in jest.config.ts (line 67), which hides the problem rather than fixing it — and the margin is now thin enough that unrelated PRs fail intermittently.

How this was found

While processing Dependabot PRs #2072 and #2073, both went red on Jest shards 5 and 6 with 60s timeouts (not assertion failures) in the SearchPicker / HouseholdItemPicker suites.

The dependency bumps were not the cause:

• chore(deps-dev): bump the dev-dependencies group with 3 updates #2072 contains no i18next/react-i18next/fastify change at all — only a lockfile repair plus eslint/stylelint — and it failed the identical tests.
• react-i18next 17.0.13 has zero runtime JS changes vs 17.0.12 (registry tarball diff: only index.d.ts + changelog).
• i18next 26.4.2's sole runtime change is a one-line $-escape in nest(), unreachable here (no $t( nesting anywhere in client/src/i18n/**).

Root cause

The regression entered beta in 038a9431 (PR #2070, "dev-dependencies group across 1 directory with 20 updates"), which bumped:

• @testing-library/user-event 14.6.1 → 14.6.7
• @testing-library/react 16.3.2 → 16.3.3
• jest 30.4.2 → 30.5.1
• jest-environment-jsdom 30.4.1 → 30.5.1

That commit's own message records the symptom and the workaround: "SearchPicker-family test timing (global testTimeout raise + a real assertion-ordering race fix)". #2070 passed CI; every PR branched from it has been failing.

Measured impact (from CI, untreated baseline on #2072)

Suite	Wall time	Failing tests
SearchPicker.test.tsx	2377 s (~40 min)	10
HouseholdItemPicker.test.tsx	498 s	2
HouseholdItemPicker.breadcrumb.test.tsx	537 s	2

Note HouseholdItemPicker.test.tsx spends ~357s across its passing tests (~30s each) — the whole file is slow, not just the tests that trip the ceiling.

Already fixed (on PR #2073 only)

Three commits convert those suites to jest.useFakeTimers() + userEvent.setup({ advanceTimers: jest.advanceTimersByTime.bind(jest) }), hoisted into each describe's beforeEach, with act(() => jest.advanceTimersByTime(300)) after each type/clear to clear the 300 ms useDebouncedCallback. No assertions were changed and no timeouts were raised. This also uncovered a latent bug: the Floating UI portal (#1708) describe block had no jest.useRealTimers() cleanup.

Remaining work

1. Sweep the rest of the client suite. There are 587 bare userEvent.setup() occurrences across client/src/**/*.test.tsx, and only 14 files currently use advanceTimers. Any suite combining a bare setup with a debounced component has the same latent slowness, currently hidden by the 60s ceiling. Largest concentrations:

   Occurrences	File
   73	client/src/pages/ReportWizardPage/ReportWizardPage.test.tsx
   52	client/src/pages/SubsidyProgramsPage/SubsidyProgramsPage.test.tsx
   48	client/src/pages/BudgetSourcesPage/BudgetSourcesPage.test.tsx
   43	client/src/pages/ManagePage/ManagePage.test.tsx
   39	client/src/pages/VendorDetailPage/VendorDetailPage.test.tsx
   36	client/src/pages/ReportWizardPage/ReportWizardPage.aiGeneration.test.tsx
   22	client/src/pages/HouseholdItemDetailPage/HouseholdItemDetailPage.test.tsx

2. Lower testTimeout back down (jest.config.ts:67) once the sweep lands. At 60000 the next suite to regress hides for a full minute per test instead of failing fast — which is exactly how this reached beta unnoticed.

3. Investigate the upstream cause. Worth confirming whether user-event 14.6.7 or jest/jsdom 30.5.x is responsible, and whether an upstream issue already exists. If the slowdown is a genuine upstream regression, pinning back may be preferable to converting hundreds of tests.

References

• Dependabot PRs: chore(deps-dev): bump the dev-dependencies group with 3 updates #2072, chore(deps): bump the prod-dependencies group with 3 updates #2073
• Introducing commit: 038a9431 (PR chore(deps-dev): bump the dev-dependencies group across 1 directory with 20 updates #2070)
• Config: jest.config.ts:67

🤖 Filed by /dependabot

[steilerDev]

Cross-linking from #2077, which I filed independently for the same residual work before I knew this issue existed. I'm closing #2077 in favour of this one — your framing ("testTimeout: 60000 is masking it") is the better description of the problem. Consolidating so the two don't drift.

Carrying over the measurement data from #2076 so it isn't lost:

Local A/B: the conversion shows no speedup when run unloaded

Full-file SearchPicker.test.tsx, --maxWorkers=1, no competing load:

Version	Result	Wall clock
Original, unconverted (real timers)	60/60 pass	1331.6 s
Converted (fake timers), run 1	60/60 pass	1290.7 s
Converted (fake timers), run 2	60/60 pass	1352.0 s

The unconverted file passes locally, so a single-worker local run never reproduces the CI failure at all.

But it demonstrably works in CI

Your #2073 run took shard 5 from 10 failures to 0 and shard 6 from 4 to 0. Those two results are only consistent if there is a real-timer-specific cost term that exists solely under CI contention — an unloaded setTimeout(..., 0) resolves in ~1 ms, but under --maxWorkers=2 plus runner noise it does not. Local single-worker runs structurally cannot exercise it. Worth recording, because it means local green proves nothing here and CI is the only oracle.

The base cost is separate, and still unexplained

Each dropdown-opening test costs ~21 s of CPU regardless of timer mode. That term is untouched by the conversion, which is why your #2073 run went green but shard 5 still took 26 min 45 s (vs a 7-8 min pre-#2070 baseline) and needed a retry, and shard 6 took 15 min 46 s. Green, but ~2-3x baseline. The suite now sits just under the ceiling instead of just over it — the same thin-margin state that took about three weeks to breach last time.

I probed one hypothesis for that base cost and it was wrong: pointerEventsCheck: Never on a representative 4-test subset gave 110.9 s -> 101.3 s, only ~9%. So the getComputedStyle ancestor walk is not the dominant term either.

Recommended next diagnostic, since two mechanism guesses have now been falsified by measurement: node --cpu-prof on a single dropdown test. 21 s of CPU in jsdom will surface one dominant frame within minutes. That should come before any further bulk conversion.

Also worth noting: pointerEventsCheck: Never should not be adopted as a perf lever

Independent of its poor measurement, it disables user-event's check that an element is not pointer-events: none — a test could then pass against a control a real user cannot click. That is assertion-weakening relocated into harness config.

And: partial conversion migrates the failure

#2073 converted SearchPicker.test.tsx fully but only 4 of 10 tests in HouseholdItemPicker.breadcrumb.test.tsx. The promotion PR's next run then failed on WorkItemPicker.test.tsx (shard 3) and HouseholdItemPicker.test.tsx (shard 6) — both previously passing, both still on real timers. The failing set is not content-determined (in the breadcrumb file, line 176 failed while the near-identical test at line 275 passed), so converting only the observed failures just relocates the problem to the next-nearest file. #2079 converts whole files for that reason.

There are 587 real-timer userEvent.setup() call sites across 45 client test files remaining.

[steilerDev]

Follow-up finding: the cost scales with keystrokes, not timers

Converting SearchPicker.test.tsx wholly onto fake timers (commit a9f8acad) barely moved its runtime — 2377s → 2329s. So for this file the wall-clock dependency was not the dominant cost, and fake timers alone will not fix it.

The residual cost tracks the number of characters typed. All three tests in the debounce behaviour block are structurally identical — same fake-timer setup, same single advanceTimersByTime(300), same shape of assertion — and differ only in typed length:

Test	Typed	Result
typing triggers searchFn with typed query after 300ms debounce	'A' (1 char)	passes
rapid typing only triggers one searchFn call after 300ms	'Alp' (3 chars)	passes
searchFn called with excludeIds as second argument	'Alpha' (5 chars)	failed 4 of 5 runs

userEvent.type() dispatches per character, and each keystroke drives a React re-render through Floating UI under jsdom. That per-render cost — not the debounce wait — is what pushes the 5-character test past the 60s ceiling. It also explains why the file was already at 1466s while passing on #2070: it has always been expensive, and the user-event 14.6.7 / jest 30.5.1 bump raised the per-interaction cost just enough to cross the line.

Implications for the sweep

1. Fake timers are necessary but not sufficient. They fixed HouseholdItemPicker.test.tsx (shard 6: 4 failures → green), because that file's cost really was debounce waiting. They did not fix SearchPicker.test.tsx. Expect both classes when working through the 587 occurrences.
2. Reducing keystrokes is a cheap, non-weakening fix where the typed text is not under test. For example searchFn called with excludeIds as second argument asserts toHaveBeenCalledWith(expect.any(String), ['item-1', 'item-2']) — the query is explicitly expect.any(String), so typing one character instead of five verifies exactly the same contract at a fifth of the render cost. This needs applying case by case, only where the assertion genuinely does not depend on the typed value.
3. Worth profiling Floating UI's render cost under jsdom before converting hundreds of tests. If the per-render expense is concentrated in @floating-ui/react (introduced for SearchPicker in 2dff2823), a targeted mock or a cheaper test-time positioning strategy would fix the whole class at once and beat a mechanical sweep.

Current status

SearchPicker.test.tsx fails an unstable subset of 2-3 tests per run (10 → 3 → 2 across runs, different tests each time), with searchFn called with excludeIds as second argument the most frequent. Both #2072 and #2073 needed a shard-5 rerun to land, which is a coin flip rather than a fix — the file sits right at the ceiling.

🤖 Added by /dependabot