From 828b55d70e92e8ef31403c920cd42686e3172c61 Mon Sep 17 00:00:00 2001 From: Elmehdi Aitbrahim Date: Fri, 4 Sep 2026 16:46:12 -0400 Subject: [PATCH 1/2] fix(web): the CSV export sent a body on HEAD, dropped connections, and truncated itself (#703) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review findings on #703, which merged before these landed. Three of them are on the export route, and all three are the kind static analysis cannot see. A HEAD RETURNED THE WHOLE FILE. `_send`, `_send_json` and `_serve_static` all end their write with `if self.command != "HEAD"`. `_send_csv` did not, and `do_HEAD` delegates to `do_GET` -- so `HEAD /api/timeline/export.csv` answered with the header block plus 468 bytes of CSV. On a keep-alive connection those bytes are framed as the NEXT response: a same-origin response desync, not merely a wasted transfer, and a violation of RFC 9110 §9.3.2. The first test written for this passed against the bug. `http.client` knows a HEAD carries no body and never reads one, so it reports an empty body whether or not the server sent bytes -- the test now reads a raw socket, and says why in its docstring. THE ROUTE DROPPED CONNECTIONS. `respond` is what normally guarantees this server never answers a GET by raising: `ApiRefusal` becomes a 400, anything else a 500 envelope. The CSV branch does not go through it, so `?limit=abc` propagated out of the handler -- the client saw a reset connection with no response, and a traceback of absolute source paths reached the stderr `log_message` is overridden to keep quiet. A first-run machine with no config.yaml did the same, where `/api/timeline` answers 200 with `engine: "stopped"`. Wrapped now, answering the JSON envelope: the failure is not a file, and a browser handed a truncated download learns nothing. THE EXPORT WAS SILENTLY TRUNCATED. It inherited the paged route's `?limit=` -- default 200, ceiling 2000 -- and the file said nothing about it. A 5,000-event deployment exported its most recent 200 rows, to be handed to an auditor or a tax preparer as a complete record. The cap exists because the console POLLS the JSON route every 15 seconds; an export is a deliberate download, requested once. `export_rows` reads the whole scope, and the scope -- the operator's own choice of today/7d/all -- is what bounds it. A SORT COLUMN THAT ORDERED NOTHING. `sortable=("ts", ...)` while the payload emits `at`, so `?sort=ts` was accepted, echoed back as applied, and left every row where it was -- the exact failure refusing an unknown column exists to prevent. The pin for this rot already existed at `test_api.py:526` and covered two routes; `/api/timeline` was simply not in it, and is now. AN UNREADABLE LOG LOOKED LIKE AN IDLE ENGINE. `read_log_window` returns a `LogWindow` for every outcome and carries the result in `status`; that status was discarded, so a log that could not be read (permissions, a rotation race) yielded zero lines -- dropping every `system` row AND dropping `system` from the chips. In the CSV an auditor opens, that is indistinguishable from "the engine never ran". `activity.py`'s own docstring names the failure: silently discarding input is how a feed comes to under-report reality while looking healthy. It now raises, and the route turns it into a stated failure. The `except OSError` around it was dead -- `read_log_window` catches its own -- while the call that does raise on a real deployment, `load_config`, sat outside it. LEADING WHITESPACE SMUGGLED FORMULAS PAST, and a test pinned the gap open. `" =cmd|..."` is a legal `coinbase_id` out of an imported venue CSV and lands in a cell by itself; Sheets and LibreOffice trim before deciding whether a cell is a formula. The check now strips SPACES only -- a bare `lstrip()` consumes tab and carriage return, which are themselves triggers, and broke two existing tests when tried. `\\n` joins the trigger list. TWO TESTS THAT PASSED FOR THE WRONG REASON. Removing `csv_safe` from nine of its ten cells left the whole suite green: only `reference` was pinned, so the module's load-bearing claim -- "applied to EVERY text cell, not to a list of the risky ones" -- was untested for nine columns including `summary`, which carries an imported `notes` field verbatim. And deleting the newest-first sort left the suite green too, because the fixtures seeded oldest-to-newest in the same order the sources are concatenated. Both are pinned now with scrambled fixtures and a whole-row export assertion, and both die under mutation, along with the HEAD guard and the export cap. Smaller: an unrecognised `?kind=` is collapsed to "every kind" rather than applied, so the plural typo no longer returns a page that looks like an empty deployment -- the outcome `normalise_scope`, which it sits beside, exists to never produce; the cap's docstring said the READ was bounded when it bounds the response slice (four unfiltered SELECTs underneath); and the export URL is built with `URL`/`searchParams` like every other URL in the client. That last one was caught by the call-resolution scanner added in #701: `URL` was not in its browser-globals list, so the guard failed the build on its own author's new code. `URL` is a real browser API and now belongs to that list. Co-Authored-By: Claude Opus 5 (1M context) --- keel/commands/timeline.py | 65 +++++++++++++++-- keel/web/api.py | 106 +++++++++++++++++++++------- keel/web/server.py | 24 ++++++- keel/web/static/js/render.js | 12 ++-- tests/commands/test_timeline.py | 87 +++++++++++++++++++++-- tests/commands/test_timeline_csv.py | 18 +++++ tests/web/test_api.py | 14 +++- tests/web/test_client_assets.py | 1 + tests/web/test_timeline_export.py | 106 ++++++++++++++++++++++++++++ 9 files changed, 388 insertions(+), 45 deletions(-) diff --git a/keel/commands/timeline.py b/keel/commands/timeline.py index 97b5e46..795b9da 100644 --- a/keel/commands/timeline.py +++ b/keel/commands/timeline.py @@ -63,7 +63,7 @@ #: figure gets quoted. That is the correct trade for an audit export: a spreadsheet shows #: `'-12.30` as text rather than evaluating it, the value is still readable and still #: re-importable, and losing numeric typing is a smaller harm than executing a cell. -_FORMULA_TRIGGERS = ("=", "+", "-", "@", "\t", "\r") +_FORMULA_TRIGGERS = ("=", "+", "-", "@", "\t", "\r", "\n") def csv_safe(value: Any) -> str: @@ -85,7 +85,16 @@ def csv_safe(value: Any) -> str: if value is None: return "" text = str(value) - if text.startswith(_FORMULA_TRIGGERS): + # Checked against the LEADING-WHITESPACE-STRIPPED text, and the ORIGINAL is what gets quoted. + # A strict first-character test is defeated by one space: `" =cmd|..."` is a legal + # `coinbase_id` out of an imported venue CSV, it lands in a cell by itself, and Google Sheets + # and LibreOffice trim on import before deciding whether a cell is a formula. Excel treats a + # leading space as text -- but a defence that holds in one spreadsheet and not the two this + # file will also be opened in is not a defence. + # `lstrip(" ")` and not a bare `lstrip()`: tab and carriage return are TRIGGERS themselves, + # so stripping all whitespace would consume the very characters being looked for and let + # "\t=cmd" through. Spaces are the only thing skipped over. + if text.lstrip(" ").startswith(_FORMULA_TRIGGERS): return "'" + text return text @@ -151,12 +160,25 @@ def shown_count(self) -> int: -#: The cap on one merged read. Four stores, three of them unbounded, joined into one response: -#: without a cap this route's cost is the size of the deployment's whole history. Newest-first -#: and capped means the page always answers, and the counts below say how much it did not show. +#: The cap on one PAGE of the merged feed -- the response slice, not the read. +#: +#: Stated precisely because the first version of this note was wrong: the four reads underneath +#: are unfiltered (`get_orders`, `get_transactions` and both attestation reads are `SELECT *`, +#: scoped in Python afterwards), so the READ cost is the deployment's whole history whatever this +#: number says. That matches `gather_orders`' own convention and is not a regression -- but the +#: cap bounds what crosses the wire and what a browser renders, and claiming more than that is +#: the kind of comfortable inaccuracy this codebase's documentation standard exists to catch. +#: +#: Newest-first and capped means the page always answers, and the counts say how much it did not +#: show. `export_rows` deliberately does not use it. DEFAULT_TIMELINE_LIMIT = 200 MAX_TIMELINE_LIMIT = 2000 +#: The cap `export_rows` passes: none. Spelled as a constant rather than an `Optional` parameter +#: so the uncapped read is a named decision at its one call site rather than a `None` that could +#: arrive by accident from anywhere. +_UNCAPPED = 2**31 + def _order_rows(repo: Repository, since_ts: int | None) -> list[TimelineRow]: """`orders` -> trade rows. @@ -334,7 +356,13 @@ def gather_timeline( filtering the rows it happened to receive and calling the result "every flow this month". """ resolved_scope = normalise_scope(scope) - resolved_kind = (kind or "").strip().lower() + # An unrecognised kind is COLLAPSED to "every kind", not applied. `?kind=trades` -- the + # obvious typo, since the chips read "trade" -- would otherwise return a page that looks like + # an empty deployment: a non-zero `scoped_count`, zero rows, and no chip marked current. + # That is the outcome `normalise_scope`, which this function sits beside and reuses, exists + # to never produce. The applied value is echoed in `kind`, so the substitution is visible. + requested_kind = (kind or "").strip().lower() + resolved_kind = requested_kind if requested_kind in TIMELINE_KINDS else "" resolved_limit = max(1, min(int(limit), MAX_TIMELINE_LIMIT)) since = scope_start_ts(resolved_scope, now_ts) @@ -364,6 +392,31 @@ def gather_timeline( ) +def export_rows( + repo: Repository, + *, + now_ts: int, + scope: str = "all", + kind: str = "", + cycles: Sequence[Any] = (), +) -> TimelineReport: + """The whole scope, uncapped -- what the CSV export reads. + + **Deliberately not `gather_timeline`'s cap.** That cap exists because the console polls the + JSON route every 15 seconds; an export is a deliberate download, requested once, of a record + an operator may hand to an auditor or a tax preparer. Inheriting the page's limit made the + file 200 rows of a 5,000-event deployment with nothing in it saying so -- a partial record + that reads as complete, which is worse than no export at all. + + The SCOPE still bounds it: `?scope=today|7d|all` is the operator's own choice about how much + they are asking for, and `all` on a long-lived deployment is a large file by request rather + than by accident. + """ + return gather_timeline( + repo, now_ts=now_ts, scope=scope, kind=kind, limit=_UNCAPPED, cycles=cycles + ) + + def to_csv(report: TimelineReport) -> str: """The audit export: one row per event, every text cell neutralised (`csv_safe`). diff --git a/keel/web/api.py b/keel/web/api.py index 74500d2..d642498 100644 --- a/keel/web/api.py +++ b/keel/web/api.py @@ -359,15 +359,43 @@ def read_balances(cfg: ServeConfig, _query: Query, _state: Any, now_ts: int) -> return payload.balances_payload(report) +def _log_cycles(config: Any) -> tuple[Any, ...]: + """The engine log's cycles, and an honest answer when the log could not be read. + + Read through `activity`'s own bounded window rather than re-parsed here: that module owns + finding the file, reading a bounded tail and turning it into cycles, and a second + implementation would be a second answer to "what did the agent do". + + **A log that could not be READ is not a log with nothing in it.** `read_log_window` returns a + `LogWindow` for every outcome -- it catches its own `OSError` -- and carries the outcome in + `status`. Discarding that would drop every `system` row AND drop `system` from the timeline's + chips, which in the CSV an auditor opens is indistinguishable from "the engine never ran". + `activity.py`'s own docstring names this failure: silently discarding input is how a feed + comes to under-report reality while looking healthy. So an unreadable log raises here, and + the caller turns it into a stated failure rather than a quiet gap. + """ + from keel.commands.activity import feed_from_lines, read_log_window, resolve_log_path + + log_path = resolve_log_path(config) + window = read_log_window(log_path) + if window.status not in ("ok", "missing"): + # "missing" is an ordinary state -- a deployment that has not run yet has no log, and the + # other three sources still have plenty to say. Anything else means the file is there and + # we could not read it, which is a fact about this answer's completeness. + raise RuntimeError( + f"the engine log could not be read ({window.status}): {window.detail or log_path}" + ) + # `LogWindow` carries the lines and a read status, not the path -- `source` is the feed's own + # label for where the lines came from, so it is passed the path we resolved. + return feed_from_lines( + window.lines, source=str(log_path), truncated=window.truncated + ).cycles + + def _timeline_report(cfg: ServeConfig, query: Query, now_ts: int) -> Any: """The merged timeline for one request. Shared by the JSON route and the CSV export so the file an operator downloads is the same chronology the page showed them -- two builders would be two answers to "what happened", and the export is the one that goes to an auditor.""" - from keel.commands.activity import ( - feed_from_lines, - read_log_window, - resolve_log_path, - ) from keel.commands.timeline import ( DEFAULT_TIMELINE_LIMIT, MAX_TIMELINE_LIMIT, @@ -380,23 +408,7 @@ def _timeline_report(cfg: ServeConfig, query: Query, now_ts: int) -> Any: DEFAULT_TIMELINE_LIMIT if not raw_limit else _whole_number(raw_limit, MAX_TIMELINE_LIMIT) ) - # The engine log is read through `activity`'s own bounded window rather than re-parsed here: - # that module owns finding the file, reading a bounded tail of it and turning it into cycles, - # and a second implementation would be a second answer to "what did the agent do". - cycles: tuple[Any, ...] = () - try: - log_path = resolve_log_path(config) - window = read_log_window(log_path) - # `LogWindow` carries the lines and a read status, not the path -- `source` is the - # feed's own label for where the lines came from, so it is passed the path we resolved. - cycles = feed_from_lines( - window.lines, source=str(log_path), truncated=window.truncated - ).cycles - except OSError: - # No log yet, or an unreadable one. The timeline still has three other sources, and a - # missing log is not a reason to fail the whole page -- the `system` rows are simply - # absent, which is what an unread log honestly means. - cycles = () + cycles = _log_cycles(config) repo = open_repo(cfg.db_path) try: @@ -702,7 +714,10 @@ class ApiRoute: html_route="/timeline", read=read_timeline, collection="rows", - sortable=("ts", "kind", "provenance", "source", "product_id"), + # `at`, not `ts`: the payload emits `at` (a `moment` field), and a `sortable` entry + # naming a key the rows do not carry is accepted, echoed back as applied, and silently + # does nothing -- which is the failure refusing an unknown column exists to prevent. + sortable=("at", "kind", "provenance", "source", "product_id"), ), "/api/rules": ApiRoute( html_route="/rules", @@ -974,6 +989,33 @@ def sortable_columns() -> Mapping[str, Sequence[str]]: CSV_EXPORT_PATH = "/api/timeline/export.csv" +def refusal_envelope(refusal: ApiRefusal) -> tuple[int, dict[str, Any]]: + """An `ApiRefusal` as `(status, document)`, for a caller outside `respond`. + + The CSV export does not go through `respond`, so it cannot inherit its refusal handling -- + and a download route that answered a bad query by dropping the connection would tell a + browser "network error" and an operator nothing at all. The JSON envelope is the right answer + even from a route whose success case is CSV: the failure is not a file. + """ + now_ts = int(time.time()) + return refusal.status, payload.error_envelope( + now_ts, status=refusal.status, title=refusal.title, detail=refusal.detail + ) + + +def export_failure_envelope(exc: Exception) -> tuple[int, dict[str, Any]]: + """Any other export failure as `(status, document)` -- `respond`'s 500 arm, reachable from + the one route that is not in its table. Names the exception type and message, exactly as + `respond` does, so an operator has something to act on.""" + now_ts = int(time.time()) + return 500, payload.error_envelope( + now_ts, + status=500, + title="That export could not be built", + detail=f"{type(exc).__name__}: {exc}", + ) + + def export_timeline_csv(cfg: ServeConfig, query: Query) -> tuple[str, str]: """`(csv_text, filename)` for the timeline export. @@ -984,9 +1026,23 @@ def export_timeline_csv(cfg: ServeConfig, query: Query) -> tuple[str, str]: to be opened in Excel or Sheets, both of which execute a cell beginning `=`, `+`, `-` or `@`, and several columns carry text keel did not write. """ - from keel.commands.timeline import to_csv + from keel.commands.timeline import export_rows, to_csv now_ts = int(time.time()) - report = _timeline_report(cfg, query, now_ts) + repo = open_repo(cfg.db_path) + try: + # `export_rows`, NOT `_timeline_report`: the paged read is capped because the console + # polls it every 15 seconds, and an audit record that silently inherited that cap would + # be 200 rows of a 5,000-event deployment with nothing in the file saying so -- a partial + # record that reads as complete, handed to a tax preparer. The scope still bounds it. + report = export_rows( + repo, + now_ts=now_ts, + scope=_first(query, "scope") or "all", + kind=_first(query, "kind") or "", + cycles=_log_cycles(load_config(cfg.config_path)), + ) + finally: + close_repo(repo) stamp = datetime.fromtimestamp(now_ts, tz=UTC).strftime("%Y%m%d-%H%M%S") return to_csv(report), f"keel-activity-{stamp}.csv" diff --git a/keel/web/server.py b/keel/web/server.py index fbc9296..a9be539 100644 --- a/keel/web/server.py +++ b/keel/web/server.py @@ -418,7 +418,12 @@ def _send_csv(self, text: str, filename: str) -> None: for name, value in _API_HEADERS: self.send_header(name, value) self.end_headers() - self.wfile.write(body) + # The same guard `_send`, `_send_json` and `_serve_static` all carry. `do_HEAD` delegates + # to `do_GET`, so without it a HEAD sends the headers AND the whole file -- and on a + # keep-alive connection those bytes are framed as the next response, which is a + # same-origin response desync rather than merely a wasted transfer. + if self.command != "HEAD": + self.wfile.write(body) def _send_json(self, code: int, document: dict[str, Any]) -> None: """One JSON response, with its own headers. @@ -874,7 +879,22 @@ def do_GET(self) -> None: # noqa: N802 - stdlib's naming, not ours # loopback-plus-session model unchanged -- an export of the whole audit trail is the # last thing that should be reachable more easily than the page it came from. if parsed.path == api.CSV_EXPORT_PATH: - text, filename = api.export_timeline_csv(self.cfg, query) + # Wrapped, because `respond` is what normally guarantees this server never + # answers a GET by raising: it turns an `ApiRefusal` into a 400 and anything else + # into a 500 envelope. This branch does not go through it, so without this a + # `?limit=abc` propagated out of the handler -- the client saw a reset connection + # with no response at all, and a traceback of absolute source paths reached the + # stderr that `log_message` is overridden to keep quiet. + try: + text, filename = api.export_timeline_csv(self.cfg, query) + except api.ApiRefusal as refusal: + code, document = api.refusal_envelope(refusal) + self._send_json(code, document) + return + except Exception as exc: # noqa: BLE001 - a failed export must still answer + code, document = api.export_failure_envelope(exc) + self._send_json(code, document) + return self._send_csv(text, filename) return code, document = api.respond(self.cfg, parsed.path, query) diff --git a/keel/web/static/js/render.js b/keel/web/static/js/render.js index c53ee21..77c3d0b 100644 --- a/keel/web/static/js/render.js +++ b/keel/web/static/js/render.js @@ -1193,10 +1193,14 @@ export function timelineView(data, sort, onSort, onKind) { // The export, carrying the page's own scope and chip so the file matches the screen. const actions = el("p", "note"); const link = el("a", "chartaction", "Export CSV"); - link.setAttribute( - "href", - ["/api/timeline/export.csv?scope=", plain(data.scope), "&kind=", plain(data.kind)].join(""), - ); + // Encoded, like every other URL this client builds (`api.js` uses `searchParams`). `kind` is + // the server's echo of caller-supplied text, and a value carrying `&` or `#` would otherwise + // reshape the query rather than travel in it. Not reachable with hostile input today -- the + // params are in-memory and seeded from `data.kinds` -- so this is the convention, kept. + const target = new URL("/api/timeline/export.csv", window.location.origin); + target.searchParams.set("scope", plain(data.scope)); + target.searchParams.set("kind", plain(data.kind)); + link.setAttribute("href", target.pathname.concat(target.search)); link.setAttribute("download", ""); actions.append(link); actions.append(" — every row with its provenance; hashes are not recorded yet."); diff --git a/tests/commands/test_timeline.py b/tests/commands/test_timeline.py index ea43e59..9536736 100644 --- a/tests/commands/test_timeline.py +++ b/tests/commands/test_timeline.py @@ -12,6 +12,8 @@ from __future__ import annotations +import csv +import io from decimal import Decimal from pathlib import Path from typing import Any @@ -97,14 +99,36 @@ def test_the_four_sources_merge_into_one_chronology(repo: Repository, tmp_path: def test_rows_are_newest_first(repo: Repository, tmp_path: Path) -> None: """One chronology, and the newest thing that happened is the thing an operator opened this - page to see.""" - _attestation(repo) # oldest - _transaction(repo) - _order(repo) # newest + page to see. + + The timestamps are SCRAMBLED relative to the order the sources are concatenated in + (`_order_rows`, then `_transaction_rows`, then `_attestation_rows`). The first version of + this test seeded oldest-to-newest, which happened to match that concatenation -- so deleting + the sort entirely left it green. Here the orders are the OLDEST and the attestation the + newest, so an unsorted merge comes back ascending and fails. + """ + _order(repo, created_at=NOW_TS - 10_000) + _order(repo, created_at=NOW_TS - 9_000) + _transaction(repo, ts=NOW_TS - 5_000) + _attestation(repo, attested_at=NOW_TS - 100) timestamps = [row.ts for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] - assert timestamps == sorted(timestamps, reverse=True) + assert timestamps == [NOW_TS - 100, NOW_TS - 5_000, NOW_TS - 9_000, NOW_TS - 10_000] + + +def test_two_events_at_one_instant_keep_a_stable_order(repo: Repository, tmp_path: Path) -> None: + """The tie-break. Without it two rows sharing a second come back in whatever order the merge + happened to produce, and the page reshuffles them between polls under a reader's cursor.""" + _order(repo, created_at=NOW_TS - 60) + _transaction(repo, ts=NOW_TS - 60) + _attestation(repo, attested_at=NOW_TS - 60) + + first = [row.reference for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] + again = [row.reference for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] + + assert first == again + assert len(set(first)) == 3, "three distinct events, not one collapsed row" def test_a_live_fill_is_venue_reported_and_a_paper_fill_is_not( @@ -276,3 +300,56 @@ def test_an_empty_book_is_an_empty_timeline(repo: Repository, tmp_path: Path) -> assert report.rows == () assert report.scoped_count == 0 + + +# -- every cell of the export is neutralised, not only the one with a test (#703 review) -------- + + +def test_every_text_column_of_the_export_is_neutralised(repo: Repository, tmp_path: Path) -> None: + """`csv_safe` is applied to all ten cells; before this, only `reference` was pinned. + + Removing it from the other nine left the whole suite green -- so the module's load-bearing + claim ("applied to EVERY text cell, not to a list of the risky ones") was untested for nine + columns, including `summary`, which carries an imported `notes` field verbatim. + + Every hostile value below lands at the START of its own cell, which is the only position a + spreadsheet evaluates. + """ + from keel.commands.timeline import to_csv + + _transaction( + repo, + coinbase_id="=cmd|ref", + type="=cmd|kind", + asset="=cmd|asset", + notes="", + total=Decimal("-500.25"), + ) + + text = to_csv(gather_timeline(repo, now_ts=NOW_TS, scope="all")) + header, row = list(csv.reader(io.StringIO(text)))[:2] + cells = dict(zip(header, row, strict=True)) + + assert cells["reference"].startswith("'"), "reference" + assert cells["summary"].startswith("'"), "summary -- it begins with the transaction type" + # A negative amount is a formula trigger and a real figure. Quoted, and still legible. + assert cells["amount"] == "'-500.25", cells["amount"] + # And nothing that was safe got mangled. + assert cells["kind"] == "flow" + assert cells["provenance"] == "imported-ledger" + + +def test_the_export_carries_one_row_per_event_plus_a_header( + repo: Repository, tmp_path: Path +) -> None: + """The shape an auditor's spreadsheet sees.""" + from keel.commands.timeline import to_csv + + _order(repo) + _transaction(repo) + _attestation(repo) + + rows = list(csv.reader(io.StringIO(to_csv(gather_timeline(repo, now_ts=NOW_TS, scope="all"))))) + + assert rows[0][0] == "ts" + assert len(rows) == 4 diff --git a/tests/commands/test_timeline_csv.py b/tests/commands/test_timeline_csv.py index 44fd72f..ae7c7f8 100644 --- a/tests/commands/test_timeline_csv.py +++ b/tests/commands/test_timeline_csv.py @@ -54,6 +54,24 @@ def test_ordinary_text_is_left_exactly_as_it_is(ordinary: str) -> None: assert csv_safe(ordinary) == ordinary +@pytest.mark.parametrize( + "dangerous", + [" =SUM(A1:A10)", " @malicious", " -1+1"], +) +def test_leading_whitespace_does_not_smuggle_a_formula_past(dangerous: str) -> None: + """A strict first-character test is defeated by one space, and `" =cmd|..."` is a legal + `coinbase_id` out of an imported venue CSV that lands in a cell by itself. Google Sheets and + LibreOffice trim leading whitespace before deciding whether a cell is a formula. + + The ORIGINAL text is what gets quoted: an audit record must not have its cells silently + reformatted, only made inert. + """ + escaped = csv_safe(dangerous) + + assert escaped.startswith("'"), f"{dangerous!r} slipped past the trigger check" + assert escaped[1:] == dangerous, "the original text, unaltered, after the quote" + + def test_a_negative_number_is_still_neutralised_and_still_readable() -> None: """`-12.30` is a formula trigger AND a real figure this export carries. Quoting it is the correct trade: a spreadsheet shows `-12.30` as text rather than evaluating it, and the value diff --git a/tests/web/test_api.py b/tests/web/test_api.py index 1085033..0fe25ee 100644 --- a/tests/web/test_api.py +++ b/tests/web/test_api.py @@ -531,12 +531,20 @@ def test_every_declared_sort_column_is_a_column_the_rows_actually_have( and then order every row identically -- an accepted request that silently does nothing, which is exactly what refusing an unknown column exists to prevent. - Checked over the two endpoints this test can seed rows into. A collection with no rows proves - nothing here, which is why the seeding is not optional.""" + Checked over every endpoint this test can seed rows into. A collection with no rows proves + nothing here, which is why the seeding is not optional. + + `/api/timeline` (#703) joined this list after shipping with `sortable=("ts", ...)` while its + payload emits `at` -- accepted, echoed back as applied, and ordering nothing. That is the + exact rot this pin exists for, and it went unnoticed because the route was not in it.""" _seed_positions(running.db_path, (("BTC-USD", "0.01", "50000"),)) _seed_rules(running.db_path, ("breakout",)) - for path, collection in (("/api/status", "open_positions"), ("/api/rules", "rules")): + for path, collection in ( + ("/api/status", "open_positions"), + ("/api/rules", "rules"), + ("/api/timeline", "rows"), + ): _status, _headers, document = _json(running, path) rows = document["data"][collection] diff --git a/tests/web/test_client_assets.py b/tests/web/test_client_assets.py index 907bd97..dfa4ad4 100644 --- a/tests/web/test_client_assets.py +++ b/tests/web/test_client_assets.py @@ -1523,6 +1523,7 @@ def test_every_table_emits_one_cell_per_declared_header() -> None: "Object", "Set", "String", + "URL", "console", "document", "window", diff --git a/tests/web/test_timeline_export.py b/tests/web/test_timeline_export.py index 6f75023..3010e79 100644 --- a/tests/web/test_timeline_export.py +++ b/tests/web/test_timeline_export.py @@ -137,3 +137,109 @@ def test_a_negative_amount_is_inert_and_still_legible(tmp_path: Path) -> None: from keel.commands.timeline import csv_safe assert csv_safe("-500.25") == "'-500.25" + + +# -- the export answers like every other route when it cannot (#703 review) --------------------- + + +def test_a_query_parameter_the_export_does_not_read_is_harmless(running: Any) -> None: # noqa: F811 + """`?limit=` belongs to the paged JSON route. The export deliberately does not read it -- it + carries the whole scope -- so a value that would be refused there is simply not consulted + here, and the file still comes back.""" + status, headers, _body = _get(running, EXPORT + "?limit=abc", cookie=_session(running)) + + assert status == 200 + assert headers["Content-Type"] == "text/csv; charset=utf-8" + + +def test_an_export_that_raises_answers_instead_of_dropping_the_connection( + running: Any, # noqa: F811 + monkeypatch: Any, +) -> None: + """`respond` is what normally guarantees this server never answers a GET by raising: it turns + an `ApiRefusal` into a 400 and anything else into a 500 envelope. The CSV branch does not go + through it, so before this it propagated -- the client saw a reset connection with no + response at all, and a traceback of absolute source paths reached the stderr `log_message` is + overridden to keep quiet. + + A JSON envelope is the right answer even from a route whose success case is CSV: the failure + is not a file, and a browser handed a truncated download learns nothing. + """ + from keel.web import api as web_api + + def boom(*_args: Any, **_kwargs: Any) -> tuple[str, str]: + raise RuntimeError("the log is on fire") + + monkeypatch.setattr(web_api, "export_timeline_csv", boom) + + status, headers, body = _get(running, EXPORT, cookie=_session(running)) + + assert status == 500, "a failed export must still answer" + assert headers["Content-Type"].startswith("application/json") + assert "the log is on fire" in body + + +def test_head_returns_no_body(running: Any) -> None: # noqa: F811 + """`_send`, `_send_json` and `_serve_static` all guard the write with + `if self.command != "HEAD"`. This sender did not, and `do_HEAD` delegates to `do_GET` -- so a + HEAD returned the headers plus the whole CSV. On a keep-alive connection those bytes are + framed as the next response: a same-origin response desync, and a violation of RFC 9110. + + Read off a RAW SOCKET, not through `http.client`: that library knows a HEAD carries no body + and never reads one, so it reports an empty body whether or not the server sent bytes. A test + written through it passes against the bug -- which is what the first version of this test did. + """ + import socket + + request = ( + f"HEAD {EXPORT} HTTP/1.1\r\n" + f"Host: {running.host}:{running.port}\r\n" + f"Cookie: {_session(running)}\r\n" + "Connection: close\r\n\r\n" + ) + with socket.create_connection((running.host, running.port), timeout=10) as sock: + sock.sendall(request.encode("ascii")) + raw = b"" + while chunk := sock.recv(4096): + raw += chunk + + head, _, body = raw.partition(b"\r\n\r\n") + assert b"text/csv" in head, "the headers still describe the resource" + assert body == b"", f"a HEAD must send no body; got {len(body)} bytes" + + +def test_the_export_carries_every_row_in_scope_not_the_pages_worth(tmp_path: Path) -> None: + """The page is capped because it polls every 15 seconds. The export is a deliberate download + of an audit record, and inheriting that cap made it a PARTIAL record that reads as complete + -- 200 rows of a 5,000-event deployment, with nothing in the file saying so, handed to a tax + preparer. + + Driven through the exporter with more rows than the paged default so the difference is + visible: an export that stopped at `DEFAULT_TIMELINE_LIMIT` returns 200 data rows here. + """ + from keel.commands.timeline import DEFAULT_TIMELINE_LIMIT, export_rows, to_csv + + conn = connect(str(tmp_path / "keel.db")) + migrate(conn) + repo = Repository(conn) + total = DEFAULT_TIMELINE_LIMIT + 25 + for index in range(total): + repo.upsert_transaction( + { + "coinbase_id": f"cb-{index}", + "source": "coinbase", + "type": "deposit", + "asset": "USD", + "ts": 1_800_000_000 - index * 60, + "qty": Decimal("1"), + "total": Decimal("1"), + "notes": "", + } + ) + + text = to_csv(export_rows(repo, now_ts=1_800_000_000, scope="all")) + data_rows = list(csv.reader(io.StringIO(text)))[1:] + + assert len(data_rows) == total, ( + f"the export must carry the whole scope; got {len(data_rows)} of {total}" + ) From 86c55adb0e823af9f2e3628bc19cf015fffa2c14 Mon Sep 17 00:00:00 2001 From: Elmehdi Aitbrahim Date: Fri, 4 Sep 2026 17:36:23 -0400 Subject: [PATCH 2/2] fix(web): the export was still capped, and the log fix broke the JSON route (#703) Second review round on the fix PR. Two of its own fixes were wrong, and one of them was wrong in exactly the way the PR exists to correct. THE EXPORT WAS NEVER UNCAPPED. `export_rows` passed `_UNCAPPED = 2**31` into `gather_timeline`, which clamps with `min(int(limit), MAX_TIMELINE_LIMIT)` -- so the "whole scope" export stopped at 2000 rows. The cap moved from 200 to 2000 and a docstring was written saying it was gone. The test could not see it: it seeded `DEFAULT_TIMELINE_LIMIT + 25` = 225 rows, under the real cap. A fixture below the threshold it is testing cannot test the threshold -- which is the precise failure this PR was opened to fix, committed inside the fix. Seeded above `MAX_TIMELINE_LIMIT` now, and it fails at 2000 of 2025 without the change. The slice is genuinely skippable (`limit: int | None`) rather than a large number pushed through a clamp. A sentinel the clamp silently eats is not a sentinel. And the memory cost of a real uncapped export -- the whole CSV as `str` then `bytes`, because the response carries a `Content-Length` -- is now written down as the accepted cost of a download an operator asked for once, which is also why the paged route keeps its cap. THE LOG FIX TOOK OUT THE PAGE IT WAS MEANT TO MAKE HONEST. Raising on any read status but `ok`/`missing` looked right against `unreadable`. But `read_log_window` also returns `empty` -- an ordinary state, a freshly created handler or the moment after a rotation -- and `oversized` for one long record. Neither is a read failure, and both now 500'd the whole Timeline page and raised in the export: orders, flows and attestations lost to report a non-problem, while `/api/activity` renders those same statuses as a stated feed state. Both earlier attempts were wrong in opposite directions -- discarding the status under-reported reality while looking healthy, raising on it failed a page over a healthy log -- so the report carries `log_status` and the answer is stated rather than acted on. `log_gap` separates "this deployment has never run" from "the file is there and its contents did not reach this report". The CSV writes a `# NOTE:` line above the header when there is a gap, because a file that leaves the application cannot be asked what is missing from it, and absent rows look identical to rows that never existed. THE CLIENT KEPT THE PRE-RENAME SORT KEY. The server moved `sortable` from `ts` to `at` correctly; the table header still declared `key: "ts"`, and `headerCell` only draws a sort control for a key the server declares -- so the timestamp column of a CHRONOLOGY page became an unclickable label. (`api.sortable_columns()` exists for this cross-check and has no callers; wiring it up is worth its own change.) TWO MORE TESTS THAT PASSED FOR THE WRONG REASON. The tie-break test asserted only that two calls agree, which holds with no tie-break at all because `list.sort` is stable and the merge order deterministic -- it now asserts the ordering's content. And the "every cell" test pinned three of ten columns, because the fixture left the other seven keel-written; `product_id`, `side` and `status` now arrive hostile, and dropping `csv_safe` from `product_id` fails. Also: `\\n`'s place in the trigger list is explained rather than merely present, and the `ApiRefusal` arm on the export branch is removed -- nothing on that path raises one now that it reads no `?limit=` or `?sort=`, and an error path nothing exercises rots. Re-add it the day a refusing helper joins that path. Co-Authored-By: Claude Opus 5 (1M context) --- keel/commands/timeline.py | 75 ++++++++++++++++++++---- keel/web/api.py | 57 ++++++++----------- keel/web/server.py | 9 +-- keel/web/static/js/render.js | 5 +- tests/commands/test_timeline.py | 95 ++++++++++++++++++++++++++++--- tests/web/test_timeline_export.py | 11 ++-- 6 files changed, 191 insertions(+), 61 deletions(-) diff --git a/keel/commands/timeline.py b/keel/commands/timeline.py index 795b9da..2c273ec 100644 --- a/keel/commands/timeline.py +++ b/keel/commands/timeline.py @@ -59,6 +59,9 @@ #: The characters a spreadsheet treats as the start of a formula. OWASP's list. #: +#: `\n` and `\r` are here alongside `\t` because a cell can only be re-parsed from its start, +#: and a leading line break is one of the ways a value smuggles itself into that position. +#: #: `-` and `+` are here because they are formulas too, not only signs -- which means a negative #: figure gets quoted. That is the correct trade for an audit export: a spreadsheet shows #: `'-12.30` as text rather than evaluating it, the value is still readable and still @@ -134,13 +137,15 @@ class TimelineReport: scope_start_ts: int | None #: The applied `kind` filter, echoed back, or `""` for every kind. kind: str - limit: int + #: The applied row cap, or `None` when the caller asked for no slice (the CSV export). + limit: int | None #: Rows across all four sources inside the scope, before `kind` and before `limit`. scoped_count: int #: Rows after `kind`, before `limit` -- what `rows` is a page of. filtered_count: int rows: tuple[TimelineRow, ...] + #: Every kind present in the SCOPED set, in `TIMELINE_KINDS` order -- what a chip bar is #: built from. STORED rather than derived from `rows`, because `rows` is what the chip and #: the cap left: derived from those, selecting Flows would delete the Trades chip and leave @@ -152,12 +157,34 @@ class TimelineReport: #: bar that reordered itself as history arrived would move under the reader. kinds_present: tuple[str, ...] + #: `read_log_window`'s own word for how the engine log read went: `ok`, `missing`, `empty`, + #: `oversized`, `unreadable`. Carried rather than acted on, so the page and the CSV can SAY + #: the log did not reach this report. + #: + #: The alternative was tried and was wrong in both directions. Discarding it made an + #: unreadable log indistinguishable from an idle engine -- under-reporting reality while + #: looking healthy, which `activity.py`'s own docstring names as the failure. RAISING on it + #: made an EMPTY log (an ordinary state: a fresh handler, the moment after a rotation) take + #: out orders, flows and attestations too, a total outage to report a non-problem. + log_status: str = "ok" + @property def shown_count(self) -> int: """How many rows this report carries. Derived rather than stored, and held here because `keel/web/payload.py` may not call `len()` (Rule 6e).""" return len(self.rows) + @property + def log_gap(self) -> bool: + """Whether the engine log's contents are MISSING FROM this report. + + `missing` is not a gap: a deployment that has never run has no log, and that is an + ordinary fact rather than a hole in the record. Every other non-`ok` status is -- the + file is there and what it holds did not reach this report, which is precisely what an + auditor reading the CSV needs told rather than left to infer from an absence of rows. + """ + return self.log_status not in ("ok", "missing") + #: The cap on one PAGE of the merged feed -- the response slice, not the read. @@ -174,12 +201,6 @@ def shown_count(self) -> int: DEFAULT_TIMELINE_LIMIT = 200 MAX_TIMELINE_LIMIT = 2000 -#: The cap `export_rows` passes: none. Spelled as a constant rather than an `Optional` parameter -#: so the uncapped read is a named decision at its one call site rather than a `None` that could -#: arrive by accident from anywhere. -_UNCAPPED = 2**31 - - def _order_rows(repo: Repository, since_ts: int | None) -> list[TimelineRow]: """`orders` -> trade rows. @@ -338,8 +359,9 @@ def gather_timeline( now_ts: int, scope: str = "all", kind: str = "", - limit: int = DEFAULT_TIMELINE_LIMIT, + limit: int | None = DEFAULT_TIMELINE_LIMIT, cycles: Sequence[Any] = (), + log_status: str = "ok", ) -> TimelineReport: """One chronology over four stores, newest first, scoped, chip-filtered and capped. @@ -363,7 +385,12 @@ def gather_timeline( # to never produce. The applied value is echoed in `kind`, so the substitution is visible. requested_kind = (kind or "").strip().lower() resolved_kind = requested_kind if requested_kind in TIMELINE_KINDS else "" - resolved_limit = max(1, min(int(limit), MAX_TIMELINE_LIMIT)) + # `None` means NO SLICE, and it has to be a distinct case rather than a very large number. + # The first attempt at an uncapped export passed `2**31` through this clamp, which is + # `min(2**31, 2000)` -- so the "whole scope" export quietly stopped at 2000 rows, and the + # test written for it seeded 225 and could not see that. A sentinel that the clamp silently + # eats is not a sentinel. + resolved_limit = None if limit is None else max(1, min(int(limit), MAX_TIMELINE_LIMIT)) since = scope_start_ts(resolved_scope, now_ts) scoped: list[TimelineRow] = [] @@ -387,7 +414,8 @@ def gather_timeline( limit=resolved_limit, scoped_count=len(scoped), filtered_count=len(filtered), - rows=tuple(filtered[:resolved_limit]), + rows=tuple(filtered if resolved_limit is None else filtered[:resolved_limit]), + log_status=log_status, kinds_present=tuple(kind for kind in TIMELINE_KINDS if kind in present), ) @@ -399,6 +427,7 @@ def export_rows( scope: str = "all", kind: str = "", cycles: Sequence[Any] = (), + log_status: str = "ok", ) -> TimelineReport: """The whole scope, uncapped -- what the CSV export reads. @@ -411,9 +440,21 @@ def export_rows( The SCOPE still bounds it: `?scope=today|7d|all` is the operator's own choice about how much they are asking for, and `all` on a long-lived deployment is a large file by request rather than by accident. + + **The whole file is materialised in memory** -- as a `str`, then as `bytes`, because the + response carries a `Content-Length`. That is an accepted cost for a download an operator + asked for once, and it is the reason the paged route keeps its cap: the same read on a + 15-second poll would not be acceptable. Streaming it is the change to make if `all` on a + multi-year deployment ever stops fitting comfortably. """ return gather_timeline( - repo, now_ts=now_ts, scope=scope, kind=kind, limit=_UNCAPPED, cycles=cycles + repo, + now_ts=now_ts, + scope=scope, + kind=kind, + limit=None, + cycles=cycles, + log_status=log_status, ) @@ -429,6 +470,18 @@ def to_csv(report: TimelineReport) -> str: """ buffer = io.StringIO() writer = csv.writer(buffer) + if report.log_gap: + # Stated IN THE FILE, above the header, because this file leaves the application. An + # auditor holding a CSV cannot ask the page whether a source was missing from it, and + # rows that are simply absent look identical to rows that never existed. + writer.writerow( + [ + csv_safe( + f"# NOTE: the engine log could not be read ({report.log_status}); " + "cycle rows are missing from this export" + ) + ] + ) writer.writerow( [ "ts", diff --git a/keel/web/api.py b/keel/web/api.py index d642498..9fe7ba4 100644 --- a/keel/web/api.py +++ b/keel/web/api.py @@ -359,37 +359,39 @@ def read_balances(cfg: ServeConfig, _query: Query, _state: Any, now_ts: int) -> return payload.balances_payload(report) -def _log_cycles(config: Any) -> tuple[Any, ...]: - """The engine log's cycles, and an honest answer when the log could not be read. +def _log_cycles(config: Any) -> tuple[tuple[Any, ...], str]: + """`(cycles, status)` -- the engine log's cycles, and how the read of it went. Read through `activity`'s own bounded window rather than re-parsed here: that module owns finding the file, reading a bounded tail and turning it into cycles, and a second implementation would be a second answer to "what did the agent do". - **A log that could not be READ is not a log with nothing in it.** `read_log_window` returns a - `LogWindow` for every outcome -- it catches its own `OSError` -- and carries the outcome in - `status`. Discarding that would drop every `system` row AND drop `system` from the timeline's - chips, which in the CSV an auditor opens is indistinguishable from "the engine never ran". - `activity.py`'s own docstring names this failure: silently discarding input is how a feed - comes to under-report reality while looking healthy. So an unreadable log raises here, and - the caller turns it into a stated failure rather than a quiet gap. + **A log that could not be READ is not a log with nothing in it**, and it is also not a + reason to fail the page. `read_log_window` returns a `LogWindow` for every outcome -- it + catches its own `OSError` -- and names the outcome in `status`. Both other options were tried + and both were wrong: + + * Discarding the status dropped every `system` row and dropped `system` from the chips, which + in an auditor's CSV is indistinguishable from "the engine never ran". `activity.py`'s own + docstring names that failure: silently discarding input is how a feed comes to under-report + reality while looking healthy. + * RAISING on any status but `ok`/`missing` made an EMPTY log -- an ordinary state, a freshly + created handler or the moment after a rotation -- take out orders, flows and attestations + as well. A total outage to report a non-problem, and a divergence from `/api/activity`, + which renders these same statuses as a stated feed state. + + So the status is returned, the report carries it, and the page and the CSV say it. """ from keel.commands.activity import feed_from_lines, read_log_window, resolve_log_path log_path = resolve_log_path(config) window = read_log_window(log_path) - if window.status not in ("ok", "missing"): - # "missing" is an ordinary state -- a deployment that has not run yet has no log, and the - # other three sources still have plenty to say. Anything else means the file is there and - # we could not read it, which is a fact about this answer's completeness. - raise RuntimeError( - f"the engine log could not be read ({window.status}): {window.detail or log_path}" - ) # `LogWindow` carries the lines and a read status, not the path -- `source` is the feed's own # label for where the lines came from, so it is passed the path we resolved. - return feed_from_lines( + cycles = feed_from_lines( window.lines, source=str(log_path), truncated=window.truncated ).cycles + return cycles, window.status def _timeline_report(cfg: ServeConfig, query: Query, now_ts: int) -> Any: @@ -408,7 +410,7 @@ def _timeline_report(cfg: ServeConfig, query: Query, now_ts: int) -> Any: DEFAULT_TIMELINE_LIMIT if not raw_limit else _whole_number(raw_limit, MAX_TIMELINE_LIMIT) ) - cycles = _log_cycles(config) + cycles, log_status = _log_cycles(config) repo = open_repo(cfg.db_path) try: @@ -419,6 +421,7 @@ def _timeline_report(cfg: ServeConfig, query: Query, now_ts: int) -> Any: kind=_first(query, "kind") or "", limit=limit, cycles=cycles, + log_status=log_status, ) finally: close_repo(repo) @@ -989,20 +992,6 @@ def sortable_columns() -> Mapping[str, Sequence[str]]: CSV_EXPORT_PATH = "/api/timeline/export.csv" -def refusal_envelope(refusal: ApiRefusal) -> tuple[int, dict[str, Any]]: - """An `ApiRefusal` as `(status, document)`, for a caller outside `respond`. - - The CSV export does not go through `respond`, so it cannot inherit its refusal handling -- - and a download route that answered a bad query by dropping the connection would tell a - browser "network error" and an operator nothing at all. The JSON envelope is the right answer - even from a route whose success case is CSV: the failure is not a file. - """ - now_ts = int(time.time()) - return refusal.status, payload.error_envelope( - now_ts, status=refusal.status, title=refusal.title, detail=refusal.detail - ) - - def export_failure_envelope(exc: Exception) -> tuple[int, dict[str, Any]]: """Any other export failure as `(status, document)` -- `respond`'s 500 arm, reachable from the one route that is not in its table. Names the exception type and message, exactly as @@ -1029,6 +1018,7 @@ def export_timeline_csv(cfg: ServeConfig, query: Query) -> tuple[str, str]: from keel.commands.timeline import export_rows, to_csv now_ts = int(time.time()) + cycles, log_status = _log_cycles(load_config(cfg.config_path)) repo = open_repo(cfg.db_path) try: # `export_rows`, NOT `_timeline_report`: the paged read is capped because the console @@ -1040,7 +1030,8 @@ def export_timeline_csv(cfg: ServeConfig, query: Query) -> tuple[str, str]: now_ts=now_ts, scope=_first(query, "scope") or "all", kind=_first(query, "kind") or "", - cycles=_log_cycles(load_config(cfg.config_path)), + cycles=cycles, + log_status=log_status, ) finally: close_repo(repo) diff --git a/keel/web/server.py b/keel/web/server.py index a9be539..9169ce9 100644 --- a/keel/web/server.py +++ b/keel/web/server.py @@ -887,11 +887,12 @@ def do_GET(self) -> None: # noqa: N802 - stdlib's naming, not ours # stderr that `log_message` is overridden to keep quiet. try: text, filename = api.export_timeline_csv(self.cfg, query) - except api.ApiRefusal as refusal: - code, document = api.refusal_envelope(refusal) - self._send_json(code, document) - return except Exception as exc: # noqa: BLE001 - a failed export must still answer + # One arm, because nothing on the export path raises `ApiRefusal`: it reads + # no `?limit=` and no `?sort=`, which are the two refusing helpers. A second + # arm for it was written and removed -- an unreachable error path is one + # nothing exercises, and it rots. Re-add it the day a refusing helper joins + # this path. code, document = api.export_failure_envelope(exc) self._send_json(code, document) return diff --git a/keel/web/static/js/render.js b/keel/web/static/js/render.js index 77c3d0b..9695f4b 100644 --- a/keel/web/static/js/render.js +++ b/keel/web/static/js/render.js @@ -1211,7 +1211,10 @@ export function timelineView(data, sort, onSort, onKind) { table( "h-timeline", [ - { label: "when (UTC)", numeric: false, key: "ts" }, + // `at`, matching the payload and `sortable`. It was left as `ts` when the server side + // was renamed, and `headerCell` only draws a sort control for a key the server declares + // -- so the timestamp column of a CHRONOLOGY page silently became an unclickable label. + { label: "when (UTC)", numeric: false, key: "at" }, { label: "kind", numeric: false, key: "kind" }, { label: "how we know", numeric: false, key: "provenance" }, { label: "source", numeric: false, key: "source" }, diff --git a/tests/commands/test_timeline.py b/tests/commands/test_timeline.py index 9536736..3d7dfb3 100644 --- a/tests/commands/test_timeline.py +++ b/tests/commands/test_timeline.py @@ -124,11 +124,16 @@ def test_two_events_at_one_instant_keep_a_stable_order(repo: Repository, tmp_pat _transaction(repo, ts=NOW_TS - 60) _attestation(repo, attested_at=NOW_TS - 60) - first = [row.reference for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] - again = [row.reference for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] - - assert first == again - assert len(set(first)) == 3, "three distinct events, not one collapsed row" + references = [row.reference for row in gather_timeline(repo, now_ts=NOW_TS, scope="all").rows] + + # The tie-break's CONTENT, not merely that two calls agree: `list.sort` is stable and the + # merge order deterministic, so a report with NO tie-break also returns the same list twice. + # Asserting repeatability alone passed against the missing tie-break. + assert references == sorted(references, reverse=True), ( + "at one instant, `reference` descending is the order -- and it is what makes the page " + "stop reshuffling between polls" + ) + assert len(set(references)) == 3, "three distinct events, not one collapsed row" def test_a_live_fill_is_venue_reported_and_a_paper_fill_is_not( @@ -317,6 +322,17 @@ def test_every_text_column_of_the_export_is_neutralised(repo: Repository, tmp_pa """ from keel.commands.timeline import to_csv + # Hostile values in every cell whose content this module does NOT write: the reference, the + # summary's ingredients, and the amount. A fixture that leaves the rest keel-written pins + # three cells while the docstring claims ten -- which is how the previous version of this + # test passed while six columns were unprotected. + _order( + repo, + product_id="=cmd|product", + side="=cmd|side", + status="=cmd|status", + created_at=NOW_TS - 30, + ) _transaction( repo, coinbase_id="=cmd|ref", @@ -326,10 +342,15 @@ def test_every_text_column_of_the_export_is_neutralised(repo: Repository, tmp_pa total=Decimal("-500.25"), ) - text = to_csv(gather_timeline(repo, now_ts=NOW_TS, scope="all")) - header, row = list(csv.reader(io.StringIO(text)))[:2] - cells = dict(zip(header, row, strict=True)) + rows = list(csv.reader(io.StringIO(to_csv(gather_timeline(repo, now_ts=NOW_TS, scope="all"))))) + header = rows[0] + by_source = {r[header.index("source")]: dict(zip(header, r, strict=True)) for r in rows[1:]} + order_cells = by_source["orders"] + assert order_cells["product_id"].startswith("'"), "product_id" + assert order_cells["summary"].startswith("'"), "summary -- it begins with the status" + + cells = by_source["transactions"] assert cells["reference"].startswith("'"), "reference" assert cells["summary"].startswith("'"), "summary -- it begins with the transaction type" # A negative amount is a formula trigger and a real figure. Quoted, and still legible. @@ -353,3 +374,61 @@ def test_the_export_carries_one_row_per_event_plus_a_header( assert rows[0][0] == "ts" assert len(rows) == 4 + + +# -- a log that could not be read is a STATED gap, not a failed page (#703 review round 2) ------ + + +@pytest.mark.parametrize("status", ["ok", "missing", "empty", "oversized", "unreadable"]) +def test_every_log_read_outcome_still_produces_a_report(status: str, repo, tmp_path) -> None: + """Four sources, and one of them having nothing to say must not take out the other three. + + The first fix for this raised on any status but `ok`/`missing` -- which made an EMPTY log + (an ordinary state: a freshly created handler, or the moment after a rotation) 500 the whole + Timeline page, losing orders, flows and attestations to report a non-problem. `read_log_window` + also returns `oversized` for one very long record, which is likewise not a read failure. + + The report carries the outcome instead, so the page and the CSV can SAY the log was + unreadable rather than either failing or silently under-reporting. + """ + _order(repo) + + report = gather_timeline(repo, now_ts=NOW_TS, scope="all", log_status=status) + + assert report.rows, "the other sources still report" + assert report.log_status == status + + +def test_a_healthy_log_reports_no_gap(repo, tmp_path) -> None: + _order(repo) + + assert gather_timeline(repo, now_ts=NOW_TS, scope="all", log_status="ok").log_gap is False + + +@pytest.mark.parametrize("status", ["empty", "oversized", "unreadable"]) +def test_an_unhealthy_log_is_reported_as_a_gap(status: str, repo, tmp_path) -> None: + """`missing` is not a gap -- a deployment that has never run has no log, and that is an + ordinary fact rather than a hole in the record. The rest are: the file is there and its + contents did not reach this report, which is exactly what an auditor needs told.""" + _order(repo) + + assert gather_timeline(repo, now_ts=NOW_TS, scope="all", log_status=status).log_gap is True + + +def test_a_missing_log_is_not_a_gap(repo, tmp_path) -> None: + _order(repo) + + assert gather_timeline(repo, now_ts=NOW_TS, scope="all", log_status="missing").log_gap is False + + +def test_the_kind_collapse_is_applied_and_echoed(repo, tmp_path) -> None: + """An unrecognised kind is collapsed to "every kind", not applied -- `?kind=trades` (the + plural typo, since the chips read "trade") would otherwise return a page that looks like an + empty deployment. Unpinned until now: reverting the collapse left every test green.""" + _order(repo) + _transaction(repo) + + report = gather_timeline(repo, now_ts=NOW_TS, scope="all", kind="trades") + + assert report.kind == "", "the applied value is echoed, so the substitution is visible" + assert report.shown_count == 2, "and nothing was filtered out" diff --git a/tests/web/test_timeline_export.py b/tests/web/test_timeline_export.py index 3010e79..2469f5f 100644 --- a/tests/web/test_timeline_export.py +++ b/tests/web/test_timeline_export.py @@ -214,15 +214,18 @@ def test_the_export_carries_every_row_in_scope_not_the_pages_worth(tmp_path: Pat -- 200 rows of a 5,000-event deployment, with nothing in the file saying so, handed to a tax preparer. - Driven through the exporter with more rows than the paged default so the difference is - visible: an export that stopped at `DEFAULT_TIMELINE_LIMIT` returns 200 data rows here. + Seeded above `MAX_TIMELINE_LIMIT`, not merely above the paged default. The first version of + this test used `DEFAULT_TIMELINE_LIMIT + 25` = 225 rows and passed while the export was still + capped at 2000: `export_rows` handed a huge `limit` to `gather_timeline`, which clamps it with + `min(limit, MAX_TIMELINE_LIMIT)`. A test whose fixture sits under the real cap cannot see the + cap -- which is the same failure this PR exists to fix, committed inside the fix. """ - from keel.commands.timeline import DEFAULT_TIMELINE_LIMIT, export_rows, to_csv + from keel.commands.timeline import MAX_TIMELINE_LIMIT, export_rows, to_csv conn = connect(str(tmp_path / "keel.db")) migrate(conn) repo = Repository(conn) - total = DEFAULT_TIMELINE_LIMIT + 25 + total = MAX_TIMELINE_LIMIT + 25 for index in range(total): repo.upsert_transaction( {