Module bundle installs: writing 31 MB takes <1 s, but 1–7 minutes of idle sit BETWEEN packages — a full pull takes ~30–40 min instead of ~1 #2446

Activity

1. rbuergi commented on Aug 26, 2026

   

   rbuergi

   on Aug 26, 2026

   ContributorAuthor

   More actions

   Diagnosis corrected by the activity feed — the inter-package time is not idle, it is per-package CONTENT IMPORT into the mesh.

   At 20:15:45–47Z the feed shows, per space, the chain Update {Space} to latest → Content manifest → Import manifest → Import {Space} (N nodes): Hosting (94 nodes), Collaboration (12), Essentials (4), Publish… Each package's install = sub-second binary drop + a mesh import with per-node writes/indexing — the latter is the 1–7 minutes.

   The churn evidence: Import manifest (Hosting) is at version 37, content-manifest at 22/15 — these have run dozens of times today. Unchanged content is being re-walked instead of no-oped by its content signature. So the fix direction sharpens: the import pipeline must short-circuit on an unchanged content signature at the MANIFEST level (one comparison, zero node visits), not merely skip per node — the same idempotence contract the installer's IsUnchanged already applies to package binaries, extended to the content half. MW_INSTALL_DIFF=1 instrumentation (plugins repo #708) shows exactly what each re-import actually rewrites.

   Measured consequence unchanged: identity-flipping platform builds pay ~30–40 min/portal for what should be ~1–2 min (all binaries new, nearly all content unchanged).

   🤖 Generated with Claude Code
2. rbuergi commented on Aug 28, 2026

   

   rbuergi

   on Aug 28, 2026

   ContributorAuthor

   More actions

   Narrowing this: the gaps are bounded waits EXPIRING, and their sizing explains the 1→7 min spread.

   The issue's own hypothesis — "at least one wait is event/timer-shaped rather than work-shaped" — is supported by what the install path can wait on. Per package, PackageInstaller carries:

   bound	value
   WarmTimeout	90 s
   RootTypeSettleTimeout	90 s
   GatingSettleTimeout	30 s
   DeclaredAccessVerifyBudget	30 s
   RootRecycleTimeout	30 s
   RootReadyTimeout	20 s
   RootTypeProbeTimeout	10 s
   SeedBound(n)	30 s + 30 s × installed types

   Summed, that is ~5.5 minutes before SeedBound even scales — squarely inside the observed 1–7 minute window.

   SeedBound is the one that explains the spread rather than just the magnitude. It is SeedFloor + SeedPerType × typeCount (30 s + 30 s per installed type), so a package with ten types carries a 5.5-minute ceiling on its own. Packages differ in type count, so the per-package gap differs — which is exactly the 1→7 min variance, and it is not what a fixed timer-paced drain would produce.

   Note these are ceilings, not sleeps: none costs anything if the work it bounds completes. So the observation "31 MB written in under a second, then minutes of idle" means the I/O finished and something the installer is waiting on did not — which reframes the question usefully:

   • it is not "why is the queue paced at 1/min" (there is no such pacer in this file — the only Intervals are 100 ms re-query polls, the sanctioned pattern);
   • it is "which of these bounds is expiring, and why does the thing it waits for never arrive?"

   What would settle it

   Each expiry is observable. The next time a pull is watched, grep the portal log across the gap for the messages these bounds emit — whichever one appears names the wait, and its own message says what it was waiting for. If it is SeedBound, the fallback it guards is a Roslyn compile per type at up to 5 min each, so the bound is deliberately generous and the real defect is upstream of it.

   Not attempted here

   I have not fixed anything: the fix depends on which bound expires, and choosing without that evidence would be raising or lowering a timeout — the band-aid AGENTS.md forbids. Raising them would make the pull slower; lowering them would convert a busy seed into the expensive compile the seed exists to avoid, which its own comment warns is "strictly worse than either".
3. rbuergi commented on Aug 31, 2026

   

   rbuergi

   on Aug 31, 2026

   ContributorAuthor

   More actions

   One of the eight bounds expires in SILENCE — which is why the log-reading step this issue prescribes could never have completed

   The triage above lands on exactly the right next step:

   "Each expiry is observable. The next time a pull is watched, grep the portal log across the gap for the messages these bounds emit — whichever one appears names the wait."

   I checked that premise across every .Timeout(<named bound>) in PackageInstaller rather than assuming it. Seven of the eight report their own expiry. One does not.

   line   bound                        reports on expiry?
     521  GatingSettleTimeout          yes
     636  DeclaredAccessVerifyBudget   yes
    1172  RootRecycleTimeout           🚨 NO — silent
    1274  RootTypeSettleTimeout        yes
    1399  RootReadyTimeout             yes
    1453  RootTypeProbeTimeout         yes
    1481  WarmTimeout                  yes
    3405  SeedBound(typeCount)         yes
   

   RootTeardownSettled:

   return live.DisposalCompleted
       .Take(1)
       .Timeout(RootRecycleTimeout)                                  // 30 s
       .Catch<Unit, Exception>(_ => Observable.Return(Unit.Default)) // ← swallowed, no log
       .DefaultIfEmpty(Unit.Default);

   Continuing is right; continuing in silence is not. The bound's own remark says it "is only ever reached when a hub's teardown itself wedges" — so expiring it is not a slow path, it is the wedge, and that is the single most interesting event on this path. Thirty seconds per occurrence, appearing nowhere.

   Why this blocked the diagnosis rather than merely being untidy

   The technique this issue depends on is read the log across the gap and see which bound names itself. For this bound the answer would always have been "none of them" — a gap caused by it is unattributable by construction, and the reader would conclude the stall came from somewhere else entirely. A wait nobody can see is a wait nobody can fix.

   It is also the AGENTS.md swallow-and-continue shape ("catch {} / swallow-and-continue that hides a fault instead of surfacing it"), narrowly applied: the recovery is correct, only the silence is wrong.

   Fixed, with a control so it cannot come back

   The arm now logs the root, the bound and what it was waiting for, and still returns so the install proceeds — byte-identical recovery, no behaviour change. InstallerBoundsNameThemselvesGuard asserts every bounded wait in the installer reports its own expiry, plus a self-test that the scanner actually finds the bounds (a regex matching nothing would satisfy the first test vacuously — the same defect one level up). Mutation-proved: restoring the silent swallow fails the guard, naming file, line and bound.

   🚨 This does NOT close the issue

   It makes the next occurrence diagnosable; it does not say which bound is expiring. That still needs a live pull, exactly as the triage above says. What changes is that the pull no longer has to be watched — the log will now name whichever bound it was, including this one.
4. rbuergi

   closed this as completedin #2875on Aug 31, 2026