feat: add PDF render timing to convert and demo routes
Some checks failed
Build & Deploy to Staging / Build & Deploy to Staging (push) Failing after 1m42s

- renderPdf() and renderUrlPdf() now return { pdf, durationMs }
- Timing wraps the actual render with Date.now()
- Log render duration via logger.info
- Add X-Render-Time response header in convert and demo routes
- Update all callers in convert, demo, templates routes
- Add TDD tests in render-timing.test.ts
- Update existing test mocks for new return shape
This commit is contained in:
Hoid 2026-03-06 11:08:06 +01:00
parent 0283e9dae8
commit f9caef82e6
13 changed files with 165 additions and 23 deletions

View file

@ -52,7 +52,7 @@ describe("Body size limits", () => {
vi.resetModules();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
const { demoRouter } = await import("../routes/demo.js");
const { convertRouter } = await import("../routes/convert.js");

View file

@ -150,8 +150,11 @@ describe("browser pool", () => {
it("generates a PDF buffer from HTML", async () => {
await browserModule.initBrowser();
const result = await browserModule.renderPdf("<h1>Hello</h1>");
expect(Buffer.isBuffer(result)).toBe(true);
expect(result.toString()).toContain("%PDF");
expect(result).toHaveProperty("pdf");
expect(result).toHaveProperty("durationMs");
expect(Buffer.isBuffer(result.pdf)).toBe(true);
expect(result.pdf.toString()).toContain("%PDF");
expect(typeof result.durationMs).toBe("number");
});
it("sets content and disables JS on the page", async () => {
@ -237,7 +240,9 @@ describe("browser pool", () => {
it("navigates to URL and generates PDF", async () => {
await browserModule.initBrowser();
const result = await browserModule.renderUrlPdf("https://example.com");
expect(Buffer.isBuffer(result)).toBe(true);
expect(result).toHaveProperty("pdf");
expect(result).toHaveProperty("durationMs");
expect(Buffer.isBuffer(result.pdf)).toBe(true);
const usedPage = mockBrowsers
.flatMap((b: any) => b._pages.slice(0, 2))
.find((p: any) => p.goto.mock.calls.length > 0);

View file

@ -14,8 +14,8 @@ beforeEach(async () => {
vi.resetModules();
const { renderPdf, renderUrlPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderUrlPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock url"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
vi.mocked(renderUrlPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock url"), durationMs: 10 });
const dns = await import("node:dns/promises");
vi.mocked(dns.default.lookup).mockResolvedValue({ address: "93.184.216.34", family: 4 } as any);

View file

@ -15,8 +15,8 @@ beforeEach(async () => {
vi.resetModules();
const { renderPdf, renderUrlPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderUrlPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock url"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
vi.mocked(renderUrlPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock url"), durationMs: 10 });
const dns = await import("node:dns/promises");
vi.mocked(dns.default.lookup).mockResolvedValue({ address: "93.184.216.34", family: 4 } as any);

View file

@ -14,7 +14,7 @@ beforeEach(async () => {
vi.resetModules();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
const { demoRouter } = await import("../routes/demo.js");
app = express();

View file

@ -0,0 +1,126 @@
import { describe, it, expect, vi, beforeEach } from "vitest";
import express from "express";
import request from "supertest";
// Mock browser service to return { pdf, durationMs }
vi.mock("../services/browser.js", () => ({
renderPdf: vi.fn(),
renderUrlPdf: vi.fn(),
}));
describe("PDF render timing", () => {
describe("browser service return type", () => {
it("renderPdf returns { pdf, durationMs }", async () => {
// Reset modules to get unmocked version for this test
vi.restoreAllMocks();
vi.resetModules();
// We can't easily test the real renderPdf without a browser,
// so we test the shape via the mock contract and integration tests below
});
});
describe("convert routes set X-Render-Time header", () => {
let app: express.Express;
beforeEach(async () => {
vi.clearAllMocks();
vi.resetModules();
const { renderPdf, renderUrlPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 42 } as any);
vi.mocked(renderUrlPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 55 } as any);
const { convertRouter } = await import("../routes/convert.js");
app = express();
app.use(express.json({ limit: "500kb" }));
app.use((req, _res, next) => {
(req as any).apiKey = { id: "test-key", name: "test", tier: "free", active: true };
(req as any).keyRow = { id: "test-key", name: "test", tier: "free", active: true, owner_email: "test@test.com" };
next();
});
app.use("/v1/convert", convertRouter);
});
it("POST /v1/convert/html sets X-Render-Time header", async () => {
const res = await request(app)
.post("/v1/convert/html")
.set("content-type", "application/json")
.send({ html: "<h1>Hello</h1>" });
expect(res.status).toBe(200);
expect(res.headers["x-render-time"]).toBe("42");
});
it("POST /v1/convert/markdown sets X-Render-Time header", async () => {
const res = await request(app)
.post("/v1/convert/markdown")
.set("content-type", "application/json")
.send({ markdown: "# Hello" });
expect(res.status).toBe(200);
expect(res.headers["x-render-time"]).toBe("42");
});
});
describe("demo routes set X-Render-Time header", () => {
let app: express.Express;
beforeEach(async () => {
vi.clearAllMocks();
vi.resetModules();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 99 } as any);
const { demoRouter } = await import("../routes/demo.js");
app = express();
app.use(express.json({ limit: "500kb" }));
app.use("/v1/demo", demoRouter);
});
it("POST /v1/demo/html sets X-Render-Time header", async () => {
const res = await request(app)
.post("/v1/demo/html")
.set("content-type", "application/json")
.send({ html: "<h1>Hello</h1>" });
expect(res.status).toBe(200);
expect(res.headers["x-render-time"]).toBe("99");
});
it("POST /v1/demo/markdown sets X-Render-Time header", async () => {
const res = await request(app)
.post("/v1/demo/markdown")
.set("content-type", "application/json")
.send({ markdown: "# Hello" });
expect(res.status).toBe(200);
expect(res.headers["x-render-time"]).toBe("99");
});
});
describe("templates route destructures correctly", () => {
// Templates route doesn't need X-Render-Time header per task,
// but must correctly destructure { pdf, durationMs }
let app: express.Express;
beforeEach(async () => {
vi.clearAllMocks();
vi.resetModules();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 30 } as any);
const dbMod = await import("../services/db.js");
if (vi.isMockFunction(dbMod.default?.prepare)) {
// db is already mocked elsewhere
}
});
it("templates route still returns valid PDF after refactor", async () => {
// This is covered by existing templates-route tests;
// we just verify the mock shape works
const { renderPdf } = await import("../services/browser.js");
const result = await vi.mocked(renderPdf)("<h1>test</h1>");
expect(result).toHaveProperty("pdf");
expect(result).toHaveProperty("durationMs");
expect((result as any).durationMs).toBe(30);
});
});
});

View file

@ -56,8 +56,8 @@ vi.mock("../services/keys.js", () => {
vi.mock("../services/browser.js", () => ({
initBrowser: vi.fn().mockResolvedValue(undefined),
closeBrowser: vi.fn().mockResolvedValue(undefined),
renderPdf: vi.fn().mockResolvedValue(Buffer.from("%PDF-1.4 mock pdf content here")),
renderUrlPdf: vi.fn().mockResolvedValue(Buffer.from("%PDF-1.4 mock url pdf content")),
renderPdf: vi.fn().mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock pdf content here"), durationMs: 10 }),
renderUrlPdf: vi.fn().mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock url pdf content"), durationMs: 10 }),
getPoolStats: vi.fn().mockReturnValue({
poolSize: 16,
totalPages: 16,

View file

@ -16,7 +16,7 @@ beforeEach(async () => {
vi.clearAllMocks();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
const { authMiddleware } = await import("../middleware/auth.js");
const { usageMiddleware } = await import("../middleware/usage.js");

View file

@ -8,7 +8,7 @@ beforeEach(async () => {
vi.clearAllMocks();
const { renderPdf } = await import("../services/browser.js");
vi.mocked(renderPdf).mockResolvedValue(Buffer.from("%PDF-1.4 mock"));
vi.mocked(renderPdf).mockResolvedValue({ pdf: Buffer.from("%PDF-1.4 mock"), durationMs: 10 });
const { authMiddleware } = await import("../middleware/auth.js");
const { usageMiddleware } = await import("../middleware/usage.js");

View file

@ -113,13 +113,14 @@ convertRouter.post("/html", async (req: Request & { acquirePdfSlot?: () => Promi
? body.html
: wrapHtml(body.html, body.css);
const pdf = await renderPdf(fullHtml, {
const { pdf, durationMs } = await renderPdf(fullHtml, {
...validation.sanitized,
});
const filename = sanitizeFilename(body.filename || "document.pdf");
res.setHeader("Content-Type", "application/pdf");
res.setHeader("Content-Disposition", `inline; filename="${filename}"`);
res.setHeader("X-Render-Time", String(durationMs));
res.send(pdf);
} catch (err: any) {
logger.error({ err }, "Convert HTML error");
@ -214,13 +215,14 @@ convertRouter.post("/markdown", async (req: Request & { acquirePdfSlot?: () => P
}
const html = markdownToHtml(body.markdown, body.css);
const pdf = await renderPdf(html, {
const { pdf, durationMs } = await renderPdf(html, {
...validation.sanitized,
});
const filename = sanitizeFilename(body.filename || "document.pdf");
res.setHeader("Content-Type", "application/pdf");
res.setHeader("Content-Disposition", `inline; filename="${filename}"`);
res.setHeader("X-Render-Time", String(durationMs));
res.send(pdf);
} catch (err: any) {
logger.error({ err }, "Convert MD error");
@ -345,7 +347,7 @@ convertRouter.post("/url", async (req: Request & { acquirePdfSlot?: () => Promis
slotAcquired = true;
}
const pdf = await renderUrlPdf(body.url, {
const { pdf, durationMs } = await renderUrlPdf(body.url, {
...validation.sanitized,
hostResolverRules: `MAP ${parsed.hostname} ${resolvedAddress}`,
});
@ -353,6 +355,7 @@ convertRouter.post("/url", async (req: Request & { acquirePdfSlot?: () => Promis
const filename = sanitizeFilename(body.filename || "page.pdf");
res.setHeader("Content-Type", "application/pdf");
res.setHeader("Content-Disposition", `inline; filename="${filename}"`);
res.setHeader("X-Render-Time", String(durationMs));
res.send(pdf);
} catch (err: any) {
logger.error({ err }, "Convert URL error");

View file

@ -133,7 +133,7 @@ router.post("/html", async (req: Request & { acquirePdfSlot?: () => Promise<void
printBackground: true,
margin: { top: "0", right: "0", bottom: "0", left: "0" },
};
const pdf = await renderPdf(fullHtml, {
const { pdf, durationMs } = await renderPdf(fullHtml, {
...defaultOpts,
...validation.sanitized,
});
@ -142,6 +142,7 @@ router.post("/html", async (req: Request & { acquirePdfSlot?: () => Promise<void
res.setHeader("Content-Type", "application/pdf");
res.setHeader("Content-Disposition", `attachment; filename="${filename}"`);
res.setHeader("Content-Length", pdf.length);
res.setHeader("X-Render-Time", String(durationMs));
res.send(pdf);
} catch (err: any) {
if (err.message === "QUEUE_FULL") {
@ -237,7 +238,7 @@ router.post("/markdown", async (req: Request & { acquirePdfSlot?: () => Promise<
printBackground: true,
margin: { top: "0", right: "0", bottom: "0", left: "0" },
};
const pdf = await renderPdf(fullHtml, {
const { pdf, durationMs } = await renderPdf(fullHtml, {
...defaultOpts,
...validation.sanitized,
});
@ -246,6 +247,7 @@ router.post("/markdown", async (req: Request & { acquirePdfSlot?: () => Promise<
res.setHeader("Content-Type", "application/pdf");
res.setHeader("Content-Disposition", `attachment; filename="${filename}"`);
res.setHeader("Content-Length", pdf.length);
res.setHeader("X-Render-Time", String(durationMs));
res.send(pdf);
} catch (err: any) {
if (err.message === "QUEUE_FULL") {

View file

@ -166,7 +166,7 @@ templatesRouter.post("/:id/render", async (req: Request, res: Response) => {
const sanitizedPdf = { format: "A4" as string, ...validation.sanitized };
const html = renderTemplate(id, data);
const pdf = await renderPdf(html, sanitizedPdf);
const { pdf, durationMs } = await renderPdf(html, sanitizedPdf);
const filename = sanitizeFilename(data._filename || `${id}.pdf`);
res.setHeader("Content-Type", "application/pdf");

View file

@ -239,10 +239,11 @@ export interface PdfRenderOptions {
export async function renderPdf(
html: string,
options: PdfRenderOptions = {}
): Promise<Buffer> {
): Promise<{ pdf: Buffer; durationMs: number }> {
const { page, instance } = await acquirePage();
try {
await page.setJavaScriptEnabled(false);
const startTime = Date.now();
const result = await Promise.race([
(async () => {
await page.setContent(html, { waitUntil: "domcontentloaded", timeout: 15_000 });
@ -267,7 +268,9 @@ export async function renderPdf(
setTimeout(() => reject(new Error("PDF_TIMEOUT")), 30_000)
),
]);
return result;
const durationMs = Date.now() - startTime;
logger.info(`PDF rendered in ${durationMs}ms (html, ${result.length} bytes)`);
return { pdf: result, durationMs };
} finally {
releasePage(page, instance);
}
@ -279,7 +282,7 @@ export async function renderUrlPdf(
waitUntil?: string;
hostResolverRules?: string;
} = {}
): Promise<Buffer> {
): Promise<{ pdf: Buffer; durationMs: number }> {
const { page, instance } = await acquirePage();
try {
await page.setJavaScriptEnabled(false);
@ -316,6 +319,7 @@ export async function renderUrlPdf(
});
}
}
const startTime = Date.now();
const result = await Promise.race([
(async () => {
await page.goto(url, {
@ -342,7 +346,9 @@ export async function renderUrlPdf(
setTimeout(() => reject(new Error("PDF_TIMEOUT")), 30_000)
),
]);
return result;
const durationMs = Date.now() - startTime;
logger.info(`PDF rendered in ${durationMs}ms (url, ${result.length} bytes)`);
return { pdf: result, durationMs };
} finally {
releasePage(page, instance);
}