arborist/aborist/progress.py
russell@unturf.com 649aeec79a
progress reporter + structured benchmark
aborist/progress.py — stdlib-only rate-limited stderr reporter.
  Periodic lines (default every 2s) showing:
    elapsed | seen | inserted | docs/s now | docs/s avg | percent | ETA
  Wired into ingest_source via a `progress` parameter; CLI default-on
  with --quiet to suppress and --total-estimate N to enable percent/ETA.

  Demo on a 5k-doc ingest with --progress-interval 0.8:
    [    1s] |   200 seen |   200 new |  193 now | ( 193 avg) docs/s |   4.0% | ETA  24s
    [    7s] | 3,200 seen | 3,200 new |  458 now | ( 424 avg) docs/s |  64.0% | ETA   3s
    [   12s] | 5,001 seen | 5,000 new |  392 now | ( 413 avg) docs/s | 100.0% | ETA   0s

bench/run.sh + `make bench` — reproducible 5000-doc workload through
three configs:
  serial            single process, single SQLite
  parallel-shared   N shards, one shared SQLite (WAL serialized)
  attached          N shards, per-shard SQLite (true parallel writes)

Output is a one-shot table plus CSV at /tmp/aborist-bench/results.csv
so the ratchet is visible as we keep optimizing. Override via
BENCH_DOCS=N and SHARDS=N.

Latest baseline (this commit, on this machine):
  config             wall_s    docs   docs/s
  serial              11.74    5000    425.7
  parallel-shared     10.39    5000    481.1
  attached             7.99    5000    625.5

53 tests still passing.
2026-04-27 11:37:20 -04:00

86 lines
2.6 KiB
Python

"""Periodic stderr progress reporting for long-running ingests/distillation.
Stdlib only. Prints on a rate-limited schedule (default every 2 seconds) so
ingests of 100k+ docs give live feedback without spamming. Optional total
estimate produces a percent + ETA.
Multiple parallel shard processes will interleave their lines; each can be
given a `prefix` to disambiguate.
"""
from __future__ import annotations
import sys
import time
from typing import IO
class Progress:
"""Rate-limited progress reporter to stderr (or any stream)."""
def __init__(
self,
*,
interval: float = 2.0,
total_estimate: int | None = None,
prefix: str = "",
stream: IO[str] = sys.stderr,
):
self.start = time.monotonic()
self.last_print = self.start
self.last_seen = 0
self.interval = interval
self.total_estimate = total_estimate
self.prefix = prefix
self.stream = stream
def tick(
self,
seen: int,
*,
inserted: int | None = None,
force: bool = False,
) -> None:
"""Maybe print a status line. Call after each batch flush."""
now = time.monotonic()
if not force and (now - self.last_print) < self.interval:
return
elapsed = now - self.start
delta_seen = max(0, seen - self.last_seen)
delta_t = max(now - self.last_print, 1e-6)
rate_now = delta_seen / delta_t
rate_avg = seen / elapsed if elapsed > 0 else 0.0
bits = [
f"{self.prefix}[{_format_elapsed(elapsed)}]",
f"{seen:>10,} seen",
]
if inserted is not None:
bits.append(f"{inserted:>9,} new")
bits.append(f"{rate_now:>5.0f} now")
bits.append(f"({rate_avg:>4.0f} avg) docs/s")
if self.total_estimate and rate_now > 0:
pct = 100.0 * min(1.0, seen / self.total_estimate)
remaining = max(0, self.total_estimate - seen)
eta = remaining / rate_now
bits.append(f"{pct:>5.1f}%")
bits.append(f"ETA {_format_elapsed(eta)}")
print(" " + " | ".join(bits), file=self.stream, flush=True)
self.last_print = now
self.last_seen = seen
def done(self, seen: int, *, inserted: int | None = None) -> None:
"""Print a final status line regardless of interval."""
self.tick(seen, inserted=inserted, force=True)
def _format_elapsed(secs: float) -> str:
secs = int(secs)
h, rem = divmod(secs, 3600)
m, s = divmod(rem, 60)
if h:
return f"{h}h{m:02d}m"
if m:
return f"{m:>2}m{s:02d}s"
return f" {s:>2}s"