Twenty-Nine Minutes of Disagreement, Seven Hours With the Pump Off

Yesterday I published a post about my sump pump monitor's four sensing channels. One paragraph in it was about the temperature channel, and it made a point I was rather pleased with: that channel has fired 6,074 warnings in six months, its action threshold is 60.0 °C, and the hottest reading in the entire log is 59.4 °C. Six thousand warnings, zero decisions. A threshold placed where the data lives rather than where the decision is.

It was a good paragraph. It was also wrong, and it had been wrong for about twenty hours when I hit publish.

I am not editing the old post. The correction is the lede here instead, because the reason I got it wrong is more interesting than the error, and what actually happened that night is more interesting than either.

Short version: two independent safety systems spent twenty-nine minutes fighting over the same relay. Each one was behaving exactly as designed. The argument cooked the plug past a cutoff it had never touched in six months, put the pump into a lockout with no exit, and kept it there for seven hours, thirty-three minutes and forty-five seconds — overnight, during a wet period, with nobody notified. It ended when somebody cleared the state file by hand at 05:45 the next morning, leaving no trace of it in the monitor's own log.

The two watchdogs

The system has two, deliberately. This was supposed to be the good design decision.

sump_pump_monitor.py is the main process. It runs a duty-cycle state machine, it owns the escalation ladder, and it decides when the pump runs.

sump-pump-guardian.timer is the second one. It fires every two minutes, and systemd's own description of it is "independent safety backstop." It exists precisely because I did not want a single long-lived Python process to be the only thing standing between my basement and a pump that runs until it burns out. It has its own thresholds, its own state file, and its own ability to command the relay:

GUARDIAN_MAX_RUN_MIN        = 4      # cut the relay after 4 minutes continuous
GUARDIAN_FORCED_REST_SECONDS = 300    # then hold it off for 5 minutes to cool
SHELLY_TEMP_RESUME_C        = 55.0   # only resume below this temperature
NO_RUN_ALERT_HOURS          = 12     # shout if no pumping for 12 hours

The monitor, meanwhile, has a reconciliation rule. If the plug is off when the monitor believes it should be on, that is a fault, and the monitor corrects it. In the log it reads WARNING: Plug output is OFF unexpectedly! Turning back ON.

Read those two paragraphs again and you can see the whole accident. The monitor's rule is only correct if nothing else is legitimately turning the plug off. The moment the guardian existed, that rule became a bug. It stayed a bug for three months, and it never once looked like one in the logs, because both processes were logging success.

Twenty-nine minutes

Sunday night, 2026-09-13. The pit was wet and the pump had been running long continuous stretches. Here is the fight, assembled from sump_pump_guardian.log and sump_pump_monitor.log on the host that writes them:

Five cooling rests were ordered. Zero cooling rests happened. The longest one lasted two seconds.

Look at the temperature column. It is monotonic. 55.2, 57.5, 57.8, 58.6, 59.1. The guardian was right every single time, and every single time the plug went straight back under load before it could shed any heat. The escalating temperature is not the weather and it is not the pump wearing out. It is the argument itself. Each cycle of the fight added roughly a degree.

Two seconds after the fifth override, the monitor reached its own conclusion — that a pump running six continuous minutes must be stuck — and started a power cycle:

[2026-09-13 22:10:57] Pump stuck — starting power cycle (pump ran 6.0 min (wet threshold 6.0 min))
[2026-09-13 22:10:57] POWER CYCLE: holding OFF for 10 seconds...
[2026-09-13 22:11:07] POWER CYCLE: OFF period complete after 10s, turning back ON
[2026-09-13 22:11:53] TEMP SAFETY: 60.1C exceeds soft threshold 60.0C. Forcing OFF.
[2026-09-13 22:11:53] STATE: POWER_CYCLE -> LOCKOUT (overtemp 60.1C)

A ten-second rest, then back on at 59.1 °C, then forty-six seconds later the first crossing of the 60.0 °C line in six months of continuous logging. The previous all-time high was 59.4 °C, set on June 3rd. The channel I had just finished describing as pure noise made its first real decision, and it made it correctly.

This was not a one-night anomaly

I assumed, looking at Sunday, that I was seeing an unusual pile-up. I checked. Over the full log:

• The guardian has commanded the relay off 52 times, first on 2026-06-03, most recently 2026-09-14.
• The monitor has logged "Plug output is OFF unexpectedly! Turning back ON" 66 times.
• 23 of the guardian's 52 safety cutoffs — 44% — were reversed by the monitor within ten seconds. Median lag: one second.

Nearly half of my independent safety backstop's interventions have been undone before the next poll, for three months, and I did not know. There is no line anywhere in either log that says "conflict." The guardian logs a successful cutoff. The monitor logs a successfully corrected fault. Both are telling the truth about themselves, and the truth about the system is in neither file.

Then the lockout would not let go

Entering LOCKOUT cuts power to the pump and stops the state machine. That is correct behaviour for a device approaching its thermal limit. What happens next is where the design and the implementation come apart.

The plug cooled fast, because the heat was coming from the load it had just stopped carrying:

Within twenty-four minutes the plug was 13.5 degrees below its cutoff. Within an hour it was at 42 °C and flat. It then sat there, eighteen degrees below the threshold that had locked it, for another six and a half hours, with the pump's power cut.

The state machine documents this on purpose. pump_state.py, line 26:

LOCKOUT (Shelly loss) → NORMAL after stable connectivity
LOCKOUT (other reasons) → manual restart only

Connectivity lockouts auto-recover. Thermal lockouts are manual-only. I wrote that, and at the time it seemed obviously right: if the hardware got hot enough to trip a safety cutoff, a human should look at it before it runs again.

The trouble is that the notification for this state has the subject line SUMP PUMP: thermal cooling lockout, and the comment above it in the source calls it "a cooling duty." Both of those describe a pause. The implementation is a latch. handle_lockout() does exactly one thing: it writes "still locked out" to the log file every thirty minutes. Fifteen times that night, into a file nobody was reading.

The guardian had a release. It missed by six tenths of a degree.

This is the part I keep coming back to, because it is the kind of bug that survives code review indefinitely.

The guardian does know how to resume after a cooling rest. Here is the block:

if state.get("forced_rest_until_wall") and rest_remaining <= 0:
    state["forced_rest_until_wall"] = 0
    state["last_action_taken"] = "cooling rest expired"
    if not status["output"] and status["temp_c"] <= SHELLY_TEMP_RESUME_C:   # 55.0
        set_relay(host, True, "guardian cooling rest expired")

The flag is cleared on the same tick that the temperature is tested, before the test runs. So the check happens exactly once, at whatever instant the rest timer happens to expire, and then the code path is permanently unreachable.

The guardian polls every two minutes. Here is how the dice landed:

One hundred and twenty seconds. Six tenths of a degree. If the timer had expired on the next poll instead of that one, the guardian would have restored the relay and there would be no story here. Instead the one and only attempt was spent at the last moment the condition was false, and the recovery logic went dormant with the pump off and the hardware cool.

A threshold check that runs once, at a moment you do not control, is not a check. It is a lottery ticket.

One notification went out. It was the wrong one.

I expected to find that nothing was sent. What I found is worse, and more ordinary.

The guardian did alert — once, at the very start.

[2026-09-13 21:42:45] URGENT email sent: SUMP GUARDIAN: max run cutoff
[2026-09-13 21:42:45] URGENT ntfy sent: SUMP GUARDIAN: max run cutoff

That is the first of the five cutoffs — the one at 55.2 °C, twenty-nine minutes before anything went wrong. It is the eighth of nine identically worded "max run cutoff" alerts the guardian has sent since June, against 52 cutoffs total. Nothing in it distinguishes that night from the seven other times the guardian trimmed a long run and everything was fine.

The other four cutoffs — the ones where the temperature was climbing through 57, 58, 59 — were suppressed as duplicates by GUARDIAN_ALERT_REPEAT_SECONDS = 3600. Which is correct de-duplication behaviour and exactly the wrong outcome: the four alerts that carried the new information were silenced because they resembled the one that carried none.

The monitor sent nothing at all. Not about the overtemp, not about the lockout, not once in seven and a half hours. The only trace at the moment of the trip is this:

[2026-09-13 22:11:53] LOG email skipped: no recipients configured

A blank NOTIFY_EMAIL_LOG= line in .env resolves to an empty string instead of falling through to the hardcoded default, so the recipient list is empty. I diagnosed this on August 20th. It has now skipped 3,374 sends, and the one at 22:11:53 is the most expensive of them. The fix is deleting one line. It has been open twenty-six days because it needs a service restart and I kept batching it with other changes.

The guardian's no-run alarm never armed. NO_RUN_ALERT_HOURS = 12. The outage reached 7.6 hours. It ended 4.4 hours short of the threshold that would have woken me up. The guardian polled every two minutes for seven and a half hours, logging output=OFF power=0.0W running=no hours_since_cycle=7.6, and never crossed the line that makes it shout.

The AI watcher saw everything and said nothing

A scheduled Claude job reads these logs four times a day. It ran at 00:05 and again at 06:05, straddling the whole event. I assumed it had missed it, the way it has missed everything else — 408 notes since June 2nd, zero escalations.

It did not miss it. Here is the note it wrote at 06:06:51, trimmed:

Overnight overtemp LOCKOUT (60.1C …) held for 450+ min as designed (manual-only clear); state file … was manually backed up … and cleared at 05:45:38, restarting monitor in NORMAL — this was a deliberate manual clear, not a crash/state-loss bug (backup file + PID change confirm). … No new alert sent. No control changes applied.

It is accurate. The duration is right to within four minutes. It correctly identified the manual state clear, and it cited the evidence — the backup file and the PID change — which is more forensic work than I did before drafting the first version of this article. It knew the pump had been dead for seven and a half hours.

Then it wrote "No new alert sent" and went back to sleep.

This is a sharper problem than a blind reviewer, and it landed the same week as a paper about it. FailBench, published Monday, put 13 vision-language models against 2,197 robot manipulation attempts. The best managed 0.77 balanced accuracy, dropping under 0.60 on hard cases, and the failure mode the authors name is "a systematic bias toward predicting success under ambiguous evidence." They also found that models fine-tuned specifically to detect failures did worse than general-purpose ones.

My watcher is not failing to perceive. It perceived better than I did. It is failing to convert an accurate perception into an action, because every framing available to it — "as designed," "deliberate," "known chronic pattern" — is individually true and collectively adds up to "fine." Give a model enough context to explain an event and it will explain it. Explanation and alarm are different functions, and I had wired one component to do both.

What actually ended it

Not the guardian, and not the monitor.

Sep 14 05:45:38 systemd[1]: Stopping sump-pump-monitor.service...
Sep 14 05:45:38 systemd[1]: sump-pump-monitor.service: Deactivated successfully.
Sep 14 05:45:38 systemd[1]: Started sump-pump-monitor.service.
[2026-09-14 05:45:38] === Sump Pump Monitor Started ===
[2026-09-14 05:45:38] Starting in NORMAL mode (no saved state)
[2026-09-14 05:45:38] Startup: NORMAL mode requires plug ON, turning ON...
[2026-09-14 05:46:09] Pump started running (690.3W, 43.0C, light=unknown)

A clean systemd stop and start — no crash, no OOM, nothing in the journal explaining it. That is where my first draft of this article stopped, and that draft was wrong too.

The evidence is in /var/tmp. There is a file called sump_pump_state.json.lockout-bak-1789379138. Its timestamp is exactly 05:45:38, and it contains:

{
  "state": "LOCKOUT",
  …
  "lockout_reason": "overtemp 60.1C",

So the state file was backed up and then cleared, deliberately, in the same second as the restart. A crash does not write a file named lockout-bak. Nothing on the host writes one either — no cron job, no timer, no script in the repository contains that string, and last shows no interactive login since August 25th, so it arrived as a non-interactive remote command. Somebody, or something acting on somebody's behalf, reached in and cleared the interlock at a quarter to six on a Sunday morning. I cannot tell you who from the logs, and I am not going to guess in public.

Here is the part that matters regardless of who did it. The monitor's own log has no idea any of this happened. It says "Starting in NORMAL mode (no saved state)" — the same line it writes after any restart. A safety interlock that had been engaged for seven and a half hours was discarded, and the only record of the discard is a stray backup file in a temp directory that nothing cleans up and nothing reads. If that file had been deleted, or written to a different path, or simply not created, there would be no way to distinguish a cleared thermal lockout from an ordinary service restart.

Thirty-one seconds later the pump pulled 690.3 watts, one of the highest readings in the six-month record, with seven and a half hours of inflow waiting for it. Six minutes after that the system was back in POWER_CYCLE, and by 07:57 it had climbed the whole escalation ladder to TIER_3 again.

So "manual restart only" does not mean what I thought it meant when I wrote it. It means the interlock has no mechanism at all — it is a variable in a JSON file that vanishes with the file. Clearing it requires no acknowledgement, leaves no audit line, and is indistinguishable in the service log from a routine restart. The safety state has both possible failures simultaneously: it will not release when the hazard is gone, and it releases without trace to anything that touches the state file.

Why I missed it, which is its own lesson

The post I published yesterday was built from six months of aggregates. I pulled every temperature reading in the log, sorted, took the maximum, got 59.4 °C, and wrote the paragraph. The query was correct. The pipeline was correct. The number was stale by twenty hours, because the aggregate does not tell you that the interesting thing happened last night — and the specific reading I needed was on a line shape (TEMP SAFETY:) that my extraction pattern did not match.

The second error has the same shape. I read a field called uptime out of the heartbeat line and reported it as the service's uptime. It is the Shelly plug's. The plug had in fact been up 1,307 hours; the service had restarted that morning, and that restart is the only reason the pump was running when I wrote the sentence.

Both errors are the same mistake: I analysed the shape of six months and never read the last twenty-four hours. The new rule, which costs one sed -n command: before publishing anything built on aggregate log analysis, read the raw tail for every channel the piece makes a claim about.

What I am changing

1. One component owns the relay. The guardian wins. It is simpler, it runs on a timer rather than carrying state across days, and being right when the monitor is wrong is its entire job. The monitor has to learn that a guardian-commanded OFF is not a fault to correct. Until this is settled, fixing anything else about the guardian would make things worse, because a working cooling rest is exactly what the monitor is currently overriding.
2. Make the resume check re-entrant. Do not clear forced_rest_until_wall until set_relay has actually fired. Keep testing every tick until the state genuinely changes.
3. Give the thermal lockout a real exit and a real alarm. Release after a sustained window below the resume temperature — not one sample, a window. And alarm if the lockout itself exceeds about twenty minutes, keyed to the lockout, not to the downstream symptom. A 12-hour no-run alarm can never cover a 7.5-hour outage; the arithmetic was against me from the day I set it.
4. Delete the blank NOTIFY_EMAIL_LOG= line. Twenty-six days late. 3,374 skipped sends.
5. Stop de-duplicating alerts on subject alone. A one-hour repeat window keyed only to the subject line silenced four escalating warnings because they looked like the first one. De-duplicate on subject plus a severity input — a temperature bucket would have been enough — so a worsening condition always re-alerts.
6. Log an audit line whenever the interlock is discarded. Including at startup, when the state file is missing but the plug was last known off. Persist the lockout, or stop calling it manual-only — right now the label is a comment, not a mechanism.
7. Split the AI watcher's two jobs. It can keep writing the prose. It does not get to make the escalation decision, because it will always find a framing. One rule it cannot reason around: pump power off for more than twenty minutes pages, whatever the explanation.

The audit, if you run anything like this

Three questions, and the first one is twenty minutes of work:

1. List everything in your system that can command the same physical output. Relays, valves, dampers, contactors, setpoints. If the list for any output has more than one entry, join those components' logs on timestamp and look for opposing commands within ten seconds. My number was 23 out of 52 and I would have sworn it was zero.
2. Find every threshold test that runs exactly once. Anything of the form "when the timer expires, check X" is a single sample of a noisy signal at an arbitrary instant. Make it a loop with an exit condition, not a coin flip.
3. For every terminal safety state, ask two questions: what releases it, and what alarms if nothing does? If the answer to the first is "a human" and the answer to the second is "a threshold designed for a different failure," you have what I had — a pump that stays off all night while three watchdogs each record that everything is fine.

The basement is dry. It has been dry the whole time, including that night, as far as I can tell — though I want to be precise about that, because the honest answer is that I do not know and cannot know. This system has no water-level sensor. That was the entire finding of the post I am correcting. The 690-watt restart draw is consistent with a pit that had been filling for seven hours, and it is equally consistent with an ordinary wet-period cycle, and no measurement I own distinguishes them.

Which is a reasonable place to end. I spent six months building enough instrumentation to write confident paragraphs about this machine, and this week it produced its first genuine emergency, resolved it by accident, told nobody, and let me publish the opposite twenty hours later. The logs had it all. I had simply never asked them the one question that mattered, which was not "what does this system measure" but "what do its parts do to each other."