From 11bc1997e85f45dc31cab7db5ca04a1d1e22b34a Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 00:22:24 +0200 Subject: [PATCH 01/16] diagnostics(control): expose EV fuse budget evidence for start skew Signed-off-by: Segran --- .changeset/ev-fuse-budget-evidence.md | 5 ++ go/internal/control/ev_fuse_budget.go | 34 +++++++-- go/internal/control/ev_fuse_incident_test.go | 73 ++++++++++++++++++++ 3 files changed, 105 insertions(+), 7 deletions(-) create mode 100644 .changeset/ev-fuse-budget-evidence.md create mode 100644 go/internal/control/ev_fuse_incident_test.go diff --git a/.changeset/ev-fuse-budget-evidence.md b/.changeset/ev-fuse-budget-evidence.md new file mode 100644 index 000000000..0407a0d07 --- /dev/null +++ b/.changeset/ev-fuse-budget-evidence.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Include bounded common/latest site, EV-credit, import and phase-limit evidence in debug logs for EV fuse-budget decisions, without changing charging limits. diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index 1008b0d84..bca60ca86 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -1,7 +1,9 @@ package control import ( + "context" "encoding/json" + "log/slog" "math" "sort" "time" @@ -24,6 +26,7 @@ func finiteFuseValue(w float64) bool { return !math.IsNaN(w) && !math.IsInf(w, 0 type evFuseBalance struct { gridW, poolW, pendingW float64 latestPoolW, latestPendingW float64 + siteAt time.Time } // EVFuseBudget refreshes the common EV cap before a charger command, also @@ -43,12 +46,29 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State // The common balance includes later observed DER increases. Keep the // newest site/phase read as an independent bound so the same increase is // not counted once in its grid watts and again as a pending command. - cap := evHeadroomW(state.effectiveImportCeilingW(fuseMaxW), balance.gridW+balance.pendingW, balance.poolW) - latestCap := evHeadroomW(state.phaseImportCeilingW(fuseMaxW, meter), meter.RawW+balance.latestPendingW, balance.latestPoolW) + commonCeiling := state.effectiveImportCeilingW(fuseMaxW) + latestCeiling := state.phaseImportCeilingW(fuseMaxW, meter) + cap := evHeadroomW(commonCeiling, balance.gridW+balance.pendingW, balance.poolW) + latestCap := evHeadroomW(latestCeiling, meter.RawW+balance.latestPendingW, balance.latestPoolW) + // Keep the arithmetic and guard order unchanged. Evidence belongs to this + // exact decision, rather than a later status snapshot with different polls. + phaseCap := latestCap + phaseKnown := false if phaseW, known := evPhaseIncreaseW(meter, state, configs, balance.latestPoolW); known { - latestCap = math.Min(latestCap, math.Max(0, balance.latestPoolW+phaseW-balance.latestPendingW)) - } - return math.Min(cap, latestCap), true + phaseKnown = true + phaseCap = math.Max(0, balance.latestPoolW+phaseW-balance.latestPendingW) + } + finalCap := math.Min(cap, math.Min(latestCap, phaseCap)) + if slog.Default().Enabled(context.Background(), slog.LevelDebug) { + slog.Debug("EV fuse budget evidence", + "common_site_at_ms", balance.siteAt.UnixMilli(), "latest_site_received_at_ms", meter.UpdatedAt.UnixMilli(), + "physical_fuse_w", fuseMaxW, "configured_import_ceiling_w", state.PeakImportCeilingW, + "common_ceiling_w", commonCeiling, "latest_ceiling_w", latestCeiling, + "common_grid_w", balance.gridW, "common_ev_credit_w", balance.poolW, "common_pending_battery_w", balance.pendingW, + "latest_grid_w", meter.RawW, "latest_ev_credit_w", balance.latestPoolW, "latest_pending_battery_w", balance.latestPendingW, + "common_cap_w", cap, "latest_site_cap_w", latestCap, "phase_bound_known", phaseKnown, "phase_cap_w", phaseCap, "final_cap_w", finalCap) + } + return finalCap, true } // A managed EV earns replacement credit only across a site observation that @@ -57,7 +77,7 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State // The existing bounded telemetry ring owns the samples; no second cache or // filtered load estimate participates in the hard limit. func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.DerReading, points []loadpoint.State, now time.Time) evFuseBalance { - balance := evFuseBalance{gridW: meter.RawW} + balance := evFuseBalance{gridW: meter.RawW, siteAt: meter.UpdatedAt} siteAt := meter.UpdatedAt from := now.Add(-telemetry.ControlWindowDuration) windows := store.ControlWindows(from, now) @@ -112,7 +132,7 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De balance.pendingW, coherent = pendingBatteryIncreaseAt(batteries, site.At) } if coherent { - balance.gridW, balance.poolW = site.PowerW, credit + balance.gridW, balance.poolW, balance.siteAt = site.PowerW, credit, site.At return balance } } diff --git a/go/internal/control/ev_fuse_incident_test.go b/go/internal/control/ev_fuse_incident_test.go new file mode 100644 index 000000000..c93f2e15c --- /dev/null +++ b/go/internal/control/ev_fuse_incident_test.go @@ -0,0 +1,73 @@ +package control + +import ( + "bytes" + "encoding/json" + "log/slog" + "math" + "testing" + "time" + + "github.com/srcfl/ftw/go/internal/loadpoint" + "github.com/srcfl/ftw/go/internal/telemetry" +) + +// This is a synthetic ambiguity reproducer inspired by issue #1674, not a +// replay of missing field-level control observations. A delayed EV start and +// a new household load can present the same latest site/EV readings. Until +// the physical flow is confirmed, neither can earn guessed replacement credit. +func TestImportCeilingStartSkewEvidence(t *testing.T) { + + store := telemetry.NewStore() + at := time.Now().Add(-10 * time.Second) + emit := func(driver string, kind telemetry.DerType, w float64, when time.Time, phases bool) { + data := map[string]any{"control_power_observed_at": when.Format(time.RFC3339Nano), "control_power_available": true} + if phases { + data["l1_a"], data["l2_a"], data["l3_a"] = 10.01, 11.19, 10.02 + } + b, _ := json.Marshal(data) + store.Update(driver, kind, w, nil, b) + store.RecordDriverSuccess(driver) + } + emit("car", telemetry.DerEV, 0, at, false) + emit("meter", telemetry.DerMeter, 900, at.Add(time.Second), true) + emit("meter", telemetry.DerMeter, 7100, at.Add(5*time.Second), true) + st := NewState(0, 0, "meter") + st.SiteFuseAmps, st.SiteFuseVoltage, st.SiteFusePhases = 25, 230, 3 + st.PeakImportCeilingW = 7500 + now := time.Now() + st.clock = func() time.Time { return now } + var log bytes.Buffer + old := slog.Default() + slog.SetDefault(slog.New(slog.NewJSONHandler(&log, &slog.HandlerOptions{Level: slog.LevelDebug}))) + defer slog.SetDefault(old) + capW, known := EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p"}}, 17250) + if !known || math.Abs(capW-400) > .001 { + t.Fatalf("unconfirmed EV cannot earn credit: cap=%v known=%v", capW, known) + } + var e map[string]any + if err := json.Unmarshal(log.Bytes(), &e); err != nil { + t.Fatal(err) + } + for key, want := range map[string]float64{"configured_import_ceiling_w": 7500, "physical_fuse_w": 17250, "latest_grid_w": 7100, "latest_ev_credit_w": 0, "latest_site_cap_w": 400, "final_cap_w": 400} { + if e[key] != want { + t.Fatalf("%s=%v want %v", key, e[key], want) + } + } + // The 400 W cap is below the field site's 4140 W minimum and thus + // explains why that possible observation sequence would stop charging. + if capW >= 4140 { + t.Fatal("incident minimum-step condition not reproduced") + } + + // Once actual EV power brackets a site observation, the same site reading + // earns replacement credit. Diagnostic logging must not alter that recovery. + emit("car", telemetry.DerEV, 6200, at.Add(6*time.Second), false) + emit("meter", telemetry.DerMeter, 7100, at.Add(7*time.Second), true) + emit("car", telemetry.DerEV, 6200, at.Add(8*time.Second), false) + now = time.Now() + capW, known = EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p"}}, 17250) + if !known || math.Abs(capW-6600) > .001 { + t.Fatalf("confirmed EV recovery changed: cap=%v known=%v", capW, known) + } +} From 83a49eea15433e8c317aed7448c44c3fed693863 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 00:24:18 +0200 Subject: [PATCH 02/16] diagnostics(control): retain blocked budget evidence in normal logs at most once a minute Signed-off-by: Segran --- .changeset/ev-fuse-budget-evidence.md | 2 +- go/internal/control/dispatch.go | 2 ++ go/internal/control/ev_fuse_budget.go | 14 +++++++++++--- go/internal/control/ev_fuse_incident_test.go | 12 +++++++++--- 4 files changed, 23 insertions(+), 7 deletions(-) diff --git a/.changeset/ev-fuse-budget-evidence.md b/.changeset/ev-fuse-budget-evidence.md index 0407a0d07..1b033f400 100644 --- a/.changeset/ev-fuse-budget-evidence.md +++ b/.changeset/ev-fuse-budget-evidence.md @@ -2,4 +2,4 @@ "ftw": patch --- -Include bounded common/latest site, EV-credit, import and phase-limit evidence in debug logs for EV fuse-budget decisions, without changing charging limits. +Report rate-limited common/latest site, EV-credit, import and phase-limit evidence when an EV fuse budget falls below the charging minimum, without changing charging limits. diff --git a/go/internal/control/dispatch.go b/go/internal/control/dispatch.go index 8d894f8f1..fc8694fa4 100644 --- a/go/internal/control/dispatch.go +++ b/go/internal/control/dispatch.go @@ -532,6 +532,8 @@ type State struct { // command so battery and EV cooperatively share the fuse budget. // Recomputed every dispatch tick. FuseEVMaxW float64 + // Caller holds the control lock; diagnostic output is limited to once per minute. + evFuseEvidenceAt time.Time // FuseSaturated signals that the joint allocator had to scale battery // and/or EV demand to fit under the fuse this tick. Used to gate the // loadpoint controller's read of FuseEVMaxW and as the trigger for diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index bca60ca86..1e02d4a47 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -1,7 +1,6 @@ package control import ( - "context" "encoding/json" "log/slog" "math" @@ -59,8 +58,17 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State phaseCap = math.Max(0, balance.latestPoolW+phaseW-balance.latestPendingW) } finalCap := math.Min(cap, math.Min(latestCap, phaseCap)) - if slog.Default().Enabled(context.Background(), slog.LevelDebug) { - slog.Debug("EV fuse budget evidence", + minimumW := 0.0 + for _, cfg := range configs { + for _, point := range points { + if point.PluggedIn && point.ID == cfg.ID && cfg.MinChargeW > 0 && (minimumW == 0 || cfg.MinChargeW < minimumW) { + minimumW = cfg.MinChargeW + } + } + } + if minimumW > 0 && finalCap < minimumW && (state.evFuseEvidenceAt.IsZero() || now.Before(state.evFuseEvidenceAt) || now.Sub(state.evFuseEvidenceAt) >= time.Minute) { + state.evFuseEvidenceAt = now + slog.Info("EV fuse budget below charging minimum", "minimum_charge_w", minimumW, "common_site_at_ms", balance.siteAt.UnixMilli(), "latest_site_received_at_ms", meter.UpdatedAt.UnixMilli(), "physical_fuse_w", fuseMaxW, "configured_import_ceiling_w", state.PeakImportCeilingW, "common_ceiling_w", commonCeiling, "latest_ceiling_w", latestCeiling, diff --git a/go/internal/control/ev_fuse_incident_test.go b/go/internal/control/ev_fuse_incident_test.go index c93f2e15c..51786633c 100644 --- a/go/internal/control/ev_fuse_incident_test.go +++ b/go/internal/control/ev_fuse_incident_test.go @@ -39,9 +39,9 @@ func TestImportCeilingStartSkewEvidence(t *testing.T) { st.clock = func() time.Time { return now } var log bytes.Buffer old := slog.Default() - slog.SetDefault(slog.New(slog.NewJSONHandler(&log, &slog.HandlerOptions{Level: slog.LevelDebug}))) + slog.SetDefault(slog.New(slog.NewJSONHandler(&log, &slog.HandlerOptions{Level: slog.LevelInfo}))) defer slog.SetDefault(old) - capW, known := EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p"}}, 17250) + capW, known := EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p", MinChargeW: 4140}}, 17250) if !known || math.Abs(capW-400) > .001 { t.Fatalf("unconfirmed EV cannot earn credit: cap=%v known=%v", capW, known) } @@ -60,13 +60,19 @@ func TestImportCeilingStartSkewEvidence(t *testing.T) { t.Fatal("incident minimum-step condition not reproduced") } + // Repeated blocked ticks must not flood the production log ring. + before := log.Len() + _, _ = EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p", MinChargeW: 4140}}, 17250) + if log.Len() != before { + t.Fatal("unchanged blocked verdict was logged again inside one minute") + } // Once actual EV power brackets a site observation, the same site reading // earns replacement credit. Diagnostic logging must not alter that recovery. emit("car", telemetry.DerEV, 6200, at.Add(6*time.Second), false) emit("meter", telemetry.DerMeter, 7100, at.Add(7*time.Second), true) emit("car", telemetry.DerEV, 6200, at.Add(8*time.Second), false) now = time.Now() - capW, known = EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p"}}, 17250) + capW, known = EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p", MinChargeW: 4140}}, 17250) if !known || math.Abs(capW-6600) > .001 { t.Fatalf("confirmed EV recovery changed: cap=%v known=%v", capW, known) } From e7b210defba37d4ba3b6992194142468d1fe9700 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 00:39:22 +0200 Subject: [PATCH 03/16] fix(ev): confirm resumed delivery and expose stalled limited charging Signed-off-by: Segran --- .changeset/ev-positive-offer-recovery.md | 5 ++ go/internal/api/api_clamped_no_draw_test.go | 40 +++++++++++ go/internal/api/api_control_feedback.go | 10 +++ go/internal/loadpoint/controller_resume.go | 17 ++++- .../controller_resume_confirm_test.go | 66 +++++++++++++++++++ .../loadpoint/manual_clamped_no_draw_test.go | 22 +++++++ go/internal/loadpoint/manual_status.go | 5 ++ web/app.js | 8 +-- web/control-feedback.js | 6 +- web/control-feedback.test.mjs | 10 +++ web/ev-commanded-reason.test.mjs | 4 +- web/ev-manual-feedback.test.mjs | 13 +++- 12 files changed, 195 insertions(+), 11 deletions(-) create mode 100644 .changeset/ev-positive-offer-recovery.md create mode 100644 go/internal/api/api_clamped_no_draw_test.go create mode 100644 go/internal/loadpoint/controller_resume_confirm_test.go create mode 100644 go/internal/loadpoint/manual_clamped_no_draw_test.go diff --git a/.changeset/ev-positive-offer-recovery.md b/.changeset/ev-positive-offer-recovery.md new file mode 100644 index 000000000..d057fbe67 --- /dev/null +++ b/.changeset/ev-positive-offer-recovery.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Report sustained zero EV power despite an accepted positive limited offer, distinguish site power limits from main-fuse overload, and retry acknowledged resumes after FTW's own zero offer at a bounded rate until measured charging or the retry limit. diff --git a/go/internal/api/api_clamped_no_draw_test.go b/go/internal/api/api_clamped_no_draw_test.go new file mode 100644 index 000000000..d1f8293bb --- /dev/null +++ b/go/internal/api/api_clamped_no_draw_test.go @@ -0,0 +1,40 @@ +package api + +import ( + "github.com/srcfl/ftw/go/internal/telemetry" + "testing" + "time" +) + +func TestPositiveEVClampDoesNotHideNoPowerResponse(t *testing.T) { + now := time.Now() + connected := true + for _, tc := range []struct { + name, core string + sent, actual float64 + fresh bool + age time.Duration + want string + }{ + {"accepted ten amp offer, reason 78", "fuse_limit", 6900, 0, true, 3 * time.Minute, "no_power_response"}, + {"intentional zero", "fuse_limit", 0, 0, true, 3 * time.Minute, "fuse_limit"}, + {"still in grace", "fuse_limit", 6900, 0, true, time.Minute, "fuse_limit"}, + {"charging at limited rate", "fuse_limit", 6900, 6800, true, 3 * time.Minute, "fuse_limit"}, + {"stale charger", "fuse_limit", 6900, 0, false, 3 * time.Minute, "telemetry_stale"}, + {"stale site", "site_meter_stale", 6900, 0, true, 3 * time.Minute, "site_meter_stale"}, + {"cooldown", "fuse_cooldown", 6900, 0, true, 3 * time.Minute, "fuse_cooldown"}, + } { + t.Run(tc.name, func(t *testing.T) { + f := ControlFeedback{Kind: "ev", RequestedA: watts(15), OfferedA: watts(10), SentW: watts(tc.sent), ActualW: watts(tc.actual), ObservedAtMs: now.UnixMilli(), DeviceReason: "limited by dynamic charger current"} + cmd := telemetry.CommandEvidence{Result: "accepted", Since: now.Add(-tc.age), PowerMismatchSince: now.Add(-tc.age)} + classifyControlFeedback(&f, cmd, true, tc.fresh, tc.core, &connected, now) + setControlStatus(&f) + if f.Reason != tc.want { + t.Fatalf("got %+v want %s", f, tc.want) + } + if tc.want == "no_power_response" && f.Status != "not_following" { + t.Fatalf("zero power must be visible: %+v", f) + } + }) + } +} diff --git a/go/internal/api/api_control_feedback.go b/go/internal/api/api_control_feedback.go index 73826f215..72086b4dd 100644 --- a/go/internal/api/api_control_feedback.go +++ b/go/internal/api/api_control_feedback.go @@ -415,6 +415,16 @@ func classifyControlFeedback(f *ControlFeedback, cmd telemetry.CommandEvidence, set("waiting", "not_connected", "info") return } + // A positive clamp explains the lower offer, not prolonged zero delivery. + // Keep known safety pauses and unconfirmed/stale commands authoritative. + if f.Kind == "ev" && commanded && cmd.Result == "accepted" && + coreReason != "site_meter_stale" && coreReason != "site_phase_currents_stale" && coreReason != "fuse_cooldown" && + f.SentW != nil && *f.SentW > 100 && f.ActualW != nil && math.Abs(*f.ActualW) < 100 && + f.OfferedA != nil && *f.OfferedA > 0 && !cmd.Since.IsZero() && now.Sub(cmd.Since) >= 2*time.Minute && + !cmd.PowerMismatchSince.IsZero() && now.Sub(cmd.PowerMismatchSince) >= 2*time.Minute && f.ObservedAtMs >= cmd.Since.UnixMilli() { + set("warning", "no_power_response", "warning") + return + } if f.RequestedA != nil && f.DeviceLimitA != nil && *f.RequestedA > *f.DeviceLimitA+0.5 { set("limited", "device_limit", "warning") return diff --git a/go/internal/loadpoint/controller_resume.go b/go/internal/loadpoint/controller_resume.go index 49017b2eb..408fe0907 100644 --- a/go/internal/loadpoint/controller_resume.go +++ b/go/internal/loadpoint/controller_resume.go @@ -11,6 +11,7 @@ type resumeOffer struct { generation uint64 nextAttempt time.Time retryDelay time.Duration + acknowledgedAttempts int } // resumeAfterZeroOffer remembers our standdown independently of commanded W. @@ -37,6 +38,14 @@ func (c *Controller) resumeAfterZeroOffer(ctx context.Context, cfg Config, sampl if !exists || now.Before(previous.nextAttempt) { return } + if previous.acknowledgedAttempts >= 3 { + if previous.acknowledgedAttempts == 3 { + slog.Warn("loadpoint resume acknowledged but no charge observed", "lp", cfg.ID, "driver", cfg.DriverName) + previous.acknowledgedAttempts++ + c.resumeOffers[cfg.ID] = previous + } + return + } if err := c.sendDispatchWithDeadline(ctx, cfg.DriverName, []byte(`{"action":"ev_resume"}`)); err != nil { previous.retryDelay = min(time.Minute, max(5*time.Second, 2*previous.retryDelay)) previous.nextAttempt = now.Add(previous.retryDelay) @@ -45,5 +54,11 @@ func (c *Controller) resumeAfterZeroOffer(ctx context.Context, cfg Config, sampl "retry_at", previous.nextAttempt, "err", err) return } - delete(c.resumeOffers, cfg.ID) + // An HTTP acknowledgement does not establish that the contactor closed. + // Retry at a bounded rate, under the current dispatch gates, and stop after + // three acknowledged attempts. Only observed delivery clears the proof. + previous.acknowledgedAttempts++ + previous.nextAttempt = now.Add(30 * time.Second) + previous.retryDelay = 0 + c.resumeOffers[cfg.ID] = previous } diff --git a/go/internal/loadpoint/controller_resume_confirm_test.go b/go/internal/loadpoint/controller_resume_confirm_test.go new file mode 100644 index 000000000..31520c8d4 --- /dev/null +++ b/go/internal/loadpoint/controller_resume_confirm_test.go @@ -0,0 +1,66 @@ +package loadpoint + +import ( + "context" + "testing" + "time" +) + +func TestResumeAcknowledgementWaitsForMeasuredCharge(t *testing.T) { + now := time.Date(2026, 10, 17, 0, 0, 0, 0, time.UTC) + sender := &fakeSender{} + cfg := Config{ID: "garage", DriverName: "easee", MinChargeW: 4140, MaxChargeW: 11000, AllowedStepsW: []float64{0, 4140, 6900, 11000}} + samples := map[string]EVSample{"easee": {Connected: true, RequestActive: true, DeviceID: "box", SessionID: "plug-1", ConnectionGeneration: 1}} + dir := &Directive{SlotStart: now, SlotEnd: now.Add(time.Hour), LoadpointEnergyWh: map[string]float64{"garage": 0}} + c := newTestController(t, []Config{cfg}, dir, samples, sender) + c.Tick(context.Background(), now) + dir.LoadpointEnergyWh["garage"] = 11000 + for _, seconds := range []int{5, 10, 35, 65, 95, 125} { + c.Tick(context.Background(), now.Add(time.Duration(seconds)*time.Second)) + } + if n := countAction(sender.calls, "ev_resume"); n != 3 { + t.Fatalf("need bounded retries until delivery, got %d resumes: %+v", n, sender.calls) + } + sample := samples["easee"] + sample.PowerW = 6900 + samples["easee"] = sample + c.Tick(context.Background(), now.Add(130*time.Second)) + sample.PowerW = 0 + samples["easee"] = sample + c.Tick(context.Background(), now.Add(160*time.Second)) + if n := countAction(sender.calls, "ev_resume"); n != 3 { + t.Fatalf("measured delivery must clear resume proof, got %d", n) + } +} + +func TestAcknowledgedResumeRetryRespectsSessionAndStops(t *testing.T) { + for _, stop := range []string{"session", "safety", "plan_pause"} { + t.Run(stop, func(t *testing.T) { + now := time.Date(2026, 10, 17, 0, 0, 0, 0, time.UTC) + sender := &fakeSender{} + cfg := Config{ID: "garage", DriverName: "easee", MinChargeW: 4140, MaxChargeW: 11000} + samples := map[string]EVSample{"easee": {Connected: true, RequestActive: true, DeviceID: "box", SessionID: "one", ConnectionGeneration: 1}} + dir := &Directive{SlotStart: now, SlotEnd: now.Add(time.Hour), LoadpointEnergyWh: map[string]float64{"garage": 0}} + c := newTestController(t, []Config{cfg}, dir, samples, sender) + c.Tick(context.Background(), now) + dir.LoadpointEnergyWh["garage"] = 11000 + c.Tick(context.Background(), now.Add(5*time.Second)) + if countAction(sender.calls, "ev_resume") != 1 { + t.Fatal(sender.calls) + } + switch stop { + case "session": + sample := samples["easee"] + sample.SessionID = "two" + sample.ConnectionGeneration = 2 + samples["easee"] = sample + case "plan_pause": + dir.LoadpointEnergyWh["garage"] = 0 + } + c.TickWithDispatch(context.Background(), now.Add(35*time.Second), stop != "safety") + if countAction(sender.calls, "ev_resume") != 1 { + t.Fatalf("retry crossed %s: %+v", stop, sender.calls) + } + }) + } +} diff --git a/go/internal/loadpoint/manual_clamped_no_draw_test.go b/go/internal/loadpoint/manual_clamped_no_draw_test.go new file mode 100644 index 000000000..6fb6af3d2 --- /dev/null +++ b/go/internal/loadpoint/manual_clamped_no_draw_test.go @@ -0,0 +1,22 @@ +package loadpoint + +import ( + "testing" + "time" +) + +func TestPositiveClampDoesNotHideAcceptedZeroDraw(t *testing.T) { + at := time.Date(2026, 10, 17, 0, 12, 0, 0, time.UTC) + h := ManualHold{PowerW: 10350, StartedAt: at} + st := State{Phases: 3, VoltageV: 230, CommandedKnown: true, CommandedW: 6900, CommandedReason: "fuse_limit", CommandedSinceMs: at.UnixMilli()} + ch := ChargerReading{Known: true, UpdatedAt: at.Add(8 * time.Minute), LimitKnown: true, LimitA: 10, Reason: "limited by dynamic charger current"} + m := ManualStatusFrom(h, true, st, ch, at.Add(8*time.Minute)) + if m.State != ManualNotDrawing || m.CommandedA != 10 || m.RequestedA != 15 || m.LimitReason != "fuse_limit" { + t.Fatalf("positive clamp masks zero delivery: %+v", m) + } + st.CommandedW = 0 + ch.LimitA = 0 + if m := ManualStatusFrom(h, true, st, ch, at.Add(8*time.Minute)); m.State != ManualLimited { + t.Fatalf("intentional zero must remain limited: %+v", m) + } +} diff --git a/go/internal/loadpoint/manual_status.go b/go/internal/loadpoint/manual_status.go index 6b47121a2..c1654b2ad 100644 --- a/go/internal/loadpoint/manual_status.go +++ b/go/internal/loadpoint/manual_status.go @@ -186,6 +186,9 @@ func ManualStatusFrom(h ManualHold, held bool, st State, ch ChargerReading, now return m } + if clamp { + m.LimitReason = st.CommandedReason + } limitMatches := m.ChargerLimitKnown && m.CommandedA >= 0 && math.Abs(ch.LimitA-m.CommandedA) < 1 switch { case ch.Unavailable || st.PowerUnavailable: @@ -205,6 +208,8 @@ func ManualStatusFrom(h ManualHold, held bool, st State, ch ChargerReading, now if clamp { m.LimitReason = st.CommandedReason } + case limitMatches && m.CommandedW >= manualChargingFloorW && elapsed >= manualAcceptGrace: + m.State = ManualNotDrawing case clamp: m.State = ManualLimited m.LimitReason = st.CommandedReason diff --git a/web/app.js b/web/app.js index 589250457..89b408346 100644 --- a/web/app.js +++ b/web/app.js @@ -2866,12 +2866,12 @@ case "limited": if (m.limit_reason === "charger_limit") return "The charger limits this request to " + cmdA + " (" + reqA + " requested)."; if (m.limit_reason === "fuse_cooldown") { - return "Paused: main-fuse protection — " + reqA + " requested; charging resumes on its own." + sinceP; + return "Paused by site power limits — " + reqA + " requested; charging resumes on its own." + sinceP; } if (m.limit_reason === "site_meter_stale") { return "Paused for safety: site-meter data is stale — " + reqA + " requested; charging resumes when telemetry recovers."; } - return "Main fuse limits this charge to " + cmdA + " right now (" + reqA + " requested)." + sinceP; + return "Site power limits cap this charge at " + cmdA + " right now (" + reqA + " requested)." + sinceP; } return "FTW received " + reqA + ". Waiting for charger status." + end; } @@ -2919,7 +2919,7 @@ ? "Charging on plan until " + evFmtClock(lp.plan_next_end_ms) + "." + kwPlanned : "Charging."; if (lp.commanded_reason === "fuse_limit") { - text += " Rate is limited by the main fuse right now."; + text += " Rate is limited by site power limits right now."; } } else if (lp.goal_complete === true) { text = "The car confirmed this charging goal is complete."; @@ -2944,7 +2944,7 @@ // The specific pauses beat the generic branches — this is the // line that stops an operator debugging cable and charger while // the box is protecting the main fuse (#1009). - text = "Paused: main-fuse protection — the house is using the headroom; charging resumes on its own." + kwPlanned; + text = "Paused by site power limits — the house is using the headroom; charging resumes on its own." + kwPlanned; tone = "var(--text)"; } else if (lp.commanded_known && !lp.commanded_w && lp.commanded_reason === "site_meter_stale") { text = "Paused for safety: site-meter data is stale — charging resumes when telemetry recovers."; diff --git a/web/control-feedback.js b/web/control-feedback.js index 95fda5faa..18a184e63 100644 --- a/web/control-feedback.js +++ b/web/control-feedback.js @@ -63,7 +63,7 @@ const REASON_TITLES = { no_plan_budget: 'Waiting for the plan', pv_surplus_pause: 'Waiting for spare solar', wake_kick: 'Starting the charger', vehicle_complete: 'Car is full', vehicle_limit_completion: 'Car reached its limit', vehicle_not_requesting: 'Car not taking power', battery_full: 'Battery full', battery_nearly_full: 'Battery nearly full', battery_nearly_empty: 'Battery nearly empty', - core_limit: 'Limited by FTW', fuse_limit: 'Limited by the main fuse', fuse_cooldown: 'Waiting after a fuse limit', + core_limit: 'Limited by FTW', fuse_limit: 'Limited by site power limits', fuse_cooldown: 'Waiting after a site power limit', charger_limit: 'Limited by FTW’s charger setting', device_limit: 'Charger limit', offered_current_lower: 'Charger offers less current', device_fault: 'Device fault', telemetry_stale: 'No fresh readings', readings_lost: 'Lost control', command_failed: 'Commands failing', command_unconfirmed: 'Command not confirmed', default_failed: 'Cannot hand back control', @@ -92,8 +92,8 @@ function sentence(row) { case 'battery_nearly_full': return `Taking ${controlPower(actual)} of ${controlPower(row.sent_w)} at ${percent(row.battery_soc)}. A battery charges slower when it is nearly full.`; case 'battery_nearly_empty': return `Giving ${controlPower(actual)} of ${controlPower(row.sent_w)} at ${percent(row.battery_soc)}. A battery limits discharge when it is nearly empty.`; case 'core_limit': return `FTW’s safety limits set the target to ${target(row)}.`; - case 'fuse_limit': return `FTW lowered the rate to ${target(row)} to protect the main fuse. It rises when the house uses less.`; - case 'fuse_cooldown': return 'FTW waits a moment after a fuse limit before it raises the rate.'; + case 'fuse_limit': return `FTW lowered the rate to ${target(row)} to stay within the site’s fuse and import limits.`; + case 'fuse_cooldown': return 'FTW waits a moment after a site power limit before it raises the rate.'; case 'charger_limit': return 'The charger limit in FTW’s settings caps the rate.'; case 'device_limit': return `The charger’s own limit is ${amps(row.device_limit_a)}, below the ${amps(row.requested_a)} FTW asked for.`; case 'offered_current_lower': return `The charger offers ${amps(row.offered_a)}, below the ${amps(row.requested_a)} FTW asked for.`; diff --git a/web/control-feedback.test.mjs b/web/control-feedback.test.mjs index 00654f005..bdef3a5ea 100644 --- a/web/control-feedback.test.mjs +++ b/web/control-feedback.test.mjs @@ -140,3 +140,13 @@ test('the summary answers the question for the whole site', () => { assert.equal(controlSummary([row({status: 'not_controlled', reason: 'observe_only'})]).tone, 'neutral'); assert.equal(controlSummary([row()], false).tone, 'stale'); }); + + +test('limited positive EV offer does not explain prolonged zero delivery', () => { + const missing=controlStatus(row({kind:'ev',status:'not_following',reason:'no_power_response',severity:'warning',requested_w:10350,sent_w:6900,actual_w:0,requested_a:15,offered_a:10,device_reason:'limited by dynamic charger current'})); + assert.equal(missing.title,'Not following'); + assert.match(missing.text,/6.9 kW charge.*no power/); + const capped=controlStatus(row({kind:'ev',status:'limited',reason:'fuse_limit',sent_w:6900,actual_w:6800})); + assert.equal(capped.title,'Limited by site power limits'); + assert.match(capped.text,/fuse and import limits/); +}); diff --git a/web/ev-commanded-reason.test.mjs b/web/ev-commanded-reason.test.mjs index 017440d88..745ec3bc5 100644 --- a/web/ev-commanded-reason.test.mjs +++ b/web/ev-commanded-reason.test.mjs @@ -9,7 +9,7 @@ const source = readFileSync(new URL('./app.js', import.meta.url), 'utf8'); test('every pause reason has its own sentence', () => { assert.match(source, /commanded_reason === "fuse_cooldown" \|\| lp\.commanded_reason === "fuse_limit"/); - assert.match(source, /Paused: main-fuse protection/); + assert.match(source, /Paused by site power limits/); assert.match(source, /commanded_reason === "site_meter_stale"/); assert.match(source, /Paused for safety: site-meter data is stale/); assert.match(source, /commanded_reason === "pv_surplus_pause"/); @@ -20,5 +20,5 @@ test('every pause reason has its own sentence', () => { assert.match(source, /The ready time has passed, so FTW is not charging/); assert.match(source, /Battery level is assumed, not read from the car/); // A fuse-limited ongoing charge says so too. - assert.match(source, /Rate is limited by the main fuse right now/); + assert.match(source, /Rate is limited by site power limits right now/); }); diff --git a/web/ev-manual-feedback.test.mjs b/web/ev-manual-feedback.test.mjs index 4076398db..96aba8e1f 100644 --- a/web/ev-manual-feedback.test.mjs +++ b/web/ev-manual-feedback.test.mjs @@ -25,7 +25,7 @@ test('the status line follows the charger through every state', () => { assert.match(statusText, /Waiting for the car to start drawing/); assert.match(statusText, /but the car is not drawing/); assert.match(statusText, /The charger has not acted on/); - assert.match(statusText, /Main fuse limits this charge/); + assert.match(statusText, /Site power limits cap this charge/); // The charger's own words are part of the sentence. assert.match(statusText, /Charger reports: " \+ m\.charger_reason/); // Elapsed time comes from the box's since_ms, not from click time. @@ -139,3 +139,14 @@ test('pending manual save is distinct from an actual write failure', () => { assert.doesNotMatch(render({ ...paused, manual_save_pending: false }).textContent, /Saving it/); assert.match(render({ ...paused, manual_save_error: true }).textContent, /could not be saved/); }); + + +test('ten amp positive clamp remains distinct from zero delivery with reason 78', () => { + const manual = {active:true,state:'not_drawing',requested_a:15,commanded_a:10,limit_reason:'fuse_limit',charger_reason:'limited by dynamic charger current'}; + const words = describeManual({manual_active:true,current_power_w:0,manual}); + assert.match(words,/Charger offers 10 A but the car is not drawing/); + assert.match(words,/limited by dynamic charger current/); + assert.doesNotMatch(words,/Main fuse|charging resumes on its own/); + const limited=describeManual({manual_active:true,current_power_w:0,manual:{...manual,state:'limited'}}); + assert.match(limited,/Site power limits cap this charge at 10 A/); +}); From 815e3053be49dcce65ccfb12d18839d02890f247 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 01:42:32 +0200 Subject: [PATCH 04/16] fix(control): align common EV budget with historical site observations Signed-off-by: Segran --- .changeset/ev-common-balance-alignment.md | 5 ++ go/internal/control/ev_fuse_alignment_test.go | 83 +++++++++++++++++++ go/internal/control/ev_fuse_budget.go | 33 ++++++-- 3 files changed, 116 insertions(+), 5 deletions(-) create mode 100644 .changeset/ev-common-balance-alignment.md create mode 100644 go/internal/control/ev_fuse_alignment_test.go diff --git a/.changeset/ev-common-balance-alignment.md b/.changeset/ev-common-balance-alignment.md new file mode 100644 index 000000000..8f597ecd7 --- /dev/null +++ b/.changeset/ev-common-balance-alignment.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Avoid false EV stops when the common balance revisits an older site observation after an observed EV stop/restart, and avoid a full battery discharge fallback when a fresh battery observation already precedes the latest site reading. Keep independent latest-site, phase, pending-order and unknown-history bounds. diff --git a/go/internal/control/ev_fuse_alignment_test.go b/go/internal/control/ev_fuse_alignment_test.go new file mode 100644 index 000000000..ac7945d7f --- /dev/null +++ b/go/internal/control/ev_fuse_alignment_test.go @@ -0,0 +1,83 @@ +package control + +import ( + "encoding/json" + "github.com/srcfl/ftw/go/internal/loadpoint" + "github.com/srcfl/ftw/go/internal/telemetry" + "math" + "testing" + "time" +) + +func TestEVFuseAlignment(t *testing.T) { + for _, tc := range []struct { + name string + restart, grid, want float64 + }{ + {"restart does not rewrite old balance", 7527, 7154, 7230}, + {"new household load still stops", 7527, 12000, 3027}, + {"latest low EV still stops", 286, 7154, 632}, + } { + t.Run(tc.name, func(t *testing.T) { + now := time.Now() + store := telemetry.NewStore() + emit := func(driver string, kind telemetry.DerType, ago time.Duration, w float64) { + d := map[string]any{"control_power_observed_at": now.Add(-ago).Format(time.RFC3339Nano)} + if kind == telemetry.DerMeter { + d["l1_a"], d["l2_a"], d["l3_a"] = 10.0, 11.2, 10.0 + } + b, _ := json.Marshal(d) + store.Update(driver, kind, w, nil, b) + store.RecordDriverSuccess(driver) + } + emit("battery", telemetry.DerBattery, 7*time.Second, -1000) + emit("car", telemetry.DerEV, 7*time.Second, 6836) + emit("meter", telemetry.DerMeter, 6*time.Second, 7106) + emit("car", telemetry.DerEV, 5*time.Second, 6836) + emit("car", telemetry.DerEV, 4*time.Second, 286) + emit("battery", telemetry.DerBattery, 3*time.Second, -1000) + emit("car", telemetry.DerEV, 2*time.Second, tc.restart) + emit("meter", telemetry.DerMeter, time.Second, tc.grid) + st := NewState(0, 0, "meter") + st.SiteFuseAmps, st.SiteFuseVoltage, st.SiteFusePhases = 25, 230, 3 + st.PeakImportCeilingW = 7500 + st.DriverLimits = map[string]PowerLimits{"battery": {MaxChargeW: 10000, MaxDischargeW: 10000}} + got, _ := EVFuseBudget(store, st, []loadpoint.State{{ID: "car", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "car", DriverName: "car", PhaseMode: "3p"}}, 17250) + if math.Abs(got-tc.want) > .01 { + t.Fatalf("cap=%v want=%v", got, tc.want) + } + }) + } +} + +func TestEVFuseLatestFallbackUsesSameBatteryBaseline(t *testing.T) { + now := time.Now() + store := telemetry.NewStore() + for _, p := range []struct { + driver string + kind telemetry.DerType + ago time.Duration + w float64 + }{ + {"battery", telemetry.DerBattery, 2 * time.Millisecond, -990.37234241847}, + {"meter", telemetry.DerMeter, time.Millisecond, 6.832}, + } { + d, _ := json.Marshal(map[string]any{"control_power_observed_at": now.Add(-p.ago).Format(time.RFC3339Nano)}) + store.Update(p.driver, p.kind, p.w, nil, d) + store.RecordDriverSuccess(p.driver) + } + st := NewState(0, 0, "meter") + st.PeakImportCeilingW = 7500 + st.DriverLimits = map[string]PowerLimits{"battery": {MaxChargeW: 10000, MaxDischargeW: 10000}} + got, _ := EVFuseBudget(store, st, nil, nil, 17250) + if math.Abs(got-7493.168) > .01 { + t.Fatalf("cap=%v want7493.168", got) + } + // A pending zero order can remove the observed discharge. Even with + // the preceding fresh measurement, that loss must still be reserved. + pendingEVOrder(store, 0, now.Add(-3*time.Millisecond), "accepted") + got, _ = EVFuseBudget(store, st, nil, nil, 17250) + if math.Abs(got-(7493.168-990.37234241847)) > .01 { + t.Fatalf("pending discharge release lost: cap=%v", got) + } +} diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index 1e02d4a47..fab918bbb 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -49,8 +49,8 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State latestCeiling := state.phaseImportCeilingW(fuseMaxW, meter) cap := evHeadroomW(commonCeiling, balance.gridW+balance.pendingW, balance.poolW) latestCap := evHeadroomW(latestCeiling, meter.RawW+balance.latestPendingW, balance.latestPoolW) - // Keep the arithmetic and guard order unchanged. Evidence belongs to this - // exact decision, rather than a later status snapshot with different polls. + // Keep the newest site and phase bounds authoritative even when the + // common historical balance has more replacement credit. phaseCap := latestCap phaseKnown := false if phaseW, known := evPhaseIncreaseW(meter, state, configs, balance.latestPoolW); known { @@ -129,7 +129,7 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De } credit, coherent := 0.0, true for _, ev := range series { - w, ok := bracketedEVPower(ev.points, site.At, ev.latest) + w, ok := bracketedEVPowerAt(ev.points, site.At, ev.latest) if !ok { coherent = false break @@ -144,7 +144,19 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De return balance } } - balance.pendingW, _ = pendingBatteryIncreaseAt(batteries, siteAt) + // No common bracket exists. A battery already observed before this + // latest site read uses the same baseline as the latest-site guard. + // A first battery observation AFTER the site read cannot establish how + // much earlier discharge the meter contains: retain its full fallback. + balance.pendingW = 0 + for _, battery := range batteries { + if battery.fresh && !battery.current.Seen().After(siteAt) { + balance.pendingW += math.Max(0, battery.upperW-battery.current.PowerW) + } else { + reserve, _ := pendingBatteryIncreaseAt([]pendingBatterySeries{battery}, siteAt) + balance.pendingW += reserve + } + } return balance } @@ -156,7 +168,10 @@ func qualifiedFuseObservation(r *telemetry.DerReading, now time.Time) (telemetry return p, ok && !p.Seen().After(now) && now.Sub(p.Seen()) <= telemetry.ControlWindowDuration } -func bracketedEVPower(points []telemetry.ControlObservation, at time.Time, latest float64) (float64, bool) { +// bracketedEVPowerAt evaluates the historical site instant. Later EV +// stops are handled by the separate latest-site/phase bounds, not by +// retroactively subtracting them from this older grid observation. +func bracketedEVPowerAt(points []telemetry.ControlObservation, at time.Time, latest float64) (float64, bool) { var before, after telemetry.ControlObservation hasBefore, hasAfter := false, false for _, p := range points { @@ -174,6 +189,14 @@ func bracketedEVPower(points []telemetry.ControlObservation, at time.Time, lates return 0, false } baseline := math.Max(0, math.Min(latest, math.Min(before.PowerW, after.PowerW))) + return baseline, true +} + +func bracketedEVPower(points []telemetry.ControlObservation, at time.Time, latest float64) (float64, bool) { + baseline, known := bracketedEVPowerAt(points, at, latest) + if !known { + return 0, false + } // Another slow device may force an older common site observation. A // later observed stop still removes its replacement credit, even if // the charger has since started again. From b05957c2cc3d99989b5025f73e2ea651f2ccb281 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 01:56:23 +0200 Subject: [PATCH 05/16] test(app): wait for published plan revision after plug-in Signed-off-by: Segran --- go/cmd/ftw/app_link_plan_push_test.go | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/go/cmd/ftw/app_link_plan_push_test.go b/go/cmd/ftw/app_link_plan_push_test.go index ee1748271..8527ce567 100644 --- a/go/cmd/ftw/app_link_plan_push_test.go +++ b/go/cmd/ftw/app_link_plan_push_test.go @@ -107,8 +107,12 @@ func TestAPlugInReachesAStreamingPhoneAsAPlan(t *testing.T) { mgr.Observe("easee", true, 0, 0, true) cable := owner.waitPlan(t, func(p appproto.Plan) bool { return len(p.Chargers) == 1 && p.Chargers[0].PluggedIn }) tookCable := time.Since(plugged) + // A push reads plan revision and charger windows separately. A solve + // finishing between those reads can expose the new windows with the + // preceding revision. Wait for the published revision as well as the + // windows; the delivery deadline below still applies to that full result. got := owner.waitPlan(t, func(p appproto.Plan) bool { - return len(p.Chargers) == 1 && p.Chargers[0].PluggedIn && !p.Chargers[0].Pending && len(p.Chargers[0].Windows) > 0 + return p.Rev > first.Rev && len(p.Chargers) == 1 && p.Chargers[0].PluggedIn && !p.Chargers[0].Pending && len(p.Chargers[0].Windows) > 0 }) took := time.Since(plugged) t.Logf("plug-in to the cable on a phone: %v (pending %v); to the plan: %v, %d windows, %d Wh", From 1fe1195b9f15ca9bb0f1827c9b0033c4c5ef94a9 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 02:04:10 +0200 Subject: [PATCH 06/16] fix(control): retain qualified EV credit in latest-site fallback Signed-off-by: Segran --- .changeset/ev-latest-fallback-credit.md | 5 ++ go/internal/control/ev_fuse_budget.go | 14 +++- go/internal/control/ev_fuse_fallback_test.go | 67 ++++++++++++++++++++ 3 files changed, 84 insertions(+), 2 deletions(-) create mode 100644 .changeset/ev-latest-fallback-credit.md create mode 100644 go/internal/control/ev_fuse_fallback_test.go diff --git a/.changeset/ev-latest-fallback-credit.md b/.changeset/ev-latest-fallback-credit.md new file mode 100644 index 000000000..d33d1cff4 --- /dev/null +++ b/.changeset/ev-latest-fallback-credit.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Keep qualified latest-site EV replacement credit when a common bracket is unavailable, and avoid retaining an obsolete older grid demand when no positive EV remains to align. Latest-site, phase, missing-measurement and pending-battery bounds still apply. diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index fab918bbb..763aa9636 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -127,6 +127,12 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De if site.At.Before(from) || site.At.After(now) || !finiteFuseValue(site.PowerW) { continue } + // Without a positive managed EV observation, an older high site + // sample has no replacement credit to align. Use the latest site + // fallback instead of retaining demand from a completed EV stop. + if len(series) == 0 && !site.At.Equal(siteAt) { + continue + } credit, coherent := 0.0, true for _, ev := range series { w, ok := bracketedEVPowerAt(ev.points, site.At, ev.latest) @@ -144,8 +150,12 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De return balance } } - // No common bracket exists. A battery already observed before this - // latest site read uses the same baseline as the latest-site guard. + // No common bracket exists. Keep the EV credit already qualified at + // this latest site instant; dropping it here would count the same EV + // as household demand in a second bound on the very same site reading. + balance.poolW = balance.latestPoolW + // A battery already observed before this latest site read uses the + // same baseline as the latest-site guard. // A first battery observation AFTER the site read cannot establish how // much earlier discharge the meter contains: retain its full fallback. balance.pendingW = 0 diff --git a/go/internal/control/ev_fuse_fallback_test.go b/go/internal/control/ev_fuse_fallback_test.go new file mode 100644 index 000000000..8ba46e741 --- /dev/null +++ b/go/internal/control/ev_fuse_fallback_test.go @@ -0,0 +1,67 @@ +package control + +import ( + "encoding/json" + "math" + "testing" + "time" + + "github.com/srcfl/ftw/go/internal/loadpoint" + "github.com/srcfl/ftw/go/internal/telemetry" +) + +func TestEVFuseFallbackKeepsLatestEVProof(t *testing.T) { + for _, tc := range []struct { + name string + ev, grid, want float64 + oldSite, evAfter, offline bool + phase float64 + }{ + {name: "01:55 preceding EV without common bracket", ev: 6820, grid: 6587, want: 7733}, + {name: "real household increase", ev: 6820, grid: 12000, want: 2320}, + {name: "later EV cannot fund earlier site", ev: 6820, grid: 6587, want: 913, evAfter: true}, + {name: "missing EV earns no credit", ev: 6820, grid: 6587, want: 913, offline: true}, + {name: "01:58 stopped EV does not retain older high grid", ev: 0, grid: -99.39, want: 7599.39, oldSite: true}, + {name: "phase limit remains authoritative", ev: 6820, grid: 6587, want: 6130, phase: 25}, + } { + t.Run(tc.name, func(t *testing.T) { + now := time.Now() + store := telemetry.NewStore() + emit := func(driver string, kind telemetry.DerType, ago time.Duration, w float64) { + d := map[string]any{"control_power_observed_at": now.Add(-ago).Format(time.RFC3339Nano)} + if kind == telemetry.DerMeter { + a := tc.phase + if a == 0 { + a = 10 + } + d["l1_a"], d["l2_a"], d["l3_a"] = a, a, a + } + b, _ := json.Marshal(d) + store.Update(driver, kind, w, nil, b) + store.RecordDriverSuccess(driver) + } + emit("battery", telemetry.DerBattery, 5*time.Second, -1000) + if tc.oldSite { + emit("meter", telemetry.DerMeter, 4*time.Second, 6640) + } + emit("battery", telemetry.DerBattery, 3*time.Second, -1000) + age := 2 * time.Second + if tc.evAfter { + age = 500 * time.Millisecond + } + emit("car", telemetry.DerEV, age, tc.ev) + emit("meter", telemetry.DerMeter, time.Second, tc.grid) + if tc.offline { + store.Remove("car") + } + st := NewState(0, 0, "meter") + st.SiteFuseAmps, st.SiteFuseVoltage, st.SiteFusePhases = 25, 230, 3 + st.PeakImportCeilingW = 7500 + st.DriverLimits = map[string]PowerLimits{"battery": {MaxChargeW: 10000, MaxDischargeW: 10000}} + got, _ := EVFuseBudget(store, st, []loadpoint.State{{ID: "car", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "car", DriverName: "car", PhaseMode: "3p"}}, 17250) + if math.Abs(got-tc.want) > .01 { + t.Fatalf("cap=%v want=%v", got, tc.want) + } + }) + } +} From 8a02c0ab6849b99417f0a71a5c1974bc7ac2c07f Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 02:58:26 +0200 Subject: [PATCH 07/16] fix(ev): retain confirmed power anchors and require sustained recovery Signed-off-by: Segran --- .changeset/ev-confirmed-power-and-resume.md | 5 + go/internal/control/ev_battery_headroom.go | 2 +- .../control/ev_confirmed_transition_test.go | 48 +++++++++ go/internal/control/ev_fuse_budget.go | 2 +- go/internal/loadpoint/controller_resume.go | 46 ++++++-- .../controller_resume_after_zero_test.go | 9 +- .../controller_resume_confirm_test.go | 9 +- .../controller_resume_delivery_test.go | 62 +++++++++++ .../control_confirmed_anchor_test.go | 101 ++++++++++++++++++ go/internal/telemetry/control_observations.go | 49 ++++++++- 10 files changed, 319 insertions(+), 14 deletions(-) create mode 100644 .changeset/ev-confirmed-power-and-resume.md create mode 100644 go/internal/control/ev_confirmed_transition_test.go create mode 100644 go/internal/loadpoint/controller_resume_delivery_test.go create mode 100644 go/internal/telemetry/control_confirmed_anchor_test.go diff --git a/.changeset/ev-confirmed-power-and-resume.md b/.changeset/ev-confirmed-power-and-resume.md new file mode 100644 index 000000000..2a7d87e3f --- /dev/null +++ b/.changeset/ev-confirmed-power-and-resume.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Retain fresh confirmations of change-only power samples in the bounded control buffer without changing source times or counting repeated confirmations as new physical samples. Require ten seconds of fresh, meaningful charging before ending EV resume tracking, so small startup pulses cannot cancel recovery. diff --git a/go/internal/control/ev_battery_headroom.go b/go/internal/control/ev_battery_headroom.go index 209873f17..584d0d2f4 100644 --- a/go/internal/control/ev_battery_headroom.go +++ b/go/internal/control/ev_battery_headroom.go @@ -25,7 +25,7 @@ func clampEVBatteryHeadroom(targets []DispatchTarget, store *telemetry.Store, st return targets } now := state.now() - windows := store.ControlWindows(now.Add(-telemetry.ControlWindowDuration), now) + windows := store.ConfirmedControlWindows(now.Add(-telemetry.ControlWindowDuration), now) need := make(map[string]float64, len(state.evFuseDemands)) phaseMode := make(map[string]string, len(state.evFuseDemands)) for _, demand := range state.evFuseDemands { diff --git a/go/internal/control/ev_confirmed_transition_test.go b/go/internal/control/ev_confirmed_transition_test.go new file mode 100644 index 000000000..e39463e67 --- /dev/null +++ b/go/internal/control/ev_confirmed_transition_test.go @@ -0,0 +1,48 @@ +package control + +import ( + "encoding/json" + "github.com/srcfl/ftw/go/internal/loadpoint" + "github.com/srcfl/ftw/go/internal/telemetry" + "math" + "testing" + "time" +) + +func TestEVFuseConfirmedSteadyPowerSurvivesRateChange(t *testing.T) { + for _, tc := range []struct { + name string + before, grid, want float64 + missing, stopped bool + }{ + {"known charging then rate decrease", 6183, 7019, 5238, false, false}, + {"new household load still limits", 6183, 10000, 2257, false, false}, + {"new start earns no guessed credit", 0, 7019, 481, false, false}, + {"missing observation revokes old credit", 6183, 7019, 481, true, false}, + {"observed stop before restart retains zero credit", 6183, 7019, 481, false, true}, + } { + t.Run(tc.name, func(t *testing.T) { + store := telemetry.NewStore() + emit := func(driver string, kind telemetry.DerType, w float64, at time.Time, confirmed bool) { + d, _ := json.Marshal(map[string]any{"control_power_observed_at": at.Format(time.RFC3339Nano), "control_power_confirmed": confirmed}) + store.Update(driver, kind, w, nil, d) + store.RecordDriverSuccess(driver) + } + emit("car", telemetry.DerEV, tc.before, time.Now().Add(-time.Minute), true) + if tc.missing { + store.Update("car", telemetry.DerEV, tc.before, nil, []byte(`{"control_power_available":false}`)) + } + emit("meter", telemetry.DerMeter, tc.grid, time.Now(), false) + if tc.stopped { + emit("car", telemetry.DerEV, 0, time.Now(), true) + } + emit("car", telemetry.DerEV, 4757, time.Now(), true) + st := NewState(0, 0, "meter") + st.PeakImportCeilingW = 7500 + got, _ := EVFuseBudget(store, st, []loadpoint.State{{ID: "car", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "car", DriverName: "car", PhaseMode: "3p"}}, 17250) + if math.Abs(got-tc.want) > .01 { + t.Fatalf("cap=%v want=%v", got, tc.want) + } + }) + } +} diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index 763aa9636..5dfb73575 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -88,7 +88,7 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De balance := evFuseBalance{gridW: meter.RawW, siteAt: meter.UpdatedAt} siteAt := meter.UpdatedAt from := now.Add(-telemetry.ControlWindowDuration) - windows := store.ControlWindows(from, now) + windows := store.ConfirmedControlWindows(from, now) batteries := pendingBatterySeriesForFuse(store, state, windows, now) sites := windows[state.SiteMeterDriver+":"+telemetry.DerMeter.String()].Points if current, ok := qualifiedFuseObservation(meter, now); ok { diff --git a/go/internal/loadpoint/controller_resume.go b/go/internal/loadpoint/controller_resume.go index 408fe0907..aa9b89cb1 100644 --- a/go/internal/loadpoint/controller_resume.go +++ b/go/internal/loadpoint/controller_resume.go @@ -3,15 +3,17 @@ package loadpoint import ( "context" "log/slog" + "math" "time" ) type resumeOffer struct { - driver, device, session string - generation uint64 - nextAttempt time.Time - retryDelay time.Duration - acknowledgedAttempts int + driver, device, session string + generation uint64 + nextAttempt time.Time + retryDelay time.Duration + acknowledgedAttempts int + deliverySince, deliveryAt time.Time } // resumeAfterZeroOffer remembers our standdown independently of commanded W. @@ -31,11 +33,39 @@ func (c *Controller) resumeAfterZeroOffer(ctx context.Context, cfg Config, sampl c.resumeOffers[cfg.ID] = proof return } - if sample.PowerW >= DeliveringW { - delete(c.resumeOffers, cfg.ID) + if !exists { return } - if !exists || now.Before(previous.nextAttempt) { + // A small startup pulse is not successful recovery. Require fresh, + // advancing observations near a supported charging step for ten seconds. + // The current offer can be lower than the configured 3p minimum after a + // phase change. Leave the shared DeliveringW semantics unchanged. + minimum := cfg.MinChargeW + if minimum <= 0 { + minimum = offerW + } + // Allow ten percent variation around the nominal-voltage minimum. + floor := math.Max(DeliveringW, 0.9*math.Min(minimum, offerW)) + observedAt := sample.PowerAt + if observedAt.IsZero() { + observedAt = now // Legacy telemetry uses the fresh-read contract. + } + fresh := !sample.PowerUnavailable && !observedAt.After(now) && now.Sub(observedAt) <= min(sample.PowerWindow(), 10*time.Second) + if fresh && finite(sample.PowerW) && sample.PowerW >= floor { + if previous.deliverySince.IsZero() || observedAt.Before(previous.deliveryAt) || observedAt.Sub(previous.deliveryAt) > 10*time.Second { + previous.deliverySince = observedAt + } + previous.deliveryAt = observedAt + if observedAt.Sub(previous.deliverySince) >= 10*time.Second { + delete(c.resumeOffers, cfg.ID) + } else { + c.resumeOffers[cfg.ID] = previous + } + return // Already drawing: observe it rather than sending another resume. + } + previous.deliverySince, previous.deliveryAt = time.Time{}, time.Time{} + c.resumeOffers[cfg.ID] = previous + if now.Before(previous.nextAttempt) { return } if previous.acknowledgedAttempts >= 3 { diff --git a/go/internal/loadpoint/controller_resume_after_zero_test.go b/go/internal/loadpoint/controller_resume_after_zero_test.go index 782bde8bc..0454abbee 100644 --- a/go/internal/loadpoint/controller_resume_after_zero_test.go +++ b/go/internal/loadpoint/controller_resume_after_zero_test.go @@ -194,9 +194,16 @@ func TestTickCancelsResumeRetryWhenSessionProofChanges(t *testing.T) { } samples["easee"] = sample c.Tick(context.Background(), now.Add(10*time.Second)) + zeroAt := now.Add(15 * time.Second) + if change == "delivering" { + // Recovery needs sustained delivery, not one startup pulse. + c.Tick(context.Background(), now.Add(15*time.Second)) + c.Tick(context.Background(), now.Add(20*time.Second)) + zeroAt = now.Add(25 * time.Second) + } sample.Connected, sample.ConnectionUnknown, sample.PowerW = true, false, 0 samples["easee"] = sample - c.Tick(context.Background(), now.Add(15*time.Second)) + c.Tick(context.Background(), zeroAt) if attempts != 1 { t.Fatalf("stale retry crossed %s boundary: %d attempts", change, attempts) } diff --git a/go/internal/loadpoint/controller_resume_confirm_test.go b/go/internal/loadpoint/controller_resume_confirm_test.go index 31520c8d4..77bde4902 100644 --- a/go/internal/loadpoint/controller_resume_confirm_test.go +++ b/go/internal/loadpoint/controller_resume_confirm_test.go @@ -24,7 +24,14 @@ func TestResumeAcknowledgementWaitsForMeasuredCharge(t *testing.T) { sample := samples["easee"] sample.PowerW = 6900 samples["easee"] = sample - c.Tick(context.Background(), now.Add(130*time.Second)) + for _, seconds := range []int{130, 135, 140} { + sample.PowerAt = now.Add(time.Duration(seconds) * time.Second) + samples["easee"] = sample + c.Tick(context.Background(), sample.PowerAt) + } + if _, exists := c.resumeOffers[cfg.ID]; exists { + t.Fatal("sustained measured charging did not clear recovery proof") + } sample.PowerW = 0 samples["easee"] = sample c.Tick(context.Background(), now.Add(160*time.Second)) diff --git a/go/internal/loadpoint/controller_resume_delivery_test.go b/go/internal/loadpoint/controller_resume_delivery_test.go new file mode 100644 index 000000000..81daa07f7 --- /dev/null +++ b/go/internal/loadpoint/controller_resume_delivery_test.go @@ -0,0 +1,62 @@ +package loadpoint + +import ( + "context" + "testing" + "time" +) + +func TestResumeRequiresSustainedMeaningfulDelivery(t *testing.T) { + for _, tc := range []struct { + name string + power, offer float64 + gap, stale, unavailable bool + clear bool + }{ + {name: "130 W pulse", power: 130, offer: 4830}, + {name: "800 W pulse", power: 800, offer: 4830}, + {name: "full power briefly", power: 4757, offer: 4830, gap: true}, + {name: "cached high sample", power: 4757, offer: 4830, stale: true}, + {name: "unknown high power", power: 4757, offer: 4830, unavailable: true}, + {name: "sustained charging", power: 4757, offer: 4830, clear: true}, + {name: "voltage tolerance at minimum", power: 3800, offer: 4140, clear: true}, + {name: "one phase offer", power: 1350, offer: 1380, clear: true}, + } { + t.Run(tc.name, func(t *testing.T) { + now := time.Now() + cfg := Config{ID: "car", DriverName: "easee", MinChargeW: 4140} + resumes := 0 + c := &Controller{send: func(context.Context, string, []byte) error { resumes++; return nil }} + sample := EVSample{DeviceID: "box", SessionID: "one", ConnectionGeneration: 1} + c.resumeAfterZeroOffer(context.Background(), cfg, sample, 0, now) + c.resumeAfterZeroOffer(context.Background(), cfg, sample, tc.offer, now.Add(time.Second)) + for _, seconds := range []int{5, 10, 15} { + sample.PowerW = tc.power + sample.PowerUnavailable = tc.unavailable + sample.PowerAt = now.Add(time.Duration(seconds) * time.Second) + if tc.stale { + sample.PowerAt = now.Add(5 * time.Second) + } + if tc.gap && seconds == 10 { + sample.PowerW = 0 + } + c.resumeAfterZeroOffer(context.Background(), cfg, sample, tc.offer, now.Add(time.Duration(seconds)*time.Second)) + } + _, exists := c.resumeOffers[cfg.ID] + if exists == tc.clear { + t.Fatalf("resume proof exists=%v want clear=%v", exists, tc.clear) + } + sample.PowerW = 0 + sample.PowerUnavailable = false + sample.PowerAt = now.Add(35 * time.Second) + c.resumeAfterZeroOffer(context.Background(), cfg, sample, tc.offer, now.Add(35*time.Second)) + want := 2 + if tc.clear { + want = 1 + } + if resumes != want { + t.Fatalf("resumes=%v want=%v", resumes, want) + } + }) + } +} diff --git a/go/internal/telemetry/control_confirmed_anchor_test.go b/go/internal/telemetry/control_confirmed_anchor_test.go new file mode 100644 index 000000000..58679cfa5 --- /dev/null +++ b/go/internal/telemetry/control_confirmed_anchor_test.go @@ -0,0 +1,101 @@ +package telemetry + +import ( + "fmt" + "testing" + "time" +) + +func confirmedAnchorData(at time.Time) []byte { + return []byte(fmt.Sprintf(`{"control_power_observed_at":%q,"control_power_confirmed":true}`, at.Format(time.RFC3339Nano))) +} + +func TestConfirmedControlAnchorRetainsSourceTimeAndOneSample(t *testing.T) { + now := time.Now() + source := now.Add(-time.Minute) + s := NewStore() + for i := 10; i >= 1; i-- { + s.recordControlObservation("car", DerEV, 6183, confirmedAnchorData(source), now.Add(-time.Duration(i)*time.Second)) + } + points := copyConfirmedControlPoints(s.controlObservations["car:ev"], now.Add(-20*time.Second), now) + if len(points) != 1 || !points[0].At.Equal(source) || !points[0].Seen().Equal(now.Add(-time.Second)) { + t.Fatalf("confirmed anchor lost or duplicated: %+v", points) + } + if physical := copyControlPoints(points, now.Add(-20*time.Second), now); len(physical) != 0 { + t.Fatalf("response verifier received an old confirmed anchor: %+v", physical) + } + if w := observationWindow(points, now.Add(-20*time.Second), now); w.Count != 0 || w.Usable(now) { + t.Fatalf("confirmation manufactured source samples: %+v", w) + } + if expired := copyConfirmedControlPoints(points, now, now.Add(time.Second)); len(expired) != 0 { + t.Fatal("expired confirmation remained usable") + } +} + +func TestConfirmedControlAnchorMissingOrConflictingDataBreaksProof(t *testing.T) { + now := time.Now() + source := now.Add(-time.Minute) + for _, tc := range []struct { + name string + data []byte + power float64 + }{ + {"missing", []byte(`{"control_power_available":false,"control_power_confirmed":true}`), 6183}, + {"unconfirmed old source", []byte(fmt.Sprintf(`{"control_power_observed_at":%q}`, source.Format(time.RFC3339Nano))), 6183}, + {"different power at same source time", confirmedAnchorData(source), 0}, + } { + t.Run(tc.name, func(t *testing.T) { + s := NewStore() + s.recordControlObservation("car", DerEV, 6183, confirmedAnchorData(source), now.Add(-time.Second)) + s.recordControlObservation("car", DerEV, tc.power, tc.data, now) + if ps := s.controlObservations["car:ev"]; len(ps) != 0 { + t.Fatalf("invalid proof retained: %+v", ps) + } + }) + } +} + +func TestConfirmedControlAnchorRetainsStopAndBoundsFrozenConfirmation(t *testing.T) { + now := time.Now() + s := NewStore() + source := now.Add(-time.Minute) + s.recordControlObservation("car", DerEV, 6183, confirmedAnchorData(source), now.Add(-time.Second)) + s.recordControlObservation("car", DerEV, 0, confirmedAnchorData(now), now) + s.recordControlObservation("car", DerEV, 4757, confirmedAnchorData(now.Add(time.Second)), now.Add(time.Second)) + ps := copyConfirmedControlPoints(s.controlObservations["car:ev"], now.Add(-20*time.Second), now.Add(time.Second)) + if len(ps) != 3 || ps[1].PowerW != 0 { + t.Fatalf("stop was lost: %+v", ps) + } + s.recordControlObservation("car", DerEV, 4757, confirmedAnchorData(now.Add(time.Second)), now.Add(10*time.Second)) + frozen := copyConfirmedControlPoints(s.controlObservations["car:ev"], now, now.Add(5*time.Second)) + for _, p := range frozen { + if p.Seen().After(now.Add(5 * time.Second)) { + t.Fatalf("confirmation escaped frozen interval: %+v", p) + } + } +} + +func TestConfirmedControlAnchorDoesNotManufactureResponseWindow(t *testing.T) { + now := time.Now() + source := now.Add(-15 * time.Second) + s := NewStore() + for i := 10; i >= 1; i-- { + s.recordControlObservation("car", DerEV, 6183, confirmedAnchorData(source), now.Add(-time.Duration(i)*time.Second)) + } + ps := copyConfirmedControlPoints(s.controlObservations["car:ev"], now.Add(-20*time.Second), now) + w := observationWindow(ps, now.Add(-20*time.Second), now) + if len(ps) != 1 || w.Count != 1 || w.Usable(now) { + t.Fatalf("ten confirmations must remain one physical sample: points=%+v window=%+v", ps, w) + } +} + +func TestConfirmedControlWindowsSeparateBoundsFromResponseSamples(t *testing.T) { + s := NewStore() + now := time.Now() + s.Update("car", DerEV, 6183, nil, confirmedAnchorData(now.Add(-time.Minute))) + physical := s.ControlWindows(now.Add(-20*time.Second), time.Now())["car:ev"] + bounds := s.ConfirmedControlWindows(now.Add(-20*time.Second), time.Now())["car:ev"] + if len(physical.Points) != 0 || len(bounds.Points) != 1 || physical.Window.Count != 0 || bounds.Window.Count != 0 { + t.Fatalf("confirmed interval became physical response evidence: physical=%+v bounds=%+v", physical, bounds) + } +} diff --git a/go/internal/telemetry/control_observations.go b/go/internal/telemetry/control_observations.go index 59612953f..1740822f8 100644 --- a/go/internal/telemetry/control_observations.go +++ b/go/internal/telemetry/control_observations.go @@ -40,7 +40,7 @@ func (s *Store) recordControlObservation(driver string, kind DerType, power floa k := key(driver, kind) invalidate := func() { delete(s.controlObservations, k) } p, known := ControlPowerObservation(power, data, now) - if !known || now.Sub(p.At) > 10*time.Second { + if !known || now.Sub(p.Seen()) > 10*time.Second { invalidate() return } @@ -50,6 +50,18 @@ func (s *Store) recordControlObservation(driver string, kind DerType, power floa } points := s.controlObservations[k] if len(points) > 0 && !at.After(points[len(points)-1].At) { + last := &points[len(points)-1] + if at.Equal(last.At) { + if p.PowerW != last.PowerW { + invalidate() // One source time cannot prove two power levels. + return + } + // A change-only source confirms the same physical sample. Keep + // its source time and a single point; extend only its confirmation. + if p.ConfirmedAt.After(last.ConfirmedAt) { + last.ConfirmedAt = p.ConfirmedAt + } + } return } if kind != DerEV && kind != DerBattery && kind != DerV2X && len(points) > 0 && at.Unix() == points[len(points)-1].At.Unix() { @@ -102,6 +114,17 @@ func (s *Store) controlBaseline(now time.Time) map[string]ControlBaseline { return result } func (s *Store) ControlWindows(from, now time.Time) map[string]ControlBaseline { + return s.controlWindows(from, now, false) +} + +// ConfirmedControlWindows also retains a change-only source's confirmed +// interval for time-aligned power bounds. Window still counts only distinct +// physical measurements. Response verification uses ControlWindows instead. +func (s *Store) ConfirmedControlWindows(from, now time.Time) map[string]ControlBaseline { + return s.controlWindows(from, now, true) +} + +func (s *Store) controlWindows(from, now time.Time, confirmations bool) map[string]ControlBaseline { s.mu.RLock() defer s.mu.RUnlock() result := map[string]ControlBaseline{} @@ -109,7 +132,11 @@ func (s *Store) ControlWindows(from, now time.Time) map[string]ControlBaseline { if rd.DerType == DerVehicle { continue } - result[k] = ControlBaseline{rd.Driver, rd.DerType, observationWindow(s.controlObservations[k], from, now), copyControlPoints(s.controlObservations[k], from, now)} + points := copyControlPoints(s.controlObservations[k], from, now) + if confirmations { + points = copyConfirmedControlPoints(s.controlObservations[k], from, now) + } + result[k] = ControlBaseline{rd.Driver, rd.DerType, observationWindow(s.controlObservations[k], from, now), points} } return result } @@ -118,6 +145,24 @@ func copyControlPoints(points []ControlObservation, from, until time.Time) []Con var out []ControlObservation for _, p := range points { if !p.At.Before(from) && !p.At.After(until) { + if p.ConfirmedAt.After(until) { + p.ConfirmedAt = until + } + out = append(out, p) + } + } + return out +} + +func copyConfirmedControlPoints(points []ControlObservation, from, until time.Time) []ControlObservation { + var out []ControlObservation + for _, p := range points { + if !p.Seen().Before(from) && !p.At.After(until) { + // Keep confirmed anchors for time-aligned bounds, without + // moving At or counting them as new response measurements. + if p.ConfirmedAt.After(until) { + p.ConfirmedAt = until + } out = append(out, p) } } From 15847d0de864ebacba586ba48deb11270c536816 Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 12:30:08 +0200 Subject: [PATCH 08/16] chore(ev): keep detailed fuse budget evidence at debug level Signed-off-by: Segran --- .changeset/ev-fuse-budget-evidence.md | 2 +- go/internal/control/ev_fuse_budget.go | 2 +- go/internal/control/ev_fuse_incident_test.go | 5 ++++- 3 files changed, 6 insertions(+), 3 deletions(-) diff --git a/.changeset/ev-fuse-budget-evidence.md b/.changeset/ev-fuse-budget-evidence.md index 1b033f400..985e58451 100644 --- a/.changeset/ev-fuse-budget-evidence.md +++ b/.changeset/ev-fuse-budget-evidence.md @@ -2,4 +2,4 @@ "ftw": patch --- -Report rate-limited common/latest site, EV-credit, import and phase-limit evidence when an EV fuse budget falls below the charging minimum, without changing charging limits. +Report debug-level, rate-limited common/latest site, EV-credit, import and phase-limit evidence when an EV fuse budget falls below the charging minimum, without changing charging limits. diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index 5dfb73575..f64483981 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -68,7 +68,7 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State } if minimumW > 0 && finalCap < minimumW && (state.evFuseEvidenceAt.IsZero() || now.Before(state.evFuseEvidenceAt) || now.Sub(state.evFuseEvidenceAt) >= time.Minute) { state.evFuseEvidenceAt = now - slog.Info("EV fuse budget below charging minimum", "minimum_charge_w", minimumW, + slog.Debug("EV fuse budget below charging minimum", "minimum_charge_w", minimumW, "common_site_at_ms", balance.siteAt.UnixMilli(), "latest_site_received_at_ms", meter.UpdatedAt.UnixMilli(), "physical_fuse_w", fuseMaxW, "configured_import_ceiling_w", state.PeakImportCeilingW, "common_ceiling_w", commonCeiling, "latest_ceiling_w", latestCeiling, diff --git a/go/internal/control/ev_fuse_incident_test.go b/go/internal/control/ev_fuse_incident_test.go index 51786633c..85f23565f 100644 --- a/go/internal/control/ev_fuse_incident_test.go +++ b/go/internal/control/ev_fuse_incident_test.go @@ -39,7 +39,7 @@ func TestImportCeilingStartSkewEvidence(t *testing.T) { st.clock = func() time.Time { return now } var log bytes.Buffer old := slog.Default() - slog.SetDefault(slog.New(slog.NewJSONHandler(&log, &slog.HandlerOptions{Level: slog.LevelInfo}))) + slog.SetDefault(slog.New(slog.NewJSONHandler(&log, &slog.HandlerOptions{Level: slog.LevelDebug}))) defer slog.SetDefault(old) capW, known := EVFuseBudget(store, st, []loadpoint.State{{ID: "a", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "a", DriverName: "car", PhaseMode: "3p", MinChargeW: 4140}}, 17250) if !known || math.Abs(capW-400) > .001 { @@ -49,6 +49,9 @@ func TestImportCeilingStartSkewEvidence(t *testing.T) { if err := json.Unmarshal(log.Bytes(), &e); err != nil { t.Fatal(err) } + if e["level"] != "DEBUG" { + t.Fatalf("budget evidence level=%v want DEBUG", e["level"]) + } for key, want := range map[string]float64{"configured_import_ceiling_w": 7500, "physical_fuse_w": 17250, "latest_grid_w": 7100, "latest_ev_credit_w": 0, "latest_site_cap_w": 400, "final_cap_w": 400} { if e[key] != want { t.Fatalf("%s=%v want %v", key, e[key], want) From cde5cdbc2123da0142a880abdd59437834b1ca2e Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 13:43:30 +0200 Subject: [PATCH 09/16] fix(ev): record source provenance for rejected charging credit Signed-off-by: Segran --- .changeset/ev-zero-credit-provenance.md | 5 ++ go/internal/control/ev_fuse_budget.go | 10 +++ go/internal/control/ev_fuse_evidence.go | 65 ++++++++++++++++++++ go/internal/control/ev_fuse_evidence_test.go | 44 +++++++++++++ 4 files changed, 124 insertions(+) create mode 100644 .changeset/ev-zero-credit-provenance.md create mode 100644 go/internal/control/ev_fuse_evidence.go create mode 100644 go/internal/control/ev_fuse_evidence_test.go diff --git a/.changeset/ev-zero-credit-provenance.md b/.changeset/ev-zero-credit-provenance.md new file mode 100644 index 000000000..93a494f9a --- /dev/null +++ b/.changeset/ev-zero-credit-provenance.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +Include per-charger source, confirmation and receipt times and zero-credit reasons in bounded debug-level EV budget diagnostics. Preserve conservative charging limits when source observations are uncertain. diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index f64483981..3573d3f2f 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -26,6 +26,7 @@ type evFuseBalance struct { gridW, poolW, pendingW float64 latestPoolW, latestPendingW float64 siteAt time.Time + evEvidence []evFuseEvidence } // EVFuseBudget refreshes the common EV cap before a charger command, also @@ -74,6 +75,7 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State "common_ceiling_w", commonCeiling, "latest_ceiling_w", latestCeiling, "common_grid_w", balance.gridW, "common_ev_credit_w", balance.poolW, "common_pending_battery_w", balance.pendingW, "latest_grid_w", meter.RawW, "latest_ev_credit_w", balance.latestPoolW, "latest_pending_battery_w", balance.latestPendingW, + "ev_credit_evidence", balance.evEvidence, "common_cap_w", cap, "latest_site_cap_w", latestCap, "phase_bound_known", phaseKnown, "phase_cap_w", phaseCap, "final_cap_w", finalCap) } return finalCap, true @@ -111,11 +113,19 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De r := store.Get(point.DriverName, telemetry.DerEV) h := store.DriverHealth(point.DriverName) current, ok := qualifiedFuseObservation(r, now) + evidence := fuseEVEvidence(point.DriverName, r, h, current, ok, now) + balance.evEvidence = append(balance.evEvidence, evidence) if !ok || h == nil || !h.TelemetryLive() || current.PowerW <= 0 { continue // Unknown EV power stays inside the measured site demand. } ps := windows[point.DriverName+":"+telemetry.DerEV.String()].Points ps = append(ps, current) // Includes explicit change-only confirmations. + credit := evPowerAtLatestSite(ps, siteAt, current) + balance.evEvidence[len(balance.evEvidence)-1].LatestCreditW = credit + balance.evEvidence[len(balance.evEvidence)-1].Points = len(ps) + if credit <= 0 { + balance.evEvidence[len(balance.evEvidence)-1].Reason = "no_bracket_or_observed_stop" + } series = append(series, evSeries{math.Min(current.PowerW, r.RawW), current, ps}) } for _, ev := range series { diff --git a/go/internal/control/ev_fuse_evidence.go b/go/internal/control/ev_fuse_evidence.go new file mode 100644 index 000000000..734d5c3d2 --- /dev/null +++ b/go/internal/control/ev_fuse_evidence.go @@ -0,0 +1,65 @@ +package control + +import ( + "encoding/json" + "time" + + "github.com/srcfl/ftw/go/internal/telemetry" +) + +// Evidence captures the same EV reading used by the budget, not a later status +// snapshot. It is diagnostic only and never supplies replacement credit. +type evFuseEvidence struct { + ReportedSourceAt string `json:"reported_source_at"` + Driver string `json:"driver"` + Reason string `json:"reason"` + RawW float64 `json:"raw_w"` + PowerW float64 `json:"control_power_w"` + ReceivedAt time.Time `json:"received_at"` + SourceAt time.Time `json:"source_at"` + ConfirmedAt time.Time `json:"confirmed_at"` + SourceValid bool `json:"source_valid"` + Qualified bool `json:"qualified"` + TelemetryLive bool `json:"telemetry_live"` + LatestCreditW float64 `json:"latest_credit_w"` + Points int `json:"points"` +} + +func fuseEVEvidence(driver string, r *telemetry.DerReading, health *telemetry.DriverHealth, p telemetry.ControlObservation, qualified bool, now time.Time) evFuseEvidence { + e := evFuseEvidence{Driver: driver, Reason: "missing_reading", Qualified: qualified} + if r == nil { + return e + } + e.RawW, e.ReceivedAt = r.RawW, r.UpdatedAt + // Keep the source timestamp even when qualification rejected the reading. + var reported struct { + ControlPowerObservedAt string `json:"control_power_observed_at"` + PowerObservedAt string `json:"power_observed_at"` + } + _ = json.Unmarshal(r.Data, &reported) + e.ReportedSourceAt = reported.ControlPowerObservedAt + if e.ReportedSourceAt == "" { + e.ReportedSourceAt = reported.PowerObservedAt + } + source, valid := telemetry.ControlPowerObservation(r.RawW, r.Data, r.UpdatedAt) + e.PowerW, e.SourceAt, e.ConfirmedAt, e.SourceValid = source.PowerW, source.At, source.ConfirmedAt, valid + if !valid { + e.SourceAt, e.ConfirmedAt = time.Time{}, time.Time{} + } + e.TelemetryLive = health != nil && health.TelemetryLive() + switch { + case !valid: + e.Reason = "invalid_or_unavailable_source" + case r.UpdatedAt.After(now) || now.Sub(r.UpdatedAt) > telemetry.ControlPowerMaxAge(r.Data): + e.Reason = "stale_or_future_receipt" + case !qualified: + e.Reason = "stale_or_future_control_observation" + case !e.TelemetryLive: + e.Reason = "telemetry_not_live" + case p.PowerW <= 0: + e.Reason = "observed_nonpositive_power" + default: + e.Reason = "qualified" + } + return e +} diff --git a/go/internal/control/ev_fuse_evidence_test.go b/go/internal/control/ev_fuse_evidence_test.go new file mode 100644 index 000000000..a1afa81f6 --- /dev/null +++ b/go/internal/control/ev_fuse_evidence_test.go @@ -0,0 +1,44 @@ +package control + +import ( + "encoding/json" + "testing" + "time" + + "github.com/srcfl/ftw/go/internal/loadpoint" + "github.com/srcfl/ftw/go/internal/telemetry" +) + +func TestEVFuseZeroEvidenceKeepsSourceAndReceiptTimes(t *testing.T) { + now := time.Now() + sourceAt := now.Add(-time.Minute) + for _, tc := range []struct{ name, data, reason string }{ + {"confirmed cloud zero", `"control_power_confirmed":true`, "observed_nonpositive_power"}, + {"unavailable source", `"control_power_available":false`, "invalid_or_unavailable_source"}, + } { + t.Run(tc.name, func(t *testing.T) { + store := telemetry.NewStore() + data := []byte(`{"control_power_observed_at":"` + sourceAt.Format(time.RFC3339Nano) + `",` + tc.data + `}`) + store.Update("car", telemetry.DerEV, 0, nil, data) + store.RecordDriverSuccess("car") + store.Update("meter", telemetry.DerMeter, 12323, nil, []byte(`{"l1_a":20.45,"l2_a":17.05,"l3_a":15.87}`)) + st := NewState(0, 0, "meter") + st.SiteFuseAmps, st.SiteFuseVoltage, st.SiteFusePhases = 25, 230, 3 + balance := coherentEVBalance(store, st, store.Get("meter", telemetry.DerMeter), []loadpoint.State{{ID: "car", DriverName: "car", PluggedIn: true}}, time.Now()) + if len(balance.evEvidence) != 1 { + t.Fatalf("missing zero-credit evidence: %+v", balance) + } + e := balance.evEvidence[0] + if e.Reason != tc.reason || e.ReportedSourceAt != sourceAt.Format(time.RFC3339Nano) || !e.ReceivedAt.After(e.SourceAt) || e.LatestCreditW != 0 { + t.Fatalf("evidence=%+v", e) + } + if _, err := json.Marshal(e); err != nil { + t.Fatal(err) + } + capW, _ := EVFuseBudget(store, st, []loadpoint.State{{ID: "car", DriverName: "car", PluggedIn: true}}, []loadpoint.Config{{ID: "car", DriverName: "car", PhaseMode: "3p", MinChargeW: 4140}}, 17250) + if capW >= 4140 { + t.Fatalf("uncertainty must not authorize charging: cap=%v", capW) + } + }) + } +} From 4cae2e329aa8cf0bce51b2d4451330c8239fed6a Mon Sep 17 00:00:00 2001 From: Segran Date: Sat, 17 Oct 2026 14:04:34 +0200 Subject: [PATCH 10/16] fix(ev): keep diagnostic telemetry snapshots in telemetry package Signed-off-by: Segran --- go/internal/control/ev_fuse_budget.go | 6 +- go/internal/control/ev_fuse_evidence.go | 65 ++----------------- .../telemetry/control_power_evidence.go | 63 ++++++++++++++++++ 3 files changed, 72 insertions(+), 62 deletions(-) create mode 100644 go/internal/telemetry/control_power_evidence.go diff --git a/go/internal/control/ev_fuse_budget.go b/go/internal/control/ev_fuse_budget.go index 3573d3f2f..a6e37c696 100644 --- a/go/internal/control/ev_fuse_budget.go +++ b/go/internal/control/ev_fuse_budget.go @@ -25,6 +25,7 @@ func finiteFuseValue(w float64) bool { return !math.IsNaN(w) && !math.IsInf(w, 0 type evFuseBalance struct { gridW, poolW, pendingW float64 latestPoolW, latestPendingW float64 + latestGridW float64 siteAt time.Time evEvidence []evFuseEvidence } @@ -74,7 +75,7 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State "physical_fuse_w", fuseMaxW, "configured_import_ceiling_w", state.PeakImportCeilingW, "common_ceiling_w", commonCeiling, "latest_ceiling_w", latestCeiling, "common_grid_w", balance.gridW, "common_ev_credit_w", balance.poolW, "common_pending_battery_w", balance.pendingW, - "latest_grid_w", meter.RawW, "latest_ev_credit_w", balance.latestPoolW, "latest_pending_battery_w", balance.latestPendingW, + "latest_grid_w", balance.latestGridW, "latest_ev_credit_w", balance.latestPoolW, "latest_pending_battery_w", balance.latestPendingW, "ev_credit_evidence", balance.evEvidence, "common_cap_w", cap, "latest_site_cap_w", latestCap, "phase_bound_known", phaseKnown, "phase_cap_w", phaseCap, "final_cap_w", finalCap) } @@ -88,6 +89,7 @@ func EVFuseBudget(store *telemetry.Store, state *State, points []loadpoint.State // filtered load estimate participates in the hard limit. func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.DerReading, points []loadpoint.State, now time.Time) evFuseBalance { balance := evFuseBalance{gridW: meter.RawW, siteAt: meter.UpdatedAt} + balance.latestGridW = balance.gridW siteAt := meter.UpdatedAt from := now.Add(-telemetry.ControlWindowDuration) windows := store.ConfirmedControlWindows(from, now) @@ -113,7 +115,7 @@ func coherentEVBalance(store *telemetry.Store, state *State, meter *telemetry.De r := store.Get(point.DriverName, telemetry.DerEV) h := store.DriverHealth(point.DriverName) current, ok := qualifiedFuseObservation(r, now) - evidence := fuseEVEvidence(point.DriverName, r, h, current, ok, now) + evidence := evFuseEvidence{ControlPowerEvidence: telemetry.DescribeControlPower(point.DriverName, r, h, current, ok, now)} balance.evEvidence = append(balance.evEvidence, evidence) if !ok || h == nil || !h.TelemetryLive() || current.PowerW <= 0 { continue // Unknown EV power stays inside the measured site demand. diff --git a/go/internal/control/ev_fuse_evidence.go b/go/internal/control/ev_fuse_evidence.go index 734d5c3d2..3eade9c45 100644 --- a/go/internal/control/ev_fuse_evidence.go +++ b/go/internal/control/ev_fuse_evidence.go @@ -1,65 +1,10 @@ package control -import ( - "encoding/json" - "time" +import "github.com/srcfl/ftw/go/internal/telemetry" - "github.com/srcfl/ftw/go/internal/telemetry" -) - -// Evidence captures the same EV reading used by the budget, not a later status -// snapshot. It is diagnostic only and never supplies replacement credit. +// Budget-specific fields accompany the immutable diagnostic snapshot. type evFuseEvidence struct { - ReportedSourceAt string `json:"reported_source_at"` - Driver string `json:"driver"` - Reason string `json:"reason"` - RawW float64 `json:"raw_w"` - PowerW float64 `json:"control_power_w"` - ReceivedAt time.Time `json:"received_at"` - SourceAt time.Time `json:"source_at"` - ConfirmedAt time.Time `json:"confirmed_at"` - SourceValid bool `json:"source_valid"` - Qualified bool `json:"qualified"` - TelemetryLive bool `json:"telemetry_live"` - LatestCreditW float64 `json:"latest_credit_w"` - Points int `json:"points"` -} - -func fuseEVEvidence(driver string, r *telemetry.DerReading, health *telemetry.DriverHealth, p telemetry.ControlObservation, qualified bool, now time.Time) evFuseEvidence { - e := evFuseEvidence{Driver: driver, Reason: "missing_reading", Qualified: qualified} - if r == nil { - return e - } - e.RawW, e.ReceivedAt = r.RawW, r.UpdatedAt - // Keep the source timestamp even when qualification rejected the reading. - var reported struct { - ControlPowerObservedAt string `json:"control_power_observed_at"` - PowerObservedAt string `json:"power_observed_at"` - } - _ = json.Unmarshal(r.Data, &reported) - e.ReportedSourceAt = reported.ControlPowerObservedAt - if e.ReportedSourceAt == "" { - e.ReportedSourceAt = reported.PowerObservedAt - } - source, valid := telemetry.ControlPowerObservation(r.RawW, r.Data, r.UpdatedAt) - e.PowerW, e.SourceAt, e.ConfirmedAt, e.SourceValid = source.PowerW, source.At, source.ConfirmedAt, valid - if !valid { - e.SourceAt, e.ConfirmedAt = time.Time{}, time.Time{} - } - e.TelemetryLive = health != nil && health.TelemetryLive() - switch { - case !valid: - e.Reason = "invalid_or_unavailable_source" - case r.UpdatedAt.After(now) || now.Sub(r.UpdatedAt) > telemetry.ControlPowerMaxAge(r.Data): - e.Reason = "stale_or_future_receipt" - case !qualified: - e.Reason = "stale_or_future_control_observation" - case !e.TelemetryLive: - e.Reason = "telemetry_not_live" - case p.PowerW <= 0: - e.Reason = "observed_nonpositive_power" - default: - e.Reason = "qualified" - } - return e + telemetry.ControlPowerEvidence + LatestCreditW float64 `json:"latest_credit_w"` + Points int `json:"points"` } diff --git a/go/internal/telemetry/control_power_evidence.go b/go/internal/telemetry/control_power_evidence.go new file mode 100644 index 000000000..8b7b955ab --- /dev/null +++ b/go/internal/telemetry/control_power_evidence.go @@ -0,0 +1,63 @@ +package telemetry + +import ( + "encoding/json" + "time" +) + +// ControlPowerEvidence captures the same EV reading used by the budget, not a later status +// snapshot. It is diagnostic only and never supplies replacement credit. +type ControlPowerEvidence struct { + ReportedSourceAt string `json:"reported_source_at"` + Driver string `json:"driver"` + Reason string `json:"reason"` + RawW float64 `json:"raw_w"` + PowerW float64 `json:"control_power_w"` + ReceivedAt time.Time `json:"received_at"` + SourceAt time.Time `json:"source_at"` + ConfirmedAt time.Time `json:"confirmed_at"` + SourceValid bool `json:"source_valid"` + Qualified bool `json:"qualified"` + TelemetryLive bool `json:"telemetry_live"` +} + +// DescribeControlPower describes the supplied decision snapshot, including rejected +// or offline readings, for diagnostics only. It never authorizes control. +func DescribeControlPower(driver string, r *DerReading, health *DriverHealth, p ControlObservation, qualified bool, now time.Time) ControlPowerEvidence { + e := ControlPowerEvidence{Driver: driver, Reason: "missing_reading", Qualified: qualified} + if r == nil { + return e + } + e.RawW, e.ReceivedAt = r.RawW, r.UpdatedAt + // Keep the source timestamp even when qualification rejected the reading. + var reported struct { + ControlPowerObservedAt string `json:"control_power_observed_at"` + PowerObservedAt string `json:"power_observed_at"` + } + _ = json.Unmarshal(r.Data, &reported) + e.ReportedSourceAt = reported.ControlPowerObservedAt + if e.ReportedSourceAt == "" { + e.ReportedSourceAt = reported.PowerObservedAt + } + source, valid := ControlPowerObservation(r.RawW, r.Data, r.UpdatedAt) + e.PowerW, e.SourceAt, e.ConfirmedAt, e.SourceValid = source.PowerW, source.At, source.ConfirmedAt, valid + if !valid { + e.SourceAt, e.ConfirmedAt = time.Time{}, time.Time{} + } + e.TelemetryLive = health != nil && health.TelemetryLive() + switch { + case !valid: + e.Reason = "invalid_or_unavailable_source" + case r.UpdatedAt.After(now) || now.Sub(r.UpdatedAt) > ControlPowerMaxAge(r.Data): + e.Reason = "stale_or_future_receipt" + case !qualified: + e.Reason = "stale_or_future_control_observation" + case !e.TelemetryLive: + e.Reason = "telemetry_not_live" + case p.PowerW <= 0: + e.Reason = "observed_nonpositive_power" + default: + e.Reason = "qualified" + } + return e +} From e3ea0c48312e3f36ab144b77af93b273fcd87493 Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 06:32:32 +0200 Subject: [PATCH 11/16] test(ev): distinguish current limits from resume during OCPP reconnect Signed-off-by: Fredrik Ahlgren --- go/cmd/ftw/ev_ocpp_reconnect_test.go | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/go/cmd/ftw/ev_ocpp_reconnect_test.go b/go/cmd/ftw/ev_ocpp_reconnect_test.go index b9e6e0c42..07f6a3368 100644 --- a/go/cmd/ftw/ev_ocpp_reconnect_test.go +++ b/go/cmd/ftw/ev_ocpp_reconnect_test.go @@ -92,16 +92,21 @@ func TestOCPPReconnectDoesNotUnplugOrResumeOldStart(t *testing.T) { bus.Subscribe(events.KindChargingConnected, func(events.Event) { connectedEvents++ }) bus.Publish(events.HealthTick{Health: map[string]telemetry.DriverHealth{"garage": {Status: telemetry.StatusOk, LastSuccess: &now}}, Now: now}) commands := []float64{} + sendCount := 0 ctrl := loadpoint.NewController(manager, func(time.Time) (loadpoint.Directive, bool) { return loadpoint.Directive{}, false }, func(name string) (loadpoint.EVSample, bool) { return currentEVSample(tel.Get(name, telemetry.DerEV), tel.DriverHealth(name), time.Minute, time.Now(), srv.Handler().IsOnline(name), currentOCPPDeviceID(srv.Handler(), name)) }, func(_ context.Context, _ string, p []byte) error { var d struct { - Power float64 `json:"power_w"` + Power float64 `json:"power_w"` + Action string `json:"action"` } if e := json.Unmarshal(p, &d); e != nil { return e } - commands = append(commands, d.Power) + sendCount++ + if d.Action == "ev_set_current" { + commands = append(commands, d.Power) + } return nil }) ctrl.SetSiteFuse(loadpoint.SiteFuse{MaxAmps: 16, Voltage: 230, PhaseCnt: 3}) @@ -111,7 +116,7 @@ func TestOCPPReconnectDoesNotUnplugOrResumeOldStart(t *testing.T) { ctrl.SetManualHold("garage", loadpoint.ManualHold{Persistent: true, PowerW: power}) tick() before, _ := manager.State("garage") - commandCount := len(commands) + commandCount := sendCount cp.Stop() await(func() bool { r := tel.Get("garage", telemetry.DerEV) @@ -128,7 +133,7 @@ func TestOCPPReconnectDoesNotUnplugOrResumeOldStart(t *testing.T) { if !ok || hold.PowerW != 0 || !st.PluggedIn || st.ManualRestoreUnconfirmed != (power > 0) { t.Fatalf("unknown socket lost safety: hold=%+v state=%+v", hold, st) } - if len(commands) != commandCount { + if sendCount != commandCount { t.Fatal("unknown cable dispatched a command") } if st.UpdatedAtMs != before.UpdatedAtMs { From 9caf7e110bf7643b3ad76168a64ebd8ef6bdf745 Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 06:35:15 +0200 Subject: [PATCH 12/16] fix(ev): recheck Stop and charger session after setting current Signed-off-by: Fredrik Ahlgren --- .../controller_positive_recovery_test.go | 46 +++++++++++++++++++ go/internal/loadpoint/controller_resume.go | 20 ++++++++ 2 files changed, 66 insertions(+) diff --git a/go/internal/loadpoint/controller_positive_recovery_test.go b/go/internal/loadpoint/controller_positive_recovery_test.go index 96951f753..0fac700dd 100644 --- a/go/internal/loadpoint/controller_positive_recovery_test.go +++ b/go/internal/loadpoint/controller_positive_recovery_test.go @@ -2,6 +2,7 @@ package loadpoint import ( "context" + "encoding/json" "errors" "math" "testing" @@ -83,3 +84,48 @@ func TestPositiveOfferRecoveryWithoutPriorZero(t *testing.T) { }) } } + +func TestRecoveryRechecksStopAndSessionAfterCurrentWrite(t *testing.T) { + for _, boundary := range []string{"stop", "unplug", "session", "unknown", "started drawing"} { + t.Run(boundary, func(t *testing.T) { + now := time.Now() + cfg := Config{ID: "garage", DriverName: "easee", MinChargeW: 4140, MaxChargeW: 10350} + dir := &Directive{SlotStart: now, SlotEnd: now.Add(time.Hour), LoadpointEnergyWh: map[string]float64{cfg.ID: 0}} + sample := EVSample{Connected: true, RequestActive: true, DeviceID: "charger", SessionID: "one", ConnectionGeneration: 1} + samples := map[string]EVSample{cfg.DriverName: sample} + sender := &fakeSender{} + c := newTestController(t, []Config{cfg}, dir, samples, sender) + c.Tick(context.Background(), now) + dir.LoadpointEnergyWh[cfg.ID] = 10350 + c.send = func(ctx context.Context, driver string, payload []byte) error { + var command struct { + Action string `json:"action"` + PowerW float64 `json:"power_w"` + } + if err := json.Unmarshal(payload, &command); err != nil { + return err + } + if command.Action == "ev_set_current" && command.PowerW > 0 { + switch boundary { + case "stop": + c.SetManualHold(cfg.ID, ManualHold{PowerW: 0, Persistent: true}) + case "unplug": + sample.Connected = false + case "session": + sample.SessionID = "two" + case "unknown": + sample.ConnectionUnknown = true + case "started drawing": + sample.PowerW = 4712 + } + samples[cfg.DriverName] = sample + } + return sender.Send(ctx, driver, payload) + } + c.Tick(context.Background(), now.Add(5*time.Second)) + if countAction(sender.calls, "ev_resume") != 0 { + t.Fatalf("resume crossed %s during current write", boundary) + } + }) + } +} diff --git a/go/internal/loadpoint/controller_resume.go b/go/internal/loadpoint/controller_resume.go index 481a9ec44..523012a25 100644 --- a/go/internal/loadpoint/controller_resume.go +++ b/go/internal/loadpoint/controller_resume.go @@ -41,6 +41,26 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl c.resumeOffers[cfg.ID] = proof return } + // The current write can block while a Stop or socket change arrives. + // Recheck before reopening the contactor, using the newest observation. + if hold, held := c.GetManualHold(cfg.ID, now); held && hold.PowerW == 0 { + delete(c.resumeOffers, cfg.ID) + return + } + if c.tel != nil { + latest, live := c.tel(cfg.DriverName) + if !live || !latest.Connected || latest.ConnectionUnknown || latest.DeviceID != sample.DeviceID || + latest.SessionID != sample.SessionID || latest.ConnectionGeneration != sample.ConnectionGeneration { + delete(c.resumeOffers, cfg.ID) + return + } + sample = latest + // A poll may have arrived during the current write. Judge it against + // the time after that call, while still rejecting future source times. + if checkedAt := time.Now(); sample.PowerAt.After(now) && !sample.PowerAt.After(checkedAt) { + now = checkedAt + } + } if !exists { if proof.device == "" || proof.session == "" || !sample.RequestActive { return From 2682b04dc5eca8d8f8e9f569d7cfeee392757dd8 Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 06:55:37 +0200 Subject: [PATCH 13/16] fix(ev): use observed recovery evidence and recheck Stop after commands Signed-off-by: Fredrik Ahlgren --- .changeset/ev-recovery-measured-delivery.md | 2 +- go/cmd/ftw/ev_observation.go | 4 +- go/cmd/ftw/ev_observation_test.go | 17 +++++ go/internal/api/api_clamped_no_draw_test.go | 2 +- go/internal/api/api_control_feedback.go | 13 ++-- .../api/api_ev_ramping_no_draw_test.go | 67 ++++++++++++++++++ go/internal/loadpoint/controller.go | 23 +++++-- .../controller_positive_recovery_test.go | 21 +++++- go/internal/loadpoint/controller_resume.go | 68 +++++++++---------- .../controller_wake_delivery_test.go | 43 ++++++++++++ go/internal/loadpoint/manual_status.go | 4 -- 11 files changed, 210 insertions(+), 54 deletions(-) diff --git a/.changeset/ev-recovery-measured-delivery.md b/.changeset/ev-recovery-measured-delivery.md index 3f79adc77..db876fdba 100644 --- a/.changeset/ev-recovery-measured-delivery.md +++ b/.changeset/ev-recovery-measured-delivery.md @@ -2,4 +2,4 @@ "ftw": patch --- -Resume a known charging session after sustained non-delivery and keep checking until measured power returns. Set the safe current before resuming. Do not interrupt charging from a delayed vehicle status, cycle a charger after an accepted vehicle start, or wake a read-only vehicle. Show sustained zero draw even while FTW adjusts the current, and record command evidence when charging stops. +Resume a known charging session after sustained non-delivery and keep checking until measured power returns. Set the safe current before resuming. Do not interrupt charging from a delayed vehicle status, cycle a charger after an accepted vehicle start, or wake a read-only vehicle. Show sustained zero draw even while FTW adjusts the current, and record command evidence when charging stops. Keep missing power unknown and recheck Stop and the plug session after slow commands. diff --git a/go/cmd/ftw/ev_observation.go b/go/cmd/ftw/ev_observation.go index 30080ca1c..be3d1e10b 100644 --- a/go/cmd/ftw/ev_observation.go +++ b/go/cmd/ftw/ev_observation.go @@ -46,13 +46,15 @@ func currentEVSample(r *telemetry.DerReading, health *telemetry.DriverHealth, wa sample := loadpoint.EVSample{ConnectionGeneration: d.ConnectionGeneration, PowerW: r.RawW, PowerAt: r.UpdatedAt, PowerMaxAge: time.Duration(min(max(d.PowerMaxAgeS, 0), 180)) * time.Second, Connected: *d.Connected, RequestActive: active, DeviceID: deviceID, SessionID: d.SessionID, SessionWhUnavailable: d.SessionWh == nil} + _, powerKnown := telemetry.ControlPowerObservation(r.RawW, r.Data, r.UpdatedAt) + sample.PowerUnavailable = !powerKnown if d.SessionWh != nil { sample.SessionWh = *d.SessionWh } if d.PowerAt != "" { at, err := time.Parse(time.RFC3339Nano, d.PowerAt) sample.PowerAt = at - sample.PowerUnavailable = err != nil || at.After(now.Add(time.Second)) || (now.Sub(at) > sample.PowerWindow() && r.RawW > 0) + sample.PowerUnavailable = sample.PowerUnavailable || err != nil || at.After(now.Add(time.Second)) || (now.Sub(at) > sample.PowerWindow() && r.RawW > 0) } if d.EnergyAt != "" { at, err := time.Parse(time.RFC3339Nano, d.EnergyAt) diff --git a/go/cmd/ftw/ev_observation_test.go b/go/cmd/ftw/ev_observation_test.go index 383a17000..c80f4528e 100644 --- a/go/cmd/ftw/ev_observation_test.go +++ b/go/cmd/ftw/ev_observation_test.go @@ -68,3 +68,20 @@ func TestEVSourceCadenceDoesNotExtendTransportWatchdog(t *testing.T) { t.Fatal("source cadence bypassed transport watchdog") } } + +func TestEVObservationKeepsUnknownPowerSeparateFromZero(t *testing.T) { + now := time.Now() + health := &telemetry.DriverHealth{Status: telemetry.StatusOk} + for _, available := range []bool{false, true} { + data, _ := json.Marshal(map[string]any{ + "connected": true, "session_id": "same", "control_power_available": available, + "control_power_observed_at": now.Add(-5 * time.Minute).Format(time.RFC3339Nano), + "control_power_confirmed": true, + }) + r := &telemetry.DerReading{UpdatedAt: now, Data: data} + sample, ok := currentEVSample(r, health, time.Minute, now, false, "charger") + if !ok || !sample.Connected || sample.PowerUnavailable == available { + t.Fatalf("available=%t: unknown power became a measured zero or an unplug: %+v", available, sample) + } + } +} diff --git a/go/internal/api/api_clamped_no_draw_test.go b/go/internal/api/api_clamped_no_draw_test.go index d1f8293bb..017e0b649 100644 --- a/go/internal/api/api_clamped_no_draw_test.go +++ b/go/internal/api/api_clamped_no_draw_test.go @@ -26,7 +26,7 @@ func TestPositiveEVClampDoesNotHideNoPowerResponse(t *testing.T) { } { t.Run(tc.name, func(t *testing.T) { f := ControlFeedback{Kind: "ev", RequestedA: watts(15), OfferedA: watts(10), SentW: watts(tc.sent), ActualW: watts(tc.actual), ObservedAtMs: now.UnixMilli(), DeviceReason: "limited by dynamic charger current"} - cmd := telemetry.CommandEvidence{Result: "accepted", Since: now.Add(-tc.age), PowerMismatchSince: now.Add(-tc.age)} + cmd := telemetry.CommandEvidence{Result: "accepted", Since: now.Add(-tc.age), NoPowerSince: now.Add(-tc.age), NoPowerAt: now} classifyControlFeedback(&f, cmd, true, tc.fresh, tc.core, &connected, now) setControlStatus(&f) if f.Reason != tc.want { diff --git a/go/internal/api/api_control_feedback.go b/go/internal/api/api_control_feedback.go index 765f30fe1..f1547bd54 100644 --- a/go/internal/api/api_control_feedback.go +++ b/go/internal/api/api_control_feedback.go @@ -417,13 +417,12 @@ func classifyControlFeedback(f *ControlFeedback, cmd telemetry.CommandEvidence, } // A positive clamp explains the lower offer, not prolonged zero delivery. // Keep known safety pauses and unconfirmed/stale commands authoritative. - noPowerObserved := !cmd.NoPowerSince.IsZero() && cmd.NoPowerAt.Sub(cmd.NoPowerSince) >= 2*time.Minute - noPowerForCommand := !cmd.Since.IsZero() && now.Sub(cmd.Since) >= 2*time.Minute && - !cmd.PowerMismatchSince.IsZero() && now.Sub(cmd.PowerMismatchSince) >= 2*time.Minute && f.ObservedAtMs >= cmd.Since.UnixMilli() + evMismatchObserved := !cmd.PowerMismatchSince.IsZero() && cmd.LastObservation.Sub(cmd.PowerMismatchSince) >= 2*time.Minute + noPowerObserved := evMismatchObserved || !cmd.NoPowerSince.IsZero() && cmd.NoPowerAt.Sub(cmd.NoPowerSince) >= 2*time.Minute if f.Kind == "ev" && commanded && cmd.Result == "accepted" && coreReason != "site_meter_stale" && coreReason != "site_phase_currents_stale" && coreReason != "fuse_cooldown" && f.SentW != nil && *f.SentW > 100 && f.ActualW != nil && math.Abs(*f.ActualW) < 100 && - f.OfferedA != nil && *f.OfferedA > 0 && (noPowerObserved || noPowerForCommand) { + f.OfferedA != nil && *f.OfferedA > 0 && noPowerObserved { set("warning", "no_power_response", "warning") return } @@ -479,7 +478,11 @@ func classifyControlFeedback(f *ControlFeedback, cmd telemetry.CommandEvidence, if cmd.LastGapW != nil { gap = *cmd.LastGapW } - if !cmd.PowerMismatchSince.IsZero() && now.Sub(cmd.PowerMismatchSince) >= grace && gap > telemetry.ControlToleranceW(*f.SentW) { + mismatchSettled := !cmd.PowerMismatchSince.IsZero() && now.Sub(cmd.PowerMismatchSince) >= grace + if f.Kind == "ev" { + mismatchSettled = evMismatchObserved + } + if mismatchSettled && gap > telemetry.ControlToleranceW(*f.SentW) { if reason := batteryChargeLevelLimit(f); reason != "" { set("limited", reason, "info") return diff --git a/go/internal/api/api_ev_ramping_no_draw_test.go b/go/internal/api/api_ev_ramping_no_draw_test.go index 2299692f3..76c427a83 100644 --- a/go/internal/api/api_ev_ramping_no_draw_test.go +++ b/go/internal/api/api_ev_ramping_no_draw_test.go @@ -31,3 +31,70 @@ func TestEVRampingOfferDoesNotHideSustainedZeroDraw(t *testing.T) { } }) } + +func TestEVNoPowerWarningRequiresAdvancingObservations(t *testing.T) { + for _, core := range []string{"fuse_limit", "manual_hold"} { + for _, advancing := range []bool{false, true} { + t.Run(fmt.Sprintf("%s/advancing=%t", core, advancing), func(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + start := time.Now() + tel := telemetry.NewStore() + srv := New(&Deps{Tel: tel}) + cmd := tel.BeginCommand("easee", []byte(`{"action":"ev_set_current","power_w":6900}`), start) + tel.CompleteCommand(cmd, "accepted") + for i := 0; i <= 25; i++ { + at := start + if advancing { + at = time.Now() + } + tel.Update("easee", telemetry.DerEV, 0, nil, []byte(fmt.Sprintf( + `{"max_a":10,"power_max_age_s":180,"control_power_observed_at":%q}`, at.Format(time.RFC3339Nano)))) + if i < 25 { + time.Sleep(5 * time.Second) + } + } + f := srv.controlFeedback(time.Now())[0] + evidence, _ := tel.CommandEvidence("easee", "ev") + connected := true + classifyControlFeedback(&f, evidence, true, true, core, &connected, time.Now()) + want := "no_power_response" + if !advancing { + want = "waiting_response" + if core == "fuse_limit" { + want = core + } + } + if f.Reason != want { + t.Fatalf("got %s, want %s; evidence: %+v", f.Reason, want, evidence) + } + }) + }) + } + } +} + +func TestEVStartupPulseDoesNotHideAnObservedMismatch(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + tel := telemetry.NewStore() + srv := New(&Deps{Tel: tel}) + cmd := tel.BeginCommand("easee", []byte(`{"action":"ev_set_current","power_w":6900}`), time.Now()) + tel.CompleteCommand(cmd, "accepted") + for i := 0; i <= 25; i++ { + power := 0.0 + if i == 20 { + power = 299 + } + tel.Update("easee", telemetry.DerEV, power, nil, []byte(`{"max_a":10}`)) + if i < 25 { + time.Sleep(5 * time.Second) + } + } + f := srv.controlFeedback(time.Now())[0] + evidence, _ := tel.CommandEvidence("easee", "ev") + connected := true + classifyControlFeedback(&f, evidence, true, true, "fuse_limit", &connected, time.Now()) + if f.Reason != "no_power_response" { + t.Fatalf("startup pulse hid a two-minute measured shortfall: %+v", f) + } + }) +} diff --git a/go/internal/loadpoint/controller.go b/go/internal/loadpoint/controller.go index 3dec44bba..23f3caeef 100644 --- a/go/internal/loadpoint/controller.go +++ b/go/internal/loadpoint/controller.go @@ -41,7 +41,7 @@ type Controller struct { // registry owns cross-command serialization and lifecycle cancellation. commandTimeout time.Duration wallboxCycleSeq atomic.Uint64 - resumeOffers map[string]resumeOffer // owned by the dispatch tick + resumeOffers map[string]*resumeOffer // owned by the dispatch tick energySamples map[string]*meteredEnergy // fuseEVMax is this tick's EV share of the site fuse. nil means no cap. @@ -1605,8 +1605,6 @@ func (c *Controller) tickOne(ctx context.Context, now time.Time, lpCfg Config, s if sendErr != nil { slog.Warn("loadpoint dispatch", "lp", lpCfg.ID, "driver", lpCfg.DriverName, "err", sendErr) - } - if sendErr != nil { // Never start wake work from a command that did not complete. In // particular, a timeout may still be unwinding inside the registry; // its per-driver owner restores default before another command runs. @@ -1621,6 +1619,16 @@ func (c *Controller) tickOne(ctx context.Context, now time.Time, lpCfg Config, s // wake side effects of a dispatch that Core has just rejected. return } + // The current write can block while Stop or new charger data arrives. + // Reuse the same session check for recovery and vehicle wake work. + latest, checkedAt, live := c.currentChargeSample(now, lpCfg, sample) + if !live { + if offerW > 0 { + delete(c.resumeOffers, lpCfg.ID) + } + return + } + sample, now = latest, checkedAt // Establish the safe current before reopening a paused session. The // charger may still retain a higher limit from before our standdown. if haveOffer && offerW > 0 { @@ -1639,10 +1647,11 @@ func (c *Controller) maybeWakeVehicle(ctx context.Context, now time.Time, lpCfg if c == nil || c.send == nil { return } + var live bool + sample, now, live = c.currentChargeSample(now, lpCfg, sample) // Vehicle APIs can lag the charger by minutes. Do not interrupt measured // delivery, or turn missing charger power into evidence of a sleeping car. - if sample.PowerUnavailable || !finite(sample.PowerW) || sample.PowerW >= DeliveringW || - sample.PowerAt.After(now) || (!sample.PowerAt.IsZero() && now.Sub(sample.PowerAt) > sample.PowerWindow()) { + if !live || !chargerIdleForWake(sample, now) { return } pw, _ := cmd["power_w"].(float64) @@ -1753,6 +1762,10 @@ func (c *Controller) maybeWakeVehicle(ctx context.Context, now time.Time, lpCfg // driver implementing the standard ev_pause / ev_resume actions // gets this for free. // + latest, checkedAt, live := c.currentChargeSample(now, lpCfg, sample) + if !live || !chargerIdleForWake(latest, checkedAt) { + return + } c.cycleWallbox(lpID, lpCfg.DriverName) } diff --git a/go/internal/loadpoint/controller_positive_recovery_test.go b/go/internal/loadpoint/controller_positive_recovery_test.go index 0fac700dd..e8c144920 100644 --- a/go/internal/loadpoint/controller_positive_recovery_test.go +++ b/go/internal/loadpoint/controller_positive_recovery_test.go @@ -86,7 +86,7 @@ func TestPositiveOfferRecoveryWithoutPriorZero(t *testing.T) { } func TestRecoveryRechecksStopAndSessionAfterCurrentWrite(t *testing.T) { - for _, boundary := range []string{"stop", "unplug", "session", "unknown", "started drawing"} { + for _, boundary := range []string{"stop", "unplug", "session", "unknown", "started drawing", "stop during resume", "drawing during resume"} { t.Run(boundary, func(t *testing.T) { now := time.Now() cfg := Config{ID: "garage", DriverName: "easee", MinChargeW: 4140, MaxChargeW: 10350} @@ -96,6 +96,7 @@ func TestRecoveryRechecksStopAndSessionAfterCurrentWrite(t *testing.T) { sender := &fakeSender{} c := newTestController(t, []Config{cfg}, dir, samples, sender) c.Tick(context.Background(), now) + c.SetVehicleStatus(func(string) (string, string, bool) { return "tesla", "Stopped", true }) dir.LoadpointEnergyWh[cfg.ID] = 10350 c.send = func(ctx context.Context, driver string, payload []byte) error { var command struct { @@ -105,6 +106,15 @@ func TestRecoveryRechecksStopAndSessionAfterCurrentWrite(t *testing.T) { if err := json.Unmarshal(payload, &command); err != nil { return err } + if command.Action == "ev_resume" { + switch boundary { + case "stop during resume": + c.SetManualHold(cfg.ID, ManualHold{PowerW: 0, Persistent: true}) + case "drawing during resume": + sample.PowerW = 4712 + } + samples[cfg.DriverName] = sample + } if command.Action == "ev_set_current" && command.PowerW > 0 { switch boundary { case "stop": @@ -123,9 +133,16 @@ func TestRecoveryRechecksStopAndSessionAfterCurrentWrite(t *testing.T) { return sender.Send(ctx, driver, payload) } c.Tick(context.Background(), now.Add(5*time.Second)) - if countAction(sender.calls, "ev_resume") != 0 { + wantResumes := 0 + if boundary == "stop during resume" || boundary == "drawing during resume" { + wantResumes = 1 + } + if countAction(sender.calls, "ev_resume") != wantResumes { t.Fatalf("resume crossed %s during current write", boundary) } + if countAction(sender.calls, "charge_start") != 0 || countAction(sender.calls, "ev_pause") != 0 { + t.Fatalf("vehicle wake crossed %s during current write", boundary) + } }) } } diff --git a/go/internal/loadpoint/controller_resume.go b/go/internal/loadpoint/controller_resume.go index 523012a25..6da320de4 100644 --- a/go/internal/loadpoint/controller_resume.go +++ b/go/internal/loadpoint/controller_resume.go @@ -22,51 +22,57 @@ type resumeOffer struct { // one timestamp still cannot advance either delivery or no-draw proof. const resumeObservationGap = 15 * time.Second +// Commands may block while Stop or a new plug session arrives. Use this +// check after either charger dispatch or a vehicle start attempt. +func (c *Controller) currentChargeSample(now time.Time, cfg Config, previous EVSample) (EVSample, time.Time, bool) { + if hold, held := c.GetManualHold(cfg.ID, now); held && hold.PowerW == 0 { + return EVSample{}, now, false + } + if c.tel == nil { + return previous, now, true + } + sample, live := c.tel(cfg.DriverName) + if !live || !sample.Connected || sample.ConnectionUnknown || sample.DeviceID != previous.DeviceID || + sample.SessionID != previous.SessionID || sample.ConnectionGeneration != previous.ConnectionGeneration { + return sample, now, false + } + if checkedAt := time.Now(); sample.PowerAt.After(now) && !sample.PowerAt.After(checkedAt) { + now = checkedAt + } + return sample, now, true +} + +func chargerIdleForWake(sample EVSample, now time.Time) bool { + return !sample.PowerUnavailable && finite(sample.PowerW) && sample.PowerW < DeliveringW && + !sample.PowerAt.After(now) && (sample.PowerAt.IsZero() || now.Sub(sample.PowerAt) <= sample.PowerWindow()) +} + // recoverOfferedCharge resumes our zero offer, or a known plug session that // still asks for charge after two minutes of accepted positive offers without // delivery. The current limit must succeed before this optional resume. Only // measured delivery ends recovery; an acknowledgement is not a charge. func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sample EVSample, offerW float64, now time.Time) { if c.resumeOffers == nil { - c.resumeOffers = make(map[string]resumeOffer) + c.resumeOffers = make(map[string]*resumeOffer) } proof := resumeOffer{driver: cfg.DriverName, device: sample.DeviceID, session: sample.SessionID, generation: sample.ConnectionGeneration} - previous, exists := c.resumeOffers[cfg.ID] - if previous.driver != proof.driver || previous.device != proof.device || previous.session != proof.session || previous.generation != proof.generation { + previous := c.resumeOffers[cfg.ID] + if previous != nil && (previous.driver != proof.driver || previous.device != proof.device || previous.session != proof.session || previous.generation != proof.generation) { delete(c.resumeOffers, cfg.ID) - exists = false + previous = nil } if offerW <= 0 { proof.zeroOffer = true - c.resumeOffers[cfg.ID] = proof - return - } - // The current write can block while a Stop or socket change arrives. - // Recheck before reopening the contactor, using the newest observation. - if hold, held := c.GetManualHold(cfg.ID, now); held && hold.PowerW == 0 { - delete(c.resumeOffers, cfg.ID) + c.resumeOffers[cfg.ID] = &proof return } - if c.tel != nil { - latest, live := c.tel(cfg.DriverName) - if !live || !latest.Connected || latest.ConnectionUnknown || latest.DeviceID != sample.DeviceID || - latest.SessionID != sample.SessionID || latest.ConnectionGeneration != sample.ConnectionGeneration { - delete(c.resumeOffers, cfg.ID) - return - } - sample = latest - // A poll may have arrived during the current write. Judge it against - // the time after that call, while still rejecting future source times. - if checkedAt := time.Now(); sample.PowerAt.After(now) && !sample.PowerAt.After(checkedAt) { - now = checkedAt - } - } - if !exists { + if previous == nil { if proof.device == "" || proof.session == "" || !sample.RequestActive { return } - previous = proof + previous = &proof previous.noDrawSince = now + c.resumeOffers[cfg.ID] = previous } if !previous.zeroOffer && !sample.RequestActive { delete(c.resumeOffers, cfg.ID) @@ -90,7 +96,6 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl if !fresh || !finite(sample.PowerW) { previous.deliverySince, previous.deliveryAt = time.Time{}, time.Time{} previous.noDrawSince, previous.noDrawAt = time.Time{}, time.Time{} - c.resumeOffers[cfg.ID] = previous return } if sample.PowerW >= floor { @@ -100,8 +105,6 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl previous.deliveryAt = observedAt if observedAt.Sub(previous.deliverySince) >= 10*time.Second { delete(c.resumeOffers, cfg.ID) - } else { - c.resumeOffers[cfg.ID] = previous } return // Already drawing: observe it rather than sending another resume. } @@ -112,12 +115,10 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl previous.noDrawSince = now } previous.noDrawAt = observedAt - c.resumeOffers[cfg.ID] = previous if previous.noDrawAt.Sub(previous.noDrawSince) < 2*time.Minute { return } } - c.resumeOffers[cfg.ID] = previous if now.Before(previous.nextAttempt) { return } @@ -125,14 +126,12 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl if previous.acknowledgedAttempts == 3 { slog.Warn("loadpoint resume acknowledged but no charge observed", "lp", cfg.ID, "driver", cfg.DriverName) previous.acknowledgedAttempts++ - c.resumeOffers[cfg.ID] = previous } return } if err := c.sendDispatchWithDeadline(ctx, cfg.DriverName, []byte(`{"action":"ev_resume"}`)); err != nil { previous.retryDelay = min(time.Minute, max(5*time.Second, 2*previous.retryDelay)) previous.nextAttempt = now.Add(previous.retryDelay) - c.resumeOffers[cfg.ID] = previous slog.Warn("loadpoint resume failed", "lp", cfg.ID, "driver", cfg.DriverName, "retry_at", previous.nextAttempt, "err", err) return @@ -145,5 +144,4 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl "attempt", previous.acknowledgedAttempts, "offer_w", offerW, "observed_w", sample.PowerW, "power_at", sample.PowerAt) previous.nextAttempt = now.Add(30 * time.Second) previous.retryDelay = 0 - c.resumeOffers[cfg.ID] = previous } diff --git a/go/internal/loadpoint/controller_wake_delivery_test.go b/go/internal/loadpoint/controller_wake_delivery_test.go index 37756a7be..7feb67d48 100644 --- a/go/internal/loadpoint/controller_wake_delivery_test.go +++ b/go/internal/loadpoint/controller_wake_delivery_test.go @@ -2,6 +2,7 @@ package loadpoint import ( "context" + "errors" "math" "testing" "testing/synctest" @@ -90,3 +91,45 @@ func TestAcceptedVehicleStartDoesNotPauseCharger(t *testing.T) { } }) } + +func TestWakeRechecksAfterVehicleStartRefusal(t *testing.T) { + for _, boundary := range []string{"stop", "unplug", "session", "unknown", "charging", "missing power"} { + t.Run(boundary, func(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + now := time.Now() + sender := &outcomeSender{errFor: map[string]error{"tesla": errors.New("vehicle refused start")}} + c, cfg, _ := outcomeFixture(t, now, sender) + sample := EVSample{Connected: true, RequestActive: true, DeviceID: "charger", SessionID: "one", PowerAt: now} + c.tel = func(string) (EVSample, bool) { return sample, true } + c.SetVehicleStatus(func(string) (string, string, bool) { return "tesla", "Stopped", true }) + c.send = func(ctx context.Context, driver string, payload []byte) error { + if driver == "tesla" { + switch boundary { + case "stop": + c.SetManualHold(cfg.ID, ManualHold{PowerW: 0, Persistent: true}) + case "unplug": + sample.Connected = false + case "session": + sample.SessionID = "two" + case "unknown": + sample.ConnectionUnknown = true + case "charging": + sample.PowerW = 4712 + case "missing power": + sample.PowerUnavailable = true + } + } + return sender.Send(ctx, driver, payload) + } + c.Tick(context.Background(), now) + time.Sleep(wallboxCycleGap) + synctest.Wait() + for _, call := range sender.sent() { + if call.action == "ev_pause" || call.action == "ev_resume" { + t.Fatalf("charger cycle crossed %s during vehicle start: %+v", boundary, call) + } + } + }) + }) + } +} diff --git a/go/internal/loadpoint/manual_status.go b/go/internal/loadpoint/manual_status.go index c1654b2ad..427160876 100644 --- a/go/internal/loadpoint/manual_status.go +++ b/go/internal/loadpoint/manual_status.go @@ -205,14 +205,10 @@ func ManualStatusFrom(h ManualHold, held bool, st State, ch ChargerReading, now m.State = ManualSent case st.CurrentPowerW >= manualChargingFloorW: m.State = ManualCharging - if clamp { - m.LimitReason = st.CommandedReason - } case limitMatches && m.CommandedW >= manualChargingFloorW && elapsed >= manualAcceptGrace: m.State = ManualNotDrawing case clamp: m.State = ManualLimited - m.LimitReason = st.CommandedReason case limitMatches && elapsed >= manualAcceptGrace: m.State = ManualNotDrawing case limitMatches: From a4265936b5c24aa7bbc6c4a16e1b51415583776c Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 06:57:19 +0200 Subject: [PATCH 14/16] refactor(ev): reuse the checked power sample Signed-off-by: Fredrik Ahlgren --- go/cmd/ftw/ev_observation.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/go/cmd/ftw/ev_observation.go b/go/cmd/ftw/ev_observation.go index be3d1e10b..949687145 100644 --- a/go/cmd/ftw/ev_observation.go +++ b/go/cmd/ftw/ev_observation.go @@ -46,7 +46,7 @@ func currentEVSample(r *telemetry.DerReading, health *telemetry.DriverHealth, wa sample := loadpoint.EVSample{ConnectionGeneration: d.ConnectionGeneration, PowerW: r.RawW, PowerAt: r.UpdatedAt, PowerMaxAge: time.Duration(min(max(d.PowerMaxAgeS, 0), 180)) * time.Second, Connected: *d.Connected, RequestActive: active, DeviceID: deviceID, SessionID: d.SessionID, SessionWhUnavailable: d.SessionWh == nil} - _, powerKnown := telemetry.ControlPowerObservation(r.RawW, r.Data, r.UpdatedAt) + _, powerKnown := telemetry.ControlPowerObservation(sample.PowerW, r.Data, r.UpdatedAt) sample.PowerUnavailable = !powerKnown if d.SessionWh != nil { sample.SessionWh = *d.SessionWh From 3b6ff98a40a1e4d126927e5f0e2567f5825432f2 Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 07:01:21 +0200 Subject: [PATCH 15/16] refactor(ev): skip recovery state for normal charging Signed-off-by: Fredrik Ahlgren --- go/internal/loadpoint/controller_resume.go | 19 ++++++++----------- 1 file changed, 8 insertions(+), 11 deletions(-) diff --git a/go/internal/loadpoint/controller_resume.go b/go/internal/loadpoint/controller_resume.go index 6da320de4..fe8577737 100644 --- a/go/internal/loadpoint/controller_resume.go +++ b/go/internal/loadpoint/controller_resume.go @@ -66,8 +66,15 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl c.resumeOffers[cfg.ID] = &proof return } + // Ten seconds near the supported minimum prove recovery. A normal + // charge with no recovery in progress needs no retry record at all. + minimum := cfg.MinChargeW + if minimum <= 0 { + minimum = offerW + } + floor := math.Max(DeliveringW, 0.9*math.Min(minimum, offerW)) if previous == nil { - if proof.device == "" || proof.session == "" || !sample.RequestActive { + if proof.device == "" || proof.session == "" || !sample.RequestActive || sample.PowerW >= floor { return } previous = &proof @@ -78,16 +85,6 @@ func (c *Controller) recoverOfferedCharge(ctx context.Context, cfg Config, sampl delete(c.resumeOffers, cfg.ID) return } - // A small startup pulse is not successful recovery. Require fresh, - // advancing observations near a supported charging step for ten seconds. - // The current offer can be lower than the configured 3p minimum after a - // phase change. Leave the shared DeliveringW semantics unchanged. - minimum := cfg.MinChargeW - if minimum <= 0 { - minimum = offerW - } - // Allow ten percent variation around the nominal-voltage minimum. - floor := math.Max(DeliveringW, 0.9*math.Min(minimum, offerW)) observedAt := sample.PowerAt if observedAt.IsZero() { observedAt = now // Legacy telemetry uses the fresh-read contract. From e89f27a2a94bee811195e6ac515e741adc2e565d Mon Sep 17 00:00:00 2001 From: Fredrik Ahlgren Date: Sun, 18 Oct 2026 07:03:43 +0200 Subject: [PATCH 16/16] fix(ev): describe missing vehicle charge control Signed-off-by: Fredrik Ahlgren --- go/internal/api/api_loadpoint_vehicle.go | 2 +- go/internal/loadpoint/controller.go | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/go/internal/api/api_loadpoint_vehicle.go b/go/internal/api/api_loadpoint_vehicle.go index 6659c186c..a2aff8c1c 100644 --- a/go/internal/api/api_loadpoint_vehicle.go +++ b/go/internal/api/api_loadpoint_vehicle.go @@ -58,7 +58,7 @@ func (s *Server) handleLoadpointForceStart(w http.ResponseWriter, r *http.Reques writeJSON(w, 404, map[string]string{"error": "loadpoint not found", "loadpoint_id": id}) return case errors.Is(err, loadpoint.ErrForceStartNoVehicleBound): - writeJSON(w, 422, map[string]string{"error": "no vehicle driver bound to loadpoint", "loadpoint_id": id}) + writeJSON(w, 422, map[string]string{"error": "no vehicle driver with charge control bound to loadpoint", "loadpoint_id": id}) return case err != nil: // Generic 502 — do NOT surface the underlying driver error diff --git a/go/internal/loadpoint/controller.go b/go/internal/loadpoint/controller.go index 23f3caeef..472cb253a 100644 --- a/go/internal/loadpoint/controller.go +++ b/go/internal/loadpoint/controller.go @@ -814,7 +814,7 @@ func (c *Controller) RefreshVehicle(ctx context.Context, lpID string) error { var ( ErrForceStartNotReady = errors.New("loadpoint controller not ready (missing vehicleStatus/send wiring)") ErrForceStartLoadpointGone = errors.New("loadpoint not found") - ErrForceStartNoVehicleBound = errors.New("no vehicle driver bound to loadpoint") + ErrForceStartNoVehicleBound = errors.New("no vehicle driver with charge control bound to loadpoint") ) // ForceStartVehicle sends charge_start now, past the auto-wake backoff.