diff --git a/.changeset/driver-failure-reaches-default.md b/.changeset/driver-failure-reaches-default.md new file mode 100644 index 00000000..dfd7ba9e --- /dev/null +++ b/.changeset/driver-failure-reaches-default.md @@ -0,0 +1,5 @@ +--- +"ftw": patch +--- + +A driver that cannot actuate now receives its autonomous default mode, and leaves dispatch and the plan while it can't. Two cases were missed before. A driver that reports a device fault — a Ferroamp EnergyHub in Fault Mode with its relays open, a Pixii mid-calibration — kept polling, so the staleness watchdog saw nothing wrong and never asked it for its safe state; it was dropped from dispatch and held its last setpoint indefinitely. And a driver that answered every poll but rejected every command stayed marked healthy, so it stayed in the dispatch set and in the MPC fleet, and the power the plan counted on but never got became grid import instead. Three refused commands in a row now take a driver out of control until it accepts one again, with one command let through every five minutes so a device that recovers on its own comes back without an operator. Both cases send the driver's own declared default exactly once per transition, and both re-arm on recovery. `observe_only` drivers still receive no command of any kind. diff --git a/go/cmd/ftw/driver_command_deadline.go b/go/cmd/ftw/driver_command_deadline.go index 2f2048e5..42f5357a 100644 --- a/go/cmd/ftw/driver_command_deadline.go +++ b/go/cmd/ftw/driver_command_deadline.go @@ -51,10 +51,11 @@ func driverCommandTimeout(controlInterval time.Duration) time.Duration { return timeout } -// sendDriverCommand sends one dispatch command under its own deadline. -// A timeout is logged at Warn with the driver name so a chronically slow -// driver shows up in the log instead of quietly eating tick cadence; -// kind names the dispatch path ("driver send", "pv curtail send"). +// sendDriverCommand sends one dispatch command under its own deadline and +// returns what the driver made of it. A timeout is logged at Warn with the +// driver name so a chronically slow driver shows up in the log instead of +// quietly eating tick cadence; kind names the dispatch path ("driver send", +// "pv curtail send"). // // A timeout is deliberately not recorded as a driver failure. The driver // goroutine serialises polls and commands, so a driver wedged inside @@ -62,7 +63,8 @@ func driverCommandTimeout(controlInterval time.Duration) time.Duration { // watchdog already walks it to its autonomous default mode. Counting the // timeout separately would double-book the same fault and could push a // merely slow cloud driver out of control on one bad round trip. -func sendDriverCommand(ctx context.Context, reg driverCommandSender, kind, name string, payload []byte, timeout time.Duration) { +// driverActuationTracker applies the same rule to the error it returns. +func sendDriverCommand(ctx context.Context, reg driverCommandSender, kind, name string, payload []byte, timeout time.Duration) error { cmdCtx, cancel := context.WithTimeout(ctx, timeout) defer cancel() err := reg.Send(cmdCtx, name, payload) @@ -73,4 +75,5 @@ func sendDriverCommand(ctx context.Context, reg driverCommandSender, kind, name default: slog.Warn(kind, "name", name, "err", err) } + return err } diff --git a/go/cmd/ftw/driver_failure_default.go b/go/cmd/ftw/driver_failure_default.go new file mode 100644 index 00000000..eb89b92f --- /dev/null +++ b/go/cmd/ftw/driver_failure_default.go @@ -0,0 +1,245 @@ +package main + +import ( + "context" + "errors" + "log/slog" + "sort" + "time" + + "github.com/srcfl/ftw/go/internal/drivers" + "github.com/srcfl/ftw/go/internal/telemetry" +) + +// The invariant this file serves: "a failed/stale driver receives its +// autonomous default mode." The watchdog covers stale. This covers failed — +// a driver that answers every poll but cannot put power where core asked. +// +// Two conditions reach it, and they are the same condition seen from +// opposite ends of the wire: +// +// - the driver says so, via host.set_device_fault: a Ferroamp EnergyHub +// in Fault Mode with its relays open, a Pixii mid-calibration; +// - core sees it, because the driver refused the commands core sent. +// A driver that answers polls and rejects writes stays Status=ok, so +// nothing else notices; it sits in the dispatch set and in the MPC +// fleet holding whatever setpoint it last accepted, and the power the +// plan is counting on silently becomes grid import. +// +// Both land in telemetry as DeviceFault, so IsOnline() — the predicate the +// dispatcher and the planner already share — drops the driver from both. +// This tracker's own job is the other half: walk it to its declared default +// exactly once per transition, and re-arm when it can actuate again. +// +// Only dispatch commands are counted, never the default release itself. A +// driver that rejects the default is reporting that it was never under +// control — see set_self_consumption in sungrow.lua, which returns the +// default as held rather than failed for exactly that case — and nothing +// here escalates on it. + +const ( + // driverRefusalLimit is how many refused dispatch commands in a row + // mark a driver as unable to actuate. Three, matching + // DriverHealth.RecordError's degrade threshold: a single rejected + // Modbus write is a normal event on a busy device, three in a row at + // control cadence is not. + driverRefusalLimit = 3 + + // driverRefusalRetryInterval is how long an excluded driver stays out + // before one command is let through to test it again. A refusal is not + // always permanent — an inverter can reject writes through a firmware + // restart or a grid-code ride-through and take them again afterwards — + // so the exclusion must not need an operator to end it. Long enough + // that a device that stays broken sees one command per five minutes + // rather than one per second. + driverRefusalRetryInterval = 5 * time.Minute + + // driverCannotActuateReason labels the default requests this tracker + // makes, next to the watchdog's "watchdog" and the freshness gate's + // site_meter_stale. + driverCannotActuateReason = "driver_cannot_actuate" +) + +// driverActuationTracker emits one DefaultMode request per driver that has +// stopped being able to actuate, and re-arms when it recovers. Same shape as +// staleSiteDefaultTracker, which does this per site-meter transition; this +// one is per driver. +// +// Not safe for concurrent use: both methods run on the control-loop +// goroutine, recordCommandOutcome during dispatch and update at the top of +// the following tick. +type driverActuationTracker struct { + tel *telemetry.Store + refusals map[string]refusalState + defaulted map[string]struct{} +} + +type refusalState struct { + consecutive int + reason string + // excludedAt is when the driver was last put out of dispatch, and + // zero while it is still in. It dates the retry window. + excludedAt time.Time +} + +func newDriverActuationTracker(tel *telemetry.Store) *driverActuationTracker { + return &driverActuationTracker{ + tel: tel, + refusals: map[string]refusalState{}, + defaulted: map[string]struct{}{}, + } +} + +// dispatchCommand sends one dispatch command and files what the driver made +// of it. Wraps sendDriverCommand so the dispatch loop has one call, not two. +func (t *driverActuationTracker) dispatchCommand( + ctx context.Context, + reg driverCommandSender, + kind, name string, + payload []byte, + timeout time.Duration, + now time.Time, +) { + t.recordCommandOutcome(name, sendDriverCommand(ctx, reg, kind, name, payload, timeout), now) +} + +// recordCommandOutcome files the result of one dispatch command. Only a +// refusal counts; see isCommandRefusal for what does not. +func (t *driverActuationTracker) recordCommandOutcome(name string, err error, now time.Time) { + if t == nil || t.tel == nil { + return + } + if err == nil { + if _, tracked := t.refusals[name]; tracked { + delete(t.refusals, name) + t.tel.SetDriverCommandFault(name, false, "") + } + return + } + if !isCommandRefusal(err) { + return + } + if t.refusals == nil { + t.refusals = map[string]refusalState{} + } + st := t.refusals[name] + st.consecutive++ + st.reason = err.Error() + if st.consecutive >= driverRefusalLimit && st.excludedAt.IsZero() { + st.excludedAt = now + t.tel.SetDriverCommandFault(name, true, st.reason) + } + t.refusals[name] = st +} + +// update walks every driver that cannot actuate to its autonomous default, +// once per transition, and returns the names to send it to. It also ends the +// retry window for drivers excluded long enough to deserve another try. +// +// observeOnly drivers are never returned. A telemetry-only driver must +// receive no command at all, and that includes the safe one: core has no +// mandate over a device it was only asked to watch, and the "default" it +// would send is a write to an inverter somebody else is controlling. +func (t *driverActuationTracker) update(now time.Time, observeOnly map[string]bool) []string { + if t == nil || t.tel == nil { + return nil + } + health := t.tel.AllHealth() + + for name, st := range t.refusals { + if _, known := health[name]; !known { + // Driver removed or restarted: its health record went with + // it, and so did the fault. Start it over clean. + delete(t.refusals, name) + delete(t.defaulted, name) + continue + } + if st.excludedAt.IsZero() || now.Sub(st.excludedAt) < driverRefusalRetryInterval { + continue + } + // Retry window is up. Let one command through: a single fresh + // refusal puts the driver straight back out, an accepted one + // clears the record entirely. + st.consecutive = driverRefusalLimit - 1 + st.excludedAt = time.Time{} + t.refusals[name] = st + t.tel.SetDriverCommandFault(name, false, "") + // health holds copies, so apply the release to this tick's + // snapshot too — otherwise the latch below reads the driver as + // still faulted and defaults a driver we just let back in. + if h, ok := health[name]; ok { + h.SetCommandFault(false, "") + health[name] = h + } + slog.Info("driver exclusion retry window elapsed — letting one command through", + "driver", name, "window", driverRefusalRetryInterval) + } + + var pending []string + for name, h := range health { + if !h.DeviceFault { + continue + } + if observeOnly[name] { + continue + } + if h.Status == telemetry.StatusOffline { + // Stale is the watchdog's transition to own, and it has + // already sent this driver its default this tick. + continue + } + if _, done := t.defaulted[name]; done { + continue + } + if t.defaulted == nil { + t.defaulted = map[string]struct{}{} + } + t.defaulted[name] = struct{}{} + pending = append(pending, name) + slog.Warn("driver cannot actuate — reverting it to its autonomous default", + "driver", name, "reason", h.DeviceFaultReason) + } + + for name := range t.defaulted { + h, known := health[name] + if known && h.DeviceFault { + continue + } + delete(t.defaulted, name) + if known { + slog.Info("driver can actuate again — back in dispatch", "driver", name) + } + } + + sort.Strings(pending) + return pending +} + +// isCommandRefusal separates "this device rejected the write" from the other +// ways a Send can fail. Each exclusion is a fault somebody else already owns, +// and counting it here would book it twice: +// +// - observe_only: the registry refused on the driver's behalf and never +// touched the device. It says nothing about the hardware; +// - control blocked: the registry is already holding this driver in its +// default and retrying with backoff; +// - deadline/cancel: a driver wedged in device I/O stops emitting +// telemetry too, and the staleness watchdog walks it to its default. +// Same reasoning as sendDriverCommand's timeout handling — a slow cloud +// driver must not lose control over one bad round trip. +// +// ErrCommandMayHaveRun is not an exclusion: the registry wraps a genuine +// refusal in it, and errors.Is sees the cause through Unwrap. +func isCommandRefusal(err error) bool { + switch { + case err == nil: + return false + case errors.Is(err, drivers.ErrObserveOnly): + return false + case errors.Is(err, drivers.ErrControlBlocked): + return false + case errors.Is(err, context.DeadlineExceeded), errors.Is(err, context.Canceled): + return false + } + return true +} diff --git a/go/cmd/ftw/driver_failure_default_test.go b/go/cmd/ftw/driver_failure_default_test.go new file mode 100644 index 00000000..c0675c9d --- /dev/null +++ b/go/cmd/ftw/driver_failure_default_test.go @@ -0,0 +1,251 @@ +package main + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/srcfl/ftw/go/internal/drivers" + "github.com/srcfl/ftw/go/internal/telemetry" +) + +// pollingStore stands up a driver that is answering polls normally: fresh +// telemetry, Status ok, nothing the staleness watchdog would ever act on. +func pollingStore(t *testing.T, names ...string) *telemetry.Store { + t.Helper() + tel := telemetry.NewStore() + for _, name := range names { + soc := 0.5 + tel.Update(name, telemetry.DerBattery, 0, &soc, nil) + tel.DriverHealthMut(name).RecordSuccess() + } + return tel +} + +// Hole (a): a driver that polls fine and flags DeviceFault produced no +// watchdog transition — WatchdogScan keys on LastSuccess only — so it was +// dropped from dispatch and then held its last setpoint forever. Nothing +// ever asked it for its declared safe state. +func TestDeviceFaultReachesDefaultOncePerTransition(t *testing.T) { + tel := pollingStore(t, "ferroamp") + tracker := newDriverActuationTracker(tel) + now := time.Now() + + if pending := tracker.update(now, nil); len(pending) != 0 { + t.Fatalf("healthy driver was sent a default: %v", pending) + } + + tel.SetDriverDeviceFault("ferroamp", true, "EnergyHub Fault Mode") + assertStringsEqual(t, tracker.update(now, nil), []string{"ferroamp"}) + + // The driver re-asserts the fault on every poll. That must not turn + // into one default command per control tick. + for i := 0; i < 5; i++ { + now = now.Add(time.Second) + tel.SetDriverDeviceFault("ferroamp", true, "EnergyHub Fault Mode") + if pending := tracker.update(now, nil); len(pending) != 0 { + t.Fatalf("tick %d re-sent the default: %v", i, pending) + } + } + + // Recovery re-arms the latch; the next fault is protected again. + tel.SetDriverDeviceFault("ferroamp", false, "") + if pending := tracker.update(now.Add(time.Second), nil); len(pending) != 0 { + t.Fatalf("recovery sent a default: %v", pending) + } + tel.SetDriverDeviceFault("ferroamp", true, "EnergyHub Fault Mode again") + assertStringsEqual(t, tracker.update(now.Add(2*time.Second), nil), []string{"ferroamp"}) +} + +// A stale driver is the watchdog's transition. It has already sent that +// driver its default this tick; the tracker must not send a second one. +func TestStaleDriverIsLeftToTheWatchdog(t *testing.T) { + tel := pollingStore(t, "ferroamp") + tracker := newDriverActuationTracker(tel) + now := time.Now() + + tel.SetDriverDeviceFault("ferroamp", true, "EnergyHub Fault Mode") + tel.WatchdogScan(time.Nanosecond) // walk it offline the way staleness does + + if pending := tracker.update(now, nil); len(pending) != 0 { + t.Fatalf("stale driver got a second default: %v", pending) + } +} + +// An observe_only driver must receive no command at all, and that includes +// the safe one — core has no mandate over a device it was only asked to +// watch. +func TestObserveOnlyDriverNeverReceivesADefault(t *testing.T) { + tel := pollingStore(t, "neighbour-inverter") + tracker := newDriverActuationTracker(tel) + + tel.SetDriverDeviceFault("neighbour-inverter", true, "fault mode") + pending := tracker.update(time.Now(), map[string]bool{"neighbour-inverter": true}) + if len(pending) != 0 { + t.Fatalf("observe_only driver was sent a default: %v", pending) + } +} + +// Hole (b): a driver that answers every poll and rejects every command kept +// Status=ok, so it stayed in the dispatch set and in the MPC fleet. The plan +// went on counting on power it never delivered, and the shortfall became +// grid import. +func TestRefusedCommandsExcludeDriverAndReachTheDefaultOnce(t *testing.T) { + tel := pollingStore(t, "sungrow") + tracker := newDriverActuationTracker(tel) + refuse := &stubSender{handler: func(ctx context.Context, name string) error { + return errors.New("modbus write refused") + }} + now := time.Now() + payload := []byte(`{"action":"battery","power_w":-2000}`) + + // A single refusal is a normal event on a busy device. + tracker.dispatchCommand(context.Background(), refuse, "driver send", "sungrow", payload, time.Second, now) + if h := tel.DriverHealth("sungrow"); !h.IsOnline() { + t.Fatal("one refused write dropped the battery out of control") + } + + for i := 1; i < driverRefusalLimit; i++ { + now = now.Add(time.Second) + tracker.dispatchCommand(context.Background(), refuse, "driver send", "sungrow", payload, time.Second, now) + } + + h := tel.DriverHealth("sungrow") + if h.IsOnline() { + t.Fatalf("driver refused %d commands in a row and is still counted as controllable", + driverRefusalLimit) + } + // IsOnline is the predicate ComputeDispatch and the MPC fleet share, so + // this is what drops it from both. Status stays ok: it is still talking. + if h.Status != telemetry.StatusOk { + t.Errorf("Status = %v, want ok — the driver is answering polls", h.Status) + } + if h.DeviceFaultReason == "" { + t.Error("exclusion carries no operator-facing reason") + } + + assertStringsEqual(t, tracker.update(now, nil), []string{"sungrow"}) + if pending := tracker.update(now.Add(time.Second), nil); len(pending) != 0 { + t.Fatalf("a driver held out of dispatch was defaulted again: %v", pending) + } +} + +// The exclusion must not need an operator to end it: a device can reject +// writes through a firmware restart and take them again afterwards. +func TestExcludedDriverIsRetriedAndRecovers(t *testing.T) { + tel := pollingStore(t, "sungrow") + tracker := newDriverActuationTracker(tel) + refusing := true + sender := &stubSender{handler: func(ctx context.Context, name string) error { + if refusing { + return errors.New("modbus write refused") + } + return nil + }} + now := time.Now() + payload := []byte(`{"action":"battery","power_w":-2000}`) + + for i := 0; i < driverRefusalLimit; i++ { + tracker.dispatchCommand(context.Background(), sender, "driver send", "sungrow", payload, time.Second, now) + } + tracker.update(now, nil) + if tel.DriverHealth("sungrow").IsOnline() { + t.Fatal("driver was not excluded") + } + + // Still inside the retry window. + tracker.update(now.Add(driverRefusalRetryInterval-time.Second), nil) + if tel.DriverHealth("sungrow").IsOnline() { + t.Fatal("exclusion ended before the retry window") + } + + now = now.Add(driverRefusalRetryInterval) + tracker.update(now, nil) + if !tel.DriverHealth("sungrow").IsOnline() { + t.Fatal("retry window elapsed and the driver was not let back in") + } + + // One more refusal puts it straight back out — no second grace period. + tracker.dispatchCommand(context.Background(), sender, "driver send", "sungrow", payload, time.Second, now) + if tel.DriverHealth("sungrow").IsOnline() { + t.Fatal("a driver that refused its retry stayed in dispatch") + } + // And the fault re-armed, so it is walked to its default again. + assertStringsEqual(t, tracker.update(now, nil), []string{"sungrow"}) + + // The device takes writes again: the next accepted command clears it. + now = now.Add(driverRefusalRetryInterval) + tracker.update(now, nil) + refusing = false + tracker.dispatchCommand(context.Background(), sender, "driver send", "sungrow", payload, time.Second, now) + if !tel.DriverHealth("sungrow").IsOnline() { + t.Fatal("driver accepted a command and is still excluded") + } +} + +// Every one of these is a fault somebody else already owns. Counting them +// here would book the same fault twice, and could push a merely slow cloud +// driver out of control on one bad round trip. +func TestNonRefusalErrorsDoNotExcludeADriver(t *testing.T) { + cases := []struct { + name string + err error + }{ + {"observe only", drivers.ErrObserveOnly}, + {"control blocked", drivers.ErrControlBlocked}, + {"command deadline", context.DeadlineExceeded}, + {"tick cancelled", context.Canceled}, + {"wrapped deadline", &wrappedErr{cause: context.DeadlineExceeded}}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + if isCommandRefusal(tc.err) { + t.Fatalf("%v counted as a refusal", tc.err) + } + tel := pollingStore(t, "cloud-battery") + tracker := newDriverActuationTracker(tel) + now := time.Now() + for i := 0; i < driverRefusalLimit*2; i++ { + tracker.recordCommandOutcome("cloud-battery", tc.err, now) + now = now.Add(time.Second) + } + if !tel.DriverHealth("cloud-battery").IsOnline() { + t.Fatalf("%v excluded the driver from control", tc.err) + } + if pending := tracker.update(now, nil); len(pending) != 0 { + t.Fatalf("%v produced a default request: %v", tc.err, pending) + } + }) + } +} + +type wrappedErr struct{ cause error } + +func (e *wrappedErr) Error() string { return "command may have run: " + e.cause.Error() } +func (e *wrappedErr) Unwrap() error { return e.cause } + +// A removed driver has no health record, and a late verdict about it must +// not create one — that would put a card back in the UI for a driver that +// is gone. +func TestRemovedDriverIsForgotten(t *testing.T) { + tel := pollingStore(t, "sungrow") + tracker := newDriverActuationTracker(tel) + now := time.Now() + for i := 0; i < driverRefusalLimit; i++ { + tracker.recordCommandOutcome("sungrow", errors.New("modbus write refused"), now) + } + tracker.update(now, nil) + + tel.Remove("sungrow") + tracker.recordCommandOutcome("sungrow", errors.New("driver \"sungrow\" not found"), now) + if h := tel.DriverHealth("sungrow"); h != nil { + t.Fatalf("a removed driver was resurrected in telemetry: %+v", h) + } + if pending := tracker.update(now.Add(time.Second), nil); len(pending) != 0 { + t.Fatalf("removed driver was sent a default: %v", pending) + } + if _, tracked := tracker.refusals["sungrow"]; tracked { + t.Error("removed driver left bookkeeping behind") + } +} diff --git a/go/cmd/ftw/main.go b/go/cmd/ftw/main.go index 170f00aa..abad8f5b 100644 --- a/go/cmd/ftw/main.go +++ b/go/cmd/ftw/main.go @@ -2382,6 +2382,7 @@ func main() { const evStopHigh = 100.0 // W — "was actually drawing" const evStopLow = 50.0 // W — "now essentially zero" var staleDefaults staleSiteDefaultTracker + actuation := newDriverActuationTracker(tel) for { select { case <-sigc: @@ -2466,6 +2467,15 @@ func main() { bus.Publish(events.DriverRecovered{Driver: tr.Name, At: time.Now()}) } } + // Same law for a driver that is answering but cannot actuate, + // whether it says so itself or core found out by having its + // commands refused. Joins watchdogDefaulted so the freshness + // gate below doesn't send it a second default this tick. See + // driver_failure_default.go. + for _, name := range actuation.update(tickNow, observeOnlySnap) { + sendDriverDefault(ctx, srv, name, driverCannotActuateReason, observeOnlySnap) + watchdogDefaulted[name] = struct{}{} + } // Fire a HealthTick so subscribers that track user-level // thresholds (e.g. notifications) can evaluate their own // rules without the control loop knowing about them. @@ -2669,7 +2679,7 @@ func main() { continue } payload, _ := json.Marshal(map[string]any{"action": "battery", "power_w": t.TargetW}) - sendDriverCommand(ctx, reg, "driver send", t.Driver, payload, driverCmdTimeout) + actuation.dispatchCommand(ctx, reg, "driver send", t.Driver, payload, driverCmdTimeout, tickNow) } // ---- PV curtailment dispatch ---- diff --git a/go/internal/control/control_test.go b/go/internal/control/control_test.go index ff9f8734..7b9b4894 100644 --- a/go/internal/control/control_test.go +++ b/go/internal/control/control_test.go @@ -262,6 +262,38 @@ func TestDeviceFaultExcludesBatteryAndReallocates(t *testing.T) { } } +// Same exclusion, reached from the other side: the driver reports itself +// healthy but has rejected the commands core sent it. Before, it kept +// Status=ok and stayed in the dispatch set, so the plan went on counting on +// power it never delivered and the shortfall became grid import. +func TestCommandFaultExcludesBatteryAndReallocates(t *testing.T) { + store := seedStore(3000, []struct { // site importing 3 kW + name string + currentW, soc float64 + }{ + {"ferroamp", 0, 0.5}, + {"sungrow", 0, 0.5}, + }) + store.SetDriverCommandFault("ferroamp", true, "modbus write refused") + + st := NewState(0, 50, "ferroamp") + st.Mode = ModeSelfConsumption + var sungrow float64 + sawSungrow := false + for _, tg := range ComputeDispatch(store, st, caps(map[string]float64{"ferroamp": 15200, "sungrow": 9600}), 11040) { + if tg.Driver == "ferroamp" { + t.Errorf("a battery that refuses commands must NOT get a dispatch target, got %.0f W", tg.TargetW) + } + if tg.Driver == "sungrow" { + sungrow = tg.TargetW + sawSungrow = true + } + } + if !sawSungrow || sungrow >= 0 { + t.Errorf("sungrow should cover the load alone (negative target), got saw=%v %.0f W", sawSungrow, sungrow) + } +} + func TestChargeModeRespectsFuseGuard(t *testing.T) { store := seedStore(10000, []struct { name string diff --git a/go/internal/mpc/service_test.go b/go/internal/mpc/service_test.go index 190413e3..d2b2a848 100644 --- a/go/internal/mpc/service_test.go +++ b/go/internal/mpc/service_test.go @@ -454,6 +454,38 @@ func TestOnlineFleetParamsUsesCapacityWeightedOnlineSoC(t *testing.T) { } } +// A battery that answers polls but rejects every command is not a battery +// the plan can spend. Counting its capacity and its charge/discharge limits +// makes the optimizer promise energy that never arrives. +func TestOnlineFleetParamsDropsCommandFaultedBattery(t *testing.T) { + tel := telemetry.NewStore() + socA := 0.20 + socRefusing := 0.95 + tel.Update("a", telemetry.DerBattery, 0, &socA, nil) + tel.DriverHealthMut("a").RecordSuccess() + tel.Update("refusing", telemetry.DerBattery, 0, &socRefusing, nil) + tel.DriverHealthMut("refusing").RecordSuccess() + tel.SetDriverCommandFault("refusing", true, "modbus write refused") + + s := &Service{Tele: tel, FuseMaxW: 20000} + p, ok := s.onlineFleetParams(Params{InitialSoCPct: 50}, []BatteryFleetMember{ + {Driver: "a", CapacityWh: 10000, MaxChargeW: 3000, MaxDischargeW: 4000}, + {Driver: "refusing", CapacityWh: 50000, MaxChargeW: 9000, MaxDischargeW: 9000}, + }) + if !ok { + t.Fatal("onlineFleetParams returned ok=false") + } + if p.CapacityWh != 10000 { + t.Fatalf("CapacityWh = %.0f, want 10000 — the refusing battery must not be counted", p.CapacityWh) + } + if len(p.Storages) != 1 || p.Storages[0].ID != "a" { + t.Fatalf("Storages = %+v, want only battery a", p.Storages) + } + if math.Abs(p.InitialSoCPct-20) > 1e-9 { + t.Fatalf("InitialSoCPct = %.3f, want 20.000 — the refusing battery's 95%% must not count", p.InitialSoCPct) + } +} + func TestOnlineFleetParamsRequiresOnlineSoCTelemetry(t *testing.T) { tel := telemetry.NewStore() tel.Update("no-soc", telemetry.DerBattery, 0, nil, nil) diff --git a/go/internal/telemetry/device_fault_test.go b/go/internal/telemetry/device_fault_test.go index 3357a345..aec9e7c3 100644 --- a/go/internal/telemetry/device_fault_test.go +++ b/go/internal/telemetry/device_fault_test.go @@ -52,3 +52,63 @@ func TestStoreSetDriverDeviceFault(t *testing.T) { t.Error("clearing via the store should restore online") } } + +// The other end of the same wire: a driver that answers polls and rejects +// writes believes the device is fine and says so on every poll. Its verdict +// must not be able to clear core's, or the two would flip the driver in and +// out of the fleet for as long as the refusals lasted. +func TestDriverPollCannotClearACommandFault(t *testing.T) { + s := NewStore() + s.DriverHealthMut("sungrow").RecordSuccess() + + s.SetDriverCommandFault("sungrow", true, "modbus write refused") + if s.DriverHealth("sungrow").IsOnline() { + t.Fatal("a driver that refuses commands must leave the control set") + } + + // Every poll of a driver that thinks it is healthy. + for i := 0; i < 5; i++ { + s.SetDriverDeviceFault("sungrow", false, "") + s.RecordDriverSuccess("sungrow") + if s.DriverHealth("sungrow").IsOnline() { + t.Fatalf("poll %d cleared the command fault", i) + } + } + + s.SetDriverCommandFault("sungrow", false, "") + if !s.DriverHealth("sungrow").IsOnline() { + t.Error("clearing the command fault should restore online") + } +} + +// The driver's own fault survives core clearing its command fault: two +// sources, one derived flag, neither able to overwrite the other. +func TestDeviceAndCommandFaultsAreIndependent(t *testing.T) { + h := &DriverHealth{Name: "sungrow"} + h.RecordSuccess() + + h.SetDeviceFault(true, "inverter fault 0x12") + h.SetCommandFault(true, "modbus write refused") + if h.DeviceFaultReason != "inverter fault 0x12" { + t.Errorf("reason = %q, want the driver's own — it saw the device", h.DeviceFaultReason) + } + + h.SetCommandFault(false, "") + if !h.DeviceFault { + t.Error("clearing the command fault dropped the driver's own fault") + } + + h.SetDeviceFault(false, "") + if h.DeviceFault || !h.IsOnline() { + t.Error("with both sources clear the driver should be back in control") + } +} + +// A driver that is gone must not be resurrected by a late verdict about it. +func TestSetDriverCommandFaultDoesNotCreateHealth(t *testing.T) { + s := NewStore() + s.SetDriverCommandFault("ghost", true, "modbus write refused") + if h := s.DriverHealth("ghost"); h != nil { + t.Fatalf("command fault created a health record for an unknown driver: %+v", h) + } +} diff --git a/go/internal/telemetry/store.go b/go/internal/telemetry/store.go index a032925d..0c186d68 100644 --- a/go/internal/telemetry/store.go +++ b/go/internal/telemetry/store.go @@ -129,16 +129,49 @@ type DriverHealth struct { // detection — there is no separate "degraded" state. WatchdogTimeoutOverride time.Duration - // DeviceFault is set by a driver (via host.set_device_fault) when it can - // reach the device but the device is in a fault state where it cannot - // actuate — e.g. a Ferroamp EnergyHub in Fault Mode with its relays open. - // It is orthogonal to Status: the driver keeps emitting fresh telemetry - // (so the watchdog sees it as alive and RecordSuccess keeps Status=ok), - // but IsOnline() returns false so the dispatcher and the MPC plan exclude - // it — otherwise we keep commanding a dead battery and the un-delivered - // power silently becomes grid import. DeviceFaultReason is operator-facing. + // DeviceFault means the driver reaches the device but the device + // cannot actuate — e.g. a Ferroamp EnergyHub in Fault Mode with its + // relays open. It is orthogonal to Status: the driver keeps emitting + // fresh telemetry (so the watchdog sees it as alive and RecordSuccess + // keeps Status=ok), but IsOnline() returns false so the dispatcher and + // the MPC plan exclude it — otherwise we keep commanding a dead battery + // and the un-delivered power silently becomes grid import. + // DeviceFaultReason is operator-facing. + // + // Read it; do not assign it. It is derived from the two sources below + // so that both reach every consumer — /api/health, the driver + // inventory, the support report — through one field. DeviceFault bool DeviceFaultReason string + + // The two writers behind DeviceFault, kept apart so neither can undo + // the other. A driver re-asserts its own view on every poll; without + // the split, a core-set fault would be cleared by the next poll of a + // driver that believes the device is fine, and the two would flip the + // derived flag back and forth for as long as the fault lasted. + // + // driverFault: the driver's own verdict, via host.set_device_fault. + // commandFault: core's verdict, when the driver has refused the + // commands core sent it. Refusing to actuate is the same condition + // seen from the other end of the wire. + driverFault bool + driverFaultReason string + commandFault bool + commandFaultReason string +} + +// refreshDeviceFault recomputes the derived fault from its two sources. +// The driver's own reason wins when both are set: it saw the device. +func (h *DriverHealth) refreshDeviceFault() { + h.DeviceFault = h.driverFault || h.commandFault + switch { + case h.driverFault: + h.DeviceFaultReason = h.driverFaultReason + case h.commandFault: + h.DeviceFaultReason = h.commandFaultReason + default: + h.DeviceFaultReason = "" + } } // RecordSuccess resets error state and marks the driver healthy. Call @@ -182,25 +215,40 @@ func (h *DriverHealth) RecordError(err string) { } } -// SetOffline marks the driver offline (e.g. by watchdog). +// SetOffline marks the driver offline. WatchdogScan is the only runtime +// caller: staleness is the one condition that takes a driver offline, so +// this is the single place that writes StatusOffline. Tests use it to put +// a driver in that state directly. func (h *DriverHealth) SetOffline() { h.Status = StatusOffline } -// SetDeviceFault flags (or clears) a device-level fault — the driver reaches -// the device but it can't actuate. Independent of Status so a driver that -// keeps emitting from cache doesn't flap it back on every RecordSuccess. +// SetDeviceFault records the driver's own verdict that the device can't +// actuate. Independent of Status so a driver that keeps emitting from cache +// doesn't flap it back on every RecordSuccess. func (h *DriverHealth) SetDeviceFault(faulted bool, reason string) { - h.DeviceFault = faulted + h.driverFault = faulted + h.driverFaultReason = "" if faulted { - h.DeviceFaultReason = reason - } else { - h.DeviceFaultReason = "" + h.driverFaultReason = reason } + h.refreshDeviceFault() +} + +// SetCommandFault records core's verdict that the device can't actuate, +// because it refused the commands core sent it. Kept apart from +// SetDeviceFault so a driver still reporting itself healthy cannot clear it. +func (h *DriverHealth) SetCommandFault(faulted bool, reason string) { + h.commandFault = faulted + h.commandFaultReason = "" + if faulted { + h.commandFaultReason = reason + } + h.refreshDeviceFault() } // IsOnline reports whether the driver is usable for control. A stale-flagged -// driver (Status offline) OR one its driver flagged as device-faulted is not. +// driver (Status offline) OR one that cannot actuate is not. func (h *DriverHealth) IsOnline() bool { return h.Status != StatusOffline && !h.DeviceFault } @@ -650,7 +698,7 @@ func (s *Store) WatchdogScan(timeout time.Duration) []WatchdogTransition { stale := h.LastSuccess == nil || now.Sub(*h.LastSuccess) > eff wasOnline := h.Status != StatusOffline if stale && wasOnline { - h.Status = StatusOffline + h.SetOffline() out = append(out, WatchdogTransition{Name: name, Online: false}) } else if !stale && !wasOnline { h.Status = StatusOk @@ -685,8 +733,9 @@ func (s *Store) SetDriverDeviceFault(name string, faulted bool, reason string) { h = &DriverHealth{Name: name} s.health[name] = h } - changed := h.DeviceFault != faulted + before := h.DeviceFault h.SetDeviceFault(faulted, reason) + changed := h.DeviceFault != before s.mu.Unlock() // Log only the transition (the driver re-asserts the fault every poll) so // the entry/exit surfaces in /api/logs as an operator alert without spam. @@ -699,6 +748,33 @@ func (s *Store) SetDriverDeviceFault(name string, faulted bool, reason string) { } } +// SetDriverCommandFault records that core could not get its commands into +// this device (or that it can again). Unlike SetDriverDeviceFault this does +// NOT create a health record: only a driver that has been running can have +// refused a command, and a removed driver must not be resurrected as a card +// in the UI by a late verdict about it. Removing a driver therefore clears +// this fault along with the rest of its health. +func (s *Store) SetDriverCommandFault(name string, faulted bool, reason string) { + s.mu.Lock() + h, ok := s.health[name] + if !ok { + s.mu.Unlock() + return + } + before := h.DeviceFault + h.SetCommandFault(faulted, reason) + changed := h.DeviceFault != before + s.mu.Unlock() + if changed { + if faulted { + slog.Warn("driver refused control — excluding from dispatch + plan until it accepts a command again", + "driver", name, "reason", reason) + } else { + slog.Info("driver command fault cleared — back in control", "driver", name) + } + } +} + // WatchdogTransition describes a driver whose online state just flipped. type WatchdogTransition struct { Name string