swactor/examples/pipeline-parallel-inference/N3_POSTMORTEM_2026-05-25_1779733878.md

N=3 vast.ai deployment post-mortem — 2026-05-25 (run 1779733878)

Second N=3 deployment of 2026-05-25, and the first run on the observability upgrade (commit e8be135, the work specified in N3_OBSERVABILITY_UPGRADE_SPEC.md and motivated by N3_DATA_GAPS.md). Companion to the earlier post-mortem N3_POSTMORTEM_2026-05-25.md (run 1779720002), whose failure this deployment was meant to (a) avoid and (b) make diagnosable.

One invocation of pp-smoke-run --vastai --num-stages 3 (stub worker) on 2026-05-25 (vastai-N3-1779733878). The cluster came up cleanly, all three stage workers reached ready, the request was sent — and then SWIM membership flapped continuously and no InferenceResponse ever returned. The operator declared a deadstop at ~7 min and killed the orchestrator. Unlike last time, the bundle was recovered through the collector's own endpoint (gap 7), and the new diagnostics attributed the failure to a specific edge: the response path from the last stage back to the (NAT'd, locally-run) orchestrator.

Outcome in one line

Not a worker bug and not the relay-session loss of run 1779720002. The stage chain was healthy; the weak link was reaching the orchestrator over the relay. Per-peer dial data (gap 9) shows dials to the orchestrator failing 7/11 with Timeout while every inter-stage dial succeeded (19/19). This was indistinguishable in the previous bundle and is a one-table answer now.

Cleanup note

The run was terminated with SIGTERM (operator kill on deadstop), which — like the previous SIGKILL — skips the orchestrator's destroy-on-exit handler. Three rentals (37803546, 37803550, 37803555) were destroyed via DELETE /api/v0/instances/<id>/ (HTTP 200 each). Post-cleanup instance count = 0, verified. No leak from the earlier failed lease attempt either (see Sequence).

Sequence

Orchestrator runs locally (behind home NAT, no direct port); three stages on vast.ai RTX 4090 hosts; relay + collector on docean (146.190.110.128).

t=—      first launch dies instantly: lease_chain failed,
         "no offers available (after geo/exclusion filter)".
         Root cause: --gpu RTX_4090 (underscore) matches 0 vast.ai
         offers; the API uses "RTX 4090" (space). 0 instances leased.
t=0      relaunch with --gpu "RTX 4090": orchestrator node 146aef53,
         custom-relay banner emitted.
t=~135s  contracts 37803546/37803550/37803555 reach running,
         leased as stage-0 (aa0ef1c5), stage-1 (32abf9d6),
         stage-2 (a1ebaa08).
         "waiting for SWIM convergence (3 alive)" → converges.
t=~150s  registered pp-orchestrator; pp-entry resolved; one
         InferenceRequest sent. Enter await_response (600s budget).
t=~165s+ SWIM begins flapping. Members oscillate, e.g.:
           +63s : 32abf9d6=suspect
           +79s : 32abf9d6=dead, a1ebaa08=dead
           +94s : 32abf9d6=dead (others alive)
           +194s: 32abf9d6=dead, a1ebaa08=suspect
           +216s: aa0ef1c5=suspect
         iroh keeps exchanging messages throughout; connect-timeout
         count to peers is 0 (contrast 1779720002).
t=~419s  await_response still open, members momentarily all-alive,
         still no InferenceResponse.
t≈7min   operator declares deadstop (a peer Dead across two
         consecutive 45s heartbeats with zero forward progress),
         kills orchestrator (SIGTERM). No finalize record written.

Bundle recovery (gap 7 — worked, with a caveat)

GET /diag/bundle/vastai-N3-1779733878 returned HTTP 200 with a usable tarball — no hand tar/scp/reshape, unlike last time. The gap-7 synthesis-from-staging path is the intended fix and it functioned.

Caveat surfaced by this run: the run id was reused across the failed first lease attempt. That attempt's orchestrator (e8151ed8) called finalize("lease_chain_error"), which made the collector build and cache a tiny (5.3 KB) canonical bundle from the staging that existed at that moment — orchestrator + relay only, no stages. Because finalize_received was then true, the first GET served that stale canonical bundle rather than synthesizing from current staging. Removing the cached bundle and the junk e8151ed8 node forced re-synthesis → full 9.3 MB bundle with all five real nodes. Two residual quirks observed even after removal:

• finalize_received stayed true (the collector retains an in-memory finalize record that outlives deletion of the on-disk finalize-*.json).
• the synthesized MANIFEST.json still listed the deleted e8151ed8 node (with finalize_recorded: true) although no such directory was in the tarball.

Neither blocked analysis, but both are worth hardening: gap-7 assumed finalize == end-of-run, and run-id reuse breaks that assumption.

Bundle findings

Volume

node	role	snapshots	events
146aef53 orchestrator	orchestrator	409	4385
1c8357a1 relay (docean)	relay	186	187
aa0ef1c5 stage-0	stage	771	8638
32abf9d6 stage-1	stage	305	3234
a1ebaa08 stage-2	stage	535	5963

run_start_ms=1779734098442, run_end_ms=1779735024439 (duration_ms=925997; the tail includes the relay's continued periodic reporting after the orchestrator died — the relay on docean is still pinned to this run id, see Infra state).

Subprocess lifecycle (gap 4) — decisive

SubprocessSpawned: 3. Custom(worker_starting): 3, Custom(worker_ready): 3, Custom(worker_heartbeat): 37. No SubprocessExited.

All three stage workers spawned and became ready and stayed up. This is the single fact the 1779720002 bundle could not establish (there, stage-2 emitted neither worker_starting nor worker_ready, and we could not tell "never spawned" from "spawned and died"). The worker is conclusively ruled out as the cause this time.

Per-peer dials (gap 9) — the attribution

Totals: started=50, succeeded=42, failed=7, in-flight=1.

peer	started	ok	failed	in-flight	last_outcome	at_ms
orchestrator-146aef53	11	3	7	1	Timeout	1779734955567
stage-0 (aa0ef1c5)	1	1	0	0	Success	1779734410397
stage-1 (32abf9d6)	19	19	0	0	Success	1779734518356
stage-2 (a1ebaa08)	19	19	0	0	Success	1779734522415

Every dial between stages succeeded. Only dials to the orchestrator failed, and they failed by timeout. The last stage's InferenceResponse is addressed to the orchestrator's inbox; if it cannot dial the orchestrator, the response never lands. This table is the proximate cause of the empty result.

Relay-session field (gap 2) and conn type

stage-2's latest snapshot body.iroh.relay_session:

relay_url:           http://146.190.110.128:7843/
status:              connected
status_changed_at_ms:1779734401024
status_entered_at_ms:1779734401024
status_source:       derived

The tunnel to the relay was connected, with status_source: derived honestly flagging that iroh does not expose this natively (per spec §2). So the failure is not "tunnel died" — it is "tunnel alive, peer-connection-through-tunnel to the orchestrator dead." That distinction was the explicit acceptance criterion for gap 2, and it holds here.

First peer to go Dead: stage-2 marked stage-1 (32abf9d6) Dead at t=1779734428439, reason suspicion-timeout. Both sides conn_type=Relay (no direct hole-punch anywhere in the run). Observer probes_ok=yes, peer probes_ok=no.

SWIM churn and relay events (gap 3)

SwimTransition: 1701 over a ~7-minute run — heavy flapping, consistent with the relay-mediated reachability of a NAT'd orchestrator and the §10.3 self-incarnation flap (see SWIM_TUNING_REPORT). RelaySessionStateChanged: 8, RelayChanged: 4, IrohConnTypeChanged: 8 — relay/transport flips are now on the event stream, not just counter deltas.

Kernel network drops (gap 11)

udp.no_ports delta across the run:

node	udp.no_ports
orchestrator	+1
stage-0	+139
stage-1	+134
stage-2	+1424

stage-2 took ~10× the no-listening-port UDP drops of its siblings — an interface-level corroboration of localized relay/hole-punch path instability, surfaced automatically in the summary.

Gossip receipts (gap 10)

node	swim_piggyback	bytes	items
orchestrator	806	263825	1607
stage-0	1589	522855	3178
stage-1	563	194236	1183
stage-2	1082	340115	2069

Every node received gossip. Gossip starvation is ruled out — the flap is not "a node never heard membership," it is "membership churned because the underlying relay path to a peer was unreliable."

UDP echo probes (collector tier-2)

node	result
orchestrator	ok, rtt=293 ms, 34/35
stage-0	ok, rtt=181 ms, 55/55
stage-1	ok, rtt=405 ms, 27/28
stage-2	ok, rtt=184 ms, 38/38

All nodes had clean tier-2 reachability to docean:9081 — i.e. the hosts themselves were on the network. The failure was at the iroh peer-connection layer, not raw host reachability.

iroh version honesty (gap 6)

iroh_version: "0.98.2" on every node and in every iroh_api_missing event (4 total) — matches Cargo.lock. The hard-coded "0.96" literal from 1779720002 is gone. The API-gap list now also carries the RelayTunnel.* derived-field markers.

Observability upgrade scorecard

What this run confirms the upgrade delivers, versus what it doesn't:

gap	status	evidence
2 relay-session field	✅	relay_session.status=connected, status_source=derived
3 relay events	✅	RelaySessionStateChanged: 8, RelayChanged: 4
4 subprocess introspector	✅	SubprocessSpawned: 3; worker ruled out
6 iroh version honesty	✅	0.98.2 everywhere, lockfile match
7 bundle without finalize	✅¹	GET returned a usable 9.3 MB bundle; ¹run-id reuse exposed stale-canonical serve + sticky finalize flag
9 per-peer dials	✅	the orchestrator-reachability table (the headline finding)
10 gossip receipts	✅	per-node swim_piggyback breakdown
11 kernel counters	✅	stage-2 udp.no_ports +1424 surfaced
1 relay observability	◐	relay reports identity + 186 snapshots, but per-session lifecycle is the documented skeleton: active=0 opens=0 closes=0 (iroh-relay exposes no session hooks)
5 host metadata	◐	container_id/hostname/git_sha/iroh_version/binary_version present; host_ip_public/datacenter_id/host_country/vastai_contract_id still null — provider fields not forwarded. (The contract id does arrive, but in container_id, not vastai_contract_id.)
8 relay-port probe	✗	not present: stage probe arrays carry only collector_udp_echo (:9081); no relay-port (:7843) probe

A+B+C (the tiers the previous investigation needed) all landed and were load-bearing here. The polish/robustness tiers (5 ip/dc/country, 7 finalize edge cases, 8 relay probe, 1 relay session lifecycle) have remaining work.

Data-collection / deployment gaps surfaced by this run

1. Host provider fields not forwarded (gap 5 incomplete). The orchestrator has each rental's public IP, datacenter, country, and contract id at lease_chain return, but only the docker container id (landing in container_id) and hostname reach the boot record. host_ip_public/datacenter_id/host_country/vastai_contract_id /home_relay_url_at_boot are still null. "Which rental was stage-2" is answerable only via the container_id↔contract map, not the dedicated fields.

2. gap-7 stale-canonical serve on run-id reuse. A finalize from an earlier phase of the same run id pins a stale cached bundle, and finalize_received is sticky in collector memory across staging deletion. Serve logic should prefer the richer of {canonical, synthesized-from-current-staging} or rebuild canonical when staging has grown past the cached bundle.

3. No relay-port reachability probe (gap 8 absent). Whether stage-2 could reach docean:7843 (the relay) at moment T is still inferred from a different port (:9081 echo). The exact gap the previous post-mortem flagged remains open.

4. Relay per-session lifecycle still skeleton (gap 1). The relay reports into the bundle but cannot yet say "who closed session X and why" because iroh_relay::server exposes no session hooks. Until it does, "was this a relay-side eviction" is unanswerable from the relay side; we relied on node-side dial outcomes instead.

5. No response-leg instrumentation. The conclusion "last stage could not deliver the response" was inferred from dial timeouts + absence of an inbound response, not from a typed event on the last stage ("attempted to send InferenceResponse to orchestrator, outcome=…"). A response-send event would make this a direct read rather than an inference.

6. Environmental: orchestrator topology is the root cause. A locally-run, NAT'd orchestrator with no direct port is reachable only via the relay, and the relay path to it proved unreliable under load (7/11 inbound dials timed out, 1701 SWIM transitions). Running the orchestrator on a reachable host (e.g. docean) or giving it a direct/forwarded port is the likely fix to test next.

7. DEPLOYMENT_TEST.md GPU flag is wrong. Line 84 shows --gpu RTX_4090; vast.ai matches gpu_name literally and the underscore form returns 0 offers. The orchestrator's own default is the correct "RTX 4090". Fix the runbook example.

Artifacts

In .vastai-logs/ (gitignored) after recovery:

vastai-N3-1779733878.bundle.tar.gz        full synthesized bundle (9.3 MB, 5 nodes)
vastai-N3-1779733878.staging-full.tar.gz  raw collector staging backup (~10 MB)
vastai-N3-1779733878.tar.gz               the stale 5.3 KB canonical bundle (kept for reference)
vastai-N3-1779733878.log                  orchestrator stdout (both launch attempts)
vastai-N3-1779733878.out/summary.md       postproc summary
vastai-N3-1779733878.out/reachability.tsv
vastai-N3-1779733878.out/timeline-*.tsv   per-link timelines

Staging copy retained on docean at /var/lib/swactor-diag/vastai-N3-1779733878/ (minus the removed e8151ed8 junk node).

Infrastructure state at end of session

• docean (146.190.110.128): collector and relay running (rebuilt static-musl binaries from e8be135). The relay is still pinned to SWACTOR_DIAG_RUN_ID=vastai-N3-1779733878 and continues appending periodic snapshots to that run's staging; the next run's redeploy re-pins it. Re-pulling the bundle later will include those extra relay snapshots.
• vast.ai instances under $VAST_API_KEY: 0 (verified).