Assert Structured Logs in Tests
Capture log output in tests, assert required fields and redaction, and catch missing request context before production debugging does.
Task
Verify that requests emit structured logs with the fields needed to debug them, without asserting exact message text.
When to use this
An incident takes hours because logs lack a request id and the tenant, and the one useful line is a free-form string nobody can query.
Prerequisites
- Node.js 22 with pino 9
- A test runner such as node:test or Vitest
- A request handler that accepts an injected logger
Steps
1. Create a test logger that writes to an in-memory stream and redacts secrets.
import pino from 'pino';
import { Writable } from 'node:stream';
export function captureLogs() {
const lines = [];
const stream = new Writable({
write(chunk, _enc, cb) {
lines.push(JSON.parse(chunk.toString()));
cb();
},
});
const logger = pino(
{ level: 'info', redact: ['req.headers.authorization', 'user.email'] },
stream,
);
return { logger, lines };
}
Expected output: The test gets a logger whose output can be inspected as objects, with authorization headers redacted.
2. Emit one request log with stable field names instead of interpolated prose.
logger.info({
requestId,
tenantId,
route: req.route.path,
status: res.statusCode,
durationMs,
}, 'request completed');
Expected output: One JSON line per request containing requestId, tenantId, route, status, and durationMs.
3. Assert the fields the incident response depends on, not the message wording.
const entry = lines.find((line) => line.msg === 'request completed');
assert.equal(entry.tenantId, 'tenant-42');
assert.equal(entry.status, 200);
assert.ok(entry.durationMs >= 0);
Expected output: The test fails if a field is renamed, dropped, or accidentally removed by the redaction config.
4. Assert that secrets never reach the captured output.
const serialized = JSON.stringify(lines);
assert.ok(!serialized.includes('Bearer '));
assert.ok(!serialized.includes('[email protected]'));
Expected output: No token or email appears anywhere in the captured logs, including nested objects.
5. Add one test for the failure path with the same required fields.
await request('/api/orders', { method: 'POST', body: { quantity: -1 } });
const failure = lines.find((line) => line.status === 422);
assert.ok(failure.requestId);
assert.equal(failure.errorCode, 'validation_failed');
Expected output: Rejected requests log status, errorCode, and requestId, so support can trace a failed submission.
Troubleshooting
Problem
Captured logs interleave with the application's global logger
Solution
Inject the logger into handlers instead of importing a singleton, and never monkey-patch console for assertions.
Problem
Assertions break whenever the message wording changes
Solution
Treat msg as a stable event name or add a dedicated event field. Assert structured values, never prose.
Problem
The redaction test passes but production logs still leak
Solution
Redaction paths must match the real object shape. Test nested fields and arrays, and check serializer output rather than the input.
Limitations
- Capturing logs in a test says nothing about aggregation, retention, or indexing in the logging backend.
- Assertions depend on a stable log schema; version the contract when fields change.
- Synchronous in-memory streams hide backpressure and serialization cost that appear under load.
Logs are an interface
During an incident, logs are the primary interface between the system and the responder. If they are free-form strings, the responder greps for fragments and hopes. If they are structured, they can filter by tenantId, requestId, and status in seconds. That structure is a contract, and like any contract it needs a test: a field rename or a dropped context is a breaking change for everyone who debugs the service.
Inject the logger
A module-level singleton is convenient and untestable: every test shares it, and capturing output means patching globals. Pass the logger through the request context or constructor instead. Tests then create a logger bound to an in-memory destination, and production wires the real destination. The handler code is identical in both cases, which is what makes the test meaningful.
logger.info({ requestId, tenantId, route, status, durationMs }, 'request completed');Assert fields, not sentences
Message text changes constantly and adds no debugging value. Assert the event name (or a dedicated event field), then assert the structured values: status code, route template, tenant, duration presence. Route templates matter more than raw URLs, because raw URLs create unbounded cardinality in log indexes and leak identifiers.
Test redaction explicitly
Redaction is easy to configure and easy to break when an object shape changes. Assert that tokens, cookies, and emails never appear in the serialized output, including nested objects and arrays. Use realistic values in the test so a partial match is visible, and keep the redaction list next to the logger factory so it is reviewed with the schema.
Cover the failure path
Happy-path logs are rarely the ones needed at 2 a.m. A rejected request should log the validation error code, the request id, and the tenant, without logging the raw payload. Add a test for one failure path, and assert that sensitive fields from the body do not appear. That single test prevents both “no context” and “leaked password” incidents, which are the two ways logging causes problems.