Story: “Time-box the first high-volume benchmark” (backlog/epics/05_cli_rendering_engine_and_debenu_integration.md,
5 points, spike). Target under test (project_config.md): render 100,000 records at 300 DPI in
under 10 minutes.
Bottom line: the current render path does NOT meet the target and is not close. Throughput degrades sharply as the accumulated in-memory PDF document grows, so the small-scale numbers from Sprint 1 (392 records, ~1.8s) are not representative of high-volume behavior at all. This is a real, material risk and is being escalated as a new backlog story rather than fixed silently inside this spike (out of scope per the story's own conversation notes: “a spike-style story to gather performance information, not a final optimization guarantee”).
dotnet build src/EnvelopeRenderer.Cli/EnvelopeRenderer.Cli.csproj -c Release (net10.0,
Release configuration — not dotnet run/Debug, to avoid understating a production-representative
number).key.txt
(DebenuLicenseKeyResolver, walked up from the executable directory — same resolution path a
desktop-launched render would use).sample-data/sample-envelope-template.xml
(3 <text> elements per page: 1 static, 2 dynamic columns — same template Sprint 1 verified against).sample-data/87700 - 999999 - Wilson Township.csv verbatim 256 times
(header written once): 256 * 392 = 100,352 data rows. Rows are exact repeats rather than
synthetic-but-unique data — acceptable for a throughput/bottleneck spike since neither CsvHelper
parsing nor the render merge loop branches on row content, only on column names and value
length, and the CLI's per-record work is O(1) regardless (see “Root cause” below). Not
committed to the repo (30+ MB; regenerate on demand with the one-line awk command in this
file's git history / the Day 1 scrum log, or any equivalent script).EnvelopeRenderer.Cli.exe --template sample-envelope-template.xml --csv <generated-csv> --output <path>.pdf, with DEBENU_LICENSE_KEY resolved via key.txt exactly as
production/desktop launches do.PROGRESS render ... elapsedMs=<n> completed=<n> stream (already emitted by the
CLI per CLI_CONTRACT.md — no extra instrumentation needed) and the final PDF size on success.DrawText at exact point coordinates) — there is no DPI
knob in the current text-only pipeline, so “at 300 DPI” is satisfied vacuously for this slice.
This will matter once image handling (epic 7) lands and should be re-benchmarked then.The run was allowed to proceed for 138.8 seconds of wall time and was then deliberately
stopped (time-boxed) once the throughput trend below made the outcome unambiguous — projected
full-run time is many multiples of the 10-minute target (see “Extrapolation”). No output PDF
exists for this run since Save() is only called once every record has been added (see
“Root cause”); the process was killed before reaching record 100,352, so nothing was written to
disk for this run specifically.
Representative samples from the real PROGRESS render stream (full log evidence recorded during
this spike, not fabricated):
| Elapsed | Records completed | Records/sec in the preceding ~10s window |
|---|---|---|
| 108 ms | 1 | — |
| 1,109 ms | 442 | ~399/s (first second, before the effect below kicks in) |
| 10,147 ms | 1,389 | ~105/s |
| 20,276 ms | 1,930 | ~53/s |
| 30,416 ms | 2,346 | ~41/s |
| 40,521 ms | 2,696 | ~35/s |
| 50,626 ms | 3,004 | ~30/s |
| 60,809 ms | 3,282 | ~27/s |
| 71,009 ms | 3,533 | ~25/s |
| 81,245 ms | 3,766 | ~23/s |
| 91,447 ms | 3,985 | ~22/s |
| 101,725 ms | 4,184 | ~19/s |
| 112,015 ms | 4,381 | ~19/s |
| 122,238 ms | 4,555 | ~17/s |
| 132,617 ms | 4,724 | ~16/s |
| 138,843 ms (stopped here) | 4,827 | ~15/s and still falling |
Throughput is monotonically decreasing — not a one-time warm-up cost — and had not leveled off to a stable floor by the time the run was stopped at 4,827 of 100,352 records (4.8%). Process working-set memory grew from ~63 MB to ~76 MB over the same window (modest, not itself a risk at this scale) while CPU stayed pegged at effectively one full core the whole time — this is a compute-bound slowdown, not an I/O or memory-pressure one.
To have at least one complete, verified higher-volume data point rather than relying only on extrapolation, the same scenario was also run to completion at 2,000 records (first 2,000 rows of the same generated dataset):
PROGRESS startup elapsedMs=0 completed=0
...
PROGRESS complete elapsedMs=20775 completed=2000
exit=0
%PDF-1.4 header confirmed, 2,302,387 bytes (~1.15 KB/page —
in line with Sprint 1's 392-page/~1.3 MB result, so per-page output size is not the problem).0, matching CLI_CONTRACT.md.This confirms the CLI still produces correct output at this scale — the risk is purely throughput, not correctness.
Sprint 1 Batch 2 verified 392 records in ~1.8s (~217 rec/s using the throttled progress numbers
in CLI_CONTRACT.md's smoke example). That number was accurate for its own scale but is not
representative of high-volume behavior — the degradation only becomes visible past roughly the
first 1,000–2,000 accumulated pages, well beyond what a 392-row sample template exercises. This is
exactly the kind of thing this spike exists to catch before more work lands on the render hot path
(per the Sprint 1 retrospective action item).
The CLI's own C# merge loop (RenderEngine.Render, CsvRecordSource.ReadRecords) does O(1)
work per record: CSV rows are streamed one at a time (no full-file buffering), and each record
produces a small fixed-size list of TextDraws with no data structure that grows with the number
of records processed so far, other than a Dictionary<string,int> font-handle cache keyed by
distinct font name (this template uses exactly one font, so that cache never grows past size 1).
DebenuPdfRenderer.AddPage calls a fixed, constant number of Debenu API functions per page
(NewPage/SetPageDimensions/SetFillColor/SelectFont/SetTextSize/DrawText x3) with no
loop over prior pages.
That leaves the Debenu Quick PDF Library 10.13 native document object model itself as the
strongly suspected source of the slowdown: the whole PDF is built up in memory (confirmed — no
PDF bytes are written to disk until the single SaveToFile call after every record has been
added, so a killed 100k run leaves no output file at all, as seen above) and each additional
NewPage/DrawText call appears to cost more as the number of already-added pages grows. This
is consistent with, though not proven to be, an internal data structure in the vendor DLL that is
scanned or re-walked per operation (e.g., an internal page/object list) rather than one with O(1)
amortized append. This repo has no access to Debenu's internal source to confirm further; treating
it as an external-library characteristic to design around, not something to patch, is the
appropriate scope for a spike.
Off track. Using the observed trend (throughput still falling at ~15 rec/s and not yet at a floor when stopped at record 4,827), a full 100,352-record run would take at least on the order of 45–90+ minutes — 5x to 10x+ over the 10-minute target — and possibly worse, since the curve had not plateaued. This is a material risk, not a rounding-error miss.
Logged as both a new backlog story and a technical debt entry so it survives past this spike:
backlog/epics/05_cli_rendering_engine_and_debenu_integration.md (Status: Ready). Scope:
characterize whether the degradation is genuinely Debenu-internal (e.g. by probing whether
periodic Save+reopen batching, or Debenu's AddSubsettedFont/page-count-related settings,
change the curve) and pick a concrete mitigation (candidates to evaluate, not yet decided:
batching output into multiple PDF files and concatenating, periodic incremental saves, or an
alternate Debenu API usage pattern) before any further feature work depends on rendering
1M-record jobs (project_config.md's stated ceiling).logs/technical_debt_log.md, 2026-09-14 entry — “release-quality high-volume
benchmark target is currently missed by 5-10x+ at realistic scale.”Not fixed as part of this spike, per the story's own conversation notes (“not a final optimization guarantee”) and to avoid silently absorbing a scope-changing investigation into a 5-point spike.
Both were already in place for this run (the CLI always emits PROGRESS events and always
resolves the license key via DebenuLicenseKeyResolver) and neither is a plausible contributor:
ConsoleProgressReporter) and does O(1) work per throttled write; it cannot explain a
monotonically decreasing per-record rate, since its own overhead is constant per record
(a delegate call) and near-zero when throttled.DebenuLicenseKeyResolver.Resolve) runs exactly once at startup, before
any records are processed, so it cannot affect per-record throughput at all.Both are ruled out; the bottleneck is isolated to the per-page Debenu document-building cost described above.
Powered by TurnKey Linux.