Read the Query Log Before You Believe the Fix

Every article about N+1 ends the same way: replace the loop with include, one query instead of two hundred, ship it. I subscribed to Prisma's query event, ran four versions of the same read against this site's own database, and counted the statements. The loop was worse than advertised. The include was not one query. The number that mattered turned out to be the one nobody prints.

The table under test is real. BlogPost has a many-to-many to BlogTag through an explicit BlogPostTag join model, and right now the database holds 132 published posts, 506 tags, and 4,616 rows in the join table. A single SQL JOIN across the published slice returns 735 post-tag pairs.

Turning the log on

Prisma emits a query event per statement it sends, but only if you ask for it as an event rather than as stdout logging. The difference matters: log: ['query'] prints, log: [{ emit: 'event' }] lets you count.

// measure/client.ts
import { PrismaClient } from "@prisma/client";
 
const client = new PrismaClient({
  datasources: { db: { url: process.env.DIRECT_URL } },
  log: [{ emit: "event", level: "query" }],
});
 
const statements: { sql: string; params: string; ms: number }[] = [];
client.$on("query", (e) => {
  statements.push({ sql: e.query, params: e.params, ms: e.duration });
});
 
export { client, statements };

e.duration is the database's own timing for that statement. e.query is the parameterised SQL, with $1-style placeholders and the bound values in e.params. Two things to know before you read any of the logs below: e.duration does not include the network round trip, and the count of events is not the count of round trips if you are behind a connection pooler that batches. Everything here ran on a direct connection.

First, a baseline, because every statement count below is really a latency multiplier:

// measure/baseline.ts
import { client } from "./client";
 
const samples: number[] = [];
for (let i = 0; i < 11; i++) {
  const start = process.hrtime.bigint();
  await client.$queryRaw`SELECT 1`;
  samples.push(Number(process.hrtime.bigint() - start) / 1e6);
}
samples.sort((a, b) => a - b);
console.log("median round trip:", samples[5].toFixed(1), "ms");
// median round trip: 151.0 ms   (min 148.1, max 152.9)

151 ms, stable across eleven samples. That is a managed Postgres instance reached over the open internet, which is a pessimistic but entirely ordinary deployment. Hold onto it: from here, a statement count is a wall-clock estimate.

The loop's log is 133 lines long

// measure/loop.ts
import { client } from "./client";
 
export async function tagsByLoop() {
  const posts = await client.blogPost.findMany({
    where: { status: "PUBLISHED" },
    select: { id: true, title: true },
  });
 
  const out = [];
  for (const post of posts) {
    const tags = await client.blogTag.findMany({
      where: { posts: { some: { blogPostId: post.id } } },
      select: { id: true, name: true },
    });
    out.push({ ...post, tags });
  }
  return out;
}

133 statements, median wall time 20,728 ms over three runs. 133 multiplied by 151 ms is 20,083 ms, so the round trips account for essentially all of it — the database did almost no work. Statement 1 and statement 2 of the log:

-- 1 of 133
SELECT "public"."blog_posts"."id", "public"."blog_posts"."title"
FROM "public"."blog_posts"
WHERE "public"."blog_posts"."status" = CAST($1::text AS "public"."CourseStatus")
OFFSET $2
 
-- 2 of 133, then repeated 131 more times with a different $1
SELECT "public"."blog_tags"."id", "public"."blog_tags"."name"
FROM "public"."blog_tags"
WHERE EXISTS(
  SELECT "t0"."blogTagId" FROM "public"."blog_post_tags" AS "t0"
  WHERE ("t0"."blogPostId" = $1
     AND ("public"."blog_tags"."id") = ("t0"."blogTagId"))
)

The OFFSET $2 on statement 1 is Prisma's unconditional pagination clause; it binds 0 when you did not ask for a skip. Worth recognising so you do not go looking for the skip you never wrote.

The second statement is the interesting one, and it is not the query you would have written by hand. A some filter on a relation compiles to a correlated EXISTS subquery, not a join. That is fine for one post and it is what makes the log so uniform — 131 identical plans, 131 identical costs, 131 separate trips.

Three statements, not one

Here is the version the standard advice produces, written as a nested select so the payload stays small:

// measure/nested.ts
import { client } from "./client";
 
export function tagsByNestedSelect() {
  return client.blogPost.findMany({
    where: { status: "PUBLISHED" },
    select: {
      id: true,
      title: true,
      tags: { select: { blogTag: { select: { id: true, name: true } } } },
    },
  });
}

Three statements. Median 499 ms over five runs, which is 3 multiplied by 151 ms plus change. The log:

-- 1 of 3
SELECT "blog_posts"."id", "blog_posts"."title" FROM "public"."blog_posts"
WHERE "blog_posts"."status" = CAST($1::text AS "public"."CourseStatus") OFFSET $2
 
-- 2 of 3
SELECT "blog_post_tags"."blogPostId", "blog_post_tags"."blogTagId"
FROM "public"."blog_post_tags"
WHERE "blog_post_tags"."blogPostId" IN ($1,$2,...,$132) OFFSET $133
 
-- 3 of 3
SELECT "blog_tags"."id", "blog_tags"."name" FROM "public"."blog_tags"
WHERE "blog_tags"."id" IN ($1,$2,...,$N) OFFSET $M

One statement per table, joined by Prisma in JavaScript. Swapping select for include changes nothing about the count — I ran that too, still three. So the popular formulation, that include collapses your read into a single JOIN, is wrong on Prisma 6.19 by default, and it is wrong in a way that gets less harmless the deeper you nest: each level of relation adds a statement, and every statement is another 151 ms.

Each block is sequential, top to bottom, because statement 2 needs the ids that statement 1 returned. That dependency is why the three-statement version cannot be parallelised away, and it is the same dependency that makes the 133-statement version sequential.

Asking Postgres to do the join

Prisma does have a one-statement mode. On the schema this repo actually ships, asking for it fails outright:

await client.blogPost.findMany({
  relationLoadStrategy: "join",
  where: { status: "PUBLISHED" },
  select: { id: true },
});
// Unknown argument `relationLoadStrategy`. Available options are marked with ?.

The option only exists on a client generated with the relationJoins preview feature, which Prisma's relation-queries docs describe as available on PostgreSQL, CockroachDB and MySQL, with join as the default strategy once the flag is on and query as the opt-out. I generated a second client into a scratch directory with the flag set and re-ran the same nested select:

generator client {
  provider        = "prisma-client-js"
  previewFeatures = ["relationJoins"]
  output          = "./scratch-client"
}

One statement. Median 186 ms, against 499 ms for the three-statement form. What it sends:

SELECT "t0"."id", "t0"."title", "BlogPost_tags"."__prisma_data__" AS "tags"
FROM "public"."blog_posts" AS "t0"
LEFT JOIN LATERAL (
  SELECT COALESCE(JSONB_AGG("__prisma_data__"), '[]') AS "__prisma_data__"
  FROM (
    SELECT JSONB_BUILD_OBJECT(
      'blogTagId', "t2"."blogTagId",
      'blogTag', "BlogPostTag_blogTag"."__prisma_data__"
    ) AS "__prisma_data__"
    FROM "public"."blog_post_tags" AS "t2"
    LEFT JOIN LATERAL (
      SELECT JSONB_BUILD_OBJECT('id', "t5"."id", 'name', "t5"."name")
        AS "__prisma_data__"
      FROM "public"."blog_tags" AS "t5" WHERE "t2"."blogTagId" = "t5"."id" LIMIT $1
    ) AS "BlogPostTag_blogTag" ON TRUE
  ) AS "t3"
) AS "BlogPost_tags" ON TRUE
WHERE "t0"."status" = CAST($2::text AS "public"."CourseStatus")

JSONB_AGG over a lateral subquery per relation level — Postgres builds the nested object and Prisma hands it back. A hand-written LEFT JOIN returning flat rows for the same data took 169 ms as one statement, so the JSON assembly costs about 17 ms on 735 pairs and buys you the shape you wanted.

Four numbers for the same read:

Note the third row. Doing the batching yourself — fetch posts, fetch the join rows for all 132 ids, bucket them into a Map — lands within 2 ms of what Prisma's nested select does, because it is what Prisma's nested select does. If you have written that helper by hand and felt clever, the ORM was already doing it.

The bytes the log does not show

Statement count is not the only axis, and select versus include is where the two diverge. Both emit three statements here. What changes is the width of the rows.

// measure/bytes.ts
import { client } from "./client";
 
const narrow = await client.blogPost.findMany({
  where: { status: "PUBLISHED" },
  select: { id: true, title: true, slug: true },
});
const wide = await client.blogPost.findMany({
  where: { status: "PUBLISHED" },
});
 
const sizeOf = (v: unknown) => Buffer.byteLength(JSON.stringify(v));
console.log(sizeOf(narrow), sizeOf(wide), (sizeOf(wide) / sizeOf(narrow)).toFixed(1));
// 20709 2450712 118.3

20,709 bytes against 2,450,712 bytes, a factor of 118, for the same 132 rows. BlogPost has a content column holding the whole MDX body, and a findMany with no select and no omit pulls every scalar on the model. That is the same shape of mistake as the loop, moved one layer out: the statement count looks fine and the payload is two and a half megabytes.

What the IN list costs once it is long

Every batched version above — Prisma's, mine, and anything DataLoader produces — ends up sending WHERE col IN ($1, $2, ...). That clause has a cost curve, and it is not in the query log. It is in EXPLAIN.

// measure/inclause.ts
import { client } from "./client";
 
const real = (await client.blogPost.findMany({ select: { id: true } })).map((r) => r.id);
 
for (const size of [1, 5, 50, 132, 500, 5000]) {
  const list = [...real];
  while (list.length < size) list.push(`zzscratch${list.length}`);
  const literals = list.slice(0, size).map((v) => `'${v}'`).join(",");
  const plan = await client.$queryRawUnsafe<{ "QUERY PLAN": string }[]>(
    `EXPLAIN (ANALYZE) SELECT "blogPostId" FROM blog_post_tags
     WHERE "blogPostId" IN (${literals})`,
  );
  console.log(size, plan.map((r) => r["QUERY PLAN"]).filter((l) => /Time|Scan/.test(l)));
}

Two things happen at once and only one of them is the famous one. The plan flips from Index Only Scan to Seq Scan between 515 and 520 ids — I bisected it — which on a 4,616-row table is Postgres being correct, since scanning the whole thing beats 520 index probes. On a table of a hundred million rows that same flip is the outage.

The less famous one is the planning column. At 5,000 ids Postgres spends 37 ms deciding how to run a query that then takes 1.5 ms to run, and the planner does that work on every execution because the literal list is part of the query text. Planning cost scales with the length of your IN list, and it does not care that the answer is trivial.

Prisma also does something specific here that is worth knowing before you build a very long list. At 1,000 ids it sends 1,001 bind parameters. At 10,000 it sends 10,001. At 65,000 it sends 871 — the number of distinct ids in my array plus one — because the PostgreSQL wire protocol caps a statement at 65,535 parameters and Prisma collapses duplicates rather than fail. So the failure you might be braced for does not arrive, and instead the query quietly changes shape at a threshold that has nothing to do with your data.

DataLoader is the usual way that list gets long. Its README documents maxBatchSize with a default of Infinity, and describes batching as coalescing every load() that occurs "within a single frame of execution (a single tick of the event loop)". Both halves matter: one tick is the batching window, and nothing bounds the batch.

That reordering step is a constraint, not a nicety. The README requires the batch function to return an array the same length as the keys array and in the same order, so the Map lookup people write by habit is doing correctness work, not just tidying. Return users straight from findMany and you will hand resolvers the wrong records whenever Postgres returns rows in a different order than you asked — which it is free to do, and does.

The case for leaving it alone

The rule says never query in a loop. The log says the rule has a break-even, so I measured it: same two shapes, take: n on the parent, five runs each, median.

The crossover is at n=2. At n=1 the two are indistinguishable, both two statements and both 300 ms — and the reason the batched form is two rather than three at n=1 and n=2 is that the first published post by id has no tags, so Prisma skipped the third statement rather than send an empty IN. Above that the loop's line is 151n and the batched line is flat, and it stays flat to 132.

So the honest version of the rule is narrower than the slogan. The loop is never faster; it ties exactly once, when n is 1, and one-row reads are the case where you would not have written a loop anyway. What the table actually argues is the opposite of a caveat: the batched form has no small-n penalty to trade off, which is why the advice survives contact with measurement even though the mechanism people cite for it is wrong.

The thing I cannot get from these logs is the one I most wanted. Every number here is one client against one database with no other traffic, and the loop's 20.7 seconds is 133 sequential round trips on a connection nobody else was competing for. What 133 statements per request does when fifty requests arrive together is a different measurement with a different bottleneck, and it is not the round trip — it is whatever the statements are holding while they wait. I ran the crossover table five times each and got medians inside 20 ms, which tells me the measurement is clean and tells me nothing about the case I would actually be paged for. The EXPLAIN numbers have the same gap: 37 ms of planning on an idle instance, where the planner has the CPU to itself. Under concurrency the interesting question is whether that cost is per-backend or contended, and to answer it I would need