Query logging and errors with context

See the SQL that runs, and know exactly which query failed.

Logging every query

Pass onQuery in the engine options — it's called per statement, with the SQL and the bound params:

import { createEngine } from "tempest-db-js";

const engine = createEngine("sqlite:///app.db", {
  onQuery: ({ sql, params }) => {
    console.debug(sql, params);
  },
});

The hook fires for every session statement: execute, stream, and the BEGIN/COMMIT/SAVEPOINT of transactions.

The logger never breaks a query

If your onQuery throws, the error is swallowed — logging never brings execution down. Don't rely on it for business logic.

Tracing / metrics

onQuery is the place to measure latency (stamp time, correlate by SQL), count queries per request, or feed a tracer.

Duration: onQueryEnd

onQuery fires before the statement runs, so it cannot time anything. Its other half is onQueryEnd, which fires afterwards with what the driver took:

const engine = createEngine("postgresql://app@localhost/app", {
  onQueryEnd: ({ sql, durationMs, rowCount, error }) => {
    metrics.histogram("db.query.ms", durationMs, { failed: error !== undefined });
    if (durationMs > 200) logger.warn({ sql, durationMs, rowCount }, "slow query");
  },
});

Field	What it carries
sql / params	the same ones onQuery announced
durationMs	the driver's wall-clock time
rowCount	rows returned (SELECT/RETURNING) or affected (writes)
error	the driver's error, when the statement failed

A slow-query log in one line

createEngine(url, {
  slowQueryMs: 200,
  onQueryEnd: ({ sql, durationMs }) => logger.warn({ sql, durationMs }, "slow query"),
});

With slowQueryMs the hook is called only for statements crossing the threshold — the cheapest slow-query log there is, with no APM agent.

It fires on failure too

A failing statement calls onQueryEnd with error set and rowCount: 0. The slow statement that also fails is exactly the interesting one, and a hook that only saw the happy path would miss it.

stream() is measured until the iteration ends

For a stream, the time spans from compilation to the last row consumed — which is what answers "why is this page slow". rowCount carries how many rows came out.

Like onQuery, an error thrown inside onQueryEnd is swallowed: logging never breaks the query.

Errors carry the failing SQL

When the driver rejects a statement, tempest-db-js throws QueryExecutionError — with the SQL and params attached, instead of an opaque driver message:

import { QueryExecutionError, insert } from "tempest-db-js";

try {
  session.execute(insert(User).values({ id: 1, name: "dup" }));
  session.execute(insert(User).values({ id: 1, name: "dup" })); // duplicate PK
} catch (err) {
  if (err instanceof QueryExecutionError) {
    console.error(err.message); // includes "SQL: INSERT INTO ... params: [...]"
    err.sql;    // the exact SQL that failed
    err.params; // the bound params, in order
    err.cause;  // the original driver error
  }
}

The message carries a safe preview (long values truncated, blobs as <N bytes>); the sql/params props hold the full content for you to log.

Server-side notices (onNotice)

PostgreSQL emits a NOTICE for perfectly ordinary things — CREATE TABLE IF NOT EXISTS on a table that exists, DROP ... IF EXISTS on one that does not, a constraint whose index it creates for you. Every migration runner hits this.

The postgres.js driver prints those notices with console.log by default, which drops a nine-line object into your service's stdout, in the middle of its structured log, on every boot. tempest-db-js silences them by default and gives you the hook:

const engine = createEngine(url, {
  onNotice: (notice) => logger.debug({ pg: notice }, "postgres notice"),
});

Silence is the default on purpose

Writing to the host process's stdout is the application's decision, not a library's. Without onNotice the notice is dropped; with it, you choose the level, the shape and the destination.

An error thrown inside onNotice is swallowed, like onQuery.

Driver options (driverOptions)

For what the typed layer does not model — postgres.js's connection, types, transform, ssl, mysql2's own settings, node:sqlite's readOnly:

const engine = createEngine(url, {
  pool: { size: 10 },
  driverOptions: { ssl: "require", transform: { undefined: null } },
});

driverOptions is applied last and wins over everything the library derives (pool and onNotice included) — it is an escape hatch, so it gets the last word.

Why is this query slow? engine.explain

Timing says that it is slow; the plan says why. Instead of copying SQL out of a log into psql — and hoping the parameters match — wrap the block:

const report = await engine.explain(async (session) => {
  await new BaseRepository(Order, session).paginate({ filters: { status: "open" }, page: 3 });
});

console.log(report.summary());
for (const plan of report.plans) {
  console.log(plan.sql, plan.params, plan.summary());
}

The block gets a recording session: the plans come from the statements and the parameters the code actually used.

	PostgreSQL	SQLite
Prefix	EXPLAIN (FORMAT JSON)	EXPLAIN QUERY PLAN
analyze: true	EXPLAIN (FORMAT JSON, ANALYZE)	error — it does not exist

analyze: true executes the statement

That is how it measures. Which is why it is refused for anything that is not a read — analyzing an UPDATE would apply it a second time. To explain only the reads of a mixed block, pass { filter: isReadOnlyStatement }.

A development tool

The block runs and each statement gets an EXPLAIN afterwards — twice the round trips. Use it in a test, in an investigation, on a debug endpoint; never on the hot path.

Recap

• createEngine(url, { onQuery }) → per-statement { sql, params } hook.
• { onNotice } → server-side notices; without it, nothing is printed.
• A throwing logger is swallowed — never breaks the query.
• Driver failure → QueryExecutionError with sql, params, cause.
• { driverOptions } passes through what the library does not model, applied last.