Skip to content

OpenCode V2: first-request history reconciliation blocks the event loop for 154 seconds on a large migrated session #536

Closed

Description

@null-axiom

What happened?

I reproduced a substantial synchronous stall in Magic Context 0.43.2's rebaseSessionCoordinates when reconciling an existing V1 session for OpenCode V2.

Against a copied session containing 42,534 stored messages and 1,478 compartments, the actual reconciliation function took 154.4 seconds, blocked the event loop for approximately the same duration, and increased RSS by 708 MB. A second call after successful reconciliation took 3 ms and read no history.

The V2 integration calls this function during the context session hook, before the provider request. This makes the cost relevant to the first continuation of a large migrated conversation, rather than just an offline maintenance operation.

User-visible symptoms

In OpenCode Desktop V2, sending a message in a new session worked. Continuing a large existing session remained on Working, Stop did not respond, and the conversation accumulated Continuing after restart notices. The CLI's observed memory usage rose from roughly 400 MB to 1.6 GB.

Independent Desktop diagnostics initially received successful backend health responses, then recorded timeouts and transport failures during the stalled run.

The offline reproduction below demonstrates a blocking operation that fits these symptoms. It does not establish that this operation caused every live failure or restart.

Environment

  • Tested package: @cortexkit/opencode-magic-context 0.43.2.
  • Host involved in the reported incident: customized OpenCode Desktop 2.0.16 on macOS.
  • Offline reproduction runtime: Bun 1.4.2. These are not Node runtime measurements.
  • Input: a copied post-conversion OpenCode database and the matching pre-upgrade Magic Context database. Only a disposable MC database copy was modified.
  • No OpenCode server, provider request, or session execution was started. The plugin entry point was not imported, and network fetches were disabled.

The tested package is identified independently of the incident: the incident logs do not record the exact resolved MC package version.

Reproduction performed

  1. Use a V2 OpenCode database containing the large session, paired with a pre-upgrade MC database where that session is still stamped coordinate_generation = 'v1'.

  2. Import the actual rebaseSessionCoordinates implementation from the installed 0.43.2 bundle.

  3. Supply the production V2 reader/conversion implementation, extracted verbatim with source hashes recorded, without initializing the plugin:

    readAllV2RawMessagesForConversion
      -> V2StoreReader.history()
      -> all(sessionID, -1)
    
  4. Call:

    rebaseSessionCoordinates({
      db,
      sessionId,
      generation: "v2",
      readMessages,
    });
  5. Measure elapsed time, RSS, the reader's built-in debug counters, and a 50 ms heartbeat timer. Repeat the call after the first reconciliation completes.

The private database cannot be shared and no reproduction files are attached to this report. A public synthetic fixture has not been validated. To construct one, the relevant inputs include a large V2 session, a V1-stamped MC session with ID-anchored compartments and part tags, and index state that exercises the rebuild path. Message count alone may not reproduce the measured duration.

Results

Measurement First call, V1 stamp Second call, V2 stamp
Reconciliation elapsed time 154,418 ms 3 ms
Time inside readMessages 5,666 ms 0 ms
Remaining time, not yet attributed to individual functions 148,752 ms Approximately 3 ms
Full-history read calls 2 0
Raw messages returned across reads 85,066 0
Maximum heartbeat gap 154,504 ms 51 ms
RSS increase 708.3 MB 0.7 MB
Result rebased unchanged

The first run reported:

indexRebuilt: true
indexRowsRebuilt: 42533
compartmentsRebased: 1477
partTagsFolded: 5608
partTagsRekeyed: 7698
notesCleared: 1
lkgSlotsDropped: 1

RSS increased from 55.4 MB to 763.7 MB at the recorded checkpoints; external monitoring observed a peak of approximately 871 MB. The heartbeat measures offline execution-thread blocking, not live HTTP responsiveness.

The database contains 42,534 stored messages; the reader/conversion path returns 42,533 host-served raw messages. Its counters recorded 852 page calls and 85,068 decoded rows across the two full-history reads.

Relevant implementation

In the inspected 0.43.2 bundle:

  • dist/index.js:48888: the V2 context hook invokes rebaseSessionCoordinates with generation: "v2".
  • dist/index.js:48672: supplies the full-history conversion reader.
  • dist/index.js:47317: all() pages through history and accumulates each page into one array. Paging limits each query, not total retained history.
  • dist/index-g6hpfkqa.js:17944: the generation-change path calls buildProjection(args.readMessages(sessionId)).
  • dist/index-g6hpfkqa.js:18074: when rebuilding the index, ensureMessagesIndexed(db, sessionId, args.readMessages) performs another full read.

Both reads occur inside the real implementation, not because the harness called it twice during the first measurement.

Expected behavior

First-use reconciliation should preserve all existing history references without blocking the API-serving execution thread for minutes or requiring unnecessarily high peak memory.

The generation stamp must still be committed only after successful reconciliation. Skipping old history, stamping the session early, or building prompts against stale coordinates would not be safe fixes.

Investigation notes and limitations

  • Most elapsed time is outside the two history reads. The remaining 148.8 seconds needs profiling before attributing the bottleneck to a particular planning, tag-processing, or index-writing function.
  • A full index rebuild occurred, but the exact condition that triggered it has not been isolated. Differences in raw row counts alone do not establish that cause.
  • Structural checks found unchanged compartment counts and no inverted boundaries. Full message-ID anchoring, index semantics, and tag correctness were not independently certified.
  • This is one measured input on one machine. The exact duration and memory use may differ under other runtimes or concurrent load.
  • The second call demonstrates the completed-stamp fast path, not a performance comparison between equivalent workloads. If an attempt is interrupted before completion, that fast path may not be reached.

Potential investigation directions are profiling the reconciliation's expensive internal operations, avoiding the duplicate full-history read, and reducing retained message content. Any scheduling or background-work change must keep prompt preparation waiting safely until reconciliation succeeds.

Activity

  1. magic-alfonso commented on Sep 25, 2026

    @magic-alfonso

    Thank you, this is an unusually clear report, and the measurements point in the right direction.

    Confirmed at source: on the first OpenCode 2 request for a session last served under OpenCode 1, rebaseSessionCoordinates reads the whole history twice (once to build the projection, again in ensureMessagesIndexed for the index rebuild), keeps every message in memory, and does all of it inside the context hook before the provider request. That covers the two reads and the memory you measured. As you say, the remaining ~149 s has to be profiled before we name a cause.

    A fix is in progress:

    • profile on a large converted session of our own, plus a fixture of your shape;
    • read history once and keep only what the rebase needs;
    • remove whatever turns out to be super-linear;
    • batch the index writes.

    Your constraints stay as they are: the generation stamp commits only after a successful reconciliation, and no prompt is built against stale coordinates. I'll post before and after numbers here.

  2. magic-alfonso commented on Sep 25, 2026

    @magic-alfonso

    Fixed on master. It will be in the next release.

    Profiling showed that about 92% of the time went to a quadratic step, not to the history reads. For every message it joined, the rebase ran a LIKE ... ESCAPE scan over all of the session's part tags, a query that can't use the index. The smaller costs were:

    • the second full-history read you spotted;
    • a statement prepared for every write;
    • a queue lookup per message;
    • a prune step that was entries × shrunk messages.

    What changed:

    • History is read once, and the tag work is keyed instead of scanned.
    • Statements are prepared once and reused.
    • The fold now runs before the index clear inside the transaction. That alone took one stage from about 30 s to about 3 s.
    • The rebase now yields to the event loop between bounded chunks. The rewrite, the index clear and the generation stamp still commit as one transaction, and only after the reconciliation succeeds, so no partial state and no early stamp. The index rebuild after the commit runs in 2,000-row transactions and resumes if interrupted.

    Measured on a machine with load average 37–190, so the ranges are wide:

    input before after
    a synthetic session of your shape, 42,534 messages 123 s, one 123 s block, +1,017 MB, 2 reads 4.8–8.0 s, longest block 3.2–4.6 s, +205–236 MB, 1 read
    a real converted session of ours, about 135K messages about 20 min in one block, +10.5 GB 32–70 s total, longest block 5.7–11.3 s, +0.8–1.0 GB

    On the 135K session, most of the remaining time is OpenCode 2 decoding its own rows, and that now yields between pages. On both inputs, every table the rebase writes came out identical to the old implementation's. A second call still returns unchanged without reading history. A new test fails if the rebase reads history more than once, or if its tag queries grow with session size.

    Thanks again for the careful report; the measurements and the exact code references made this quick to find.

  3. magic-alfonso commented on Sep 28, 2026

    @magic-alfonso

    This is in 0.44.0. The first OpenCode 2 request of a session last served by OpenCode 1 still re-derives Magic Context's saved message positions, but:

    • the per-message tag lookups, which were about 90% of the time and couldn't use an index, are keyed instead of scanned;
    • history is read once instead of twice, and statements are reused;
    • the work yields to the event loop between bounded chunks, and still commits as one transaction;
    • the search-index rebuild that follows runs in 2,000-row transactions and resumes if interrupted.

    On a 42,534-message session of your shape it went from one 123-second block to 4.8 to 8.0 seconds in total, with no single block over 4.6 seconds. To update on OpenCode 2, use /plugins (ctrl+u on Magic Context) or opencode plugin update. Restart every host that shares context.db on 0.44.0 at the same time, since it migrates the database.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions