Skip to content

PostgresJs integration emits 2-3 spans per SQL statement (Query lifecycle calls handle() multiple times) #21355

@jimparo1

Description

@jimparo1

Summary

The PostgresJs integration (@sentry/node) emits 2-3 Sentry spans per logical SQL statement when using postgres (porsager/postgres) via standard await sql\…`` semantics. The underlying SQL only executes once — the duplicates are pure instrumentation overhead — but they inflate the span tree and Sentry trace volume by 2-3×.

Root cause: postgres.js's Query.prototype.{then, catch, finally, execute, forEach} each call this.handle() (postgres@3.4.9 cjs/src/query.js:139-161). The TRUE handle() is idempotent — !this.executed && (this.executed = true) && await 1 && this.handler(this) — so the underlying wire-protocol call only runs once. But Sentry's patched handle (both _patchQueryPrototype in @sentry/node and _wrapSingleQueryHandle in @sentry/core) calls startSpanManual() on every invocation without honoring this.executed, so each .then/.catch/.finally invocation creates an extra duplicate span.

The maintainers are partially aware of Query.then calling handle — there's an explicit comment at @sentry/core/src/integrations/postgresjs.ts line 218:

IMPORTANT: We must replace the handle function directly, not use a Proxy, because Query.then() internally calls this.handle(), which would bypass a Proxy wrapper.

The Proxy-bypass concern was addressed, but the implication that handle() gets called multiple times per query (once per lifecycle method) was missed.

How do you use Sentry?

@sentry/node (also affects @sentry/nestjs, @sentry/nextjs, etc. via the shared postgresJsIntegration).

Which SDK and version?

  • @sentry/node 10.55.0: bug present
  • @sentry/node 10.56.0 (current latest): bug present
  • @sentry/node develop HEAD: source unchanged, bug should still be present

Steps to reproduce

Minimal self-contained Node.js repro — no framework dependencies, just @sentry/node + postgres. Connects to a local Postgres (any superuser will do; the repro just runs SELECT 1):

package.json:

{
  "type": "commonjs",
  "dependencies": {
    "@sentry/node": "10.55.0",
    "postgres": "3.4.9"
  }
}

repro.js:

const emitted = [];

const Sentry = require("@sentry/node");
Sentry.init({
  dsn: "https://fake@o0.ingest.sentry.io/0", // fake; events are not shipped
  tracesSampleRate: 1.0,
  beforeSendSpan(span) {
    emitted.push({ op: span.op, description: span.description });
    return span;
  },
});

const postgres = require("postgres");

async function main() {
  const sql = postgres({
    host: process.env.PGHOST || "localhost",
    port: Number(process.env.PGPORT || 5432),
    database: process.env.PGDATABASE || "postgres",
    username: process.env.PGUSER || "postgres",
    password: process.env.PGPASSWORD || "",
    ssl: false,
    max: 1,
  });

  // requireParentSpan: true on the integration, so we need an active parent.
  await Sentry.startSpan({ name: "test-tx", op: "test" }, async () => {
    await sql.begin(async (tx) => {
      await tx`SELECT 1 as one`;
    });
  });

  await Sentry.flush(2000);

  const counts = new Map();
  for (const s of emitted) {
    const key = `${s.op || "?"} | ${s.description || "?"}`;
    counts.set(key, (counts.get(key) || 0) + 1);
  }
  console.log("\n--- Emitted Sentry spans ---");
  for (const [k, n] of [...counts.entries()].sort((a, b) => b[1] - a[1])) {
    console.log(`  ${n}x ${k}`);
  }
  console.log(`\nTotal db-op spans: ${emitted.filter(e => e.op === "db").length}`);
  await sql.end();
}

main().catch(err => { console.error(err); process.exit(1); });

Run:

npm install
PGUSER=<your_user> PGPASSWORD=<your_pw> node repro.js

Expected behavior

One Sentry db span per physical SQL statement that Postgres actually sees. For this repro, log_statement = all on Postgres confirms exactly 4 physical statements execute:

  1. select b.oid, b.typarray from pg_catalog.pg_type ... (postgres-js one-time type-introspection on first connection)
  2. begin
  3. SELECT 1 as one
  4. commit

So the expected db-op span count is 4.

Actual behavior (both 10.55.0 and 10.56.0)

Output:

--- Emitted Sentry spans ---
  3x db | SELECT ? as one
  3x db | commit
  2x db | begin
  1x test | test-tx
  1x db | select b.oid, b.typarray from pg_catalog.pg_type a left join pg_catalog.pg_type b on b.oid = a.typelem where a.typcategory = ? group by b.oid, b.typarray order by b.oid

Total db-op spans: 9

9 db spans for 4 SQL statements. Breakdown:

SQL statement Physical executions Sentry db spans
type-introspection 1 1 ✅
begin 1 2 ❌
SELECT 1 as one 1 3 ❌
commit 1 3 ❌

The duplicate spans are siblings (when not wrapped) or 1-outer-+-2-children (when wrapped) — the outer span becomes the OTel "active span" context, so the second and third handle() invocations' spans nest inside the first.

Sub-microsecond start-time alignment confirms they're concurrent wrappers of a single physical operation, not parallel real executions. From a production trace at our org:

06c2fbd8  start=.274  finish=.291411  dur=17.411ms  parent=8d06ac40 (← outer)
664de2d1  start=.274  finish=.291243  dur=17.243ms  parent=06c2fbd8  (← child sibling 1)
4124dcb4  start=.274  finish=.291319  dur=17.319ms  parent=06c2fbd8  (← child sibling 2)
          ↑ ALL THREE same microsecond           Δ all under 0.2ms

Three real SELECT set_config calls would total ~51ms; outer is 17.4ms — proves the children are concurrent, not sequential.

Root cause

postgres.js's Query class extends Promise and overrides Promise's lifecycle methods to lazily kick off SQL execution. From postgres@3.4.9 cjs/src/query.js:139-161:

async handle() {
  !this.executed && (this.executed = true) && await 1 && this.handler(this)
}

execute() { this.handle(); return this }
then()    { this.handle(); return super.then.apply(this, arguments) }
catch()   { this.handle(); return super.catch.apply(this, arguments) }
finally() { this.handle(); return super.finally.apply(this, arguments) }
forEach() { this.handle(); ... }

The TRUE handle() is idempotent — only the first call sets this.executed = true and invokes this.handler(this) (the wire-protocol exec). Subsequent calls are no-ops at the SQL level.

But Sentry's patched handle creates a span on every invocation. From packages/node/src/integrations/tracing/postgresjs.ts (develop HEAD):

moduleExports.Query.prototype.handle = async function(...args) {
  if (this[QUERY_FROM_INSTRUMENTED_SQL]) { return originalHandle.apply(this, args); }
  if (!self._shouldCreateSpans()) { return originalHandle.apply(this, args); }
  // ↑↑ no `this.executed` check ↑↑
  return startSpanManual({ name, op: "db" }, ...);  // creates a span every time
};

Same gap in the portable packages/core/src/integrations/postgresjs.ts _wrapSingleQueryHandle.

When a user does await sql\SELECT 1``:

Net: 1 SQL statement → 2-3 Sentry spans.

Suggested fix

Add this.executed checks alongside the existing this[QUERY_FROM_INSTRUMENTED_SQL] check in both locations:

packages/node/src/integrations/tracing/postgresjs.ts (in the file-hook patch around line 288):

 moduleExports.Query.prototype.handle = async function(...args) {
-  if (this[QUERY_FROM_INSTRUMENTED_SQL]) {
+  if (this[QUERY_FROM_INSTRUMENTED_SQL] || this.executed) {
     return originalHandle.apply(this, args);
   }
   if (!self._shouldCreateSpans()) {
     return originalHandle.apply(this, args);
   }
   // ...
 };

packages/core/src/integrations/postgresjs.ts (in _wrapSingleQueryHandle around line 220):

 const wrappedHandle = async function (this, ...args) {
+  if (this.executed) {
+    return originalHandle.apply(this, args);
+  }
   if (!_shouldCreateSpans(options)) {
     return originalHandle.apply(this, args);
   }
   // ...
 };

These checks mirror postgres.js's own idempotency guard at the span-creation boundary, so a span is only ever created for the first (and only) physical SQL execution.

Workaround for affected users

Until a fix ships, users can disable the integration via the documented config function:

Sentry.init({
  // ...
  integrations: (integrations) =>
    integrations.filter((i) => i.name !== "PostgresJs"),
});

Trade-off: loses all db spans for postgres-js queries. The broader http.server + framework spans still give request-level visibility.

Additional context

  • Verified on Node.js 24.16.0, Linux/macOS.
  • Bug exists with or without a transaction (sql.begin) — any awaited query triggers it.
  • Particularly visible with ORMs like drizzle-orm that issue many small transactional queries (e.g. SET LOCAL for RLS); a single dashboard request can multiply 12+ logical statements to 30+ Sentry spans.
  • No existing open or closed issue documents this pattern (searched 2026-06-07).

Metadata

Metadata

Assignees

Labels

No fields configured for issues without a type.

Projects

Status
No status

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions