[Bug]: Windows, large repo: run finalization forces a full fff rescan every turn, blocking the backend event loop 15-52 s on the picker lock #22586

Activity

1. juliusmarminge commented on Oct 21, 2026

   

   juliusmarminge

   on Oct 21, 2026

   Member

   More actions

   Note

   Grok responding on behalf of Julius.

   Thanks for the trace analysis. The trigger matches current main. After every run, RunFinalizationService refreshes the workspace entries for the run's directory (apps/server/src/orchestration-v2/RunFinalizationService.ts:102-106). When a search index exists for that directory, this calls WorkspaceSearchIndex.refresh (apps/server/src/workspace/WorkspaceEntries.ts:161-188), which calls finder.scanFiles() directly (apps/server/src/workspace/WorkspaceSearchIndex.ts:413-417). Nothing on that path skips the rescan when the index's file watcher is already keeping it current. So with many threads finishing in one large project, every finished run asks fff to rescan.

   The freeze itself has the same root as #11306: a synchronous fff call on the server's main thread waits on fff's own lock while the index is busy. That part sits partly in how fff runs its calls. The forced rescan after every run is a separate trigger on our side, and it can be avoided independently. Keeping this open alongside #11306 and accepting it as a bug.
2. juliusmarminge

   added

   bugSomething is broken or behaving incorrectly.Something is broken or behaving incorrectly.

   acceptedfeature request acceptedfeature request accepted

   via-triageFiled through npx t3 triageFiled through npx t3 triage

   on Oct 21, 2026
3. AdEx-Partners-DE

   added a commit that references this issue on Oct 21, 2026

   fix(server): finished runs no longer force a full file-index rescan

   ...

   This issue will close once commit cfa3be8 is merged into the 'main' branch.

   cfa3be8
4. mikeohuo commented on Oct 26, 2026

   

   mikeohuo

   on Oct 26, 2026

   Author

   More actions

   Note

   Investigated by Claude Fable 5.1 and Claude Opus 5.5 in Claude Code, with a second read by GPT-6 Astra; written on behalf of the account owner.

   Still present on 0.1.3-nightly.20261026.3726 (bundles @ff-labs/fff-node 0.11.0), same Windows machine and the same Unity repo (274,819 tracked files, 29.7 GB), now with 16 Claude sessions running at once. The numbers are worse than on 21 October, and the blocks now surface as SQLite lock waits, which is why #24895 and #24660 can look like the cause on a Windows desktop with a large repo.

   Rescans, from 107 minutes of server.trace.ndjson

   • WorkspaceSearchIndex.refresh: 48 calls, 975 s in total, p90 85 s, max 138 s. 14 of the 48 exceeded the 15 s client ping timeout. Every one has the parent chain WorkspaceEntries.refresh < RunFinalizationService.refresh < RunFinalizationService.finalize, and on current main the path is unchanged: RunFinalizationService.ts:104 → WorkspaceEntries.refresh → WorkspaceSearchIndex.ts:408 finder.scanFiles(). The waitForIndexReady child took 0 to 3.4 s, so the rest of each refresh is inside scanFiles().
   • Of the 13 intervals of 3 s or more in which no span starts or ends, 12 begin at the same instant as a WorkspaceSearchIndex.refresh and end with it. logs\event-loop-stalls.ndjson recorded 85,369 ms and 82,148 ms, matching two of those gaps; the 122 s and 138 s refreshes do not appear in it.
   • Thread names from GetThreadDescription in the server process: fff-git-status at 99 % of a core for the whole window (2,857 s CPU since 17:32), fff-watcher-own 46 %, fff-bg-0 39 %. The main JavaScript thread averages 4 % and, sampled every second during three refreshes, sat at near-zero CPU in a lock-type wait, as in the samples in [Bug]: Backend event loop blocks for minutes inside synchronous fff mixedSearch waiting on watcher lock (home-directory project) — shows as "<label> is reconnecting" #11306.
   • Process reads: median 1.7 GB/s at 116k operations/s during a refresh, 0.7 GB/s at 63k/s outside one, 94 to 98 % served from the file cache. The 16 provider children write about 0.1 MB/s, so this is not child output. No fff threads existed before 17:32 today, and the stall log has nothing over 7 s before then.
   • Turns finish about every 40 s across the 16 sessions, so the index's 15-minute idle expiry is likely never reached once the picker has created it (inference).

   Knock-on into SQLite

   Over 59 minutes: reader lane 10,703 sqlite spans, 2,673 s, of which 2,213 s is db.lock_wait_ms (max 123 s); writer lane 955 spans, 1,189 s, 1,131 s waiting (max 135 s). 21 of the 29 reader waits over 30 s fall inside a long refresh. The statements at the front of the queue are cheap on their own against the same database (OrchestrationEventStore.latestAgentSequence via ThreadPullRequestServiceV2.synchronize: covering-index search, under 1 ms; ProjectionStore.isNodeStored: primary-key read, 0.5 ms). The reader runs in a worker thread and its span ends only when the main thread processes the reply, so every reader span in flight during a block is inflated by the block. Database: 9.2 GB, 3,440 threads, orchestration_events 1.16 M rows, WAL 9 MB.

   One thing not explained by the rescan: an orchestrationV2.EventSink.write transaction held the writer lock for 136 s at 18:03 with the event loop free, and writers queued behind it (db.lock_owner_at_start.name names it). Possibly the checkpoint admission gate from #23482; not established.

   User-visible result

   SessionStore.recordClientConnection up to 70 s, ws.rpc.orchestration.subscribeThread up to 787 s; the desktop shows " is reconnecting" and remote clients "T3 Code on did not answer".

   #22603 is still the fix for the trigger. Happy to re-measure on a build that includes it.
5. kurtkuehnert commented on Oct 30, 2026

   

   kurtkuehnert

   on Oct 30, 2026

   More actions

   Note

   Investigated by Claude Opus 5.5 in Claude Code; written on behalf of the account owner.

   Another trigger for the same lock, on macOS with desktop 0.1.5 (@ff-labs/fff-node 0.11.0). Here the freeze lasted over 6 minutes, not seconds, because fff's watcher held the lock while it walked a large folder.

   Setup. The project is a folder that isn't a Git repository. It holds about 60 jj workspaces, and each workspace has a symlink into a shared data folder of about 750,000 files and 26 GB.

   What happened

   1. With the Files index open, a new workspace was created, with its link into the data folder.
   2. fff's watcher treated the new link as a new directory and walked the data folder through it. That's [Bug]: the watcher indexes the target of a new directory symlink that the scan skips, and blocks scan_files while it walks it (0.11.0) dmtrKovalenko/fff#980: the scan skips the link, but the watcher follows it.
   3. The next finished run called WorkspaceSearchIndex.refresh → scanFiles(), which waited on the watcher.
   4. The server answered nothing for over 6 minutes, and the desktop showed "did not answer", then "reconnecting".

   A sample of the server showed the JS thread in fff_scan_files → _pthread_cond_wait, and fff-watcher-own in read and open on files under the data folder. server.trace.ndjson had no span in that window. Killing the backend let the desktop start a new one.

   Before we added a root .ignore, the same project also caused the plain version of this report: indexing the whole folder took 17 s for 1.26 million files. Quitting the app during one of those freezes left the server running with PPID 1, as in #22983.

   This supports the second fix in the report above: keeping fff calls off the event loop would have turned a 6-minute freeze into a slow index.

   Workaround. A root .ignore with the data folders and .local/, where the links live. The full index is now 123,000 files in 0.8 s.
6. luigiwidmore commented on Nov 5, 2026

   

   luigiwidmore

   on Nov 5, 2026

   More actions

   Note

   Investigated by Claude Opus 5.5 in Claude Code; written on behalf of the account owner.

   Another view of the same trigger, on Linux (0.1.x nightly 2026-11-02; same code in 0.1.8-nightly.20261104.4192, @ff-labs/fff-node 0.11.0). Here it is a sustained disk-read storm, not a UI freeze. The project/thread cwd is the home directory (as in #11306).

   What we measured

   • The server process read 130–165 MB/s from disk without a break (read_bytes ≈ 900 GB in 2 days). Per-thread /proc/<pid>/task/*/io puts 100 % of it on fff-bg-0. The SQLite reader/writer threads were at ~0.
   • Sampling the process's open fds shows fff opening ordinary files all over $HOME (SDK sources, cache dirs, other tools' session logs).
   • Runs in home-rooted threads finish every few minutes. Each one calls RunFinalizationService.refresh → WorkspaceEntries.refresh → finder.scanFiles(), which also renews the 15-minute idle TTL, so the index never expires.

   What fff does on each scan (standalone repro with the bundled fff-node)

   On a 244 MB tree (15.6k files), FileFinder.create + warm-up and then each scanFiles() read ~199 MB. That is exactly the total size of all files under 10 MB. It is the same with disableContentIndexing: true, the same with cacheBudgetMax* set to 1, and the same with disableWatch: true. So disableContentIndexing does not stop the full-content read. Every post-run rescan reads the whole tree again, and for $HOME that far exceeds the page cache.

   The guard T3 turns off

   WorkspaceSearchIndex.createFinder passes enableFsRootScanning: true, enableHomeDirScanning: true. With both false, fff refuses the home dir ("Can not run certain FFF features in a file system root or home directories. Consider smaller per-project directories."). We now run a local patch that sets both to false. Threads rooted at $HOME lose the file picker and find-in-files, but nothing gets indexed, so the post-run refresh is a no-op there.

   Suggestions, in addition to #22603 (not rescanning after every run):

   1. Respect fff's home/root guard, or show the user an explicit "index the home directory?" opt-in, instead of hard-coding it on.
   2. Don't renew the idle TTL from the post-run refresh path, so an index nobody is looking at can expire.