# Logging

> Log query timings, slow queries, errors, and raw SQL with client hooks.

URL: https://better-drizzle.com/docs/guides/observability

Use these recipes when you need query timings, slow-query warnings, or error logs. better-drizzle has no built-in logger: each recipe is a few [client hooks](/docs/advanced/hooks) passed to `better(...)`. For request correlation and OpenTelemetry, see [tracing](/docs/guides/observability-tracing); to ship the hooks as one reusable plugin, see [observability plugin](/docs/guides/observability-plugin).

A client with no hooks skips the hook machinery entirely. Each hook you add costs an `await` per call, so register only the ones you use.

## Query logging with duration

Hooks do not carry a timer, so you add one. The before hook and the after hook of one call receive the same `ctx.args` object, even after plugin transforms. That makes `ctx.args` a key for a `WeakMap`:

```ts title="lib/db.ts"
import { better } from 'better-drizzle';

export type Meta = { requestId?: string; userId?: string };
export type OperationContext = {
	action: string;
	table: string;
	args: unknown;
	meta?: Meta;
};

const started = new WeakMap<object, number>();

const start = (ctx: OperationContext) => {
	started.set(ctx.args as object, performance.now());
};

export const elapsed = (args: unknown) => {
	const at = started.get(args as object);
	if (at === undefined) return undefined;

	started.delete(args as object);
	return performance.now() - at;
};

const logOperation = (ctx: OperationContext) => {
	console.info('db', {
		action: ctx.action,
		table: ctx.table,
		ms: elapsed(ctx.args),
		requestId: ctx.meta?.requestId,
	});
};

export const client = better<typeof relations, Meta>(db, {
	hooks: {
		beforeQuery: start,
		afterQuery: logOperation,
		beforeCreate: start,
		afterCreate: logOperation,
		beforeUpdate: start,
		afterUpdate: logOperation,
		beforeDelete: start,
		afterDelete: logOperation,
	},
});
```

**What the timer covers**

* `action` tells operations apart within one hook: `findMany`, `count`, `createMany`, `updateEach`, and so on. `upsert` only fires the create hooks.
* The `WeakMap` does not hold on to failed calls: if an operation throws and no after hook runs, the entry is garbage-collected with its `args`. Two concurrent calls that pass the very same args object would share an entry, so build args per call.
* The time covers the database work, including relation loading. Plugin before hooks and transforms run earlier, so they are not included.
* `.explain()` does not run query hooks, so plans you inspect do not show up in these logs.

## Slow-query warnings

Use the same timer and log at a higher level above a threshold:

```ts
import { elapsed, type OperationContext } from './lib/db';

const SLOW_MS = 200;

const logOperation = (ctx: OperationContext) => {
	const ms = elapsed(ctx.args);
	if (ms === undefined) return;

	const entry = {
		action: ctx.action,
		table: ctx.table,
		ms: Math.round(ms),
		requestId: ctx.meta?.requestId,
	};

	if (ms >= SLOW_MS) console.warn('slow db operation', entry);
	else console.debug('db', entry);
};
```

Keep argument values out of the log line. `ctx.args.where` and `ctx.args.data` often hold emails, tokens, or other personal data. To find out why a query is slow, run it again with [`.explain()`](/docs/querying/explain).

## Error logging

`onError` fires when an operation fails, when a CRUD or query hook throws, and when `.throw()` finds no row. `ctx.error` is always a `BetterDrizzleError`:

```ts
import { type BetterDrizzleError, better } from 'better-drizzle';
import { elapsed, type Meta } from './lib/db';

export const client = better<typeof relations, Meta>(db, {
	hooks: {
		// ...timing hooks from above
		onError(ctx) {
			const error = ctx.error as BetterDrizzleError;

			console.error('db error', {
				action: ctx.action,
				table: ctx.table,
				stage: ctx.stage,
				hookName: ctx.hookName,
				code: error.code,
				status: error.status,
				message: error.message,
				ms: elapsed(ctx.args),
				requestId: ctx.meta?.requestId,
			});
		},
	},
});
```

| Field                                                | Meaning                                                                             |
| ---------------------------------------------------- | ----------------------------------------------------------------------------------- |
| `stage`                                              | `'beforeHook'`, `'operation'`, or `'afterHook'`                                     |
| `hookName`                                           | the hook that threw, such as `beforeCreate`; unset when the operation itself failed |
| `error.code`                                         | a `BetterDrizzleErrorCode`, such as `RESULT_NOT_FOUND` or `OPERATION_ERROR`         |
| `error.driver`, `error.constraint`, `error.sqlState` | filled in when the error came from the database driver                              |

`error.toJSON()` returns all of these fields as a plain object, which structured loggers can take as is. Errors thrown inside `onError` are swallowed, so a broken logger does not change the result of the call.

`onError` does not cover raw SQL or transactions. They have their own hooks, shown below.

## Raw SQL logging

`beforeRaw`, `afterRaw`, and `onRawError` wrap `$raw`, `$executeRaw`, and `$rawUnsafe`. All three receive the same `ctx.rawOptions` object for one call, so it can key the timer:

```ts
import type { Meta } from './lib/db';

const rawStarted = new WeakMap<object, number>();

const rawElapsed = (key: object) => {
	const at = rawStarted.get(key);
	rawStarted.delete(key);
	return at === undefined ? undefined : performance.now() - at;
};

export const client = better<typeof relations, Meta>(db, {
	hooks: {
		beforeRaw(ctx) {
			rawStarted.set(ctx.rawOptions, performance.now());
		},
		afterRaw(ctx) {
			console.info('raw sql', {
				action: ctx.action,
				name: ctx.name,
				query: ctx.query,
				rows:
					ctx.action === 'executeRaw'
						? ctx.result.rowsAffected
						: ctx.result.length,
				ms: rawElapsed(ctx.rawOptions),
				requestId: ctx.meta?.requestId,
			});
		},
		onRawError(ctx) {
			console.error('raw sql failed', {
				action: ctx.action,
				name: ctx.name,
				query: ctx.query,
				error: ctx.error,
				ms: rawElapsed(ctx.rawOptions),
			});
		},
	},
});
```

`ctx.query` is the rendered SQL with `$1`, `$2` placeholders. Parameter values are not in it, so it is safe to log. Pass `name` (and, on PostgreSQL, `comment`) in the raw options to make log lines searchable:

```ts
const rows = await client.$raw(sql`select id from users where active = ${true}`, {
	name: 'active-user-ids',
});
```

## SQL text from Drizzle

CRUD hooks work at the operation level: action, table, args, and result. They do not show the generated SQL. When you need the statements themselves, turn on Drizzle's own logger on the database you pass to `better(...)`:

```ts
const db = drizzle({
	client: pool,
	relations,
	logger: {
		logQuery(query, params) {
			console.debug('sql', { query, params: params.length });
		},
	},
});
```

`logger: true` prints every query with its parameters. Avoid that in production if parameters can hold personal data.