From abd6057d5d5582106cd3b228d10cd1686feab130 Mon Sep 17 00:00:00 2001
From: mrramam <mrramam@ram.ac>
Date: Tue, 15 Sep 2026 12:18:05 -0700
Subject: [PATCH 1/2] feat(server): add LOG_LEVEL, and stop echoing every SQL
 statement by default

The database connection was opened with `{ verbose: console.log }`
unconditionally, so every statement the process executed was printed. On a
production Pi that measured ~6,700 statements/hour and 32MB of journal per 12
hours, enough to roll a 1GB cap in about two days.

It is also a disclosure. better-sqlite3's `verbose` hook receives the expanded
SQL with bound parameters inlined, and the calendar cache insert binds
`JSON.stringify(event.raw)` -- the unmodified upstream event. So event titles,
locations, attendees, organiser addresses and descriptions all reached the log.
Parameterised statements do not protect it.

There was no way to turn this down: no LOG_LEVEL existed, and the hook writes
to stdout through console.log without passing Fastify's logger, so a Fastify
level could not have suppressed it either.

Add LOG_LEVEL using pino's own vocabulary, since Fastify's logger is pino:
trace, debug, info, warn, error, fatal, silent. SQL tracing moves to debug --
the only level at which that volume is reasonable -- and the hook is attached
only when the level would emit it, because passing `verbose` at all makes the
driver expand every statement whether or not anything consumes the result.

Default to warn rather than pino's info. HomeGlow runs unattended on a display
whose kiosk polls continuously; a log nobody reads daily is most useful holding
things that describe a problem. Calendar sync now logs at levels that respect
that: per-cycle chatter at debug, a per-source summary at info, a missing or
disabled source at warn, and failures at error -- so a sync that breaks is
still visible at the default, where previously it was buried under ten lines a
second of SQL.

Also remove the preHandler hook that printed "Incoming request" per request.
Fastify's logger already emits incoming and completed lines with request id,
status and duration, and obeys LOG_LEVEL; the hook was a second, poorer copy no
level could switch off. Boot plus 40 requests goes from 48 log lines to 7.

An unparseable LOG_LEVEL falls back to warn and says so at warn, so a
misspelling is distinguishable from a value that worked.
---
 docs/reference/configuration.md |   1 +
 server/index.js                 |  43 ++++++++++---
 server/services/calendarSync.js |  36 +++++++----
 server/tests/logLevel.test.js   | 107 ++++++++++++++++++++++++++++++++
 server/utils/logLevel.js        |  54 ++++++++++++++++
 5 files changed, 220 insertions(+), 21 deletions(-)
 create mode 100644 server/tests/logLevel.test.js
 create mode 100644 server/utils/logLevel.js

diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md
index 9839c8f..e01ae21 100644
--- a/docs/reference/configuration.md
+++ b/docs/reference/configuration.md
@@ -14,6 +14,7 @@ database). This page covers both.
 | `DB_PATH` | `server/data/tasks.db` | Override the SQLite file location. |
 | `ENCRYPTION_KEY` | _auto-generated_ | **Optional.** Key used to encrypt stored third-party credentials. If unset, one is generated on first start — see below. Set it only to supply your own key or share one across instances; must decode to 32 bytes (`openssl rand -base64 32`). Changing it after credentials are stored invalidates them. |
 | `NODE_ENV` | — | `production` / `development`. |
+| `LOG_LEVEL` | `warn` | Logging verbosity, using pino's standard levels: `trace`, `debug`, `info`, `warn`, `error`, `fatal`, `silent`. `info` adds a line per HTTP request and a per-source calendar sync summary. **`debug` and `trace` additionally echo every SQL statement**, with bound values expanded — high volume, and calendar titles, locations and raw event payloads end up in the log. Use them for local debugging, not on a family display. |
 | `HOMEGLOW_DISABLE_BACKGROUND_JOBS` | `0` | Set to `1` to disable the nightly chore-pruning cron (useful in tests). |
 | `HOMEGLOW_DISABLE_CALENDAR_SYNC` | `0` | Set to `1` to disable the calendar sync service. |
 | `DEMO_MODE` | `false` | Set to `true` to run a **public demo instance**: in-memory DB (wiped on stop), admin PIN disabled, sample data seeded and reset every 6h (incl. live demo calendar feeds and a static weather snapshot), and abuse-prone routes (uploads, CORS proxy, OAuth, calendar source management) return 403 — calendar sync only ever fetches the seeded demo feeds. See the [Demo Mode](../guides/demo-mode.md) guide. |
diff --git a/server/index.js b/server/index.js
index 3bfbd05..8dad03b 100644
--- a/server/index.js
+++ b/server/index.js
@@ -20,7 +20,23 @@ const demoBlocked = (reply) => {
 };
 process.env.TZ = APP_TIMEZONE;
 
-const fastify = require('fastify')({ logger: true });
+const { resolveLogLevel, isSqlTraceEnabled } = require('./utils/logLevel');
+
+// Resolved before the logger exists, so a rejected value is reported through
+// console once the logger is up rather than vanishing.
+const LOG_LEVEL_RESULT = resolveLogLevel(process.env.LOG_LEVEL);
+const LOG_LEVEL = LOG_LEVEL_RESULT.level;
+
+const fastify = require('fastify')({ logger: { level: LOG_LEVEL } });
+
+if (LOG_LEVEL_RESULT.source === 'invalid') {
+  // Deliberately at warn: it survives the default level. An operator who
+  // mistyped LOG_LEVEL is precisely the person who will not see an info line.
+  fastify.log.warn(
+    `LOG_LEVEL="${LOG_LEVEL_RESULT.rejected}" is not a log level; using "${LOG_LEVEL}". ` +
+    'Valid: trace, debug, info, warn, error, fatal, silent.'
+  );
+}
 const Database = require('better-sqlite3');
 const ical = require('ical-generator');
 const node_ical = require('node-ical');
@@ -504,11 +520,13 @@ fastify.register(multipart, {
   },
 });
 
-// Add a preHandler hook to log all incoming requests
-fastify.addHook('preHandler', (request, reply, done) => {
-  console.log(`Incoming request: ${request.method} ${request.url}`);
-  done();
-});
+// Request logging is Fastify's own, not a hook of ours. Its logger already
+// emits an "incoming request" and a "request completed" line per request, with
+// the request id, status and duration attached -- and, unlike a console.log in
+// a preHandler, it obeys LOG_LEVEL. The hook that used to live here printed a
+// second, poorer copy that no level could switch off, which on a wall display
+// polling continuously is a steady leak into the journal for no added
+// information. Set LOG_LEVEL=info to see requests.
 
 // Serve static files for uploads.
 //
@@ -1832,7 +1850,14 @@ async function ConnectOrCreateDb() {
       await fs.chmod(path.dirname(dbPath), 0o777);
     }
 
-    const newDb = new Database(dbPath, { verbose: console.log });
+    // Statement tracing is attached only when the level would emit it. Passing
+    // `verbose` at all makes better-sqlite3 expand every statement's bound
+    // parameters into a string, so leaving it on and filtering downstream would
+    // still pay the cost -- and still put calendar titles, locations and the
+    // whole raw upstream payload into the log on the way past.
+    const newDb = isSqlTraceEnabled(LOG_LEVEL)
+      ? new Database(dbPath, { verbose: (sql) => fastify.log.debug({ sql }, 'sqlite statement') })
+      : new Database(dbPath);
     newDb.pragma('foreign_keys = ON');
     // WAL lets readers proceed while a writer is active (better-sqlite3 is still
     // single-threaded, but this avoids POSIX lock stalls across connections).
@@ -6242,7 +6267,7 @@ const start = async () => {
     // fetched (SSRF guard). The seeded "Family Calendar" placeholder
     // (.invalid host) is skipped by the service itself.
     if (DEMO_MODE) {
-      calendarSyncService = new CalendarSyncService(db, decryptPassword);
+      calendarSyncService = new CalendarSyncService(db, decryptPassword, fastify.log);
       if (process.env.HOMEGLOW_DISABLE_CALENDAR_SYNC !== '1') {
         calendarSyncService.initialize();
         console.log('Calendar sync enabled in demo mode (seeded demo feeds only; source management is demo-blocked)');
@@ -6250,7 +6275,7 @@ const start = async () => {
         console.log('Calendar sync jobs disabled in demo mode by HOMEGLOW_DISABLE_CALENDAR_SYNC=1 (cached events only)');
       }
     } else if (process.env.HOMEGLOW_DISABLE_CALENDAR_SYNC !== '1') {
-      calendarSyncService = new CalendarSyncService(db, decryptPassword);
+      calendarSyncService = new CalendarSyncService(db, decryptPassword, fastify.log);
       calendarSyncService.initialize();
       console.log('Calendar sync service started');
     } else {
diff --git a/server/services/calendarSync.js b/server/services/calendarSync.js
index e6adb85..fda53d4 100644
--- a/server/services/calendarSync.js
+++ b/server/services/calendarSync.js
@@ -6,17 +6,29 @@ const googleCalendar = require('./googleCalendar');
 const appleCalDAV = require('./appleCalDAV');
 const { dedupeCalendarEvents } = require('../utils/calendarDedup');
 
+// Falls back to console when no logger is supplied, so the service stays usable
+// standalone (tests construct it directly). `debug` maps to nothing in the
+// fallback: without a level there is no way to honour one, and per-cycle chatter
+// is exactly what must not be printed unconditionally.
+const CONSOLE_LOGGER = {
+  debug: () => { },
+  info: (...args) => console.log(...args),
+  warn: (...args) => console.warn(...args),
+  error: (...args) => console.error(...args),
+};
+
 class CalendarSyncService {
-  constructor(db, decryptPassword) {
+  constructor(db, decryptPassword, logger = CONSOLE_LOGGER) {
     this.db = db;
     this.decryptPassword = decryptPassword;
+    this.log = logger;
     this.syncIntervals = new Map();
     this.isSyncing = new Map();
   }
 
   initialize() {
     this.startAllSyncJobs();
-    console.log('Calendar sync service initialized');
+    this.log.info('Calendar sync service initialized');
   }
 
   normalizeAllDayEnd(end) {
@@ -44,7 +56,7 @@ class CalendarSyncService {
 
   async syncSource(sourceId) {
     if (this.isSyncing.get(sourceId)) {
-      console.log(`Sync already in progress for source ${sourceId}, skipping`);
+      this.log.debug(`Sync already in progress for source ${sourceId}, skipping`);
       return { skipped: true };
     }
 
@@ -53,7 +65,7 @@ class CalendarSyncService {
     try {
       const source = this.db.prepare('SELECT * FROM calendar_sources WHERE id = ? AND enabled = 1').get(sourceId);
       if (!source) {
-        console.log(`Source ${sourceId} not found or disabled`);
+        this.log.warn(`Source ${sourceId} not found or disabled`);
         return { success: false, error: 'Source not found or disabled' };
       }
 
@@ -65,7 +77,7 @@ class CalendarSyncService {
         return { skipped: true };
       }
 
-      console.log(`Starting sync for calendar source: ${source.name} (${source.type})`);
+      this.log.debug(`Starting sync for calendar source: ${source.name} (${source.type})`);
       const startTime = Date.now();
 
       let events = [];
@@ -113,11 +125,11 @@ class CalendarSyncService {
         VALUES (?, datetime('now'), 'success', ?, ?)
       `).run(sourceId, `Synced ${events.length} events in ${duration}ms`, events.length);
 
-      console.log(`Synced ${events.length} events for ${source.name} in ${duration}ms`);
+      this.log.info(`Synced ${events.length} events for ${source.name} in ${duration}ms`);
 
       return { success: true, eventCount: events.length, duration };
     } catch (error) {
-      console.error(`Error syncing calendar source ${sourceId}:`, error.message);
+      this.log.error(`Error syncing calendar source ${sourceId}: ${error.message}`);
 
       this.db.prepare(`
         INSERT OR REPLACE INTO calendar_sync_status (source_id, last_sync_at, last_sync_status, last_sync_message)
@@ -408,7 +420,7 @@ class CalendarSyncService {
     }
 
     if (interval <= 0) {
-      console.log(`Sync disabled for source ${sourceId}`);
+      this.log.info(`Sync disabled for source ${sourceId}`);
       return;
     }
 
@@ -416,12 +428,12 @@ class CalendarSyncService {
 
     const intervalId = setInterval(() => {
       this.syncSource(sourceId).catch(err => {
-        console.error(`Scheduled sync failed for source ${sourceId}:`, err.message);
+        this.log.error(`Scheduled sync failed for source ${sourceId}: ${err.message}`);
       });
     }, intervalMs);
 
     this.syncIntervals.set(sourceId, intervalId);
-    console.log(`Started sync job for source ${sourceId} every ${interval} minutes`);
+    this.log.info(`Started sync job for source ${sourceId} every ${interval} minutes`);
   }
 
   restartSyncJob(sourceId) {
@@ -441,7 +453,7 @@ class CalendarSyncService {
 
     setTimeout(() => {
       this.syncAllSources().catch(err => {
-        console.error('Initial sync failed:', err.message);
+        this.log.error(`Initial sync failed: ${err.message}`);
       });
     }, 5000);
   }
@@ -449,7 +461,7 @@ class CalendarSyncService {
   stopAllSyncJobs() {
     for (const [sourceId, intervalId] of this.syncIntervals) {
       clearInterval(intervalId);
-      console.log(`Stopped sync job for source ${sourceId}`);
+      this.log.info(`Stopped sync job for source ${sourceId}`);
     }
     this.syncIntervals.clear();
   }
diff --git a/server/tests/logLevel.test.js b/server/tests/logLevel.test.js
new file mode 100644
index 0000000..927af5c
--- /dev/null
+++ b/server/tests/logLevel.test.js
@@ -0,0 +1,107 @@
+const test = require('node:test');
+const assert = require('node:assert');
+
+const {
+    LEVELS,
+    DEFAULT_LEVEL,
+    resolveLogLevel,
+    isSqlTraceEnabled,
+} = require('../utils/logLevel');
+
+test('the default is warn, so an unattended install is quiet without configuration', () => {
+    assert.strictEqual(DEFAULT_LEVEL, 'warn');
+
+    for (const unset of [undefined, null, '', '   ']) {
+        const { level, source } = resolveLogLevel(unset);
+        assert.strictEqual(level, 'warn');
+        assert.strictEqual(source, 'default');
+    }
+});
+
+test('every pino level is accepted, case and whitespace insensitively', () => {
+    for (const name of LEVELS) {
+        assert.strictEqual(resolveLogLevel(name).level, name);
+        assert.strictEqual(resolveLogLevel(name.toUpperCase()).level, name);
+        assert.strictEqual(resolveLogLevel(`  ${name}  `).level, name);
+        assert.strictEqual(resolveLogLevel(name).source, 'env');
+    }
+});
+
+test('the vocabulary is pino\'s, not one invented here', () => {
+    assert.deepStrictEqual(LEVELS, ['trace', 'debug', 'info', 'warn', 'error', 'fatal', 'silent']);
+});
+
+test('a value that names no level falls back, and says which value it rejected', () => {
+    // The reason matters more than the fallback: a misspelling that silently
+    // becomes the default looks identical to one that worked.
+    const { level, source, rejected } = resolveLogLevel('verbose');
+    assert.strictEqual(level, 'warn');
+    assert.strictEqual(source, 'invalid');
+    assert.strictEqual(rejected, 'verbose');
+
+    for (const bad of ['DEBUGGING', '1', 'true', 'off', 'none']) {
+        assert.strictEqual(resolveLogLevel(bad).source, 'invalid', `${bad} should not be a level`);
+    }
+});
+
+test('an invalid value is distinguishable from an absent one', () => {
+    // Both land on warn. Only `source` tells the operator whether their
+    // LOG_LEVEL did anything, which is the whole point of reporting it.
+    assert.strictEqual(resolveLogLevel(undefined).level, resolveLogLevel('nonsense').level);
+    assert.notStrictEqual(resolveLogLevel(undefined).source, resolveLogLevel('nonsense').source);
+});
+
+test('SQL tracing is enabled only at debug and trace', () => {
+    assert.strictEqual(isSqlTraceEnabled('debug'), true);
+    assert.strictEqual(isSqlTraceEnabled('trace'), true);
+
+    for (const quiet of ['info', 'warn', 'error', 'fatal', 'silent']) {
+        assert.strictEqual(isSqlTraceEnabled(quiet), false, `${quiet} must not trace SQL`);
+    }
+});
+
+test('the shipped default does not trace SQL', () => {
+    // The regression this whole change exists to prevent: an install that sets
+    // nothing must not echo statements. 32MB per 12h on a Pi, with calendar
+    // contents inlined, came from this being unconditional.
+    assert.strictEqual(isSqlTraceEnabled(resolveLogLevel(undefined).level), false);
+});
+
+// --- the behaviour the level controls, exercised against the real driver ---
+
+const Database = require('better-sqlite3');
+
+function captureStatements(level) {
+    const seen = [];
+    const db = isSqlTraceEnabled(level)
+        ? new Database(':memory:', { verbose: (sql) => seen.push(sql) })
+        : new Database(':memory:');
+
+    db.exec('CREATE TABLE calendar_events_cache (id TEXT PRIMARY KEY, title TEXT, location TEXT)');
+    db.prepare('INSERT OR REPLACE INTO calendar_events_cache (id, title, location) VALUES (?, ?, ?)')
+        .run('evt1', "Dentist - Emma's cleaning", '123 Elm St, Springfield');
+    db.close();
+    return seen;
+}
+
+test('at debug, the driver echoes statements with bound values expanded', () => {
+    // This is the positive control. Without it, the assertions below pass
+    // against a probe that never captured anything, which is not evidence.
+    const seen = captureStatements('debug');
+    assert.ok(seen.length > 0, 'debug must capture statements');
+    assert.ok(
+        seen.some((sql) => sql.includes('Emma') && sql.includes('Elm St')),
+        'better-sqlite3 inlines bound parameters, so the trace carries event contents'
+    );
+});
+
+test('at the shipped default, no statement reaches the log at all', () => {
+    const seen = captureStatements(resolveLogLevel(undefined).level);
+    assert.deepStrictEqual(seen, [], 'default level must attach no verbose hook');
+});
+
+test('no quiet level leaks calendar contents', () => {
+    for (const quiet of ['info', 'warn', 'error', 'fatal', 'silent']) {
+        assert.deepStrictEqual(captureStatements(quiet), [], `${quiet} must not trace`);
+    }
+});
diff --git a/server/utils/logLevel.js b/server/utils/logLevel.js
new file mode 100644
index 0000000..189645e
--- /dev/null
+++ b/server/utils/logLevel.js
@@ -0,0 +1,54 @@
+// Log level, resolved once from the environment.
+//
+// Fastify's logger is pino, so the level vocabulary is already standard and is
+// reused verbatim rather than invented here. `silent` is pino's own name for
+// "log nothing"; it is accepted so an operator can turn the logger off without
+// reaching for a sentinel value.
+//
+// The default is `warn`, not pino's `info`. HomeGlow runs unattended on a wall
+// display whose kiosk polls continuously, and `info` means every HTTP request
+// is journaled forever. `warn` keeps the log to things that describe a problem,
+// which is what a log nobody reads daily is actually for. Turning it up is one
+// environment variable.
+
+const LEVELS = ['trace', 'debug', 'info', 'warn', 'error', 'fatal', 'silent'];
+
+const DEFAULT_LEVEL = 'warn';
+
+/**
+ * The pino level named by `raw`, or the default when it names nothing valid.
+ *
+ * Returns the reason alongside the level so the caller can say out loud that a
+ * value was ignored. A misspelled LOG_LEVEL that silently becomes the default
+ * is indistinguishable from one that worked, which is how someone ends up
+ * debugging production with the logging they thought they had turned on.
+ */
+function resolveLogLevel(raw) {
+    if (raw === undefined || raw === null || String(raw).trim() === '') {
+        return { level: DEFAULT_LEVEL, source: 'default' };
+    }
+
+    const normalized = String(raw).trim().toLowerCase();
+
+    if (LEVELS.includes(normalized)) {
+        return { level: normalized, source: 'env' };
+    }
+
+    return { level: DEFAULT_LEVEL, source: 'invalid', rejected: String(raw).trim() };
+}
+
+/**
+ * Whether SQL statement tracing should be wired up at this level.
+ *
+ * Deliberately a separate decision from "would pino print a debug line". The
+ * trace is better-sqlite3's `verbose` hook, and passing that hook at all makes
+ * the driver expand every statement's bound parameters into a string —
+ * unconditionally, before any level check could discard it. So the hook is
+ * attached only when the level would actually emit it; at `warn` the work is
+ * never done rather than done and thrown away.
+ */
+function isSqlTraceEnabled(level) {
+    return level === 'trace' || level === 'debug';
+}
+
+module.exports = { LEVELS, DEFAULT_LEVEL, resolveLogLevel, isSqlTraceEnabled };

From 4da1626c6969f437419f7f3a4069c05b5946447e Mon Sep 17 00:00:00 2001
From: mrramam <mrramam@ram.ac>
Date: Tue, 15 Sep 2026 14:12:17 -0700
Subject: [PATCH 2/2] feat(server): route console output through the logger,
 and add LOG_FORMAT

LOG_LEVEL governed only the two places that called fastify.log. The other
386 console.* calls in the server -- written by fourteen contributors over a
year, none of whom adopted a logger -- wrote straight to stdout and stderr,
and no level could touch them. At the default, a healthy boot still printed
seven lines and every settings fetch printed a hundred.

Rather than rewrite those sites, honour the decision already made at each
one. Every author chose console.error, .warn or .log; that IS a severity.
Patch the global console so each method routes to fastify.log at the level
of the same name, and every one of those calls obeys LOG_LEVEL at once, with
no diff at the call sites. Dependencies' console output comes along too.

Arguments are flattened with util.format before reaching pino. pino treats
trailing arguments as printf interpolation values and drops them when the
message has no placeholders, so a bare logger.info(msg, obj) would silently
lose obj -- and `console.log('Raw settings:', rows)` would log the label and
nothing else. util.format is what console itself does, so output is
byte-identical to before, now with a level attached.

This is an adoption shim, not an architecture. Migration to explicit logger
calls can proceed file by file, or not at all; the shim covers whatever has
not been converted, and comes out in one place when nothing is left.

Add LOG_FORMAT alongside: `pretty` (default) or `json`. pino's own default is
JSON, and the reversal is deliberate. HomeGlow runs on a Pi under journald,
and the usual reader is a person with journalctl open, not a pipeline.
journald already stamps time, host and pid, so those fields are dropped from
pretty output, and singleLine keeps one journal entry per event -- without
it, pino-pretty renders each object field on its own indented line and a
single request log becomes seven rows.

Consequence, accepted on purpose: at the default level a healthy boot prints
nothing. `Server running on port`, `Calendar sync service started` and
Fastify's own `Server listening` are all info. /api/stats is the health
check. Promoting a banner line to warn to buy comfort would be a lie about
severity.

An invalid LOG_FORMAT falls back to pretty and says so at warn, matching
LOG_LEVEL's behaviour.
---
 docs/reference/configuration.md  |   3 +-
 server/index.js                  |  28 +++++++--
 server/package-lock.json         |  81 +++++++++++++++++++++++-
 server/package.json              |   3 +-
 server/tests/consoleShim.test.js | 105 +++++++++++++++++++++++++++++++
 server/tests/logFormat.test.js   |  46 ++++++++++++++
 server/utils/consoleShim.js      |  60 ++++++++++++++++++
 server/utils/logFormat.js        |  54 ++++++++++++++++
 8 files changed, 372 insertions(+), 8 deletions(-)
 create mode 100644 server/tests/consoleShim.test.js
 create mode 100644 server/tests/logFormat.test.js
 create mode 100644 server/utils/consoleShim.js
 create mode 100644 server/utils/logFormat.js

diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md
index e01ae21..b00726c 100644
--- a/docs/reference/configuration.md
+++ b/docs/reference/configuration.md
@@ -14,7 +14,8 @@ database). This page covers both.
 | `DB_PATH` | `server/data/tasks.db` | Override the SQLite file location. |
 | `ENCRYPTION_KEY` | _auto-generated_ | **Optional.** Key used to encrypt stored third-party credentials. If unset, one is generated on first start — see below. Set it only to supply your own key or share one across instances; must decode to 32 bytes (`openssl rand -base64 32`). Changing it after credentials are stored invalidates them. |
 | `NODE_ENV` | — | `production` / `development`. |
-| `LOG_LEVEL` | `warn` | Logging verbosity, using pino's standard levels: `trace`, `debug`, `info`, `warn`, `error`, `fatal`, `silent`. `info` adds a line per HTTP request and a per-source calendar sync summary. **`debug` and `trace` additionally echo every SQL statement**, with bound values expanded — high volume, and calendar titles, locations and raw event payloads end up in the log. Use them for local debugging, not on a family display. |
+| `LOG_LEVEL` | `warn` | Logging verbosity, using pino's standard levels: `trace`, `debug`, `info`, `warn`, `error`, `fatal`, `silent`. Governs **all** console output from the server — every `console.log`/`warn`/`error` in the code and its dependencies is routed through the logger at the matching level. At the default, a healthy boot prints nothing and only warnings and errors appear; `info` adds startup lines, a line per HTTP request and a per-source calendar sync summary. **`debug` and `trace` additionally echo every SQL statement**, with bound values expanded — high volume, and calendar titles, locations and raw event payloads end up in the log. Use them for local debugging, not on a family display. |
+| `LOG_FORMAT` | `pretty` | `pretty` for human-readable lines (`[2026-09-15 20:29:56] WARN: …`), `json` for one pino JSON object per line. Default is `pretty` because the usual reader is a person with `journalctl` open, and journald already stamps time, host and pid. Use `json` when feeding a log pipeline. |
 | `HOMEGLOW_DISABLE_BACKGROUND_JOBS` | `0` | Set to `1` to disable the nightly chore-pruning cron (useful in tests). |
 | `HOMEGLOW_DISABLE_CALENDAR_SYNC` | `0` | Set to `1` to disable the calendar sync service. |
 | `DEMO_MODE` | `false` | Set to `true` to run a **public demo instance**: in-memory DB (wiped on stop), admin PIN disabled, sample data seeded and reset every 6h (incl. live demo calendar feeds and a static weather snapshot), and abuse-prone routes (uploads, CORS proxy, OAuth, calendar source management) return 403 — calendar sync only ever fetches the seeded demo feeds. See the [Demo Mode](../guides/demo-mode.md) guide. |
diff --git a/server/index.js b/server/index.js
index 8dad03b..a4c89de 100644
--- a/server/index.js
+++ b/server/index.js
@@ -21,22 +21,40 @@ const demoBlocked = (reply) => {
 process.env.TZ = APP_TIMEZONE;
 
 const { resolveLogLevel, isSqlTraceEnabled } = require('./utils/logLevel');
+const { resolveLogFormat, transportFor } = require('./utils/logFormat');
+const { installConsoleShim } = require('./utils/consoleShim');
 
-// Resolved before the logger exists, so a rejected value is reported through
-// console once the logger is up rather than vanishing.
+// Both resolved before the logger exists, so a rejected value can be reported
+// through the logger once it is up rather than vanishing.
 const LOG_LEVEL_RESULT = resolveLogLevel(process.env.LOG_LEVEL);
 const LOG_LEVEL = LOG_LEVEL_RESULT.level;
+const LOG_FORMAT_RESULT = resolveLogFormat(process.env.LOG_FORMAT);
+const LOG_FORMAT = LOG_FORMAT_RESULT.format;
 
-const fastify = require('fastify')({ logger: { level: LOG_LEVEL } });
+const fastify = require('fastify')({
+  logger: { level: LOG_LEVEL, transport: transportFor(LOG_FORMAT) },
+});
+
+// From here on, every console.* call in this process -- this file, the
+// services, and dependencies -- goes through fastify.log at the level matching
+// the method that was called, and therefore obeys LOG_LEVEL. See the note in
+// utils/consoleShim.js for what that means when reading console.error below.
+installConsoleShim(fastify.log);
 
+// Deliberately at warn: it survives the default level. An operator who
+// mistyped one of these is precisely the person who will not see an info line.
 if (LOG_LEVEL_RESULT.source === 'invalid') {
-  // Deliberately at warn: it survives the default level. An operator who
-  // mistyped LOG_LEVEL is precisely the person who will not see an info line.
   fastify.log.warn(
     `LOG_LEVEL="${LOG_LEVEL_RESULT.rejected}" is not a log level; using "${LOG_LEVEL}". ` +
     'Valid: trace, debug, info, warn, error, fatal, silent.'
   );
 }
+if (LOG_FORMAT_RESULT.source === 'invalid') {
+  fastify.log.warn(
+    `LOG_FORMAT="${LOG_FORMAT_RESULT.rejected}" is not a log format; using "${LOG_FORMAT}". ` +
+    'Valid: pretty, json.'
+  );
+}
 const Database = require('better-sqlite3');
 const ical = require('ical-generator');
 const node_ical = require('node-ical');
diff --git a/server/package-lock.json b/server/package-lock.json
index 588672e..2129ab6 100644
--- a/server/package-lock.json
+++ b/server/package-lock.json
@@ -20,7 +20,8 @@
         "ical-generator": "^10.2.0",
         "ical.js": "^2.2.1",
         "node-cron": "^4.6.0",
-        "node-ical": "^0.26.0"
+        "node-ical": "^0.26.0",
+        "pino-pretty": "13.1.3"
       },
       "devDependencies": {
         "c8": "^11.0.0"
@@ -699,6 +700,12 @@
       "dev": true,
       "license": "MIT"
     },
+    "node_modules/colorette": {
+      "version": "2.0.20",
+      "resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz",
+      "integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==",
+      "license": "MIT"
+    },
     "node_modules/combined-stream": {
       "version": "1.0.8",
       "resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz",
@@ -771,6 +778,15 @@
         "node": ">= 8"
       }
     },
+    "node_modules/dateformat": {
+      "version": "4.6.3",
+      "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz",
+      "integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==",
+      "license": "MIT",
+      "engines": {
+        "node": "*"
+      }
+    },
     "node_modules/debug": {
       "version": "4.4.3",
       "resolved": "https://registry.npmjs.org/debug/-/debug-4.4.3.tgz",
@@ -960,6 +976,12 @@
         "node": ">=6"
       }
     },
+    "node_modules/fast-copy": {
+      "version": "4.1.1",
+      "resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.1.1.tgz",
+      "integrity": "sha512-A4QTJmuiztpGtr6AMeJts9R4hbj2ZBUwtOaKrG6rw2y7t6+IaJKjz5M3XDs8BUznxDH43FVc6A0y/gWlMl4UtA==",
+      "license": "MIT"
+    },
     "node_modules/fast-decode-uri-component": {
       "version": "1.0.1",
       "resolved": "https://registry.npmjs.org/fast-decode-uri-component/-/fast-decode-uri-component-1.0.1.tgz",
@@ -1005,6 +1027,12 @@
         "fast-decode-uri-component": "^1.0.1"
       }
     },
+    "node_modules/fast-safe-stringify": {
+      "version": "2.1.1",
+      "resolved": "https://registry.npmjs.org/fast-safe-stringify/-/fast-safe-stringify-2.1.1.tgz",
+      "integrity": "sha512-W+KJc2dmILlPplD/H4K9l9LcAHAfPtP6BY84uVLXQ6Evcz9Lcg33Y2z1IVblT6xdY54PXYVHEv+0Wpq8Io6zkA==",
+      "license": "MIT"
+    },
     "node_modules/fast-uri": {
       "version": "3.1.3",
       "resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.3.tgz",
@@ -1378,6 +1406,12 @@
         "node": ">= 0.4"
       }
     },
+    "node_modules/help-me": {
+      "version": "5.0.0",
+      "resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz",
+      "integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==",
+      "license": "MIT"
+    },
     "node_modules/html-escaper": {
       "version": "2.0.2",
       "resolved": "https://registry.npmjs.org/html-escaper/-/html-escaper-2.0.2.tgz",
@@ -1581,6 +1615,15 @@
         "node": ">=8"
       }
     },
+    "node_modules/joycon": {
+      "version": "3.1.1",
+      "resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz",
+      "integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==",
+      "license": "MIT",
+      "engines": {
+        "node": ">=10"
+      }
+    },
     "node_modules/jsbi": {
       "version": "4.3.2",
       "resolved": "https://registry.npmjs.org/jsbi/-/jsbi-4.3.2.tgz",
@@ -1970,6 +2013,42 @@
         "split2": "^4.0.0"
       }
     },
+    "node_modules/pino-pretty": {
+      "version": "13.1.3",
+      "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.1.3.tgz",
+      "integrity": "sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==",
+      "license": "MIT",
+      "dependencies": {
+        "colorette": "^2.0.7",
+        "dateformat": "^4.6.3",
+        "fast-copy": "^4.0.0",
+        "fast-safe-stringify": "^2.1.1",
+        "help-me": "^5.0.0",
+        "joycon": "^3.1.1",
+        "minimist": "^1.2.6",
+        "on-exit-leak-free": "^2.1.0",
+        "pino-abstract-transport": "^3.0.0",
+        "pump": "^3.0.0",
+        "secure-json-parse": "^4.0.0",
+        "sonic-boom": "^4.0.1",
+        "strip-json-comments": "^5.0.2"
+      },
+      "bin": {
+        "pino-pretty": "bin.js"
+      }
+    },
+    "node_modules/pino-pretty/node_modules/strip-json-comments": {
+      "version": "5.0.3",
+      "resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz",
+      "integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==",
+      "license": "MIT",
+      "engines": {
+        "node": ">=14.16"
+      },
+      "funding": {
+        "url": "https://github.com/sponsors/sindresorhus"
+      }
+    },
     "node_modules/pino-std-serializers": {
       "version": "7.1.0",
       "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz",
diff --git a/server/package.json b/server/package.json
index 6ffc2ac..799557f 100644
--- a/server/package.json
+++ b/server/package.json
@@ -25,6 +25,7 @@
     "ical-generator": "^10.2.0",
     "ical.js": "^2.2.1",
     "node-cron": "^4.6.0",
-    "node-ical": "^0.26.0"
+    "node-ical": "^0.26.0",
+    "pino-pretty": "13.1.3"
   }
 }
diff --git a/server/tests/consoleShim.test.js b/server/tests/consoleShim.test.js
new file mode 100644
index 0000000..eff4aaf
--- /dev/null
+++ b/server/tests/consoleShim.test.js
@@ -0,0 +1,105 @@
+const test = require('node:test');
+const assert = require('node:assert');
+const pino = require('pino');
+
+const { MAPPING, installConsoleShim } = require('../utils/consoleShim');
+
+// A pino instance that writes into an array instead of stdout, so assertions
+// can read what would have been logged.
+function capturingLogger(level) {
+    const lines = [];
+    const logger = pino({ level }, { write: (s) => lines.push(JSON.parse(s)) });
+    return { logger, lines };
+}
+
+// Patch a private object rather than the real global console, so a failing
+// assertion in here can still print itself.
+function fakeConsole() {
+    return { log() { }, info() { }, debug() { }, warn() { }, error() { } };
+}
+
+test('every console method maps to the pino level of the same intent', () => {
+    assert.deepStrictEqual(MAPPING, { log: 'info', info: 'info', debug: 'debug', warn: 'warn', error: 'error' });
+});
+
+test('the severity the author chose at the call site is what the logger records', () => {
+    const { logger, lines } = capturingLogger('trace');
+    const c = fakeConsole();
+    installConsoleShim(logger, c);
+
+    c.log('a'); c.warn('b'); c.error('c'); c.debug('d'); c.info('e');
+
+    const byMsg = Object.fromEntries(lines.map((l) => [l.msg, l.level]));
+    assert.strictEqual(byMsg.a, 30, 'console.log -> info');
+    assert.strictEqual(byMsg.b, 40, 'console.warn -> warn');
+    assert.strictEqual(byMsg.c, 50, 'console.error -> error');
+    assert.strictEqual(byMsg.d, 20, 'console.debug -> debug');
+    assert.strictEqual(byMsg.e, 30, 'console.info -> info');
+});
+
+test('trailing arguments survive: the case a naive logger.info(msg, obj) would drop', () => {
+    const { logger, lines } = capturingLogger('info');
+    const c = fakeConsole();
+    installConsoleShim(logger, c);
+
+    // The exact shape of the settings dump and the DB error in index.js.
+    c.log('Raw settings from database:', [{ key: 'TZ', value: 'America/Los_Angeles' }]);
+    c.error('Failed to connect or create database:', new Error('SQLITE_CANTOPEN'));
+
+    assert.ok(lines[0].msg.includes('America/Los_Angeles'), 'array argument was formatted in, not dropped');
+    assert.ok(lines[1].msg.includes('SQLITE_CANTOPEN'), 'error message present');
+    assert.ok(lines[1].msg.includes('    at '), 'error stack present, as console would print it');
+});
+
+test('output is byte-identical to what console would have printed', () => {
+    // util.format is what console uses, so anything console could render, the
+    // shim renders the same way -- including %s placeholders and objects.
+    const util = require('util');
+    const { logger, lines } = capturingLogger('info');
+    const c = fakeConsole();
+    installConsoleShim(logger, c);
+
+    const args = ['user %s has %d chores', 'zev', 3, { extra: true }];
+    c.log(...args);
+    assert.strictEqual(lines[0].msg, util.format(...args));
+});
+
+test('at the shipped default, console.log is silent and warn/error are not', () => {
+    const { logger, lines } = capturingLogger('warn');
+    const c = fakeConsole();
+    installConsoleShim(logger, c);
+
+    c.log('startup chatter');
+    c.info('more chatter');
+    c.warn('something off');
+    c.error('something broken');
+
+    assert.deepStrictEqual(lines.map((l) => l.msg), ['something off', 'something broken']);
+});
+
+test('uninstall restores the original methods exactly', () => {
+    const { logger } = capturingLogger('info');
+    const c = fakeConsole();
+    const before = { ...c };
+    const uninstall = installConsoleShim(logger, c);
+
+    assert.notStrictEqual(c.log, before.log, 'shim installed');
+    uninstall();
+    for (const m of Object.keys(MAPPING)) {
+        assert.strictEqual(c[m], before[m], `console.${m} restored`);
+    }
+});
+
+test('the shim does not recurse if the logger itself writes via console', () => {
+    // Guard against the one way a global patch can wedge the process: a
+    // destination that calls console.*. pino writes to a stream and never
+    // does, but assert it rather than assume it.
+    let depth = 0;
+    const guard = {
+        info: (m) => { depth++; assert.ok(depth < 2, 'recursion'); depth--; },
+        warn() { }, error() { }, debug() { },
+    };
+    const c = fakeConsole();
+    installConsoleShim(guard, c);
+    assert.doesNotThrow(() => c.log('x'));
+});
diff --git a/server/tests/logFormat.test.js b/server/tests/logFormat.test.js
new file mode 100644
index 0000000..9def138
--- /dev/null
+++ b/server/tests/logFormat.test.js
@@ -0,0 +1,46 @@
+const test = require('node:test');
+const assert = require('node:assert');
+
+const { FORMATS, DEFAULT_FORMAT, resolveLogFormat, transportFor } = require('../utils/logFormat');
+
+test('pretty is the default, because the reader is usually a person with journalctl open', () => {
+    assert.strictEqual(DEFAULT_FORMAT, 'pretty');
+    for (const unset of [undefined, null, '', '  ']) {
+        assert.deepStrictEqual(resolveLogFormat(unset), { format: 'pretty', source: 'default' });
+    }
+});
+
+test('both formats are accepted, case and whitespace insensitively', () => {
+    assert.deepStrictEqual(FORMATS, ['pretty', 'json']);
+    for (const f of FORMATS) {
+        assert.strictEqual(resolveLogFormat(f).format, f);
+        assert.strictEqual(resolveLogFormat(` ${f.toUpperCase()} `).format, f);
+        assert.strictEqual(resolveLogFormat(f).source, 'env');
+    }
+});
+
+test('an unknown format falls back and names what it rejected', () => {
+    const r = resolveLogFormat('yaml');
+    assert.strictEqual(r.format, 'pretty');
+    assert.strictEqual(r.source, 'invalid');
+    assert.strictEqual(r.rejected, 'yaml');
+});
+
+test('json means pino native output: no transport at all', () => {
+    assert.strictEqual(transportFor('json'), undefined);
+});
+
+test('pretty configures pino-pretty and drops the fields journald already supplies', () => {
+    const t = transportFor('pretty');
+    assert.strictEqual(t.target, 'pino-pretty');
+    assert.strictEqual(t.options.ignore, 'pid,hostname');
+    assert.ok(t.options.translateTime, 'a human-readable timestamp, not epoch ms');
+    assert.strictEqual(t.options.colorize, false, 'no ANSI escapes into journald');
+    assert.strictEqual(t.options.singleLine, true, 'one journal entry per event');
+});
+
+test('the pretty transport target is actually installed', () => {
+    // A transport that names a missing module fails at logger construction,
+    // i.e. at server boot, which is the worst place to find out.
+    assert.doesNotThrow(() => require.resolve(transportFor('pretty').target));
+});
diff --git a/server/utils/consoleShim.js b/server/utils/consoleShim.js
new file mode 100644
index 0000000..ded47bf
--- /dev/null
+++ b/server/utils/consoleShim.js
@@ -0,0 +1,60 @@
+// Route the global console through a leveled logger.
+//
+// This is an adoption shim, not an architecture. The server has several hundred
+// console.* calls written by many hands over a year, and at every one of them
+// the author already chose a severity by picking .error, .warn or .log. That
+// decision is honoured here rather than re-made: each console method maps to
+// the logger level of the same name, so LOG_LEVEL governs all of it at once
+// and no call site has to change.
+//
+// Two details matter:
+//
+// 1. Arguments are flattened with util.format BEFORE reaching the logger.
+//    pino treats trailing arguments as printf interpolation values and drops
+//    them when the message has no placeholders, so a bare
+//    `logger.info(msg, obj)` would silently lose `obj`. util.format is exactly
+//    what console itself does, so output is byte-identical to what console
+//    would have printed, only now with a level attached.
+//
+// 2. It patches the global. Anything that logs through console after this
+//    runs -- dependencies included -- goes through the logger and obeys the
+//    level. That is mostly the point. It also means a reader who sees
+//    `console.error` in this codebase should know it is not writing to stderr.
+//
+// Migration to explicit logger calls can happen file by file, or never; the
+// shim covers whatever has not been converted.
+
+const util = require('util');
+
+const MAPPING = Object.freeze({
+    log: 'info',
+    info: 'info',
+    debug: 'debug',
+    warn: 'warn',
+    error: 'error',
+});
+
+/**
+ * Redirect console.{log,info,debug,warn,error} into `logger`.
+ *
+ * Returns a function that restores the original methods, so tests can install
+ * and remove the shim without leaking it into other tests.
+ */
+function installConsoleShim(logger, target = console) {
+    const originals = {};
+
+    for (const [method, level] of Object.entries(MAPPING)) {
+        originals[method] = target[method];
+        target[method] = (...args) => {
+            logger[level](util.format(...args));
+        };
+    }
+
+    return function uninstallConsoleShim() {
+        for (const method of Object.keys(originals)) {
+            target[method] = originals[method];
+        }
+    };
+}
+
+module.exports = { MAPPING, installConsoleShim };
diff --git a/server/utils/logFormat.js b/server/utils/logFormat.js
new file mode 100644
index 0000000..9bdfb31
--- /dev/null
+++ b/server/utils/logFormat.js
@@ -0,0 +1,54 @@
+// Log output format, resolved once from the environment.
+//
+// `pretty` is the default, which is the opposite of pino's own default and is
+// deliberate. HomeGlow runs on a Pi under journald, and the person reading its
+// log is usually an operator with `journalctl` open, not a pipeline. journald
+// already stamps every line with time, host and pid, so pino's JSON fields are
+// redundant there; what is wanted is a level and a message a human can scan.
+//
+// `json` is for anyone who does feed a pipeline (Loki, Datadog, `journalctl -o
+// json`), where each field being machine-parseable is the whole point.
+
+const FORMATS = ['pretty', 'json'];
+
+const DEFAULT_FORMAT = 'pretty';
+
+/** The format named by `raw`, or the default, with the reason alongside. */
+function resolveLogFormat(raw) {
+    if (raw === undefined || raw === null || String(raw).trim() === '') {
+        return { format: DEFAULT_FORMAT, source: 'default' };
+    }
+
+    const normalized = String(raw).trim().toLowerCase();
+
+    if (FORMATS.includes(normalized)) {
+        return { format: normalized, source: 'env' };
+    }
+
+    return { format: DEFAULT_FORMAT, source: 'invalid', rejected: String(raw).trim() };
+}
+
+/**
+ * pino transport options for a format, or undefined for pino's native JSON.
+ *
+ * `ignore: 'pid,hostname'` because journald supplies both; `translateTime`
+ * because an epoch-millisecond integer is not something a person reads.
+ */
+function transportFor(format) {
+    if (format !== 'pretty') return undefined;
+
+    return {
+        target: 'pino-pretty',
+        options: {
+            translateTime: 'SYS:yyyy-mm-dd HH:MM:ss',
+            ignore: 'pid,hostname',
+            colorize: false,
+            // One journal entry per event. Without this, pino-pretty renders
+            // each object field on its own indented line, and a single request
+            // log becomes seven journal rows.
+            singleLine: true,
+        },
+    };
+}
+
+module.exports = { FORMATS, DEFAULT_FORMAT, resolveLogFormat, transportFor };