Skip to content

Commit a4a181d

Browse files
localai-botmudler
andauthored
fix(distributed): count staging verification as progress, not as a stall (#11026)
Testing the progress-based cold-load deadline on the live cluster surfaced a false positive. The stall window observed UPLOAD bytes only, but the staging path has a phase that does real work while moving zero upload bytes: the resumable-upload verify phase. When a shard is already present on the worker from an earlier attempt, the frontend HEADs it, hashes the local copy to confirm it matches, and skips the transfer. Staging a 70 GB model with 56 GB already staged: 17:27:34 INFO Upload skipped (file already exists with matching hash) ... 17:28:20 INFO Upload skipped (file already exists with matching hash) ... 17:29:07 INFO Upload skipped (file already exists with matching hash) ... ... six-plus consecutive minutes, no bytes uploaded at all ~45s per skipped ~4 GB shard. That is correct and desirable - it is what makes resume work - but it was indistinguishable from a stall. At 45s per shard it sits inside the 5m window, so the run in flight was fine; the problem is the 600 GB scale this machinery exists to enable, where one shard can plausibly hash for longer than the window. The guard would then fire during verification of a transfer that is working perfectly. Verified mechanism: probeExisting() HEADs the worker and then calls downloader.CalculateSHA(). The staging progress callback is only consulted inside doUpload(), which the skip path never reaches, so observeLoadProgress was called zero times for the whole verify phase. Verification exposed a second, worse bug in the same path: CalculateSHA consults no context at all. An expired cold load kept hashing to completion, compared the hashes, and returned success - reporting a file as staged on a dead load. The failure only surfaced on the NEXT file, whose HEAD died immediately. That is exactly the shape of the red test here, which fails on shard 3. Fix: hash in 1 MiB chunks via hashFileWithActivity(), ticking the cold-load deadline per chunk and checking ctx per chunk. A successful HEAD also counts, since a 200 with a content hash proves the worker is serving right now. Counting hash progress does not make a dead transfer look alive: hashing is bounded, terminating work proportional to file size, in probeExisting it runs only after a HEAD proved the worker was up, and the 24h absolute cap still bounds the whole hold. The alternative of simply widening the window was rejected - it would reintroduce the size cliff this work removes. Assisted-by: Claude Code:claude-opus-4-8[1m] [Read] [Edit] [Bash] Signed-off-by: Ettore Di Giacinto <mudler@localai.io> Co-authored-by: Ettore Di Giacinto <mudler@localai.io>
1 parent 2b61e4b commit a4a181d

3 files changed

Lines changed: 234 additions & 4 deletions

File tree

core/services/nodes/file_stager_http.go

Lines changed: 68 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,8 @@ package nodes
22

33
import (
44
"context"
5+
"crypto/sha256"
6+
"encoding/hex"
57
"encoding/json"
68
"errors"
79
"fmt"
@@ -19,7 +21,6 @@ import (
1921
"github.com/mudler/xlog"
2022

2123
"github.com/mudler/LocalAI/core/services/storage"
22-
"github.com/mudler/LocalAI/pkg/downloader"
2324
"github.com/mudler/LocalAI/pkg/httpclient"
2425
)
2526

@@ -106,8 +107,14 @@ func (h *HTTPFileStager) EnsureRemote(ctx context.Context, nodeID, localPath, ke
106107
// attempt — the server uses it to detect mid-flight content drift and
107108
// reject (409) if a partial upload claims a new identity, forcing a clean
108109
// restart.
109-
localHash, err := downloader.CalculateSHA(localPath)
110+
localHash, err := hashFileWithActivity(ctx, localPath)
110111
if err != nil {
112+
if ctx.Err() != nil {
113+
// The cold load was cancelled or expired while hashing. Uploading
114+
// on a dead context can only fail, so surface it rather than
115+
// pressing on without resume-safety.
116+
return "", fmt.Errorf("hashing %s for upload to node %s: %w", localPath, nodeID, err)
117+
}
111118
// Hash failure isn't fatal — we can still upload; we just lose
112119
// resume-safety and end-of-transfer integrity checks.
113120
xlog.Warn("Failed to hash local file for upload integrity check", "localPath", localPath, "error", err)
@@ -461,7 +468,12 @@ func (h *HTTPFileStager) probeExisting(ctx context.Context, addr, localPath, key
461468
return "", false
462469
}
463470

464-
localHash, err := downloader.CalculateSHA(localPath)
471+
// A 200 with a content hash is proof the worker is alive and serving right
472+
// now, so it counts as progress in its own right — otherwise a long run of
473+
// legitimately skipped shards accrues no activity at all.
474+
observeLoadProgress(ctx)
475+
476+
localHash, err := hashFileWithActivity(ctx, localPath)
465477
if err != nil {
466478
return "", false
467479
}
@@ -473,6 +485,59 @@ func (h *HTTPFileStager) probeExisting(ctx context.Context, addr, localPath, key
473485
return remotePath, true
474486
}
475487

488+
// hashChunkSize is how much of a file is hashed between activity ticks and
489+
// cancellation checks. 1 MiB is small enough that a cancelled cold load aborts
490+
// promptly even on a huge shard, and large enough that the per-chunk bookkeeping
491+
// is irrelevant next to the hashing itself.
492+
const hashChunkSize = 1 << 20
493+
494+
// hashFileWithActivity computes a file's SHA-256 while reporting activity to the
495+
// cold-load deadline, and aborts if that deadline expires.
496+
//
497+
// Hashing is the long pole of the resumable-upload verify phase, which moves
498+
// zero upload bytes: the client HEADs the worker, hashes the local file to
499+
// confirm it matches, and skips the transfer. On the live cluster that measured
500+
// ~45s per ~4 GB shard, with six-plus consecutive minutes of no uploaded bytes.
501+
// A stall window watching only upload bytes would eventually mistake that for a
502+
// wedged worker — and precisely in the 600 GB case this machinery exists to
503+
// enable, where one shard can hash for longer than the window.
504+
//
505+
// Counting hash progress as progress is safe because it is bounded, terminating
506+
// work proportional to file size: it cannot make a dead transfer look alive
507+
// indefinitely. In probeExisting it also runs only after a successful HEAD
508+
// proved the worker was serving, and the absolute cap still bounds the whole
509+
// hold regardless.
510+
func hashFileWithActivity(ctx context.Context, path string) (string, error) {
511+
f, err := os.Open(path)
512+
if err != nil {
513+
return "", err
514+
}
515+
defer func() { _ = f.Close() }()
516+
517+
h := sha256.New()
518+
buf := make([]byte, hashChunkSize)
519+
for {
520+
// Checked per chunk: CalculateSHA consulted no context at all, so an
521+
// expired cold load used to hash to completion and report the file as
522+
// staged, turning a dead load into a silent success.
523+
if err := ctx.Err(); err != nil {
524+
return "", err
525+
}
526+
n, readErr := f.Read(buf)
527+
if n > 0 {
528+
h.Write(buf[:n])
529+
observeLoadProgress(ctx)
530+
}
531+
if errors.Is(readErr, io.EOF) {
532+
break
533+
}
534+
if readErr != nil {
535+
return "", readErr
536+
}
537+
}
538+
return hex.EncodeToString(h.Sum(nil)), nil
539+
}
540+
476541
// progressReader wraps an io.Reader and logs upload progress periodically.
477542
// If a StagingProgressCallback is present in the context, it also calls it
478543
// for UI-visible progress updates.
Lines changed: 165 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,165 @@
1+
package nodes
2+
3+
import (
4+
"context"
5+
"crypto/sha256"
6+
"encoding/hex"
7+
"fmt"
8+
"net/http"
9+
"net/http/httptest"
10+
"net/url"
11+
"os"
12+
"path/filepath"
13+
"time"
14+
15+
. "github.com/onsi/ginkgo/v2"
16+
. "github.com/onsi/gomega"
17+
)
18+
19+
// The resumable-upload fast path (HEAD the worker, hash the local file, skip
20+
// when the hashes match) is what makes resume work after a partial transfer.
21+
// It reports ZERO upload bytes for its entire duration, so a stall window that
22+
// watches only upload bytes cannot tell it apart from a wedged worker.
23+
//
24+
// Measured on the live cluster staging a 70 GB model with 56 GB already
25+
// present: ~45s per skipped ~4 GB shard, six-plus consecutive minutes with no
26+
// bytes uploaded at all. At the 600 GB scale this work exists to support, a
27+
// single shard can plausibly hash for longer than the 5m stall window.
28+
29+
// verifyShardSize keeps each shard small enough to stay friendly to /tmp while
30+
// still costing real, measurable hashing time.
31+
const verifyShardSize = 16 << 20
32+
33+
// verifyShardCount is chosen so the cumulative hashing time across consecutive
34+
// skipped shards comfortably outlasts the scaled-down stall window, mirroring
35+
// the run of consecutive skips seen on the cluster.
36+
const verifyShardCount = 6
37+
38+
func writeShard(path string, size int) string {
39+
f, err := os.Create(path)
40+
Expect(err).ToNot(HaveOccurred())
41+
defer func() { _ = f.Close() }()
42+
43+
h := sha256.New()
44+
chunk := make([]byte, 1<<20)
45+
for i := range chunk {
46+
chunk[i] = byte(i * 7)
47+
}
48+
for written := 0; written < size; written += len(chunk) {
49+
n := len(chunk)
50+
if remaining := size - written; remaining < n {
51+
n = remaining
52+
}
53+
_, err := f.Write(chunk[:n])
54+
Expect(err).ToNot(HaveOccurred())
55+
h.Write(chunk[:n])
56+
}
57+
return hex.EncodeToString(h.Sum(nil))
58+
}
59+
60+
var _ = Describe("staging verify phase and the cold-load stall window", func() {
61+
newStagerFor := func(srv *httptest.Server) *HTTPFileStager {
62+
return NewHTTPFileStager(func(string) (string, error) {
63+
u, err := url.Parse(srv.URL)
64+
if err != nil {
65+
return "", err
66+
}
67+
return u.Host, nil
68+
}, "")
69+
}
70+
71+
It("survives a run of verified-and-skipped shards that upload no bytes at all", func() {
72+
tmp := GinkgoT().TempDir()
73+
paths := make([]string, verifyShardCount)
74+
hashes := make(map[string]string, verifyShardCount)
75+
for i := range paths {
76+
key := fmt.Sprintf("shard-%d", i)
77+
paths[i] = filepath.Join(tmp, key+".safetensors")
78+
hashes[key] = writeShard(paths[i], verifyShardSize)
79+
}
80+
81+
// The worker already holds every shard from a previous attempt, so each
82+
// one is HEADed, hashed locally, and skipped.
83+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
84+
Expect(r.Method).To(Equal(http.MethodHead),
85+
"every shard must take the verify/skip path, never upload")
86+
key := filepath.Base(r.URL.Path)
87+
w.Header().Set(HeaderLocalPath, "/worker/models/"+key)
88+
w.Header().Set(HeaderContentSHA256, hashes[key])
89+
w.WriteHeader(http.StatusOK)
90+
}))
91+
defer srv.Close()
92+
93+
// Scaled-down budgets: hashing these shards takes far longer than the
94+
// window, standing in for 600 GB shards against a 5m window.
95+
ctx, cancel := newLoadDeadlineContext(context.Background(),
96+
20*time.Millisecond, 20*time.Millisecond, time.Minute)
97+
defer cancel()
98+
99+
stager := newStagerFor(srv)
100+
start := time.Now()
101+
for i, p := range paths {
102+
key := fmt.Sprintf("shard-%d", i)
103+
remotePath, err := stager.EnsureRemote(ctx, "nvidia-thor", p, key)
104+
Expect(err).ToNot(HaveOccurred(),
105+
"verifying shard %d does real work and must not be mistaken for a stall", i)
106+
Expect(remotePath).To(Equal("/worker/models/" + key))
107+
}
108+
Expect(time.Since(start)).To(BeNumerically(">", 20*time.Millisecond),
109+
"the verify run must actually have outlasted the stall window")
110+
})
111+
112+
It("does not silently succeed on the verify path after the deadline has expired", func() {
113+
// The verify path consulted no context at all: it hashed to completion
114+
// and returned success even on a dead context, so an expired cold load
115+
// looked like a staged file.
116+
tmp := GinkgoT().TempDir()
117+
localPath := filepath.Join(tmp, "shard.safetensors")
118+
hash := writeShard(localPath, 1<<20)
119+
120+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
121+
w.Header().Set(HeaderLocalPath, "/worker/models/shard")
122+
w.Header().Set(HeaderContentSHA256, hash)
123+
w.WriteHeader(http.StatusOK)
124+
}))
125+
defer srv.Close()
126+
127+
ctx, cancel := context.WithCancel(context.Background())
128+
cancel()
129+
130+
_, err := newStagerFor(srv).EnsureRemote(ctx, "nvidia-thor", localPath, "shard")
131+
Expect(err).To(HaveOccurred(),
132+
"a cancelled load must not report a file as staged")
133+
})
134+
135+
It("still kills a worker that goes silent during the verify phase", func() {
136+
tmp := GinkgoT().TempDir()
137+
localPath := filepath.Join(tmp, "small.safetensors")
138+
writeShard(localPath, 1<<20)
139+
140+
// The worker accepted the connection and then died: no HEAD response,
141+
// no bytes, no hashing. Nothing here is real work.
142+
//
143+
// Ordering matters: srv.Close() blocks until in-flight handlers return,
144+
// so the handler must be released BEFORE Close runs. Defers are LIFO.
145+
release := make(chan struct{})
146+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
147+
<-release
148+
}))
149+
defer srv.Close()
150+
defer close(release)
151+
152+
ctx, cancel := newLoadDeadlineContext(context.Background(),
153+
100*time.Millisecond, 100*time.Millisecond, time.Minute)
154+
defer cancel()
155+
156+
start := time.Now()
157+
_, err := newStagerFor(srv).EnsureRemote(ctx, "dead-node", localPath, "shard")
158+
elapsed := time.Since(start)
159+
160+
Expect(err).To(HaveOccurred(),
161+
"a silent worker must still be caught by the stall window")
162+
Expect(elapsed).To(BeNumerically("<", 10*time.Second),
163+
"the advisory lock must be released promptly")
164+
})
165+
})

docs/content/features/distributed-mode.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -79,7 +79,7 @@ The router also bounds how long a single cold load may hold the per-model adviso
7979

8080
The load starts with a base budget of `max(backend-install-timeout + model-load-timeout + 5m, 25m)` — with the defaults, `15m + 5m + 5m = 25m`. That budget covers the steps that report no progress: node selection, backend install, and the remote `LoadModel` call. Raising either timeout widens it in step, so a longer load deadline is never clipped.
8181

82-
While **model files are staging**, however, the deadline extends every time bytes actually move, and expires only once the transfer has been silent for a 5-minute stall window. Staging time is a function of checkpoint size and available bandwidth, not a constant: a 70 GB model at 26 MB/s needs about 45 minutes, and a 600 GB checkpoint needs hours. A fixed ceiling would therefore be a model-size cliff — every increase just moves the cliff to the next larger model. Extending on progress means a large model transfers for as long as it legitimately needs, while a worker that dies mid-transfer still releases the lock within the stall window.
82+
While **model files are staging**, however, the deadline extends every time staging does real work, and expires only once staging has been silent for a 5-minute stall window. Real work means uploaded bytes, and also the resumable-upload verify phase: when a shard is already present on the worker from an earlier attempt, the frontend HEADs it and hashes the local copy to confirm it matches, then skips the transfer. That phase uploads nothing at all — on a 70 GB model resuming with 56 GB already staged it ran for six-plus consecutive minutes at ~45s per shard — so hashing counts as progress too. Otherwise a resumed transfer would be mistaken for a wedged one. Staging time is a function of checkpoint size and available bandwidth, not a constant: a 70 GB model at 26 MB/s needs about 45 minutes, and a 600 GB checkpoint needs hours. A fixed ceiling would therefore be a model-size cliff — every increase just moves the cliff to the next larger model. Extending on progress means a large model transfers for as long as it legitimately needs, while a worker that dies mid-transfer still releases the lock within the stall window.
8383

8484
An absolute cap of 24h ends the hold even if progress keeps arriving, so a degenerate peer trickling a few bytes at a time cannot pin the lock forever. No configuration is needed for either value; both are sized well above any legitimate transfer.
8585

0 commit comments

Comments
 (0)