From 710ceace12bd78181972c967fe65281e71837a26 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Tue, 27 Oct 2026 13:23:00 +0100 Subject: [PATCH] fix(R-1250): the line-test hold waits until the held app has really slowed down before asking the agent Measured on demo-hp 2026-10-27: qBittorrent 5.2.4 kept sending at full speed for ~14 s after its limit fell to 1 KiB/s; the agent reads the uplink 5-15 s after the call, so every test on request was refused "not quiet" (four tries in an hour, 4.0-4.2 Mbit/s). waitDrained polls each held app's own upload (qBittorrent up_info_speed, Transmission uploadSpeed) until <= 16 KiB/s twice, 2 s apart, at most 90 s; an unreadable speed waits 20 s. Tests TestR1250_* (five), red-proved by four mutations. --- CHANGELOG.md | 9 +- controller/README.md | 3 + controller/internal/upwatch/linehold.go | 122 ++++++++++++++- .../upwatch/linehold_r1250_drain_test.go | 140 ++++++++++++++++++ controller/internal/upwatch/linehold_test.go | 18 +++ 5 files changed, 289 insertions(+), 3 deletions(-) create mode 100644 controller/internal/upwatch/linehold_r1250_drain_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index bc2f9965..71d51595 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,4 +1,4 @@ -## Unreleased (next: v0.346.0) — D53: the hub learns which apps are held; an unreadable app.yaml keeps its folder (R-1220); the ceremony keeps the off-site key (R-1218, R-1219); safe .fab export/import (R-1187); holds of uninstalled apps are not reported (R-1298); Go 1.27.3 (R-972) — committed, not released +## Unreleased (next: v0.346.0) — D53: the hub learns which apps are held; an unreadable app.yaml keeps its folder (R-1220); the ceremony keeps the off-site key (R-1218, R-1219); safe .fab export/import (R-1187); holds of uninstalled apps are not reported (R-1298); Go 1.27.3 (R-972); the line-test hold waits for the seeder to slow down (R-1250) — committed, not released **MinAgent: 0.158.1** (unchanged). Operator ruling D53 (2026-10-26, felhom.eu `09` §3 decision 265): operator-only reminders first. Needs hub with `app_held` / `app_hold_cleared` in `allowedEventTypes` (felhom.eu, same day) — an older @@ -65,6 +65,13 @@ hub answers 400 to both and nothing else changes. R-1220) and reports it cleared if it was reported; a restore hold is always reported (R-379). 9202's four orphan holds from a hand removal would otherwise have mailed weekly. Test `TestR1298_OnlyHoldsOfInstalledAppsAreReported`, red-proved; the wiring test pins the `SetInstalled` line. +- **R-1250 (the line test for a box that seeds all day):** after the hold the controller now waits until every held app + REPORTS its own upload near zero (qBittorrent `transfer/info` `up_info_speed`, Transmission `session-stats` + `uploadSpeed`; ≤ 16 KiB/s on two readings 2 s apart, at most 90 s; an unreadable speed waits 20 s) and only then asks + the agent (`upwatch.waitDrained`). Measured on demo-hp 2026-10-27: qBittorrent 5.2.4 kept sending at full speed for + ~14 s after its limit fell to 1 KiB/s, while the agent reads the uplink 5–15 s after the call — four tries in an hour, + each refused „not quiet" (4.0–4.2 Mbit/s). New `Holdable.UploadRate`. Tests `TestR1250_*` (five), red-proved by four + mutations (no wait; only the first app read; no fallback wait; no maximum → hangs). - `settings.RestoreHold.Why()` / `WireReason()`: the hold sentence moved out of `cmd/controller` (`holdWhy` calls it), so `--restore-holds` and the hub's list say the same thing. - Tests `internal/holdreport/holdreport_test.go` (8): the report field, the daily repeat, cleared once, cleared while diff --git a/controller/README.md b/controller/README.md index 9b06d78d..45966bc3 100644 --- a/controller/README.md +++ b/controller/README.md @@ -3599,6 +3599,9 @@ it), holds the app at 1 KiB/s (Transmission 1 kB/s), calls `POST /host/line-test back — the household's own included; a change made during the test stays. A killed controller puts it back at start (`RecoverHold`, before any rule); the 50 % rule skips while a record exists. Proven on demo-hp with a real seed (felhom.eu `audits/dooplex-alarms-2026-10-24/`). +**v0.346.0 (R-1250):** between the hold and the call the controller waits until every held app reports its own upload +near zero (≤ 16 KiB/s twice, 2 s apart, at most 90 s; an unreadable speed waits 20 s) — qBittorrent sends at full +speed for ~14 s after its limit falls, which made the agent refuse every test „not quiet" (measured 2026-10-27). **v0.344.0 (R-1261):** EVERY running seeder is held, one record per app (`upwatch.line_test_holds`); a record whose app was removed while held is dropped (it used to stop the 50 % rule for good); qBittorrent's hold names its slot (`up_limit` / `alt_up_limit` through `app/preferences` — `transfer/uploadLimit` follows the CURRENT speed mode), so a diff --git a/controller/internal/upwatch/linehold.go b/controller/internal/upwatch/linehold.go index 8b9ccf45..d48ba6ac 100644 --- a/controller/internal/upwatch/linehold.go +++ b/controller/internal/upwatch/linehold.go @@ -21,9 +21,12 @@ import ( // 1. reads the app's global upload limit exactly as the app stored it, and writes it to settings.json // (`upwatch.line_test_hold`) BEFORE it touches the app; // 2. sets the app's upload to HoldValue (1 KiB/s); -// 3. asks the agent for a test on request (POST /host/line-test/run: 5 s settle, 10 s quiet check, three 10-second +// 3. waits until every held app REPORTS its own upload near zero (waitDrained) — qBittorrent 5.2.4 kept sending at +// full speed for ~14 s after its limit fell to 1 KiB/s (measured on demo-hp 2026-10-27, felhom.eu +// `audits/linetest-2026-10-27/`), so the agent's quiet check, 5–15 s after the hold, refused every test; +// 4. asks the agent for a test on request (POST /host/line-test/run: 5 s settle, 10 s quiet check, three 10-second // runs 5 s apart — about 55 s); -// 4. puts the old limit back — the household's own limit included, exactly as it was — and clears the record. +// 5. puts the old limit back — the household's own limit included, exactly as it was — and clears the record. // // Whatever fails after step 1, the limit is put back first. A controller that stops between 1 and 4 finds the record // at start (RecoverHold) and puts it back then. If the app holds anything but the test value when the limit goes @@ -60,6 +63,8 @@ type Holdable interface { WriteLimit(ctx context.Context, l HeldLimit) (HeldLimit, error) // HoldValue is the test value in prev's slot: very low, never zero (zero is „no limit"). HoldValue(prev HeldLimit) HeldLimit + // UploadRate is the app's own upload speed now, B/s — read while held, to know when it has really slowed. + UploadRate(ctx context.Context) (int64, error) } // LineRunResult is the agent's answer to a test on request. @@ -201,6 +206,76 @@ func (s *Service) releaseAll(ctx context.Context, held []Holdable, hs []LineHold } } +// The drain wait (step 3). The agent refuses a test when the uplink sends 2 Mbit/s or more 5–15 s after the call, so the +// controller asks only when every held app reports its own upload at or below drainQuietBps (0.13 Mbit/s) on +// drainQuietReadings readings in a row, drainPoll apart. It never waits longer than drainMax, and asks then anyway (the +// agent judges the line). An app whose speed cannot be read gets a plain drainFallback wait instead — the measured +// drain was ~14 s. Pinned by linehold_r1250_drain_test.go. +const ( + drainPoll = 2 * time.Second + drainMax = 90 * time.Second + drainFallback = 20 * time.Second + drainQuietBps = 16 * 1024 + drainQuietReadings = 2 +) + +// drainSleep waits d; false when ctx ends first. A variable so the tests can count the waiting instead of doing it. +var drainSleep = func(ctx context.Context, d time.Duration) bool { + t := time.NewTimer(d) + defer t.Stop() + select { + case <-ctx.Done(): + return false + case <-t.C: + return true + } +} + +// waitDrained returns when every held app has slowed down to the test value, or when it cannot tell (see above). +func (s *Service) waitDrained(ctx context.Context, apps []Holdable) { + var waited time.Duration + quiet := 0 + for { + var worst int64 + var readErr error + for _, app := range apps { + r, err := app.UploadRate(ctx) + if err != nil { + readErr = fmt.Errorf("%s: %v", app.Stack(), err) + break + } + if r > worst { + worst = r + } + } + switch { + case readErr != nil: + logx.Infof(s.Log, "[upwatch] line test: cannot read the upload speed (%v) — waiting %s before asking the agent", readErr, drainFallback) + if rest := drainFallback - waited; rest > 0 { + drainSleep(ctx, rest) + } + return + case worst <= drainQuietBps: + quiet++ + if quiet >= drainQuietReadings { + logx.Infof(s.Log, "[upwatch] line test: the held app(s) slowed down after %s — asking the agent", waited) + return + } + default: + quiet = 0 + logx.Debugf(s.Log, "[upwatch] line test: held, still sending %d B/s after %s", worst, waited) + } + if waited >= drainMax { + logx.Infof(s.Log, "[upwatch] line test: the held app(s) still send %d B/s after %s — asking the agent anyway", worst, waited) + return + } + if !drainSleep(ctx, drainPoll) { + return + } + waited += drainPoll + } +} + // SeedLineTestNow runs the hold once when the agent waits for quiet and a torrent app is running (main calls it every // 15 minutes, before QBLimitNow). EVERY running seeder is held — one left seeding keeps the uplink busy and the agent // refuses the test „not quiet" every time (R-1261). A no-op otherwise. @@ -255,6 +330,7 @@ func (s *Service) SeedLineTestNow(ctx context.Context) { // Deferred: a panic in the call puts the limits back too. A killed process does not — that is RecoverHold's. res, err := func() (LineRunResult, error) { defer s.releaseAll(ctx, apps, hs) + s.waitDrained(ctx, apps) return s.LineRun(ctx) }() switch { @@ -354,6 +430,28 @@ func (q *QBittorrent) HoldValue(prev HeldLimit) HeldLimit { return HeldLimit{Bytes: 1024, Alt: prev.Alt} } +// UploadRate: transfer/info `up_info_speed` (B/s, payload and overhead together). +func (q *QBittorrent) UploadRate(ctx context.Context) (int64, error) { + h, err := q.session(ctx, true) + if err != nil { + return 0, err + } + code, b, _, err := httpDo(ctx, q.client(), "GET", q.base()+"/api/v2/transfer/info", h, nil, "") + if err != nil || code != 200 { + return 0, fmt.Errorf("qBittorrent transfer/info: HTTP %d %v", code, err) + } + var ti struct { + UpSpeed *int64 `json:"up_info_speed"` + } + if err := json.Unmarshal(b, &ti); err != nil { + return 0, fmt.Errorf("qBittorrent transfer/info: %v", err) + } + if ti.UpSpeed == nil { + return 0, fmt.Errorf("qBittorrent transfer/info: no up_info_speed") + } + return *ti.UpSpeed, nil +} + func (t *Transmission) ReadLimit(ctx context.Context) (HeldLimit, error) { var st struct { Arguments struct { @@ -386,3 +484,23 @@ func (t *Transmission) ReadLimitLike(ctx context.Context, _ HeldLimit) (HeldLimi // HoldValue: 1 kB/s with the limit switched on. func (t *Transmission) HoldValue(HeldLimit) HeldLimit { return HeldLimit{Enabled: true, KBps: 1} } + +// UploadRate: session-stats `uploadSpeed` (B/s). +func (t *Transmission) UploadRate(ctx context.Context) (int64, error) { + b, err := t.rpc(ctx, `{"method":"session-stats"}`) + if err != nil { + return 0, err + } + var st struct { + Arguments struct { + UploadSpeed *int64 `json:"uploadSpeed"` + } `json:"arguments"` + } + if err := json.Unmarshal(b, &st); err != nil { + return 0, err + } + if st.Arguments.UploadSpeed == nil { + return 0, fmt.Errorf("transmission session-stats: no uploadSpeed") + } + return *st.Arguments.UploadSpeed, nil +} diff --git a/controller/internal/upwatch/linehold_r1250_drain_test.go b/controller/internal/upwatch/linehold_r1250_drain_test.go new file mode 100644 index 00000000..5ee99a99 --- /dev/null +++ b/controller/internal/upwatch/linehold_r1250_drain_test.go @@ -0,0 +1,140 @@ +package upwatch + +import ( + "context" + "net/http" + "net/http/httptest" + "testing" + "time" +) + +// R-1250, measured on demo-hp 2026-10-27: qBittorrent 5.2.4 kept sending at full speed for ~14 s after the hold set its +// limit to 1 KiB/s, while the agent read the uplink 5–15 s after the call — every test on request was refused „not +// quiet" (four tries in one hour). The controller now asks the agent only after the held apps report their own upload +// near zero. + +// slept counts the drain waits instead of doing them (every test in this package; none waits for real). +var slept time.Duration + +func init() { + drainSleep = func(ctx context.Context, d time.Duration) bool { + slept += d + return ctx.Err() == nil + } +} + +// The consequence: the agent is asked only once the held app reported two quiet readings in a row. +// RED-PROOF: drop the waitDrained call in SeedLineTestNow → the agent is asked with 0 readings taken → fails. +func TestR1250_TheAgentIsAskedOnlyAfterTheHeldAppSlowedDown(t *testing.T) { + r := newHoldRig(t) + // 5 Mbit/s for three readings (the drain), then quiet; one noisy reading between two quiet ones restarts the count. + r.app.rates = []int64{640_000, 640_000, 610_000, 0, 300_000, 0, 0} + readsAtCall := -1 + r.during = func() { readsAtCall = r.app.rateReads } + slept = 0 + r.svc.SeedLineTestNow(context.Background()) + if r.runs != 1 { + t.Fatalf("agent asked %d times, want 1", r.runs) + } + if readsAtCall != 7 { + t.Fatalf("the agent was asked after %d speed readings, want 7 — only after two quiet readings in a row", readsAtCall) + } + if slept != 6*drainPoll { + t.Fatalf("waited %s before asking, want %s", slept, 6*drainPoll) + } + if r.app.limit != (HeldLimit{Bytes: 2_499_584}) || r.record() != nil { + t.Fatalf("after the test the app holds %+v (record %+v), want the household's limit back", r.app.limit, r.record()) + } +} + +// Every held app must be quiet, not just the first. +// RED-PROOF: read only apps[0] in waitDrained → asked while the second still sends → fails. +func TestR1250_EveryHeldAppMustSlowDown(t *testing.T) { + qb := &fakeTorrent{limit: HeldLimit{Bytes: 2_499_584}} + tr := &fakeTorrent{name: "transmission", limit: HeldLimit{Enabled: true, KBps: 500}, rates: []int64{400_000, 400_000, 400_000, 0}} + runs, trAtCall := 0, -1 + svc := &Service{Store: &memStore{}, Torrents: []Holdable{qb, tr}, + TorrentRunning: func(string) bool { return true }, + LineWaiting: func(context.Context) bool { return true }, + LineRun: func(context.Context) (LineRunResult, error) { + runs++ + trAtCall = tr.rateReads + return LineRunResult{OK: true, Mbps: 92}, nil + }} + svc.SeedLineTestNow(context.Background()) + if runs != 1 || trAtCall < 5 { + t.Fatalf("asked %d time(s) with %d transmission reading(s), want once and after its two quiet readings (5)", runs, trAtCall) + } +} + +// An app that never slows down: the agent is asked anyway after drainMax (it judges the line), and the limit comes back. +// RED-PROOF: drop the drainMax check → the loop never ends → the test times out. +func TestR1250_AnAppThatNeverSlowsIsAskedAboutAfterTheMaximum(t *testing.T) { + r := newHoldRig(t) + r.app.rates = []int64{640_000} + slept = 0 + r.svc.SeedLineTestNow(context.Background()) + if r.runs != 1 || slept != drainMax { + t.Fatalf("asked %d time(s) after %s, want once after %s", r.runs, slept, drainMax) + } + if r.app.limit != (HeldLimit{Bytes: 2_499_584}) { + t.Fatalf("after the test the app holds %+v, want the household's limit back", r.app.limit) + } +} + +// An app whose speed cannot be read: a plain drainFallback wait, then the agent. +// RED-PROOF: return at once on a read error → slept 0 → fails. +func TestR1250_AnUnreadableSpeedGetsTheFallbackWait(t *testing.T) { + r := newHoldRig(t) + r.app.failRate = true + slept = 0 + r.svc.SeedLineTestNow(context.Background()) + if r.runs != 1 || slept != drainFallback { + t.Fatalf("asked %d time(s) after %s, want once after %s", r.runs, slept, drainFallback) + } +} + +// The two real readers, against the field names the apps serve (qBittorrent 5.2.4 transfer/info, Transmission 4.x +// session-stats); a missing field is an error, never a quiet 0. +func TestR1250_UploadRateReadsTheAppsOwnSpeed(t *testing.T) { + qbBody := `{"up_info_speed":655360,"up_info_data":1}` + qs := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { + switch req.URL.Path { + case "/api/v2/auth/login": + http.SetCookie(w, &http.Cookie{Name: "SID", Value: "s"}) + w.WriteHeader(204) + case "/api/v2/transfer/info": + _, _ = w.Write([]byte(qbBody)) + default: + w.WriteHeader(404) + } + })) + defer qs.Close() + qb := &QBittorrent{Box: envBox{"qbittorrent/QBT_ADMIN_PASSWORD": "pw-canary"}, URL: qs.URL} + if v, err := qb.UploadRate(context.Background()); err != nil || v != 655360 { + t.Fatalf("qBittorrent UploadRate = %d, %v; want 655360", v, err) + } + qbBody = `{"up_info_data":1}` + if v, err := qb.UploadRate(context.Background()); err == nil { + t.Fatalf("qBittorrent without up_info_speed read %d, want an error", v) + } + + trBody := `{"arguments":{"uploadSpeed":12345,"downloadSpeed":0},"result":"success"}` + ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { + if req.Header.Get("X-Transmission-Session-Id") == "" { + w.Header().Set("X-Transmission-Session-Id", "sid") + w.WriteHeader(409) + return + } + _, _ = w.Write([]byte(trBody)) + })) + defer ts.Close() + tr := &Transmission{Box: envBox{"transmission/PASS": "tr-canary"}, URL: ts.URL} + if v, err := tr.UploadRate(context.Background()); err != nil || v != 12345 { + t.Fatalf("Transmission UploadRate = %d, %v; want 12345", v, err) + } + trBody = `{"arguments":{"downloadSpeed":0},"result":"success"}` + if v, err := tr.UploadRate(context.Background()); err == nil { + t.Fatalf("Transmission without uploadSpeed read %d, want an error", v) + } +} diff --git a/controller/internal/upwatch/linehold_test.go b/controller/internal/upwatch/linehold_test.go index 721889e5..e876f47a 100644 --- a/controller/internal/upwatch/linehold_test.go +++ b/controller/internal/upwatch/linehold_test.go @@ -20,6 +20,24 @@ type fakeTorrent struct { writes []HeldLimit failWrite bool failRead bool + rates []int64 // UploadRate answers in order, the last one repeating; none = 0 (already quiet) + rateReads int + failRate bool +} + +func (f *fakeTorrent) UploadRate(context.Context) (int64, error) { + f.rateReads++ + if f.failRate { + return 0, errors.New("transfer/info: HTTP 404") + } + if len(f.rates) == 0 { + return 0, nil + } + i := f.rateReads - 1 + if i >= len(f.rates) { + i = len(f.rates) - 1 + } + return f.rates[i], nil } func (f *fakeTorrent) Stack() string {