Skip to content

feat: route all logging through a structured pino logger - #402

Merged
Miracle656 merged 2 commits into
Divinity-Labs:mainfrom
aliyuHabibu:feat/structured-logging
Oct 18, 2026
Merged

Miracle656 merged 2 commits into
Divinity-Labs:mainfrom
aliyuHabibu:feat/structured-logging

Conversation

@aliyuHabibu

Copy link
Copy Markdown
Contributor

Every module now logs through a component-scoped pino child (ingester:sdex, job:aggregate-refresh, ws:fanout, redis, config, webhook, route:price, startup) instead of console.*, emitted as a structured component field rather than a message prefix. Fastify's request logger is built from the same options so req.log is scrubbed and formatted identically.

The level is configurable via LOG_LEVEL (default info, documented in .env.example): NDJSON when NODE_ENV=production, human-readable otherwise. Values of secret-looking env vars (DATABASE_URL, DIRECT_DATABASE_URL, REDIS_URL, and any name containing KEY/SECRET/TOKEN/PASSWORD) are scrubbed from every serialized line, including the password inside a connection string and driver error messages that echo it, while auth headers are redacted via pino redact.

Adds a test asserting no console.* survives in non-test source and that a connection string or API key value never reaches the output.

Summary

Type of change

  • Bug fix
  • New feature
  • Refactor
  • Docs
  • Tests
  • CI / tooling

Checklist

  • I have read CONTRIBUTING.md
  • npx tsc --noEmit passes
  • npm run build passes
  • I added / updated tests where relevant
  • I updated docs where relevant

Close #332

Every module now logs through a component-scoped pino child
(ingester:sdex, job:aggregate-refresh, ws:fanout, redis, config,
webhook, route:price, startup) instead of console.*, emitted as a
structured `component` field rather than a message prefix. Fastify's
request logger is built from the same options so req.log is scrubbed
and formatted identically.

The level is configurable via LOG_LEVEL (default info, documented in
.env.example): NDJSON when NODE_ENV=production, human-readable
otherwise. Values of secret-looking env vars (DATABASE_URL,
DIRECT_DATABASE_URL, REDIS_URL, and any name containing
KEY/SECRET/TOKEN/PASSWORD) are scrubbed from every serialized line,
including the password inside a connection string and driver error
messages that echo it, while auth headers are redacted via pino redact.

Adds a test asserting no console.* survives in non-test source and that
a connection string or API key value never reaches the output.
@drips-wave

drips-wave Bot commented Oct 17, 2026

Copy link
Copy Markdown

@aliyuHabibu Great news! 🎉 Based on an automated assessment of this PR, the linked Wave issue(s) no longer count against your application limits.

You can now already apply to more issues while waiting for a review of this PR. Keep up the great work! 🚀

Learn more about application limits

@Miracle656

Copy link
Copy Markdown
Collaborator

This is the one I want for #278 — pino rather than a hand-rolled wrapper, component children instead of message prefixes, a configurable LOG_LEVEL, scrubbing, and Fastify's request logger built from the same options so req.log and application logs match. That last detail is the one most implementations skip and then wonder why half the output looks different.

It conflicts now — main has moved six times this morning (#379, #380, #382, #392, #401, #310). Please rebase and I will review it properly straight away; it is next in my queue.

Heads-up on sequencing: #397 independently added a src/logging.ts with a logEvent() helper over console.*, and docs/logging.md documenting it. I have asked that author to rebase onto yours and re-express their field set as pino calls, since yours is what the issue asked for. Their fields for ingestion failures — venue, network, pair, attempt, retryMs, durationMs — are genuinely good and worth keeping when they come across, so expect a small follow-up on top of this rather than a competing change.

@Miracle656

Copy link
Copy Markdown
Collaborator

Needs a rebase — main moved six times this morning (#379, #380, #382, #392, #401, #310 all landed) and this now conflicts. Push a rebase and I will pick it up; nothing is queued ahead of it.

@aliyuHabibu

Copy link
Copy Markdown
Contributor Author

@Miracle656 Please review again. Thank you

@Miracle656 Miracle656 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the best-engineered PR I have reviewed in this repo. It does what #278 asked and then solves the problem that issue was really about.

The scrubbing is the part that matters. Not just redacting known header names, but collecting every secret-looking value out of the environment and removing it from serialized output — and specifically including the password pulled out of a connection-string URL:

including the password embedded in a connection-string URL so that driver error messages (which often echo only the credentials) are covered too

That is the exact shape of the incident this service already had: a raw pg error echoed a Postgres connection string out of /price/twap, live for about three months. A redaction list keyed on field names would not have caught it, because the secret was inside an error message, not in a field. This would.

MIN_SECRET_LENGTH is the detail that tells me you ran it. Without it REQUIRE_API_KEY=true matches SECRET_NAME_RE, and every true in every log line gets clobbered — a scrubber that quietly corrupts ordinary output is worse than none, and it is the kind of bug you only find by looking at real logs.

Two tests are worth more than the rest put together:

leaves no console.* calls in non-test source
never passes a raw connection-string env value into a log call

Those are lint rules wearing test clothing. Without them this fix decays the first time someone adds a quick console.log while debugging, and the 65 calls come back one at a time over six months. With them, it cannot.

Also right: logger.ts does not import config.ts — config imports the logger, so it reads process.env directly, and the comment says why rather than leaving the next person to rediscover the cycle. And Fastify's request logger is built from the same options, so req.log and module logs are formatted and scrubbed identically, which is the step most implementations skip.

Merging. @jamal-exe — #397 can rebase onto this now; your ingestion field set (venue, network, pair, attempt, retryMs, durationMs) is the good part and should come across as pino calls on an ingester:* child.

@Miracle656
Miracle656 merged commit 3cdb4bd into Divinity-Labs:main Oct 18, 2026
1 check passed
Miracle656 added a commit that referenced this pull request Oct 18, 2026
main went red on the guard #402 added:

    × leaves no console.* calls in non-test source
    expected [ 'src/index.ts:154', …(9) ] to deeply equal []

My doing. #252 (price_points partitioning) was branched before #402
replaced every console.* call with a component-scoped pino logger, so
merging it reintroduced ten of them — six in src/index.ts, four in
src/jobs/pricePointsPartitionJob.ts.

That guard is a lint rule wearing test clothing, and it caught exactly
what it was written to catch: the calls do not come back all at once,
they come back one merged branch at a time.

Converted to `createLogger('startup')` and a new
`createLogger('job:price-points-partition')` child, passing `err` as a
field so pino serialises the stack rather than interpolating a message
string.

logger.test.ts: 9 passed. Suite: 679 passed, tsc clean. The remaining
local failure on graphqlSchemaDrift is CRLF in my working copy — the
committed blob is LF and CI passes it.

Claude-Session: https://claude.ai/code/session_01USgemLt4Rnz4SGB1Srf3GB
This was referenced Oct 18, 2026
Miracle656 added a commit to Ugasutun/Lens that referenced this pull request Oct 18, 2026
Two gates now sit side by side in the MCP server and they are deliberately
separate:

  ERR_URL_BLOCKED       the target resolves somewhere we will never fetch —
                        private, loopback, link-local, metadata (Divinity-Labs#488/Divinity-Labs#407)
  ERR_HOST_NOT_ALLOWED  the host is reachable, but is not on the operator's
                        paid_call allow-list (Divinity-Labs#487/Divinity-Labs#404)

Both codes kept rather than one replacing the other: "I cannot reach there"
and "I will not pay there" are different answers and an agent should be able
to tell them apart.

The constructor keeps both initialisations, on main's `config_` parameter
name — it was renamed there to stop it shadowing the imported `config`.

Also exempts src/mcp/ from the console guard added in Divinity-Labs#402. The MCP server
speaks its protocol over stdout via StdioServerTransport, and pino's default
destination is stdout — routing these diagnostics through the logger would
interleave log lines with protocol frames and break every client parsing
them. stderr is the only stream it may write to, so console.error is correct
there. The exemption pattern accepts both path separators; a forward-slash
pattern matches nothing on Windows.

mcp.test.ts, mcp-paid-call-allowlist.test.ts, ssrf.test.ts: 41 passed.
Suite: 772 passed. The two local reds are CRLF in my working copy and a
mercurius 16.12 node_modules ahead of the lockfile, neither of them real.

Claude-Session: https://claude.ai/code/session_01USgemLt4Rnz4SGB1Srf3GB
jamal-exe added a commit to jamal-exe/Lens that referenced this pull request Oct 24, 2026
Resolve the logging conflict in favour of main's pino logger (Divinity-Labs#402):
venue ingestion failures now go through the ingester:<venue> child
logger with venue, network, pair, attempt, retryMs, durationMs and err
as fields, replacing the hand-rolled logEvent helper. src/logging.ts is
removed and docs/logging.md now documents the pino convention.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Sixty-five console calls and no structured logger

2 participants