iammerlijn online

Fixing a PDF pipeline: nine of ten reports completed, up from four

TL;DR

We generate report PDFs with Puppeteer in a Node.js worker pool. In a test of ten documents under production-like limits, only four finished. After reducing image sizes and concurrency and fixing page cleanup, nine finished.

We tested with a run of 10 report documents and production-like CPU and memory limits:

  • Completed documents went from 4 of 10 to 9 of 10.
  • The total time went from 7m 13s to 48s.
  • One report with 65 images went from 107 MB to 11.8 MB.

This is a small controlled test, not a measurement of the production success rate. One document still failed.

Context

The product is a SaaS for property operations. Users write inspection and issue reports with photos, and they download them as PDF. Some reports have more than 150 photos.

The API is Node.js in a Docker container on Kubernetes. PDF generation runs in a workerpool. Each worker starts Chromium through Puppeteer, renders an HTML template with the photos, and prints the page to PDF.

Only the PDFs failed

After a deploy, report generation started to time out in production. All other endpoints returned 200. On my laptop, the same reports generated without a problem.

The logs showed only a generic Error from inside the worker pool. The real stack trace got lost between the worker thread and the main thread.

Make the laptop as small as production

The problem started after a deploy, so we suspected the Docker image first. We compared the old image and the new image with docker history and docker inspect. They had the same base image, the same Node version, and the same build steps. Only the app code that COPY . . adds was different, so the image was not the cause.

Next, we looked at what my laptop has that production does not. The production pod has 1 CPU and 1 GB of memory. My laptop gave the app all of its CPU and memory.

So we gave the container the production limits on purpose:

docker build -t api .
docker run --memory=1g --cpus=1 --shm-size=64m -p 1337:1337 \
  --env-file .env \
  api

With these limits, the failure showed up locally within minutes. After that, we tested every change with the same run of 10 documents and compared the success rate, the total time, and the file size.

To see the real errors, we also logged .stack, .message, and .cause for every error that came back from a worker.

Three causes worked together

  1. Too many Chromium instances for one CPU. The pool ran several workers in parallel, and each worker had its own Chromium. On 1 CPU, parallel workers do not finish sooner. They compete for the same CPU, every render gets slower, and many renders pass the timeout.
  2. Full-size photos. The template used the original format of every uploaded photo. These files are often several MB, straight from a phone camera. Chromium had to load and decode every photo, and every photo ended up in the PDF at full size. One report with 65 photos became a 107 MB PDF.
  3. No cleanup on failure. When a render failed or timed out, the page stayed open. The next report started with less free memory, and that made the next failure more likely.

Four changes

1. One worker. On 1 CPU, one Chromium at a time is faster than several that compete:

// simplified
const pool = workerpool.pool(__dirname + "/pdf-worker.js", {
  maxWorkers: 1,
});

Extra requests wait in the pool queue. They do not start another Chromium.

2. Smaller images. The template now uses the small format of each photo instead of original. On a printed A4 page with several photos, you do not see the difference.

3. Close the page every time. A finally block closes the page after a success, a failure, or a timeout:

// simplified
const page = await browser.newPage();
try {
  await page.setContent(html, { waitUntil: "networkidle0" });
  return await page.pdf({ format: "A4" });
} finally {
  await page.close();
}

4. Return the real result. The endpoint now returns the result of the generation. When generation fails, the client gets an error right away. Before, the request hung until it timed out.

Results

We used the same run of 10 report documents with --memory=1g --cpus=1 --shm-size=64m:

MetricBeforeAfter
Completed documents4/109/10
Total time, 10 documents7m 13s48s
PDF size, report with 65 images107 MB11.8 MB

In production, reports with 27, 34, 128, and 177 photos timed out before the change. After the change, they finished in about 2.3 s, 5.6 s, 9.1 s, and 9.0 s.

What the changes cost

  • One worker means a queue. When many users request a report at the same moment, each user waits for the reports before theirs. A wait is better than a failure.
  • Smaller images are less sharp. For a printed report with several photos per page, the small format is good enough.
  • 90% is not 100%. Some reports still failed when the database or the pod was under high load. Later we added retries, tuned the timeouts, rendered long reports in chunks of pages, and shared one browser instance across reports instead of a new Chromium for each report.

The later changes are not included in the ten-document comparison above. This write-up does not establish the final production failure rate.