n1watch

README

n1watch

A tiny process that watches a PostgreSQL log and flags a potential N+1 query — the same query shape executed many times in a short burst within a single DB session. Zero dependencies (Go stdlib only).

Works with any PostgreSQL 14+ instance that has csvlog enabled. It's aimed at apps backed by a connection pool — one connection checked out per request — where a burst of the same query shape on a single DB session is almost always an N+1 inside one request. Use it two ways:

• live, while developing — tail the log and get an alert the instant a request fires an N+1;
• report, in CI — batch-scan the logs and fail the build on new hot spots (CI mode).

If your app stamps request context into a leading SQL comment (sqlcommenter-style key='value' pairs), n1watch attributes each hot spot back to it — controller, endpoint, even the triggering test (see Tracing an N+1 back to its request).

How it works

n1watch runs in two modes over the same detection core — live (tail the log and alert as N+1s happen) and report (batch-scan the logs for CI, see CI mode):

flowchart TD
    LOG[("PostgreSQL csvlog")]

    subgraph CORE["detection core (shared by both modes)"]
        direction TB
        A["extract SQL from each log record"] --> B["strip leading /* origin */ comment:<br/>controller, method, request_id …"]
        B --> C["fingerprint: 1 / 999 / $1 → ?,<br/>IN (list) → IN (?)"]
        C --> D["group per DB session + request<br/>(bounded by an idle gap, or when the origin changes)"]
        D --> E{"≥ threshold identical<br/>queries in one request?"}
    end

    LOG -->|"live: tail the newest file"| A
    LOG -->|"report: scan all files, replayed over log timestamps"| A

    E -->|"live mode"| ALERT["⚠ alert immediately<br/>console + desktop notification"]
    E -->|"report mode"| AGG["aggregate hot spots<br/>per (origin, query)"]
    AGG --> REP["render md / json / html report<br/>(exit 1 with -fail, for CI gating)"]

• Source: Postgres csvlog. (jsonlog is PG15+)
• Fingerprint: literals, string constants, $N params and IN (...) lists are collapsed, so where id = 1, where id = 999 and where id = $1 all match — while the batched fix where id IN (?) does not, so fixing an N+1 silences it.
• Per request, not per window: queries are grouped into requests — a burst of activity on one session (pooled connection), bounded by an idle gap and split when the stamped request origin changes. When a request ends, n1watch emits one alert per fingerprint that hit the threshold, with counts for that request — never summed across calls. Each alert also shows the request's total query count for context.
• Noise control: transaction/session control (BEGIN/COMMIT/SET/...), SELECT 1 health checks, and startup/infrastructure traffic (Flyway flyway_schema_history, pg_catalog/pg_namespace/information_schema introspection, set_config, version()) are ignored for the N+1 count (they still count toward the request total). Add your own patterns with -ignore.

Tracing an N+1 back to its request

Postgres only sees SQL — not your app's stack or the HTTP request. To bridge that, have your app stamp request context into a leading SQL comment as key='value' pairs (Google sqlcommenter style). n1watch is app-agnostic: any framework/language that does this works. DHIS2 has it built in (PR #22994) — enable it in dhis.conf:

monitoring.sql.context = on
monitoring.sql.context.keys = controller,method,requestId,sessionId

Each request-driven query is then prefixed, e.g. /* controller='DataSetController',method='getObjectList' */ select .... n1watch extracts it into an origin line in the alert (and strips it before fingerprinting, so grouping still works):

⚠  Possible N+1  ·  42 queries  ·  session 6a5a0a90.15b  ·  57 total queries in request
   origin : controller='DataSetController', method='getObjectList'
   query  : select sections0_.datasetid ... where sections0_.datasetid = $1

Note: the comment is only added when request context is present. Boot-time / cache-warming queries have no origin — if an N+1 shows no origin line even with this enabled, it isn't request-driven.

Reproduce handle: tie a hot spot to a specific request (-group-keys / -trace-key)

In report mode you usually want to group by the stable part of the origin (e.g. the endpoint) but still see a concrete request to reproduce. Two app-agnostic flags do this by naming origin-comment keys:

• -group-keys — keys that define a hot spot's identity (report grouping).
• -trace-key — a volatile key sampled from the worst burst as a reproduce handle (shown as a Reproduce column in markdown and in the HTML summary table, a reproduce: line on each HTML finding, and a trace field in JSON).

./n1watch -report -dir pglog -group-keys controller,method -trace-key request_id

Without these, hot spots group by the whole comment — so if a per-request key like request_id is present, every request becomes its own row. -group-keys collapses those back to one row per endpoint while -trace-key keeps a pointer to the exact offender:

| # | Worst burst | Requests | Origin | Reproduce | Query |
|--:|--:|--:|---|---|---|
| 1 | 42 | 3 | controller='DataSetMetadataController', method='getMetadata' | getMetadata_dsm_017 | `select …` |

Naming the request (or the test) that caused it. DHIS2's request_id is populated only from the inbound X-Request-ID header (RequestIdFilter; sanitized to [-_a-zA-Z0-9]{1,36}, else (illegal)) — it is never generated server-side. So a client can put its own identifier there and it flows straight into the report. For an E2E suite, send a per-test slug, e.g. X-Request-ID: = class initials + truncated method name (DataSetMetadataTest.shouldGetMetadata → DSMT_shouldGetMetadata, ≤36 chars). Then each hot spot's Reproduce value names the test that triggered it. (Any app can do the same with whatever per-request key it emits; request_id is just DHIS2's.)

Restoring full names with -trace-map. The 36-char limit forces short, abbreviated slugs. If the producer also emits a JSON file mapping each slug to its full name, pass it via -trace-map and the report shows the readable name (falling back to the raw slug when a value isn't in the map):

{ "DSMT_shouldGetMetadata": "DataSetMetadataTest#shouldGetMetadata" }

The DHIS2 e2e suite writes exactly this to target/request-id-map.json during a run, so:

./n1watch -report -dir pglog \
  -group-keys controller,method -trace-key request_id \
  -trace-map dhis-2/dhis-test-e2e/target/request-id-map.json

Setup

1. Enable statement logging — append postgresql.conf.snippet to your postgresql.conf (find it with psql -c 'SHOW config_file;'), then restart Postgres:

# whichever matches your setup:
pg_ctl -D "$PGDATA" restart            # standard Postgres
brew services restart postgresql@14    # macOS (Homebrew)
sudo systemctl restart postgresql      # Linux (systemd)

2. Build:

git clone https://github.com/david-mackessy/n1watch.git
cd n1watch
go build -o n1watch .

3. Run (foreground, to try it out):

./n1watch

Exercise a DHIS2 endpoint you suspect, and watch for alerts like:

──────────────────────────────────────────────────────────────────────────
⚠  Possible N+1  ·  187 queries  ·  session 61b2abcd.1a  ·  203 total queries in request
   origin : controller='DataElementController', method='getObjectList'
   query  : select ... from dataelement where categorycomboid = $1
   args   : $1 = '12345'
──────────────────────────────────────────────────────────────────────────

Run it as a background agent (auto-start, notifications)

Edit the /ABSOLUTE/PATH/TO/n1watch placeholder in n1watch.plist first, then:

cp n1watch.plist ~/Library/LaunchAgents/
launchctl load ~/Library/LaunchAgents/n1watch.plist   # start
launchctl unload ~/Library/LaunchAgents/n1watch.plist # stop

Alert history is appended to /tmp/n1watch.log; live notifications pop up via macOS Notification Center.

Better notifications: brew install terminal-notifier. Without it, n1watch falls back to osascript, whose notifications are attributed to Script Editor (so clicking "Show" opens Script Editor). With terminal-notifier, clicking activates Terminal instead, and alerts coalesce rather than stack. Either way the full multi-line alert is in the console / /tmp/n1watch.log — the notification is just a short ping (count + origin).

Platforms

The detector is pure Go (stdlib only) and runs on macOS, Linux, and Windows. Build locally with go build -o n1watch ., or cross-compile, e.g.:

GOOS=linux GOARCH=amd64 go build -o n1watch-linux .

OS	Default -dir	Typical Postgres log path	Notifications
macOS	/opt/homebrew/var/postgresql@14/log	Homebrew data dir	terminal-notifier, else osascript
Linux	/var/lib/postgresql/data/log	Docker / data dir (Debian: /var/lib/postgresql/<ver>/main/log)	notify-send (libnotify)
Windows	(none — pass -dir)	C:\Program Files\PostgreSQL\<ver>\data\log	BurntToast module (best-effort)

Notifications are best-effort: if the backend isn't installed it's a silent no-op — the console output and -report work identically on every OS. On headless servers run with -notify=false and rely on the report.

Running as a service

• macOS — the included n1watch.plist (launchd); see above.
• Linux — a systemd user service:

  # ~/.config/systemd/user/n1watch.service
  [Unit]
  Description=n1watch N+1 detector
  [Service]
  ExecStart=/usr/local/bin/n1watch -dir /var/lib/postgresql/data/log
  Restart=always
  [Install]
  WantedBy=default.target
  

  systemctl --user enable --now n1watch. Desktop toasts need a graphical session; on a headless box use -notify=false.
• Windows — run in a terminal, or register with Task Scheduler ("At log on", n1watch.exe -dir "C:\Program Files\PostgreSQL\16\data\log"). For toasts: Install-Module BurntToast.

CI mode — one-shot report

-report scans a whole csvlog (start to finish, over the log's own timestamps), groups it into per-request clusters, aggregates every N+1 hot spot per (origin, query), writes a markdown report, and exits non-zero (with -fail) if anything was found:

./n1watch -report -dir pglog -threshold 15 -idle 1s -out n1report.md -fail

Output:

# N+1 Query Report

_Generated in 1.24s._

⚠️ **1** potential N+1 hot spot(s) — threshold ≥15 identical queries in one request, 1 file(s) scanned.

| # | Worst burst | Requests | Origin | Query |
|--:|--:|--:|---|---|
| 1 | 42 | 3 | controller='DataSetMetadataController', method='getMetadata' | `select …(19 cols)… from categoryoption… where …=$1` |

("Worst burst" = most identical queries in a single request; "Requests" = how many requests hit this N+1.)

The whole run is timed from program start to finish. That duration is printed on the console (… N hot spot(s) in 1.24s -> n1report.md) and stamped into the report itself — the _Generated in …_ line above, the · generated in … note in the HTML subtitle, and an elapsedMs field in JSON.

Best target: the E2E job — real HTTP requests give real origin (controller/method), and you avoid false positives from integration-test setup loops.

Output formats (-format)

Same findings, three renderers:

• md (default) — GitHub-flavoured Markdown; drop into $GITHUB_STEP_SUMMARY.
• html — a self-contained, styled page: a topline summary table of real endpoints (controller · method · highest count · alerts), then auto-collapsed Critical / Medium sections that drill down by controller → alert. Queries with no request context (startup/preheat) are excluded from the endpoint count but still listed under a "(no request context)" group. Follows your OS light/dark theme with a manual toggle to override; no external assets — open it straight from a CI run.
• json — machine-readable; diff it build-over-build, feed a dashboard, or query with jq.

./n1watch -report -dir pglog -threshold 15 -format html -out n1report.html
./n1watch -report -dir pglog -threshold 15 -format json -out n1report.json

All output is HTML/JSON-escaped, so SQL containing <, ', = is safe to render.

Performance

Report mode streams each log file through a single pass — memory stays roughly constant regardless of file size, not proportional to it. In testing it scans a ~130 MB csvlog and writes the HTML report in about 2 s. The run is timed end to end; the duration is printed to the console and stamped into the report itself.

Tuning

Flag	Default	Meaning
-dir	/opt/homebrew/var/postgresql@14/log	csvlog directory
-pattern	*.csv	csvlog filename glob
-idle	1s	gap of no queries that ends a request on a connection
-threshold	15	identical queries in one request that trigger an alert
-notify	true	send a desktop notification (set -notify=false for stdout only)
-ignore	""	extra comma-separated substrings to ignore, e.g. -ignore "audit_log,sequence_"
-report	false	batch mode: scan the whole log, emit a report, then exit
-format	md	report mode output: md | json | html
-out	""	report mode: write the report to a file instead of stdout
-group-keys	""	report mode: origin-comment keys to group hot spots by, e.g. controller,method (empty = whole comment)
-trace-key	""	report mode: origin-comment key sampled as a reproduce handle, e.g. request_id
-trace-map	""	report mode: JSON file mapping trace values to human labels (e.g. slug → ClassName#method)
-trace-tags	""	report mode (html): alphanumeric substrings that become show/hide checkboxes over the summary, e.g. setup,teardown
-fail	false	report mode: exit 1 if any hot spots are found (build gating)

Lots of false positives? Raise -threshold. Seeing one request split into several alerts (e.g. it pauses mid-way)? Raise -idle. Distinct back-to-back calls merging into one? Lower -idle, or enable requestId in monitoring.sql.context.keys so n1watch splits on it.

Caveats

• log_statement = 'all' is dev-only — verbose and adds overhead. Don't pair it with log_min_duration_statement/log_duration, which add SQL-less parse/bind duration: lines (~50% of log volume) that n1watch discards.
• Fingerprinting is heuristic, not a real SQL parser; it's tuned for catching repeated parameterized lookups, which is the common Hibernate N+1.

License

Released into the public domain under The Unlicense — do anything you want with it.

Documentation

Overview

n1watch — a tiny background process that tails a PostgreSQL csvlog and alerts when it sees a potential N+1 query: the same query shape executed many times in a short burst within a single DB session.

Data source: PostgreSQL csvlog (see postgresql.conf.snippet). csvlog is used instead of jsonlog because the target instance is PG14 (jsonlog is PG15+). The watcher does its own lightweight SQL fingerprinting since PG14's csvlog has no query_id column.

Grouping: per (session_id, query-fingerprint). With HikariCP a connection is checked out per request, so a burst on one session ~= an N+1 within one request.