From b49b8ed429801b227ab645003e5978374c57438f Mon Sep 17 00:00:00 2001 From: DemchaAV Date: Mon, 3 Aug 2026 17:36:07 +0100 Subject: [PATCH] chore(benchmarks): time the preview pipeline, stage by stage MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit DocumentSession.toImages(dpi) reaches a raster through compose, layout, building a PDDocument and saving it to bytes, Loader.loadPDF, and PDFRenderer. The probe times each of those separately, warm, on two canonical workloads, so the shape of the cost is measured rather than assumed. It deliberately draws no conclusion about a direct Java2D backend. The encode stage is not serialisation — before save() the backend creates pages, walks the whole LayoutGraph, paints every fragment, resolves links and bookmarks and applies the page chrome. The PDFRenderer stage is not pixel production alone — it interprets PDF operators and then paints them through Java2D. A direct renderer would change work in both stages, so no stage here is removable, and no measurement of this pipeline predicts the cost of a different one. That comparison needs a second implementation. Three measurement details the numbers depend on: - every DPI renders from a freshly parsed document and its own PDFRenderer, because sharing one hands each later DPI the caches the first one warmed — measured at 13% on the CV and 28% on the proposal; - toImages runs on its own sessions rather than after four raster passes over the same document, in both the layout-cached and from-scratch case; - totals are summed inside an iteration and the median taken of those, since medians of separate stages do not add to the median of their sum. It joins the probe family already in this module — AllocationRateProbe, AutoSizeMeasureProbe, ChartAllocProbe, FontEmbedProbe — reuses CanonicalBenchmarkSupport, reads nothing private and changes no src/main code. benchmarks is a development module and ships to no registry. Run end to end, exit 0. --- .../com/demcha/compose/PreviewCostProbe.java | 260 ++++++++++++++++++ 1 file changed, 260 insertions(+) create mode 100644 benchmarks/src/main/java/com/demcha/compose/PreviewCostProbe.java diff --git a/benchmarks/src/main/java/com/demcha/compose/PreviewCostProbe.java b/benchmarks/src/main/java/com/demcha/compose/PreviewCostProbe.java new file mode 100644 index 00000000..3ca4c33c --- /dev/null +++ b/benchmarks/src/main/java/com/demcha/compose/PreviewCostProbe.java @@ -0,0 +1,260 @@ +package com.demcha.compose; + +import com.demcha.compose.document.api.DocumentPageSize; +import com.demcha.compose.document.api.DocumentSession; +import com.demcha.compose.document.style.DocumentInsets; +import com.demcha.compose.document.templates.api.DocumentTemplate; +import com.demcha.compose.document.templates.cv.presets.ModernProfessional; +import com.demcha.compose.document.templates.proposal.presets.ModernProposal; +import org.apache.pdfbox.Loader; +import org.apache.pdfbox.pdmodel.PDDocument; +import org.apache.pdfbox.rendering.ImageType; +import org.apache.pdfbox.rendering.PDFRenderer; + +import java.awt.image.BufferedImage; +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.function.ToLongFunction; + +/** + * Times each stage of the current preview path, so its cost is measured rather + * than assumed. + * + *

{@code DocumentSession.toImages(dpi)} reaches a raster through: open the + * session → compose → layout → build a {@code PDDocument} and + * {@code save()} it to bytes → {@code Loader.loadPDF} → + * {@code PDFRenderer}. This probe reports each of those separately, warm, on two + * canonical workloads.

+ * + *

What these numbers do and do not say

+ * + *

They describe the pipeline that exists. They are not a bound + * on what a direct Java2D backend would save, and no stage here should be read as + * "removable" or "unavoidable":

+ * + * + * + *

A direct backend therefore changes work in both stages, and no + * measurement of the present pipeline can predict the result. Comparing the two + * designs needs a second implementation to measure against.

+ * + *

Measurement notes

+ * + * + * + *

Reads nothing private and changes no {@code src/main} code.

+ */ +public final class PreviewCostProbe { + + private static final int WARMUP_ITERATIONS = 6; + private static final int MEASURED_ITERATIONS = 11; + private static final int REPORT_DPI = 96; + + private PreviewCostProbe() { + } + + /** + * Runs the probe and prints one line per measured stage. + * + * @param args ignored + * @throws Exception if any render stage fails + */ + public static void main(String[] args) throws Exception { + measure("canonical CV, ModernProfessional", + CanonicalBenchmarkSupport.canonicalCv(), + ModernProfessional.create()); + measure("long proposal, ModernProposal", + CanonicalBenchmarkSupport.canonicalProposal(), + ModernProposal.create()); + } + + private static void measure(String label, T data, DocumentTemplate template) throws Exception { + for (int i = 0; i < WARMUP_ITERATIONS; i++) { + Stages warm = new Stages(); + runStages(data, template, warm); + runToImages(data, template, warm); + } + + List samples = new ArrayList<>(); + for (int i = 0; i < MEASURED_ITERATIONS; i++) { + Stages stages = new Stages(); + runStages(data, template, stages); + runToImages(data, template, stages); + samples.add(stages); + } + + System.out.println("=== preview pipeline, stage by stage (" + label + ") ==="); + System.out.printf("pages=%d pdfBytes=%d%n", samples.get(0).pages, samples.get(0).pdfBytes); + report("session open", samples, s -> s.sessionOpenNanos); + report("compose (DSL build)", samples, s -> s.composeNanos); + report("layout (compile graph)", samples, s -> s.layoutNanos); + report("PDF encode: paint graph + save", samples, s -> s.encodeNanos); + report("PDF parse: Loader.loadPDF", samples, s -> s.parseNanos); + report("PDFRenderer 72dpi, all pages", samples, s -> s.raster72Nanos); + report("PDFRenderer 96dpi, all pages", samples, s -> s.raster96Nanos); + report("PDFRenderer 150dpi, all pages", samples, s -> s.raster150Nanos); + report("PDFRenderer 96dpi, first page", samples, s -> s.raster96FirstNanos); + report("sum of the stages at 96dpi", samples, Stages::pipelineSumAt96); + report("toImages(96), layout cached", samples, s -> s.toImagesCachedNanos); + report("toImages(96), fresh session", samples, s -> s.toImagesFromScratchNanos); + System.out.println(); + } + + /** One pass over the pipeline, timing each stage in isolation. */ + private static void runStages(T data, DocumentTemplate template, Stages stages) throws Exception { + // Opening the session is its own stage: the constructor resolves the + // backend's measurement services before a single node is composed. + // Folding it into the compose figure would attribute that setup to the + // DSL, which is the one thing this decomposition exists to avoid. + long t0 = System.nanoTime(); + DocumentSession document = session(); + long tOpen = System.nanoTime(); + stages.sessionOpenNanos = tOpen - t0; + try (document) { + template.compose(document, data); + long t1 = System.nanoTime(); + stages.composeNanos = t1 - tOpen; + + document.layoutGraph(); + long t2 = System.nanoTime(); + stages.layoutNanos = t2 - t1; + + // Layout is cached per revision, so this times the backend painting the + // graph into a PDDocument and saving it — not serialisation alone. + byte[] bytes = document.toPdfBytes(); + stages.encodeNanos = System.nanoTime() - t2; + stages.pdfBytes = bytes.length; + + long t3 = System.nanoTime(); + try (PDDocument parsed = Loader.loadPDF(bytes)) { + stages.parseNanos = System.nanoTime() - t3; + stages.pages = parsed.getNumberOfPages(); + } + + // A fresh parse per DPI: one shared PDFRenderer would hand every later + // DPI the caches the first one warmed. + stages.raster72Nanos = rasterAllPages(bytes, 72); + stages.raster96Nanos = rasterAllPages(bytes, REPORT_DPI); + stages.raster150Nanos = rasterAllPages(bytes, 150); + stages.raster96FirstNanos = rasterFirstPage(bytes, REPORT_DPI); + } + } + + /** + * The public call, measured on its own sessions so it is not preceded by four + * raster passes over the same document. + */ + private static void runToImages(T data, DocumentTemplate template, Stages stages) throws Exception { + try (DocumentSession document = session()) { + template.compose(document, data); + document.layoutGraph(); + long start = System.nanoTime(); + sinkAll(document.toImages(REPORT_DPI)); + stages.toImagesCachedNanos = System.nanoTime() - start; + } + + long start = System.nanoTime(); + try (DocumentSession document = session()) { + template.compose(document, data); + sinkAll(document.toImages(REPORT_DPI)); + } + stages.toImagesFromScratchNanos = System.nanoTime() - start; + } + + private static DocumentSession session() { + return GraphCompose.document() + .pageSize(DocumentPageSize.A4) + .margin(DocumentInsets.of(36)) + .create(); + } + + private static long rasterAllPages(byte[] pdf, int dpi) throws Exception { + try (PDDocument parsed = Loader.loadPDF(pdf)) { + PDFRenderer renderer = new PDFRenderer(parsed); + int pages = parsed.getNumberOfPages(); + long start = System.nanoTime(); + for (int page = 0; page < pages; page++) { + sink(renderer.renderImageWithDPI(page, dpi, ImageType.RGB)); + } + return System.nanoTime() - start; + } + } + + private static long rasterFirstPage(byte[] pdf, int dpi) throws Exception { + try (PDDocument parsed = Loader.loadPDF(pdf)) { + PDFRenderer renderer = new PDFRenderer(parsed); + long start = System.nanoTime(); + sink(renderer.renderImageWithDPI(0, dpi, ImageType.RGB)); + return System.nanoTime() - start; + } + } + + private static int guard; + + private static void sinkAll(List images) { + for (BufferedImage image : images) { + sink(image); + } + } + + private static void sink(BufferedImage image) { + guard += image.getWidth() + image.getHeight(); + } + + private static void report(String label, List samples, ToLongFunction field) { + List values = new ArrayList<>(samples.size()); + for (Stages sample : samples) { + values.add(field.applyAsLong(sample)); + } + Collections.sort(values); + double medianMs = values.get(values.size() / 2) / 1_000_000.0; + double minMs = values.get(0) / 1_000_000.0; + double maxMs = values.get(values.size() - 1) / 1_000_000.0; + System.out.printf("%-32s median=%8.2f ms min=%8.2f max=%8.2f%n", label, medianMs, minMs, maxMs); + } + + private static final class Stages { + long sessionOpenNanos; + long composeNanos; + long layoutNanos; + long encodeNanos; + long parseNanos; + long raster72Nanos; + long raster96Nanos; + long raster150Nanos; + long raster96FirstNanos; + long toImagesCachedNanos; + long toImagesFromScratchNanos; + int pages; + int pdfBytes; + + /** Summed per iteration, so the reported median is a median of real totals. */ + long pipelineSumAt96() { + return sessionOpenNanos + composeNanos + layoutNanos + encodeNanos + + parseNanos + raster96Nanos; + } + } +}