Your ORM is hiding the line that caused the slow query

I was building a runtime N+1 query detector for Node. The detection part worked on the first afternoon. Getting it to tell you which line of your code caused the problem took considerably longer, and taught me something about how ORMs execute queries that I had not thought about before.

This is that story, and the fix.

The symptom

The detector instruments your database driver. When the same query shape runs many times inside one request, it reports it — along with the file and line that issued it, which is the part that actually saves you time:

nplusone 1 finding in GET /orders — 51 queries, 840ms

  N+1 query  50× SELECT * FROM items WHERE order_id = ?
     at src/routes/orders.ts:47:38  (loadOrdersPage)
     612ms spent here

Enter fullscreen mode Exit fullscreen mode

That worked. Then I pointed it at an app using Drizzle and got this instead:

  N+1 query  12× select "id", "order_id" from "items" where "items"."order_id" = $1
     <unknown call site>

Enter fullscreen mode Exit fullscreen mode

Detected, counted, and attributed to nothing.

Do not theorise. Dump the stack

My first instinct was that my frame filter was too aggressive — it skips node_modules, node:internal, and the library’s own frames, so maybe it was eating something it should not have.

Rather than guess, I printed the whole stack at the exact moment the driver was called:

const originalQuery = pg.Client.prototype.query;

pg.Client.prototype.query = function (...args) {
  const previous = Error.stackTraceLimit;
  Error.stackTraceLimit = 100;
  const stack = new Error().stack.split("\n").slice(1);
  Error.stackTraceLimit = previous;

  console.log("FRAMES:", stack.length);
  stack.forEach((line, i) => {
    const mine = !/node_modules|node:internal/.test(line);
    console.log(`${String(i).padStart(3)} ${mine ? ">>>" : "   "} ${line.trim()}`);
  });

  return originalQuery.apply(this, args);
};

Enter fullscreen mode Exit fullscreen mode

Here is what came back for a single await db.select().from(items).where(...):

FRAMES: 12
  0     at Proxy.<anonymous> (.../nplusone/dist/adapters/postgresjs.js)
  1     at .../drizzle-orm/postgres-js/session.js
  2     at PostgresJsPreparedQuery.queryWithCache (.../drizzle-orm/...)
  3     at .../drizzle-orm/...
  4     at Object.startActiveSpan (.../drizzle-orm/...)
  5     at .../drizzle-orm/...
  6     at Object.startActiveSpan (.../drizzle-orm/...)
  7     at PostgresJsPreparedQuery.execute (.../drizzle-orm/...)
  8     at .../drizzle-orm/...
  9     at Object.startActiveSpan (.../drizzle-orm/...)
 10     at PgSelectBase.execute (.../drizzle-orm/...)
 11     at PgSelectBase.then (.../drizzle-orm/...)

Enter fullscreen mode Exit fullscreen mode

Twelve frames. Not one of them belongs to the application. My filter was innocent — there was nothing to find.

Why the frames are gone

Look at frame 11: PgSelectBase.then.

A Drizzle query is a lazy thenable. db.select().from(items).where(...) does not run anything — it builds an object. The query executes when something calls .then() on it, and when you write await, the thing calling .then() is the JavaScript runtime, not your code.

By that point your function has already returned. Its frame is gone from the stack. The runtime picks the thenable up from the microtask queue and calls into Drizzle, and the whole call chain from there down belongs to the ORM.

So the information is not being filtered out. It no longer exists.

TypeORM does not have this problem

This is where it gets interesting, because I assumed every ORM would behave the same way. I measured instead of assuming, and TypeORM came out fine:

repo.find()                  6x  patterns.js:31 (loadItemsForOrder)
repo.findOne()               6x  patterns.js:36
createQueryBuilder()         6x  patterns.js:42
ds.query() raw               6x  patterns.js:47

Enter fullscreen mode Exit fullscreen mode

Line numbers, function names, everything.

The difference is who triggers execution. repo.find() is an async function that you call. Node keeps async stack traces across await boundaries inside that chain, so your frame survives all the way down to the driver.

Drizzle’s await is on a thenable you built but did not call. That is the distinction — not “Drizzle is worse”, but “lazy execution moves the call out of your stack”.

Worth remembering next time you look at a stack trace and it seems too short.

Getting the line back

The stack is useless at execution time. But there is a moment when the caller is on the stack: while the query is being built. db.select().from(items).where(...) is a plain synchronous chain of method calls.

So: capture the call site during construction, carry it to execution, and let the driver-level instrumentation use it instead of walking the stack.

Carrying it is the interesting half, because construction and execution are separated by an await. That is exactly what AsyncLocalStorage is for:

import { AsyncLocalStorage } from "node:async_hooks";

const storage = new AsyncLocalStorage<CallSite>();

/** Runs `fn` with `callsite` visible to anything underneath it. */
export function runWithCallSite<T>(callsite: CallSite | undefined, fn: () => T): T {
  if (callsite === undefined) return fn();
  return storage.run(callsite, fn);
}

/** The call site published by an ORM adapter, if any. */
export function ambientCallSite(): CallSite | undefined {
  return storage.getStore();
}

Enter fullscreen mode Exit fullscreen mode

The driver adapter then prefers the ambient value over its own stack walk:

export function captureNow(): CallSite | undefined {
  const ambient = ambientCallSite();
  if (ambient !== undefined) return ambient;

  return captureCallSite();  // the stack walk, for drivers called directly
}

Enter fullscreen mode Exit fullscreen mode

And the ORM side wraps the builder so that chaining preserves the call site, and executing publishes it:

function wrapChain<T>(value: T, callsite: CallSite | undefined): T {
  return new Proxy(value as object, {
    get(target, property, receiver) {
      const inner = Reflect.get(target, property, receiver);
      if (typeof inner !== "function") return inner;

      // `.then()` / `.execute()` — the query is running now.
      if (EXECUTION_METHODS.has(property as string)) {
        return (...args: unknown[]) =>
          runWithCallSite(callsite, () => inner.apply(target, args));
      }

      // `.from()`, `.where()`, `.limit()` — still building.
      return (...args: unknown[]) => {
        const result = inner.apply(target, args);
        if (result === target) return receiver;   // chained `this`
        return wrapChain(result, callsite);
      };
    },
  }) as T;
}

Enter fullscreen mode Exit fullscreen mode

The call site is captured once, when you call db.select(), and travels with the builder through every chained method until something executes it.

Net result: the SQL comes from the driver, the line number comes from the ORM.

The result

Same query, same app, before and after:

- N+1 query  12× select "id", "order_id", "name" from "items" where "items"."order_id" = $1
-    <unknown call site>

+ N+1 query  12× select "id", "order_id", "name" from "items" where "items"."order_id" = $1
+    at drizzle-test.mjs:35

Enter fullscreen mode Exit fullscreen mode

That is the actual before and after from the same script, against PostgreSQL 16,
Drizzle 0.45.2 and postgres.js 3.4.9 — real database, not fixtures. Line 35 is
where db.select() is called inside the loop.

One trap worth knowing

The first version of this had a bug that took a while to see: I treated .values() as an execution method.

In postgres.js, .values() executes a query. In Drizzle, db.insert(t).values({...}) builds an insert. Treating it as execution broke the chain, so every insert silently lost its attribution — while selects kept working perfectly.

If you write something like this, be precise about which methods in your target library actually execute, and test inserts separately from selects. A bug that only affects half your cases is worse than one that breaks everything, because you will not notice it.

Two things I would tell past me

Measure before theorising. I was ready to rewrite my frame filter. The filter was fine. Ten minutes printing the actual stack saved an afternoon of fixing the wrong thing.

“It works” and “it works with real inputs” are different claims. Every unit test passed while this bug existed, because fixtures call the driver directly and the caller’s frame is right there. Only running against a real ORM exposed it.

The detector is nplusone — MIT, zero runtime dependencies, and it turns off when NODE_ENV=production. If you want to see the output without wiring anything up:

import { configure, record } from "nplusone";

configure({ autoScope: true });
for (const id of [1, 2, 3, 4, 5]) {
  record({ sql: "SELECT * FROM items WHERE order_id = $1", params: [id] });
}

Enter fullscreen mode Exit fullscreen mode

But honestly, the stack trace thing is the part I found interesting, and it applies to anything you instrument — tracing, logging, profiling. If your tool reports “unknown” where a line number should be, dump the stack. The answer is usually right there.