Push Timeout Diagnosis

What We Are Trying To Do

Create a repo on MuseHub and push code to it. That is the entire requirement. A user should be able to run muse push staging dev and have it complete in seconds, the same way git push origin main completes in seconds for GitHub.

The Repo Under Test

gabriel/muse — the muse VCS engine itself.

What We Know About the Push Path

Client-side batching (no CF Worker configured for staging)

The push CLI uses the local hub path (push.py:447). Objects are batched in CHUNK_OBJECTS = 500 per HTTP POST.

6,860 objects / 500 per batch = 14 batches (13 × 500 + 1 × 360)

Each batch is one call to transport.push_stream_coro() → POST {url}/push/stream.

• Non-final batches: 500 objects, no commits
• Final batch: 360 objects + 827 commits + 827 snapshots

Client HTTP settings: http2=False, timeout=300s, max_keepalive_connections=0

Server-side per batch

Request body received
    ↓
wire_push_stream() reads H frame, N×O frames, C frame, E frame
    ↓
_flush_batch(): CONCURRENCY=32 async R2 PUTs per 500 objects
    ↓
bulk_upsert_snapshot_entries(): one INSERT...ON CONFLICT
    ↓
ordered_commits loop: build new_commit_rows
    ↓
pg_insert bulk INSERT for commits
    ↓
branch pointer update
    ↓
Response sent

Cloudflare proxy in between

CF sits between the muse CLI and the staging EC2 origin. CF's 524 timeout fires when the origin does not produce a response within ~100 seconds. It is triggered by silence — no response bytes, not slow bytes.

Everything We Have Tried

Attempt 1 — Fresh push after delete+recreate (failed: CF 524)

What: Deleted gabriel/muse on staging, recreated it, ran muse push staging dev. Result: CF 524 after ~120 seconds. Diagnosis: The batch containing 500 large objects (or 6860 in one shot — unclear at the time) exceeded CF's origin timeout.

Attempt 2 — Repair script for ghost objects (worked, but wrong problem)

What: Ran a repair script that did POST /gabriel/muse/repair-object for each of 1004 missing objects. Result: Objects repaired. But no commits were ever pushed — the repo was still empty. Diagnosis: Treating the symptom, not the disease. The push itself was failing before any objects landed.

Attempt 3 — Stream _WireResponse response frames (froze)

What: Changed _WireResponse.__call__ to:

• Send http.response.start immediately (before processing)
• Forward each P frame as http.response.body chunk with more_body=True
• Send final R frame, then empty more_body=False terminator

Also changed wire_push_stream to emit yield _prog(...) every 100 commits inside the ordered_commits loop.

Result: Push started, appeared to work longer than 120s, then froze after "several minutes". Diagnosis (hypothesis): Unknown. Several candidates:

Status: NOT DEBUGGED. We do not actually know why it froze.

What We Do NOT Know (Unknowns to Resolve)

1. How long does one batch of 500 objects actually take? (R2 PUT time end-to-end)
2. Is the 524 from batch 1, or from the final batch with commits?
3. Does http.response.start actually reach CF before the R2 PUTs complete?
4. Is "froze" a CF reset, a client timeout (300s), or a server exception?
5. What is the actual terminal output when the push freezes? (we never captured it)

The Architecture We Need to Match

GitHub pushes gabriel/muse in ~5–15 seconds because:

1. git pack-objects delta-compresses all objects into one pack file (~20–50 MB)
2. Client sends that ONE file as one HTTP POST body
3. Server unpacks server-side (fast, in-process) while streaming sideband messages back
4. One round trip, streamed response, no CF timeout

Our current push:

1. Client sends objects as individual msgpack frames (no delta compression)
2. Server stores each to R2 individually (N × HTTPS round trips)
3. Server then inserts commits to Postgres
4. Server then sends response

The structural difference: N R2 PUTs vs 1 pack upload. This is the performance gap.

The Goldilocks Zone (What "Fixed" Looks Like)

A push of gabriel/muse (827 commits, 6860 objects) must:

• Complete in < 60 seconds (matching GitHub order of magnitude)
• Not trigger CF 524 (no silence > 100s at any point)
• Show progress on the terminal during the wait
• Not require exotic infrastructure (no CF Worker, no special R2 config)

Atomic Tests (Bottom-Up)

These are the smallest measurable units. Each must pass before scaling up.

Layer 0 — Baseline: can we push at all?

Layer 1 — R2 PUT latency

If T1-d > 100s, the batching approach cannot work with CF. Must change architecture.

Layer 2 — One batch, end-to-end timing

If T2-c > 100s, a single batch times out CF. Must split batches smaller or stream heartbeats.

Layer 3 — Heartbeat delivery

Requires http.response.start to actually flush through CF to the client before processing.

Layer 4 — Full push

The Experiment to Run First

Before writing any more code: measure T1-c and T2-c with exact timestamps.

Create a minimal test script (/tmp/push_timing_test.py) that:

1. Calls staging /gabriel/muse/push/stream with exactly 500 random objects
2. Timestamps: connection established, first request byte sent, last request byte sent, first response byte received, last response byte received
3. Prints each timestamp to stderr

Run it from the local machine (simulating the real CLI path, not from EC2).

If response arrives in < 10s: the streaming heartbeat approach (Attempt 3) should work, and the freeze had a different cause.

If response takes > 60s: the R2 PUT bottleneck is real and we need a pack-based upload.

If CF returns 524: the heartbeat approach must send the first response byte before the R2 PUTs complete.

Next Actions (in order)

1. [ ] Run the timing test — measure one batch of 500 objects end-to-end
2. [ ] Based on timing: decide if the streaming approach is viable or if pack upload is needed
3. [ ] TDD the chosen approach at the atomic level before implementing
4. [ ] Scale test: confirm timing is linear from 1→6860 objects

What We Now Know About the Push Path (corrected)

The global R2 PUT semaphore is 100 (not 32 as assumed above):

# musehub_wire.py:50
_R2_PUT_SEM = asyncio.Semaphore(100)

Revised R2 timing estimate for 500 objects:

• 500 PUTs / 100 concurrent = 5 rounds
• Each R2 PUT from EC2 to R2: ~50–150ms
• 5 × 150ms = 750ms per batch

Revised total estimate: each batch should complete in < 5 seconds. 14 batches = < 70 seconds total.

This is MUCH faster than the CF timeout. So why did it 524?

Unknown. We need to measure.

Code Locations