bundle pull: a 1.15 GiB leg on a 0.5 MiB/s lon1 lane runs alone for 35 min while every other lane is idle (SDXL, 2 of 2 runs)

Chiusa
  • Qualcosa non va?
#2,348 4 commenti 0 reazioni 0 assegnatari Vedi su GitHub

I maintainer di solito rispondono entro 1 giorno

Nessuno ha ancora preso questa issue.

Valutazione

Difficoltà
5/5
Tempo stimato
Più di una settimana
Idoneità per principianti
8/100
Tipo di issue
Bug
Chiarezza
Da chiarire
Stato di attività
Attiva
Stack tecnologico
rust
Ambito
distributed-systems, networking, performance

Direzione di ricerca

Start with the two open questions: why an idle lane does not steal the tail of the 1152 MiB lon1 leg, and why lon1's serve_stream span is idle 99.7% of the time. The payload names the pull-runner.sh batch, the Tempo traces d7706195c632d7584d5500efc9704401 and d315c5e8610b7359c7438dd059e14f3c, and the decdn_* counters, but no source files. Reproducing it needs the testnet, and the issue does not settle the fix direction, so it needs a maintainer decision first.

Scritto dal modello di indicizzazione a partire dal testo della issue.

Descrizione

area:client kind:bug

Summary

In bundle pull, the client gives a 1.15 GiB range of a 9.56 GiB SDXL file to lon1 as one leg. lon1 serves this file at 0.3–0.6 MiB/s on every leg. The other lanes on the same file deliver 5–12 MiB/s. The leg runs alone for 33–36 min while every other node is idle, and nothing steals its tail. It sets the finish time of the whole SDXL pull. It happened in 2 of 2 SDXL runs in a 20-run batch, on the same offsets each time.

There are two separate questions here:

  1. Client: why does no idle lane steal the tail of a leg that runs at 0.5 MiB/s for 30+ min?
  2. Node: why does lon1 serve this file from its own store at 0.3–0.6 MiB/s with its serve_stream span 99.7% idle?

Evidence (testnet, 2026-10-06/07, CLI cdf8ece3)

pull-runner.sh batch, 20 runs, all rc=0. Host routes on (en0). SDXL 4621f13e…54ed:

run wall 5a7fddce… (9.56 GiB) other SDXL runs
4 3428 s 2568.2 s, 8.58 GiB downloaded at 3.42 MiB/s, 1007.58 MiB spliced from disk 1032–2372 s on 7f938e6b/5f5605df
9 3662 s 2495.1 s, 8.58 GiB downloaded at 3.52 MiB/s

The other 11 files of the bundle finished in 172–1457 s in both runs.

Node side: every lon1 leg on 5a7fddce is slow (Tempo serve_stream, run 4)
node byte_offset + byte_len duration rate
lon1 67108864 + 128 MiB 419 s 0.31 MiB/s
lon1 2617245696 + 448 MiB 1237 s 0.36 MiB/s
lon1 3489660928 + 1152 MiB 2141 s (22:22:26→22:58:07) 0.54 MiB/s
lon1 5435817984 + 256 MiB 682 s 0.38 MiB/s
lon1 6106906624 + 320 MiB 680 s 0.47 MiB/s
lon1 6777995264 + 64 MiB 179 s 0.36 MiB/s
nbg1 6845104128 + 1536 MiB 134 s 11.4 MiB/s
ash1 335544320 + 1536 MiB 308 s 5.0 MiB/s
hel1 1946157056 + 384 MiB 66 s 5.8 MiB/s
  • The bold leg ends 8 s before the file completes (22:58:15). It is the critical path.
  • Its span (trace d7706195c632d7584d5500efc9704401): outcome=completed, bytes=1212678592, busy_ns 7.4 s, idle_ns 2133 s. It has no child spans.
  • lon1 decdn_bytes_received_total = 0 and decdn_cache_origin_fetches_total = 0 from 22:10 to 23:00. So lon1 serves these ranges from its own store, with no upstream pull. Its serves count as decdn_serve_cache_partial_hit_total.
  • lon1 decdn_iroh_socket_send_ipv4_total is a flat ~1.3 MB/s from 22:20 to 22:55. The relay counter stays at ~30 B/s, so this is a direct path.
  • The same lon1→client path carried ~19 MB/s at 21:45 in run 2 (gpt-oss). The path itself can go faster.
  • From ~22:25, decdn_bytes_served_total is 0 on all six other nodes. The client link carries only lon1's ~1.3 MB/s.

Run 9 repeats it on the same offsets. lon1 3489660928 + 1152 MiB ran 2003 s (00:01:45→00:35:08, trace d315c5e8610b7359c7438dd059e14f3c, busy_ns 6.0 s, idle_ns 1997 s). Its other legs were 0.32–0.88 MiB/s. In pulls9 (2026-10-06), lon1 also served the gpt-oss complement 02bd4845 at ~1 MB/s, so this may not be specific to SDXL.

Client side: the range waits, goes to lon1, and is never stolen
  • From 22:15:27, a queued range waits for a stream lists 3422552064+1275068416 (with 2617245696+469762048, 5435817984+268435456, 6106906624+335544320, 6777995264+67108864) with refused=1–4 no_candidate=0. Candidate lanes exist, but their grow(GrowFor::Extra) is refused. This is the permit starvation in #2341.
  • At 22:22:26, the range starts on lon1 as one 1152 MiB leg. By then, lon1's first two legs on this file had been running for 3–7 minutes at ~0.3 MiB/s.
  • No steal trims the leg. lon1's span sends bytes=1212678592 (the full 1207959552-byte range plus proof overhead) with outcome=completed. The client logs no lane fault on that leg and no queued-range wait for this file after 22:43:32.
  • Steals log at debug, and the client log at -v does not show lane coverage. So this run cannot say whether an idle lane covered the leg's suffix and declined, or covered none of it. Under the covered-suffix rule (#2303), a lane that does not cover the range's last block cannot steal from it.

Impact

Each SDXL run lost about 30 min to one leg: 3428 and 3662 s, against 1032–2372 s in earlier batches. Most of the batch's slowdown comes from these two runs: 32 MB/s for the whole batch, against 48 MB/s in pulls8.

Not in this binary

  • #2347 (a freed provider permit goes to the lane that waited first) merged after this batch. It can make the range start sooner on a faster lane. It does not change what happens to a slow leg once it runs.
  • #2346 (holder record on lane-fault lines) also merged after. There was no fault on this leg, so it would not have logged anything.

Direction (not decided)

  • Let an idle lane steal from a leg whose observed rate is far below the other lanes', even outside its covered suffix, if its node can serve the rest by pull-through.
  • Or do not give a whole multi-GiB range to a lane whose observed rate on the same file is already an order of magnitude below the others.
  • On lon1: find what the idle 99.7% of a local-store serve waits on: QUIC send, disk read, or voucher pacing.

Related

#2303 (steal needs whole-range coverage, closed; the fix limits steals to the covered suffix), #2341 / #2347 (queued range starved of permits), #2252 (one holder sets the finish time), #2256 (lon1/fra1 max_blob_size_mb = 8192; 5a7fddce is above that limit, and lon1 holds only part of it).

Lingua principale
Rust
Stelle
20
Fork
0
Merge medio
3h 16m
PR unite (30g)
263

Preparare l'ambiente

Come iniziare

  1. Leggi tutta la issue e poi la guida ai contributi del progetto.
  2. Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
  3. Fai un fork del repository e lavora su un branch.
  4. Apri una pull request che faccia riferimento al numero della issue.

Altre issue di decdn/decdn

Tutte le issue di decdn/decdn

Issue simili

Altre issue su Rust

Ricevi le nuove issue nella tua casella

Un breve riepilogo di issue GitHub adatte ai principianti.