From 385337428615a763e91d455bb678282597b60c4d Mon Sep 17 00:00:00 2001 From: andig Date: Thu, 10 Sep 2026 09:42:21 +0200 Subject: [PATCH 1/5] perf: skip the continuity pass on hard solves, and log what it did The continuity candidate is the model plus a start variable per step under a bound on the cost it just optimized, the harder problem of the two. Where the incumbent took longer than the second this stage may spend, the candidate hits the cap with nothing to show. Production measured it over five days: 14 % of joint solves ran the stage, half of those sat on the cap, p90 went from 0.68 s to 1.32 s in the deploy hour and the replica average rose 18 %. The incumbent's own clock names those requests before the second is spent, so skip them. The stage was also invisible: no timer and no outcome, so this had to be found by subtracting the timed stages from the total. It now leaves stage_seconds 'continuity' and a continuity_stage string the way the tie break does, and the request log carries both. Co-Authored-By: Claude Fable 5.1 (cherry picked from commit 02a839ed841e23fcfd8b9d7b798d68e56520e826) --- docs/comparison_objective_terms.md | 5 +++-- src/optimizer/app.py | 1 + src/optimizer/optimizer.py | 25 +++++++++++++++++++++++-- tests/test_app.py | 4 ++-- tests/test_continuity.py | 26 +++++++++++++++++++++++++- 5 files changed, 54 insertions(+), 7 deletions(-) diff --git a/docs/comparison_objective_terms.md b/docs/comparison_objective_terms.md index 56d3fef8c..a777a0eda 100644 --- a/docs/comparison_objective_terms.md +++ b/docs/comparison_objective_terms.md @@ -42,5 +42,6 @@ `c_min > 0`. It bounds both achieved objectives and each leveled grid peak separately, so fewer interruptions cannot compensate for worse economics, preferences, or peaks beyond numerical tolerances. This pass adds no term to either earlier objective. It runs only for fragmented - schedules, uses at most one second of solver time within the remaining request budget, and - retains the incumbent unless a valid schedule has fewer actual starts. + schedules, uses at most one second of solver time within the remaining request budget, is + skipped when the solve that produced the incumbent already took longer than that, and retains + the incumbent unless a valid schedule has fewer actual starts. diff --git a/src/optimizer/app.py b/src/optimizer/app.py index 08d7dd811..b0fa2bd48 100644 --- a/src/optimizer/app.py +++ b/src/optimizer/app.py @@ -277,6 +277,7 @@ def post(self): "stages": optimizer.stage_seconds, "path": optimizer.solve_path, "preferences": optimizer.preference_stage, + "continuity": optimizer.continuity_stage, "status": result.get('status'), "steps": optimizer.T, }}), flush=True) diff --git a/src/optimizer/optimizer.py b/src/optimizer/optimizer.py index f5a26bb55..67c1e48a3 100644 --- a/src/optimizer/optimizer.py +++ b/src/optimizer/optimizer.py @@ -923,6 +923,9 @@ def _solve_continuity(self, tmpdir: str, deadline: float | None) -> None: A device reported as charging enters the horizon switched on, so keeping it on is free and interrupting it costs a start. + + Leaves continuity_stage behind, the way the tie break leaves preference_stage: what the + stage did, or why it did nothing, one string per solve for the request log. """ if (self.problem.sol_status not in (pulp.LpSolutionOptimal, pulp.LpSolutionIntegerFeasible) or not _complete_solution(self.problem) or not self._is_integral()): @@ -944,8 +947,18 @@ def count_starts() -> list[int]: # a device that is charging already can reach zero starts, one that is idle needs one if all(count <= 1 - charging_now(i) for i, count in zip(eligible, before)): return + # the candidate is this model plus a start per step, under a bound on the cost it just + # optimized, so it is the harder problem: it does not finish inside a second where the + # incumbent took longer than that. Measured over five days of production, 14 % of joint + # solves ran this stage and half of those sat on the cap with nothing to show (#146). The + # incumbent's own clock says which ones they are before a second is spent. + spent = self.stage_seconds.get('probe', 0.) + self.stage_seconds.get('cost', 0.) + if spent > CONTINUITY_TIME_LIMIT: + self.continuity_stage = f'skipped, solve took {spent:.1f} s' + return remaining = CONTINUITY_TIME_LIMIT if deadline is None else min(CONTINUITY_TIME_LIMIT, deadline - time.monotonic()) if remaining <= 0: + self.continuity_stage = 'no time' return solution = {var: var.varValue for var in self.problem.variables()} @@ -977,20 +990,27 @@ def count_starts() -> list[int]: if deadline is not None: remaining = min(remaining, deadline - time.monotonic()) if remaining <= 0: + self.continuity_stage = 'no time' return - candidate.solve(self._solver(tmpdir, timeLimit=remaining)) + with self._timed('continuity'): + candidate.solve(self._solver(tmpdir, timeLimit=remaining)) + self.continuity_stage = 'MILP ' + pulp.LpStatus[candidate.status] + ' unused' if (candidate.sol_status not in (pulp.LpSolutionOptimal, pulp.LpSolutionIntegerFeasible) or not _complete_solution(candidate) or not self._is_integral()): return # CBC writes its solution with 8 significant digits, so a balance row over a 40 kWh # SOC comes back off by up to 1e-3 and candidate.valid(1e-5) rejects every candidate # (#146). CBC already held the model rows; only the bounds added here need checking. + after = count_starts() improved = (pulp.value(self.cost_objective) >= cost - 2 * CONTINUITY_TOLERANCE and pulp.value(preference) >= preferred - 2 * CONTINUITY_TOLERANCE and all(pulp.value(self.variables[f'p_{side}_peak']) <= peak_values[side] + 2 * CONTINUITY_TOLERANCE for side in self.peak_sides) - and sum(count_starts()) < sum(before)) + and sum(after) < sum(before)) + if improved: + self.continuity_stage = f'improved {sum(before)} to {sum(after)}' except pulp.PulpSolverError: + self.continuity_stage = 'solver error' return finally: if not improved: @@ -1091,6 +1111,7 @@ def solve(self) -> Dict: """ self.stage_seconds = {} + self.continuity_stage = 'not needed' if self.problem is None: with self._timed('build'): self.create_model() diff --git a/tests/test_app.py b/tests/test_app.py index 2699b387e..a442e1840 100644 --- a/tests/test_app.py +++ b/tests/test_app.py @@ -149,10 +149,10 @@ def test_every_request_logs_a_solve_line(capsys): if line.startswith('{"solve"')] assert len(lines) == 1, "every request logs exactly one solve line" solve = lines[0]["solve"] - assert {"client", "elapsed", "stages", "path", "preferences", "status", "steps"} <= set(solve) + assert {"client", "elapsed", "stages", "path", "preferences", "continuity", "status", "steps"} <= set(solve) assert solve["client"] == "evcc/0.311.1" assert solve["elapsed"] > 0 - assert solve["stages"] and set(solve["stages"]) <= {"build", "probe", "cost", "tie_break"} + assert solve["stages"] and set(solve["stages"]) <= {"build", "probe", "cost", "tie_break", "continuity"} assert solve["steps"] == len(request["time_series"]["dt"]) diff --git a/tests/test_continuity.py b/tests/test_continuity.py index e28e246fe..b6482140b 100644 --- a/tests/test_continuity.py +++ b/tests/test_continuity.py @@ -6,7 +6,8 @@ import pulp import pytest -from optimizer.optimizer import BatteryConfig, GridConfig, OptimizationStrategy, Optimizer, TimeSeriesData +from optimizer.optimizer import (CONTINUITY_TIME_LIMIT, BatteryConfig, GridConfig, OptimizationStrategy, Optimizer, + TimeSeriesData) def build(strategy: str = 'none') -> Optimizer: @@ -53,6 +54,28 @@ def test_equal_prices_prefer_one_session(monkeypatch: pytest.MonkeyPatch, probe_ assert starts(result['batteries'][0]['charging_power']) == 1 assert result['batteries'][0]['state_of_charge'][-1] == pytest.approx(1500, abs=0.1) assert pulp.value(model.cost_objective) == pytest.approx(-0.45, abs=1e-5) + assert model.continuity_stage == 'improved 3 to 1' + assert model.stage_seconds['continuity'] >= 0 + + +def test_hard_solve_skips_continuity(monkeypatch: pytest.MonkeyPatch): + # the candidate cannot beat the clock of the solve that produced the incumbent, so a solve + # that already took longer than the stage may spend gets no candidate at all + model = build() + seed_fragmented(model, monkeypatch) + seeded = model._probe_then_split + + def slow(tmpdir: str, deadline: float | None) -> None: + seeded(tmpdir, deadline) + model.stage_seconds['probe'] = CONTINUITY_TIME_LIMIT + 1 + + monkeypatch.setattr(model, '_probe_then_split', slow) + + result = model.solve() + + assert starts(result['batteries'][0]['charging_power']) == 3 + assert model.continuity_stage.startswith('skipped') + assert 'continuity' not in model.stage_seconds @pytest.mark.parametrize('schedule', [(0, 500, 0, 500, 0, 500), (0, 500, 500, 500, 0, 0)]) @@ -91,6 +114,7 @@ def test_price_gaps_keep_interruptions(monkeypatch: pytest.MonkeyPatch): assert starts(result['batteries'][0]['charging_power']) == 3 assert pulp.value(model.cost_objective) == pytest.approx(-0.45, abs=1e-5) + assert model.continuity_stage == 'MILP Optimal unused' def test_grid_shaping_takes_priority(monkeypatch: pytest.MonkeyPatch): From 878d221b2ee2ae9fc358152d09697842fa8cc606 Mon Sep 17 00:00:00 2001 From: andig Date: Mon, 14 Sep 2026 16:06:43 +0200 Subject: [PATCH 2/5] perf: cap the cost stage at 3 s and log what it left on the table The cost stage is anytime branch and bound and spends whatever the reserve leaves of the limit. On the production 10 s limit that is 5.4 s, and with the tie break seated in the rest, 17 percent of the split solves ended past the limit. An absolute cap of 3 s brings a split to about 7.5 s. Whether the seconds past 3 bought money is unknown, so the request log now carries the cost stage value and the gap CBC reported between its schedule and its bound, in currency, zero when proven. (cherry picked from commit c07ab08fe6006b5a6659dfed82c59829fdf8717f) --- README.md | 4 ++-- src/optimizer/app.py | 7 +++++++ src/optimizer/optimizer.py | 35 +++++++++++++++++++++++++++++++++-- tests/test_stage_timings.py | 6 ++++++ 4 files changed, 48 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index 0f28f5276..5d12369a4 100644 --- a/README.md +++ b/README.md @@ -48,13 +48,13 @@ The maximum is a single value out of the horizon, which leaves one gap: a load s ## How a request is solved -One request is up to five solver runs under one wall clock, `OPTIMIZER_TIME_LIMIT` (10 s in production). Each stage keeps what the previous one found unless it can improve on it without spending money. The request log carries where the clock went (`stages`), which path was taken (`path`), and what the tie break (`preferences`) and the continuity pass (`continuity`) did. +One request is up to five solver runs under one wall clock, `OPTIMIZER_TIME_LIMIT` (10 s in production). Each stage keeps what the previous one found unless it can improve on it without spending money. The request log carries where the clock went (`stages`), which path was taken (`path`), what the tie break (`preferences`) and the continuity pass (`continuity`) did, and what the cost stage found (`cost_stage_value`) against what it could not rule out (`cost_stage_gap`, currency, zero when proven). | Stage | Task | Runs when | Parameters | |---|---|---|---| | `build` | Build the MILP and scale its objective so the largest coefficient sits at `OBJECTIVE_TARGET`. | Always. | `OBJECTIVE_TARGET` 1e6 | | `probe` | Solve cost and preferences together. Proven optimal means the tie is decided in one solve: path `joint`, nothing else runs on the money. | Unless `OPTIMIZER_PROBE_SECONDS` is 0. | `OPTIMIZER_PROBE_SECONDS`, default `PROBE_SHARE` 0.2 of the limit | -| `cost` | Money only, stopped on an absolute gap. Holds back a slice of the clock for the tie break instead of taking whatever is left. | The probe did not prove its answer: path `split`. | `OPTIMIZER_GAP_ABS` 0.01 currency, `PREFERENCE_TIME_SHARE` 0.25 of the limit reserved | +| `cost` | Money only, stopped on an absolute gap. Holds back a slice of the clock for the tie break instead of taking whatever is left. | The probe did not prove its answer: path `split`. | `OPTIMIZER_GAP_ABS` 0.01 currency, `COST_TIME_LIMIT` 3 s, `PREFERENCE_TIME_SHARE` 0.25 of the limit reserved | | `tie_break`, LP | Pin the binaries the cost stage chose and move only the continuous variables, under a bound that keeps the cost found. Milliseconds, so it runs whatever the clock says. If CBC calls the bound infeasible the slack is widened tenfold per retry. | Path `split` and a strategy is configured. | `OPTIMIZER_PREFERENCE_BUDGET` 0, `COST_BOUND_SLACK` 1e-5 up to `COST_BOUND_SLACK_CEILING` 1e-2, `COST_BOUND_TOLERANCE` 1e-4, `LP_PREFERENCE_TIME_LIMIT` 1 s | | `tie_break`, MILP | Search the whole model under the same bound to beat the LP. Whichever is ahead is returned. | After the LP, clock permitting. | The reserved slice, capped at `MILP_PREFERENCE_TIME_LIMIT` 2.5 s; uncapped without a time limit | | `continuity` | Fewest charge starts for batteries with `c_min > 0`, bounded by the cost, the preference value and each levelled grid peak already reached. A preference, not a guarantee: prices, charge demands and grid shaping still win, and power may vary within a session. | A battery has more than one charging session, and the solve so far took less than the stage may spend. | `CONTINUITY_TIME_LIMIT` 1 s, `CONTINUITY_TOLERANCE` 1e-5 | diff --git a/src/optimizer/app.py b/src/optimizer/app.py index b0fa2bd48..eeec88632 100644 --- a/src/optimizer/app.py +++ b/src/optimizer/app.py @@ -41,6 +41,11 @@ def before_request_func(): return jsonify({"message": str(e)}), 401 +def money(value): + """Currency for the request log, or None where a stage did not run.""" + return None if value is None else round(value, 4) + + def dump_slow_request(payload, elapsed): """Persist requests that exhausted the solver time limit, they are the ones worth replaying. @@ -278,6 +283,8 @@ def post(self): "path": optimizer.solve_path, "preferences": optimizer.preference_stage, "continuity": optimizer.continuity_stage, + "cost_stage_value": money(optimizer.cost_stage_value), + "cost_stage_gap": money(optimizer.cost_stage_gap), "status": result.get('status'), "steps": optimizer.T, }}), flush=True) diff --git a/src/optimizer/optimizer.py b/src/optimizer/optimizer.py index 67c1e48a3..99a187f21 100644 --- a/src/optimizer/optimizer.py +++ b/src/optimizer/optimizer.py @@ -1,3 +1,5 @@ +import os +import re import shutil import time from contextlib import contextmanager @@ -145,6 +147,13 @@ def _complete_solution(problem: pulp.LpProblem) -> bool: # Requests without a time limit stay uncapped, they asked to be solved out. MILP_PREFERENCE_TIME_LIMIT = 2.5 +# clock the cost stage may spend on a split. Absolute rather than what the reserve leaves of the +# limit: the stage is anytime branch and bound and consumes whatever it is offered, so on the +# production 10 s limit every split ran 5.4 s of it and 17 percent of them ended past the limit. +# The split is 3 percent of the traffic and 38 percent of the CPU. Whether the seconds past 3 buy +# money is what cost_stage_gap is logged to answer. Requests without a time limit stay uncapped. +COST_TIME_LIMIT = 3.0 + # clock the pinned LP tie break may use. It is a linear program over a schedule that is already # feasible, worst measured 0.165 s over the stored cases, so this is a guard against a pathological # model rather than a budget. It runs even once the deadline is gone: without it a request that @@ -236,6 +245,9 @@ def __init__(self, strategy: OptimizationStrategy, grid: GridConfig, batteries: # found before it ran. Everything below that value was given away deciding the tie. self.preference_stage = None self.cost_stage_value = None + # money the cost stage could not rule out above its schedule, in currency. Zero when it + # proved the value, None when it did not run. + self.cost_stage_gap = None # 'joint' when the probe proved the whole objective, 'split' when it fell back self.solve_path = None # wall clock per stage of the last solve(), keyed build/probe/cost/tie_break. What the @@ -781,6 +793,23 @@ def _timed(self, stage): self.stage_seconds[stage] = round( self.stage_seconds.get(stage, 0.) + time.monotonic() - started, 4) + @staticmethod + def _cbc_gap(log_path, scale) -> float | None: + """Distance between CBC's schedule and its bound, from the log, in currency. + + The solution file carries no bound, only the log does: a proven solve prints none and the + gap is zero, a stopped one prints the bound it reached. + """ + with open(log_path) as log: + text = log.read() + value = re.search(r'^Objective value:\s+(\S+)', text, re.MULTILINE) + if value is None: + return None + bound = re.search(r'^(?:Lower|Upper) bound:\s+(\S+)', text, re.MULTILINE) + if bound is None: + return 0. + return abs(float(bound.group(1)) - float(value.group(1))) / scale + def _pin_integers(self): """Freeze every integer variable on the value it currently holds, undo data returned. @@ -1064,10 +1093,12 @@ def _probe_then_split(self, tmpdir, deadline) -> None: # use, see PREFERENCE_TIME_SHARE reserve = (0. if self.settings.time_limit is None else self.settings.time_limit * PREFERENCE_TIME_SHARE) - remaining = None if deadline is None else max(deadline - reserve - time.monotonic(), 0.1) + remaining = None if deadline is None else max(min(COST_TIME_LIMIT, deadline - reserve - time.monotonic()), 0.1) + log_path = os.path.join(tmpdir, 'cost.log') with self._timed('cost'): - self.problem.solve(self._solver(tmpdir, timeLimit=remaining, + self.problem.solve(self._solver(tmpdir, timeLimit=remaining, logPath=log_path, gapAbs=None if gap_abs is None else gap_abs * scale)) + self.cost_stage_gap = self._cbc_gap(log_path, scale) if pulp.LpStatus[self.problem.status] == 'Optimal' and self._is_feasible(): # the cost stage is allowed to stop on its gap, so LpSolutionOptimal is not required of diff --git a/tests/test_stage_timings.py b/tests/test_stage_timings.py index 5c2737429..0159149d9 100644 --- a/tests/test_stage_timings.py +++ b/tests/test_stage_timings.py @@ -15,6 +15,8 @@ def test_joint_path_times_build_and_probe(): assert optimizer.solve_path == 'joint' assert set(optimizer.stage_seconds) == {'build', 'probe'} + # no cost stage ran, so there is no gap to report + assert optimizer.cost_stage_gap is None assert all(seconds >= 0 for seconds in optimizer.stage_seconds.values()) @@ -28,3 +30,7 @@ def test_split_path_times_every_stage(): # no probe ran, so no probe key: an absent stage must be absent, not zero assert set(optimizer.stage_seconds) == {'build', 'cost', 'tie_break'} assert all(seconds >= 0 for seconds in optimizer.stage_seconds.values()) + # the cost stage leaves behind what it found and what CBC could not rule out above it + assert optimizer.cost_stage_value is not None + assert optimizer.cost_stage_gap is not None + assert optimizer.cost_stage_gap >= 0 From bab78f5fb183c4aa5f5d7826b41297dbb8dd6afc Mon Sep 17 00:00:00 2001 From: andig Date: Thu, 17 Sep 2026 18:17:47 +0200 Subject: [PATCH 3/5] refactor: read the charging state inline The helper pushed _solve_continuity past the return and statement limits once the rollup's stage reporting is merged in. (cherry picked from commit f73bdb11879f716c50d1da5e7c408697bb30196b) --- src/optimizer/optimizer.py | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/src/optimizer/optimizer.py b/src/optimizer/optimizer.py index 99a187f21..52e653bb7 100644 --- a/src/optimizer/optimizer.py +++ b/src/optimizer/optimizer.py @@ -962,19 +962,16 @@ def _solve_continuity(self, tmpdir: str, deadline: float | None) -> None: eligible = [i for i, active in self.variables['z_c'].items() if active is not None] - def charging_now(i: int) -> int: - return int(self.batteries[i].c_active) - def count_starts() -> list[int]: counts = [] for i in eligible: active = np.array([pulp.value(v) for v in self.variables['c'][i]]) > CONTINUITY_TOLERANCE - counts.append(int(np.count_nonzero(active & ~np.r_[bool(charging_now(i)), active[:-1]]))) + counts.append(int(np.count_nonzero(active & ~np.r_[self.batteries[i].c_active, active[:-1]]))) return counts before = count_starts() # a device that is charging already can reach zero starts, one that is idle needs one - if all(count <= 1 - charging_now(i) for i, count in zip(eligible, before)): + if all(count <= 1 - self.batteries[i].c_active for i, count in zip(eligible, before)): return # the candidate is this model plus a start per step, under a bound on the cost it just # optimized, so it is the harder problem: it does not finish inside a second where the @@ -1010,7 +1007,7 @@ def count_starts() -> list[int]: active = self.variables['z_c'][i] for t in self.time_steps: start = pulp.LpVariable(f'charge_start_{i}_{t}', lowBound=0, upBound=1) - candidate += start >= active[t] - (active[t - 1] if t else charging_now(i)) + candidate += start >= active[t] - (active[t - 1] if t else int(self.batteries[i].c_active)) starts.append(start) candidate.setObjective(-pulp.lpSum(starts)) From 57386c9160d9d7074f76014d3a0e4fbc0cb6b905 Mon Sep 17 00:00:00 2001 From: andig Date: Mon, 14 Sep 2026 16:26:27 +0200 Subject: [PATCH 4/5] feat: dump requests the capped cost stage left unproven With the cost stage capped nothing exhausts the time limit any more, so the slow request dump stopped filling. A request now also lands in it when the cost stage gap is above one currency unit, and the dump line carries that gap, so the replay corpus holds exactly the requests where a longer clock might have bought money. (cherry picked from commit 4c32a653efa5296b1ce80c283ab1aaadafbfea6c) --- src/optimizer/app.py | 19 ++++++++++++++----- src/optimizer/settings.py | 3 ++- tests/test_app.py | 20 ++++++++++++++++++++ 3 files changed, 36 insertions(+), 6 deletions(-) diff --git a/src/optimizer/app.py b/src/optimizer/app.py index eeec88632..ab1603045 100644 --- a/src/optimizer/app.py +++ b/src/optimizer/app.py @@ -46,20 +46,29 @@ def money(value): return None if value is None else round(value, 4) -def dump_slow_request(payload, elapsed): - """Persist requests that exhausted the solver time limit, they are the ones worth replaying. +# money the capped cost stage may leave unproven between its schedule and CBC's bound before +# the request is dumped for replay. The cap keeps requests short of the time limit, so the gap +# is what marks the ones worth replaying at a longer clock. +DUMP_GAP = 1.0 + + +def dump_slow_request(payload, elapsed, gap): + """Persist requests worth replaying: those that exhausted the solver time limit, and those + the cost stage left more than DUMP_GAP of money unproven on. The elapsed time covers model building as well as solving, so a request that only exceeds the limit while building is caught too. That one is equally worth looking at. """ path, limit = settings.dump_slow_requests, settings.time_limit - if not path or limit is None or elapsed < limit: + slow = limit is not None and elapsed >= limit + unproven = gap is not None and gap > DUMP_GAP + if not path or not (slow or unproven): return # one line per request, carrying the same "request" key as test_cases/*.json so a line # can be replayed by the existing harness line = json.dumps({"ts": datetime.now(timezone.utc).isoformat(timespec="seconds"), - "elapsed": round(elapsed, 3), "request": payload}) + "\n" + "elapsed": round(elapsed, 3), "gap": money(gap), "request": payload}) + "\n" try: pathlib.Path(path).parent.mkdir(parents=True, exist_ok=True) with open(path, "a") as f: @@ -289,7 +298,7 @@ def post(self): "steps": optimizer.T, }}), flush=True) - dump_slow_request(data, elapsed) + dump_slow_request(data, elapsed, optimizer.cost_stage_gap) return result except Exception as e: diff --git a/src/optimizer/settings.py b/src/optimizer/settings.py index 39c3ebf1b..34f72ddb1 100644 --- a/src/optimizer/settings.py +++ b/src/optimizer/settings.py @@ -21,4 +21,5 @@ class OptimizerSettings(BaseSettings): time_limit: float | None = Field(default=None, description="Time limit for the optimization process in seconds") log_subject: bool = Field(default=False, description="Log the JWT subject of every request. Off by default, it names accounts in the logs") dump_slow_requests: str | None = Field(default=None, - description="JSON Lines file requests that exhaust the solver time limit are appended to. Unset disables the dump") + description="JSON Lines file requests that exhaust the solver time limit, or leave more than one currency " + "unit unproven in the cost stage, are appended to. Unset disables the dump") diff --git a/tests/test_app.py b/tests/test_app.py index a442e1840..52325c1bb 100644 --- a/tests/test_app.py +++ b/tests/test_app.py @@ -7,6 +7,7 @@ import pulp import pytest +import optimizer.app as app_module from optimizer.app import app, settings @@ -138,6 +139,25 @@ def test_slow_requests_are_dumped(tmp_path, monkeypatch): assert json.loads(lines[1])["elapsed"] > 0 +def test_requests_with_an_open_gap_are_dumped(tmp_path, monkeypatch): + request = json.loads(pathlib.Path('test_cases/026-attenuate-grid-peaks.json').read_text())["request"] + dump = tmp_path / "gap.jsonl" + client = app.test_client() + monkeypatch.setattr(settings, "dump_slow_requests", str(dump)) + # the solver reads its own settings from the environment, so force the split there + monkeypatch.setenv("OPTIMIZER_PROBE_SECONDS", "0") + + # a proven cost stage has no gap to replay for + client.post("/optimize/charge-schedule", json=request) + assert not dump.exists() + + monkeypatch.setattr(app_module, "DUMP_GAP", -1.0) + client.post("/optimize/charge-schedule", json=request) + line = json.loads(dump.read_text()) + assert line["gap"] == 0 + assert line["request"] == request + + def test_every_request_logs_a_solve_line(capsys): # the key names are the Log Analytics contract: the dashboard's KQL queries parse this line, # so renaming one breaks production attribution silently From 16612987b15c8ca340e146587583d5f7d3ac2e2e Mon Sep 17 00:00:00 2001 From: andig Date: Sun, 4 Oct 2026 15:15:26 +0200 Subject: [PATCH 5/5] fix: judge the continuity stage by the cost stage clock on a split The skip gate summed probe and cost time. On the split path the probe alone is PROBE_SHARE of the time limit, so every split request skipped the stage. Gate on the cost stage the candidate extends, keep the probe for the joint path. A cost stage without a solver log reports no gap. Co-Authored-By: Claude Fable 5.1 --- src/optimizer/optimizer.py | 40 +++++++++++++++++++++++++------------- tests/test_continuity.py | 24 +++++++++++++++++++++-- 2 files changed, 49 insertions(+), 15 deletions(-) diff --git a/src/optimizer/optimizer.py b/src/optimizer/optimizer.py index 52e653bb7..3a88ed489 100644 --- a/src/optimizer/optimizer.py +++ b/src/optimizer/optimizer.py @@ -800,6 +800,9 @@ def _cbc_gap(log_path, scale) -> float | None: The solution file carries no bound, only the log does: a proven solve prints none and the gap is zero, a stopped one prints the bound it reached. """ + # no log, no solver run behind the values, see the faked stages in the tests + if not os.path.exists(log_path): + return None with open(log_path) as log: text = log.read() value = re.search(r'^Objective value:\s+(\S+)', text, re.MULTILINE) @@ -973,18 +976,8 @@ def count_starts() -> list[int]: # a device that is charging already can reach zero starts, one that is idle needs one if all(count <= 1 - self.batteries[i].c_active for i, count in zip(eligible, before)): return - # the candidate is this model plus a start per step, under a bound on the cost it just - # optimized, so it is the harder problem: it does not finish inside a second where the - # incumbent took longer than that. Measured over five days of production, 14 % of joint - # solves ran this stage and half of those sat on the cap with nothing to show (#146). The - # incumbent's own clock says which ones they are before a second is spent. - spent = self.stage_seconds.get('probe', 0.) + self.stage_seconds.get('cost', 0.) - if spent > CONTINUITY_TIME_LIMIT: - self.continuity_stage = f'skipped, solve took {spent:.1f} s' - return - remaining = CONTINUITY_TIME_LIMIT if deadline is None else min(CONTINUITY_TIME_LIMIT, deadline - time.monotonic()) - if remaining <= 0: - self.continuity_stage = 'no time' + remaining = self._continuity_clock(deadline) + if remaining is None: return solution = {var: var.varValue for var in self.problem.variables()} @@ -1037,12 +1030,33 @@ def count_starts() -> list[int]: self.continuity_stage = f'improved {sum(before)} to {sum(after)}' except pulp.PulpSolverError: self.continuity_stage = 'solver error' - return finally: if not improved: for var, value in solution.items(): var.varValue = value + def _continuity_clock(self, deadline: float | None) -> float | None: + """Seconds the continuity candidate may spend, or None with continuity_stage saying why not. + + The candidate is this model plus a start per step, under a bound on the cost it just + optimized, so it is the harder problem: it does not finish inside a second where the + incumbent took longer than that. Measured over five days of production, 14 % of joint + solves ran this stage and half of those sat on the cap with nothing to show (#146). The + incumbent's own clock says which ones they are before a second is spent: the probe on the + joint path, the cost stage on the split path. Not the probe there: it spent its clock on + the joint objective and failed, and alone it is PROBE_SHARE of the time limit, so counting + it skipped the stage on every split request (#170). + """ + spent = self.stage_seconds.get('cost', self.stage_seconds.get('probe', 0.)) + if spent > CONTINUITY_TIME_LIMIT: + self.continuity_stage = f'skipped, solve took {spent:.1f} s' + return None + remaining = CONTINUITY_TIME_LIMIT if deadline is None else min(CONTINUITY_TIME_LIMIT, deadline - time.monotonic()) + if remaining <= 0: + self.continuity_stage = 'no time' + return None + return remaining + def _probe_then_split(self, tmpdir, deadline) -> None: """ Solve the whole objective if it can be proved quickly, otherwise fall back to the split. diff --git a/tests/test_continuity.py b/tests/test_continuity.py index b6482140b..4202c0825 100644 --- a/tests/test_continuity.py +++ b/tests/test_continuity.py @@ -6,8 +6,7 @@ import pulp import pytest -from optimizer.optimizer import (CONTINUITY_TIME_LIMIT, BatteryConfig, GridConfig, OptimizationStrategy, Optimizer, - TimeSeriesData) +from optimizer.optimizer import CONTINUITY_TIME_LIMIT, BatteryConfig, GridConfig, OptimizationStrategy, Optimizer, TimeSeriesData def build(strategy: str = 'none') -> Optimizer: @@ -78,6 +77,27 @@ def slow(tmpdir: str, deadline: float | None) -> None: assert 'continuity' not in model.stage_seconds +def test_split_solve_is_judged_by_its_cost_stage(monkeypatch: pytest.MonkeyPatch): + # on the split path the probe spent its clock on the joint objective and failed, so it says + # nothing about the candidate; the cost stage it extends does. Counting the probe skipped the + # stage on every split request, the probe alone being PROBE_SHARE of the time limit (#170) + model = build() + seed_fragmented(model, monkeypatch) + seeded = model._probe_then_split + + def split(tmpdir: str, deadline: float | None) -> None: + seeded(tmpdir, deadline) + model.stage_seconds['probe'] = CONTINUITY_TIME_LIMIT + 1 + model.stage_seconds['cost'] = 0.1 + + monkeypatch.setattr(model, '_probe_then_split', split) + + result = model.solve() + + assert starts(result['batteries'][0]['charging_power']) == 1 + assert model.continuity_stage == 'improved 3 to 1' + + @pytest.mark.parametrize('schedule', [(0, 500, 0, 500, 0, 500), (0, 500, 500, 500, 0, 0)]) def test_running_session_is_not_interrupted(monkeypatch: pytest.MonkeyPatch, schedule: tuple[float, ...]): model = build()