[Perf] session/list is O(sessions) with no summary cache: 2.5-3.0 s and 59.8 MB of reads for ~7,700 sessions #7142
Replies: 5 comments
Root cause found, at code level — and my original post was wrong about itI said the cost was "generic deep-copy / deep-freeze plus cordis service resolution, paid per session". Where it is
for (const project of await this.listProjectDirs(signal)) {
for (const dir of await this.listSessionDirs(project, signal)) {
const selected = await this.resolveGenerationInDirectory(dir, signal); // per session
header = await this.readGenerationHeader(selected, void 0, signal); // per session
}
}Nested loops, one Measured, 7,666 sessions
The CPU profile is 43.6% idle, which is the tell: the thread is waiting on one file at a time. Three negative results, in case they save someone the detour
A fix that worksTwo changes confined to the listing path, so
Every variant returns an identical id list to upstream across all 7,666 sessions. Ordering, the Running this locally, end to end: Why this is worth fixing upstream rather than pagingTruncating the list is not equivalent: the sidebar's "Show N more", search, and external API consumers This also seems to be the concrete mechanism behind the "list header cache" proposed as short-term |
|
Short answers first: (1) no, it is not "expected" — pagination is simply not implemented on this endpoint, and the 1. Not implemented — the request type is the only half that exists
So "no pagination in the observed client call" is exact: neither side can paginate. Worth knowing that the machinery does exist elsewhere in this tree. The ACP bridge's 2. Where the cost comes from on the list pathThe chain for one call:
Point 5 is not where your I/O is. I could not pin the Your negative result on the sqlite knobs is consistent with the code: both are documented as knobs of the inherited batch reads and the On memoisation: the only memo I can see on this path is the root-encoding check ( 3. What a fix would have to touch
I can't speak to whether item E in #4416 would cover this, or to who might work on it — I have no verifiable information there. Mechanically your measurements point at "stop re-reading every header on every call" rather than at summary assembly, since the projection read is already zero-I/O. |
|
Thanks — that reply is far more precise than anything I could get from the outside, and two parts of On the sqlite knobs. I had tried I ran the measurement you suggested, and it disproves the I had predicted the per-record clone plus the sort accounted for the ~265 ms my patched persistence
So removing the clone entirely would buy about 11 ms. That closes it as a lead — and it means the Where the time actually sits now, on this store, with my local concurrency+cache patch applied to
By elimination that ~254 ms is in So on this store the cost now splits roughly: persistence header scan ~47%, summary assembly ~49%, For whatever it is worth as a data point: the patch I am running locally is bounded-concurrency (16) |
Status on the current release (0.1.7-rc.2): mechanism unchanged, and
|
| stage | cold (first call after unrelated I/O) | warm (repeat) |
|---|---|---|
| readdir pass, 1,360 session dirs | 3.01 s | 0.19 s |
readGenerationHeader ×1,361 (open + 8 KB + zstd; zstd included in the cold figure) |
7.24 s | 0.35 s + 0.11 s zstd |
historicalCorpusRevision equivalent |
1.78 s | 0.14 s |
| sum | 12.2 s | ~0.8 s |
The 12.2 s replication matches the same endpoint measured cold at 11.6 s; warm it is 1.5 s end to end. A single open + 8 KB read is only p50 0.38 ms / p99 1.91 ms, so the cost is the serialized per-session round-trips, not the bytes. Proportions line up with yours (header ≈ 59% of my cold sum vs your 65%). Same process, for contrast: llm/listProviders 2–79 ms, agentPresets/list 9 ms, session/modelCatalog 3 ms, fileReferences/list 3 ms.
The additional term: one list() call enumerates the corpus twice, through the same function.
// list() — master, lines 483-485
const artifacts = await this.listArtifacts(signal) // -> listGenerations() [walk #1]
const corpusRevision = artifacts.some(a => a.sourceVersion < SESSION_FORMAT_VERSION)
? await this.historicalCorpusRevision(signal) : undefined // -> listGenerations() [walk #2]listGenerations() (:1025) is the full two-level walk plus resolveGenerationInDirectory per directory, and both listArtifacts() (:1064) and historicalCorpusRevision() (:1039) call it independently. So within a single list() invocation the corpus is enumerated twice by identical code, and the second walk additionally stats every selected path and folds it into a sha256.
Measured on the 816-session / 654 MB store, warm, median of 5:
listGenerations()equivalent alone — 87 mshistoricalCorpusRevision()equivalent (same walk +stat+ sha256) — 97 ms
So ~90% of that term is a duplicate of a walk the same call has already done. The branch is also almost always taken in practice: 746 of 816 selected generations (91.4%) are < v4 on this store (v0 152, v3 594, v4 70), and 1,291 of 1,361 on the larger one.
This is orthogonal to your fix rather than an argument against it: bounded concurrency plus a directory-mtime-keyed generation cache makes each walk cheaper, while sharing a single listGenerations() result between listArtifacts() and historicalCorpusRevision() removes one of the two walks outright — inside a call that has already snapshotted the corpus. Worth noting the two walks are currently free to disagree with each other; feeding both from one enumeration is at least as correct.
On your format-migration negative result. My numbers are consistent with it — the historical-format translation is not the cost, and the corpus-revision term is second-order here (≈10% warm). One caveat if anyone wants to price that term alone: migrating changes it two ways at once, since it clears the some() trigger but leaves both artifacts in the directory for the walk to enumerate.
Practical mitigation for anyone hitting this today. Moving ~40% of the store out of the persistence root, with nothing else changed, took session/list from 1,490–2,349 ms to 428–533 ms (response 591 KB → 412 KB) and sessionReferenceResolver/candidates from 1,487–2,720 ms to 432–834 ms. That matches the workaround already noted in #5043; the cost really is linear in session count, so pruning the root is a real lever until the listing path is fixed.
|
Filed the double-enumeration finding from my comment above as its own thread so it can be tracked as a line item: #8065 — one |
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
Summary
On a store of ~7,700 sessions,
POST /api/session/listtakes 2.5–3.0 s server-side on a warmprocess, doing 65,419 read syscalls and 59.8 MB of reads to produce a 1.4 MB response. That is
~8.5 file reads and ~0.40 ms per session.
This is the list path, not the cold-open path. It complements #4416, which analyses opening one
large session and proposes "list header caching" as short-term item E but carries only the
42 ms / 412 sessions baseline for listing. The numbers below are what that item looks like at scale.
Environment
0.1.5-rc.2, Nodev24.19.0, Linux, web profile, loopback bindsession-persistence-jsonlat defaults; 7,660 of 7,660 log files are zstd (compression: zstd)session-query-sqliteat shipped defaults (path: ':memory:',openAt: never)Measurements
Timed with
curldirectly against the loopback API, so no browser is involved:session/listsubagents/listI/O attributable to one
session/list, from/proc/<pid>/iodeltas:59.8 MB read to emit 1.4 MB. Nothing is served from a cache between identical back-to-back calls;
each repeat pays the full cost.
Where the time goes
A V8 CPU profile taken while looping the endpoint (
Profiler.setSamplingInterval(200), 23,554samples) shows 39.1% idle and the rest spread thin, with no single hot spot:
Roughly 19% is generic deep-copy / deep-freeze (
dsh-util-values) plus cordis service resolution,paid per session, against only ~3% in the actual header scan. The per-session constant, not the header
read, appears to dominate: ~0.40 ms/session here (~0.33 ms after the threadpool change below) versus the ~0.10 ms/session implied by 42 ms / 412 — roughly 3-4x.
Profiling caveat worth recording
A profile captured across a browser page load reports 99.8% idle and is misleading — that window
can contain no list call at all. It also makes
subagents/listlook slow: it shows ~3.5 s in browserdevtools purely from client-side queueing behind
session/list, while being 12 ms when called directly.Both of those led me to wrong conclusions before I profiled under load.
What I tried
UV_THREADPOOL_SIZE4 → 32session-query-sqlitepersistedReadConcurrency4 → 32 andpreparedSessionCacheSize5 → 512The second is the interesting negative: those defaults look like the gate for an inherited batch read,
but raising them did nothing for this path. The partial win from the libuv threadpool suggests the
remaining cost is CPU-side per-session work rather than read concurrency.
Questions
session/listexpected to scale linearly with total session count with no header/summary cache?There is no pagination in the observed client call; the whole corpus comes back in one 1.4 MB payload
even though
SessionListRequestaccepts acursor.dsh-util-values) necessary on the list path,or could summaries be built once and memoised until a session's generation changes?
I'm happy to test a patch against this store.
Related: #4416 (cold-open materialisation, proposes E), #3413 (
streamOpenTimeoutMs, different layer).Edit: corrected the session count from "~4,700" to the measured 7,657 (verified three ways: relay
listing, session directories on disk, log-file count). The original came from a UI label, not a count.
That moves the per-session cost from 0.53 ms to ~0.40 ms and the gap versus the 42 ms / 412 baseline
from ~5x to ~3-4x. The syscall, byte and timing measurements are unchanged.
All reactions