Forecast from the right end of the window, and from the level shown
Some checks failed
CI / backend (push) Failing after 8s
CI / naming (push) Successful in 2s
CI / frontend (push) Successful in 8s
CI / migrations-mysql (push) Failing after 6s

Four defects stacked into one nonsense report: cartridges at 20% claiming four
days, cartridges at 1% claiming weeks.

The root cause is a Zabbix API detail. `limit` caps the whole result set rather
than each item, and the query sorted ascending, so the cap kept the OLDEST rows
in the window. A four-cartridge printer polled every five minutes writes over
100k readings in 90 days; the forecast was fitted to the first few days of that
and nothing since. Every rate was real and every rate described a cartridge
thrown away three months ago. Nothing in the output looks wrong, which is why
it needed pinning in a test rather than a comment.

A 90-day burn rate does not need every individual poll, so a long window now
reads hourly trends - the table meant for this, a tenth of the rows, and kept
longer. Raw history serves short windows and any item a site keeps no trends
for. Both are fetched newest-first with the budget scaled per item.

Second, the countdown was computed from the last stored reading while the level
displayed was the live one, so the two could disagree by a whole cartridge. The
live level is now what the countdown divides. A live level far above the stored
run means it was swapped since the last reading, and that is reported as a
replacement rather than as a collapse in the burn rate.

Third, at or below 5% a cartridge reads as empty rather than as a slow drain.
At 1% losing a tenth of a point a day the arithmetic says ten days. The printer
is out of toner, and it is the first thing to order.

Fourth, the days-left column spanned the printer's rows, so the printer's
soonest figure was printed beside every supply it had. That alone accounts for
the shape of both complaints: a healthy cartridge wearing its neighbour's
deadline, and an empty one wearing a number that belonged to nothing on its row.

Also fixes float-typed supplies vanishing from any printer that also had an
integer-typed one - they live in different history tables and the fetch stopped
at whichever answered first.

Not verified against live data: Zabbix is not reachable from the dev box.
This commit is contained in:
cproudlock
2026-08-13 10:54:23 -04:00
parent 1e884dc02a
commit 7d66551622
7 changed files with 376 additions and 25 deletions

View File

@@ -79,6 +79,33 @@ each fix ships with the check, report or document that would have surfaced it.
### Fixed ### Fixed
- The toner forecast was reading the wrong end of the window. Zabbix applies a
query's `limit` to the whole answer rather than to each item, and combined
with an ascending sort that kept the OLDEST rows: a four-cartridge printer
polled every five minutes writes over 100k readings in 90 days, so a "90 day"
forecast was fitted to the first few days of the window and nothing since.
That is where "4 days left" beside a cartridge at 20% came from - the rate
was real, it just described a cartridge thrown away in May. Long windows now
read hourly trends, which is the table meant for this and is a tenth of the
rows; short ones read raw history, newest first, with a budget scaled per
item.
- The forecast now counts down from the level it displays. It showed the live
reading but computed days-left from the last stored one, so the two could
disagree by a whole cartridge. A live level far above the stored run is
treated as a swap that happened since the last reading rather than as a
collapse in the burn rate.
- A cartridge at or below 5% reads as empty rather than as a slow drain. At 1%
losing a tenth of a point a day the arithmetic said ten days; the printer is
out of toner, and it is the first thing that should be ordered.
- Days-left in the forecast is per cartridge again. It was rendered in a cell
spanning the printer's rows, which put the printer's soonest figure beside
every supply it had - a cartridge at 20% displaying "4 days" that belonged to
the black beside it, and a cartridge at 1% displaying weeks that belonged to
nothing on that row at all.
- Supplies typed as floats were dropped from the forecast on any printer that
also had an integer-typed one. The two live in different Zabbix history
tables and the fetch stopped at whichever answered first, so half a printer's
cartridges silently had no history at all.
- A shop-floor PC that reported the machine number of a machine ShopDB already - A shop-floor PC that reported the machine number of a machine ShopDB already
knew got a 500 from the collector, on every report, forever. The reported knew got a 500 from the collector, on every report, forever. The reported
machine number was being written to the PC's own `assets.assetnumber`, which machine number was being written to the PC's own `assets.assetnumber`, which

View File

@@ -1541,16 +1541,18 @@ def supplies_forecast():
if not supplies: if not supplies:
continue continue
itemids = [s['itemid'] for s in supplies if s.get('itemid')] itemids = [s['itemid'] for s in supplies if s.get('itemid')]
history = service.gethistory(itemids, days=days) history = service.getlevelhistory(itemids, days=days)
analysed = [] analysed = []
for supply in supplies: for supply in supplies:
points = history.get(str(supply.get('itemid')), []) points = history.get(str(supply.get('itemid')), [])
detail = analyse(points) # The live read is the level the report shows, so it is also the
# level the countdown is computed from - history lags a poll, and a
# row whose level and days-left came from different moments reads
# as broken.
detail = analyse(points, currentlevel=supply.get('level'))
detail['name'] = supply.get('name') detail['name'] = supply.get('name')
detail['color'] = supply.get('color') detail['color'] = supply.get('color')
# Trust the live read for the level; history can lag a poll behind.
detail['currentlevel'] = supply.get('level', detail['currentlevel'])
analysed.append(detail) analysed.append(detail)
entry = { entry = {

View File

@@ -55,7 +55,14 @@
</thead> </thead>
<tbody> <tbody>
<!-- Sorted by days left, not by level: a cartridge at 60% falling <!-- Sorted by days left, not by level: a cartridge at 60% falling
fast is ordered before one sitting at 8% that never moves. --> fast is ordered before one sitting at 8% that never moves.
Days left is per CARTRIDGE, not per printer. It used to span
the printer's rows, so every supply displayed the soonest one
of them - a cartridge at 20% sat beside "4 days" that belonged
to the black next to it. The printer number still decides
where the printer sorts; it does not label a row it is not
about. -->
<template v-for="p in printers" :key="p.printerid"> <template v-for="p in printers" :key="p.printerid">
<tr v-for="(s, index) in p.supplies" :key="p.printerid + s.name" <tr v-for="(s, index) in p.supplies" :key="p.printerid + s.name"
:class="{ 'row-group-start': index === 0 }"> :class="{ 'row-group-start': index === 0 }">
@@ -65,10 +72,12 @@
</router-link> </router-link>
<div class="muted small">{{ p.ipaddress }}</div> <div class="muted small">{{ p.ipaddress }}</div>
</td> </td>
<td v-if="index === 0" :rowspan="p.supplies.length"> <td>
<span class="days" :class="urgency(p.daysleft)"> <span v-if="s.daysleft === 0" class="days critical">empty now</span>
{{ p.daysleft }} days <span v-else-if="s.daysleft != null" class="days" :class="urgency(s.daysleft)">
{{ s.daysleft }} days
</span> </span>
<span v-else class="muted">-</span>
</td> </td>
<td>{{ s.name }}</td> <td>{{ s.name }}</td>
<td>{{ s.currentlevel != null ? Math.round(s.currentlevel) + '%' : '-' }}</td> <td>{{ s.currentlevel != null ? Math.round(s.currentlevel) + '%' : '-' }}</td>

View File

@@ -29,6 +29,13 @@ MIN_POINTS_FOR_ESTIMATE = 4
# says "never", which is worse than saying nothing. # says "never", which is worse than saying nothing.
MIN_DROP_FOR_ESTIMATE = 2 MIN_DROP_FOR_ESTIMATE = 2
# At or below this, the cartridge is done and the arithmetic stops being the
# useful answer. A supply sitting at 1% that drains a tenth of a point a day
# computes to ten days; a printer at 1% is out of toner as far as anyone
# standing at it is concerned, and it is what should be ordered first. Rate is
# still reported - only the days-left figure is floored.
EMPTY_LEVEL = 5
def _asfloat(value): def _asfloat(value):
try: try:
@@ -101,11 +108,17 @@ def burn_rate(points):
return drop / days return drop / days
def analyse(points, rise=REPLACEMENT_RISE): def analyse(points, rise=REPLACEMENT_RISE, currentlevel=None):
"""Everything the report needs about one supply. """Everything the report needs about one supply.
`currentlevel` is the live reading from the printer, when the caller has
one. It is what the days-left figure is computed against, because it is
what the report displays: taking the level from the display and the
countdown from the last stored history point lets the two disagree, and a
row reading "20% - 4 days left" is read as a broken report, correctly.
Returns: Returns:
currentlevel latest reading, or None currentlevel live reading if given, else the latest stored one
daysleft at the current rate, or None when there is no estimate daysleft at the current rate, or None when there is no estimate
burnrateperday percent per day, or None burnrateperday percent per day, or None
reason why there is no estimate - shown rather than hidden, so reason why there is no estimate - shown rather than hidden, so
@@ -117,11 +130,15 @@ def analyse(points, rise=REPLACEMENT_RISE):
""" """
points = normalise(points) points = normalise(points)
result = { result = {
'currentlevel': None, 'daysleft': None, 'burnrateperday': None, 'currentlevel': currentlevel, 'daysleft': None, 'burnrateperday': None,
'reason': None, 'replacements': 0, 'lastreplaced': None, 'reason': None, 'replacements': 0, 'lastreplaced': None,
'basisdays': 0, 'points': [], 'basisdays': 0, 'points': [],
} }
if not points: if not points:
# A live level with no history is still worth acting on when it is low.
if currentlevel is not None and currentlevel <= EMPTY_LEVEL:
result['daysleft'] = 0
else:
result['reason'] = 'no history' result['reason'] = 'no history'
return result return result
@@ -130,13 +147,30 @@ def analyse(points, rise=REPLACEMENT_RISE):
result['lastreplaced'] = replacements[-1].isoformat() if replacements else None result['lastreplaced'] = replacements[-1].isoformat() if replacements else None
run = current_run(points, rise=rise) run = current_run(points, rise=rise)
result['currentlevel'] = run[-1][1] stored = run[-1][1]
level = stored if currentlevel is None else currentlevel
result['currentlevel'] = level
result['points'] = [(when.isoformat(), level) for when, level in run] result['points'] = [(when.isoformat(), level) for when, level in run]
if len(run) >= 2: if len(run) >= 2:
result['basisdays'] = round( result['basisdays'] = round(
(run[-1][0] - run[0][0]).total_seconds() / 86400, 1) (run[-1][0] - run[0][0]).total_seconds() / 86400, 1)
# A live level well above the stored run means it was swapped since the
# last stored reading. The run describes the cartridge that came out.
if currentlevel is not None and currentlevel - stored >= rise:
result['replacements'] += 1
result['reason'] = 'replaced recently'
return result
rate = burn_rate(run) rate = burn_rate(run)
# Empty is empty. Ordering by a rate below this level ranks a dead
# cartridge behind a healthy one that happens to be draining faster.
if level <= EMPTY_LEVEL:
result['daysleft'] = 0
result['burnrateperday'] = round(rate, 2) if rate is not None else None
return result
if rate is None: if rate is None:
# Say which of the three it is; "no estimate" alone invites a bug report. # Say which of the three it is; "no estimate" alone invites a bug report.
if len(run) < MIN_POINTS_FOR_ESTIMATE: if len(run) < MIN_POINTS_FOR_ESTIMATE:
@@ -147,7 +181,7 @@ def analyse(points, rise=REPLACEMENT_RISE):
return result return result
result['burnrateperday'] = round(rate, 2) result['burnrateperday'] = round(rate, 2)
result['daysleft'] = max(0, int(run[-1][1] / rate)) result['daysleft'] = max(0, int(level / rate))
return result return result

View File

@@ -220,37 +220,119 @@ class ZabbixService:
}) })
return supplies return supplies
def gethistory(self, itemids, days=90, limit=5000): # Per item, per call. Zabbix applies `limit` to the WHOLE result set, not
# per item, so the budget is multiplied by the number of items asked for.
HISTORY_PER_ITEM = 2000
def gethistory(self, itemids, days=90, peritem=None):
"""Raw level history for supply items: {itemid: [(clock, value), ...]}. """Raw level history for supply items: {itemid: [(clock, value), ...]}.
Zabbix keeps this already - we simply never asked for it. history=3 is Ordered oldest-first, which is what the analysis expects.
the unsigned-integer table, which is where a percent-remaining item
lands; a site that types the item as float would need history=0, so a Two things about the Zabbix API make the obvious call return the wrong
miss falls back rather than erroring. rows, and both bit us:
* `limit` caps the whole answer, not each item. A four-cartridge
printer polled every five minutes writes over 100k rows in 90 days.
* combined with `sortorder: ASC`, the cap keeps the OLDEST rows - so a
"90 day" request came back holding the first few days of the window
and nothing since. Every rate was computed from history a quarter of
a year stale.
So: sort DESC to keep the NEWEST rows, scale the budget by item count,
and hand back ascending.
history=3 is the unsigned-integer table, where a percent-remaining item
lands; a site that types the item as float needs history=0. Items can be
split across the two, so both are asked and the results merged - an
earlier version stopped as soon as either answered, which silently lost
every float-typed supply on a printer that also had an integer one.
Returns {} when Zabbix is off or unreachable, so callers degrade to Returns {} when Zabbix is off or unreachable, so callers degrade to
"no estimate" instead of failing. "no estimate" instead of failing.
""" """
if not itemids: if not itemids:
return {} return {}
itemids = [str(i) for i in itemids]
peritem = peritem or self.HISTORY_PER_ITEM
timefrom = int(time.time()) - days * 86400 timefrom = int(time.time()) - days * 86400
collected = {} collected = {}
for historytype in (3, 0): for historytype in (3, 0):
outstanding = [i for i in itemids if i not in collected]
if not outstanding:
break
rows = self._apicall("history.get", { rows = self._apicall("history.get", {
"output": "extend", "output": "extend",
"history": historytype, "history": historytype,
"itemids": list(itemids), "itemids": outstanding,
"time_from": timefrom, "time_from": timefrom,
"sortfield": "clock", "sortfield": "clock",
"sortorder": "ASC", "sortorder": "DESC",
"limit": limit, "limit": peritem * len(outstanding),
}) or [] }) or []
for row in rows: for row in rows:
collected.setdefault(str(row.get("itemid")), []).append( collected.setdefault(str(row.get("itemid")), []).append(
(row.get("clock"), row.get("value"))) (row.get("clock"), row.get("value")))
# Items live in one table or the other; stop once something answered.
if collected: for itemid, points in collected.items():
break points.reverse() # DESC came back; analysis wants ASC
return collected
# Trends are hourly aggregates and are kept far longer than raw history.
# 90 days of raw 5-minute readings is 26k rows an item; the same window in
# trends is 2160. For a burn rate over months that is the right table -
# nothing is gained by fitting a line through every individual poll.
TRENDS_MIN_DAYS = 7
TRENDS_PER_ITEM = 3000
def gettrends(self, itemids, days=90, peritem=None):
"""Hourly level averages: {itemid: [(clock, value), ...]}, oldest first.
Same `limit` caveat as gethistory - it caps the whole answer, so the
budget is scaled and the sort is DESC.
Returns {} if trends are not kept (a site can set the trend period to
0), which is a real configuration, not an error. Callers fall back to
raw history.
"""
if not itemids:
return {}
itemids = [str(i) for i in itemids]
peritem = peritem or self.TRENDS_PER_ITEM
timefrom = int(time.time()) - days * 86400
rows = self._apicall("trend.get", {
"output": ["itemid", "clock", "value_avg"],
"itemids": itemids,
"time_from": timefrom,
"sortfield": "clock",
"sortorder": "DESC",
"limit": peritem * len(itemids),
}) or []
collected = {}
for row in rows:
collected.setdefault(str(row.get("itemid")), []).append(
(row.get("clock"), row.get("value_avg")))
for itemid, points in collected.items():
points.reverse()
return collected
def getlevelhistory(self, itemids, days=90):
"""Level history for a forecast, from whichever table serves it best.
Trends for a long window, raw history for a short one, and raw history
for any item the trend table has nothing for.
"""
if not itemids:
return {}
if days < self.TRENDS_MIN_DAYS:
return self.gethistory(itemids, days=days)
collected = self.gettrends(itemids, days=days)
missing = [i for i in (str(i) for i in itemids) if not collected.get(i)]
if missing:
collected.update(self.gethistory(missing, days=days))
return collected return collected
def getpingstatus(self, ip: str) -> str: def getpingstatus(self, ip: str) -> str:

View File

@@ -99,6 +99,58 @@ def test_days_left_never_goes_negative():
assert result['daysleft'] == 0 assert result['daysleft'] == 0
def test_live_level_drives_the_countdown_not_the_stored_one():
"""The report shows the live level, so it must count down from that one.
History lags a poll, and trends lag an hour. Displaying 20% beside a
countdown computed from a stored 4% is how a report loses its reader.
"""
result = analyse(series([100, 80, 60, 40]), currentlevel=20)
assert result['currentlevel'] == 20
assert result['burnrateperday'] == 20.0 # 60 points over 3 days
assert result['daysleft'] == 1 # 20 / 20, not 40 / 20
def test_a_nearly_empty_cartridge_reads_as_empty_not_as_weeks_away():
"""1% draining a tenth of a point a day computes to ten days. It is out."""
result = analyse(series([2.0, 1.7, 1.4, 1.1]), currentlevel=1)
assert result['daysleft'] == 0
def test_empty_sorts_ahead_of_a_fast_healthy_cartridge():
empty = analyse(series([2.0, 1.7, 1.4, 1.1]), currentlevel=1)
healthy = analyse(series([100, 80, 60, 40]))
assert empty['daysleft'] < healthy['daysleft']
def test_a_low_live_level_is_actionable_without_any_history():
"""A printer new to Zabbix still reports it is out of toner."""
result = analyse([], currentlevel=1)
assert result['daysleft'] == 0
assert result['reason'] is None
def test_no_history_and_a_healthy_level_still_says_no_history():
result = analyse([], currentlevel=80)
assert result['daysleft'] is None
assert result['reason'] == 'no history'
def test_a_live_level_above_the_stored_run_means_it_was_just_swapped():
"""Trends lag an hour; a cartridge changed in that hour must not inherit
the rate of the one that came out."""
result = analyse(series([40, 30, 20, 10]), currentlevel=100)
assert result['daysleft'] is None
assert result['reason'] == 'replaced recently'
assert result['replacements'] == 1
def test_printer_sorts_by_its_soonest_supply(): def test_printer_sorts_by_its_soonest_supply():
"""A colour MFP is as urgent as its most pressing cartridge.""" """A colour MFP is as urgent as its most pressing cartridge."""
supplies = [{'daysleft': 40}, {'daysleft': 6}, {'daysleft': None}] supplies = [{'daysleft': 40}, {'daysleft': 6}, {'daysleft': None}]

View File

@@ -0,0 +1,145 @@
"""Tests for how level history is fetched out of Zabbix.
These are about the shape of the API call, not about the arithmetic done
afterwards, because that is where the forecast went wrong: the numbers were
computed correctly from the wrong rows.
Zabbix applies `limit` to the whole result set rather than to each item, so a
capped query sorted ascending returns the OLDEST rows in the window. A
four-cartridge printer polled every five minutes writes over 100k rows in 90
days; the report was reading the first few days of that and calling it current.
No arithmetic recovers from it, and nothing about the output looks wrong -
which is why it is pinned here.
"""
from plugins.printers.services.zabbix_service import ZabbixService
class RecordingService(ZabbixService):
"""A service whose API calls are recorded and answered from a script."""
def __init__(self, answers=None):
super().__init__()
self.calls = []
self.answers = answers or {}
def _apicall(self, method, params):
self.calls.append((method, params))
answer = self.answers.get(method)
if callable(answer):
return answer(params)
return answer or []
def paramsfor(self, method):
return [params for name, params in self.calls if name == method]
def rows(itemid, values, start=1780000000, step=3600):
"""history.get rows, newest first, as a DESC query returns them."""
return [{'itemid': str(itemid), 'clock': str(start + i * step),
'value': str(value)} for i, value in enumerate(values)][::-1]
def test_history_asks_for_the_newest_rows_not_the_oldest():
service = RecordingService({'history.get': rows(1, [90, 80, 70])})
service.gethistory(['1'], days=90)
params = service.paramsfor('history.get')[0]
assert params['sortorder'] == 'DESC'
assert params['sortfield'] == 'clock'
def test_history_budget_scales_with_the_number_of_items():
"""One cap shared by four cartridges is a quarter of a cartridge each."""
service = RecordingService({'history.get': rows(1, [90, 80])})
service.gethistory(['1', '2', '3', '4'], days=90)
params = service.paramsfor('history.get')[0]
assert params['limit'] == ZabbixService.HISTORY_PER_ITEM * 4
def test_history_comes_back_oldest_first():
"""The analysis reads a series forwards; DESC is a fetch detail."""
service = RecordingService({'history.get': rows(1, [90, 80, 70])})
result = service.gethistory(['1'], days=90)
clocks = [int(clock) for clock, _ in result['1']]
assert clocks == sorted(clocks)
assert [value for _, value in result['1']] == ['90', '80', '70']
def test_items_split_across_both_history_tables_are_all_returned():
"""A printer can carry an integer-typed supply and a float-typed one.
Stopping at the first table that answered dropped every item in the other,
and a missing cartridge looks exactly like a cartridge with no history.
"""
def answer(params):
if params['history'] == 3:
return rows(1, [90, 80])
return rows(2, [70, 60])
service = RecordingService({'history.get': answer})
result = service.gethistory(['1', '2'], days=90)
assert set(result) == {'1', '2'}
def test_the_second_table_is_only_asked_about_what_is_still_missing():
def answer(params):
return rows(1, [90, 80]) if params['history'] == 3 else []
service = RecordingService({'history.get': answer})
service.gethistory(['1', '2'], days=90)
assert service.paramsfor('history.get')[1]['itemids'] == ['2']
def test_a_long_window_reads_trends_rather_than_every_poll():
"""90 days of raw readings is 26k rows an item and hours of transfer for a
number that is a slope."""
service = RecordingService({'trend.get': [
{'itemid': '1', 'clock': '1780000000', 'value_avg': '80'},
{'itemid': '1', 'clock': '1779996400', 'value_avg': '90'},
]})
result = service.getlevelhistory(['1'], days=90)
assert service.paramsfor('trend.get')
assert not service.paramsfor('history.get')
assert [value for _, value in result['1']] == ['90', '80']
def test_a_short_window_reads_raw_history():
"""Over a few days the hourly average has too few points to fit."""
service = RecordingService({'history.get': rows(1, [90, 80])})
service.getlevelhistory(['1'], days=2)
assert service.paramsfor('history.get')
assert not service.paramsfor('trend.get')
def test_an_item_with_no_trends_falls_back_to_its_raw_history():
"""A site can keep trends for 0 days. That is a setting, not a fault."""
service = RecordingService({
'trend.get': [{'itemid': '1', 'clock': '1780000000', 'value_avg': '80'}],
'history.get': rows(2, [70, 60]),
})
result = service.getlevelhistory(['1', '2'], days=90)
assert service.paramsfor('history.get')[0]['itemids'] == ['2']
assert set(result) == {'1', '2'}
def test_no_items_asks_nothing():
service = RecordingService()
assert service.getlevelhistory([], days=90) == {}
assert service.calls == []