Improve: reduce the container boot log to six lines

api/src/server.js

@@ -33,37 +33,44 @@ http.createServer(dispatch).listen(PORT, () => {
   const pkg = require('../package.json');
   const version = process.env.APP_VERSION || pkg.version;
   const widgets = Object.keys(getRegistry());
-  const W = 47;
-  const bar = c => c + '─'.repeat(W) + (c === '┌' ? '┐' : '┘');
-  const mid = t => '│ ' + t.padEnd(W - 2) + ' │';
-  const wlist = widgets.slice(0, 4).join(', ') + (widgets.length > 4 ? ', ...' : '');
+  /* The port the container listens on, not PORT: nginx fronts the API, so PORT
+     is internal and naming it here sends operators to an address that answers
+     for nobody. */
+  const row = (label, value) => '  ' + label.padEnd(11) + value;
   const lines = [
     '',
-    '  ' + bar('┌'),
-    '  ' + mid('STACKYARD'),
-    '  ' + mid('self-hosted dashboard · v' + version),
-    '  ' + bar('└'),
-    `  ➜  Web UI:    http://localhost:${PORT}`,
-    `  ➜  Config:    ${CONFIG_PATH}`,
-    `  ➜  Icons:     ${ICONS_PATH}`,
-    `  ➜  Widgets:   ${widgets.length} loaded (${wlist})`,
-    `  ➜  Node:      ${process.version}`,
-    '',
+    `  Stackyard ${version} · Node ${process.version}`,
+    row('Dashboard', ':80 in the container'),
+    row('Config', CONFIG_PATH),
+    row('Icons', ICONS_PATH),
+    row('Widgets', `${widgets.length} loaded`),
   ];
   try {
     const ll = require('./config').loadConfig().settings.logLevel;
     if (ll) log.setLevel(ll);
   } catch {}
   log.print(lines.join('\n'));
 
+  /* The banner bypasses level filtering and the logfmt shape, so this is the
+     only greppable record that the app came up. */
+  log.info('server ready', {
+    version,
+    port: PORT,
+    widgets: widgets.length,
+    node: process.version,
+  });
+
   /* With this on, clients can spoof X-Forwarded-* unless there really is a proxy
-     in front. Flagged at boot so the misconfiguration is visible. */
-  if (process.env.TRUST_PROXY === 'true')
-    log.warn(
-      'TRUST_PROXY is enabled: X-Forwarded-Proto is trusted, so a request claiming https gets a Secure session cookie. Only safe behind a reverse proxy you control.',
-    );
-  if (process.env.TRUST_PROXY === 'true' && !process.env.TRUSTED_PROXY)
-    log.warn(
-      'TRUST_PROXY is set but TRUSTED_PROXY is not: rate limiting counts every request through the front proxy as one client. Set TRUSTED_PROXY to the proxy address.',
-    );
+     in front. Flagged at boot so the misconfiguration is visible. The unset case
+     covers the trust exposure too, so only ever one line. */
+  if (process.env.TRUST_PROXY === 'true') {
+    if (process.env.TRUSTED_PROXY)
+      log.warn(
+        'TRUST_PROXY is on, so forwarded headers are trusted; this is only safe behind a reverse proxy you control.',
+      );
+    else
+      log.warn(
+        'TRUST_PROXY without TRUSTED_PROXY trusts forwarded headers from any client and rate-limits all traffic as one; set TRUSTED_PROXY to the proxy address.',
+      );
+  }
 });

api/src/widgets.js

@@ -258,7 +258,9 @@ function loadRegistry() {
     };
   }
 
-  log.info('widget registry loaded', { count: Object.keys(reg).length, widgets: Object.keys(reg) });
+  /* debug, not info: the banner and the readiness record both carry the count,
+     so the names are the only extra here. Refusals stay at warn above. */
+  log.debug('widget registry loaded', { count: Object.keys(reg).length, widgets: Object.keys(reg) });
   _registry = reg;
   _rejected = rejected;
   return reg;

api/test/boot-output.test.js

@@ -0,0 +1,150 @@
+/* What the container prints at boot.
+
+   Spawned as a real child process rather than by requiring server.js. The
+   banner goes out through log.print, which bypasses level filtering and the
+   logfmt shape; the server starts listening on require; and both TRUST_PROXY
+   branches are decided once inside the listen callback. Reading the real
+   process output is the only way to assert on any of that. */
+
+const { test } = require('node:test');
+const assert = require('node:assert/strict');
+const path = require('node:path');
+const fs = require('node:fs');
+const net = require('node:net');
+const { spawn } = require('node:child_process');
+const { tmpDir } = require('../test-support/tmp');
+
+const SERVER = path.join(__dirname, '../src/server.js');
+
+/* Two widgets, so the count the banner prints is one this test controls rather
+   than however many ship in the image. */
+function widgetsDir() {
+  const dir = tmpDir('boot-widgets');
+  for (const name of ['alpha', 'beta']) {
+    const d = path.join(dir, name);
+    fs.mkdirSync(d, { recursive: true });
+    fs.writeFileSync(
+      path.join(d, 'widget.json'),
+      JSON.stringify({
+        name,
+        label: name,
+        sizes: ['medium'],
+        views: { main: { src: 'index.html' } },
+      }),
+    );
+    fs.writeFileSync(path.join(d, 'index.html'), '');
+  }
+  return dir;
+}
+
+async function freePort() {
+  const srv = net.createServer();
+  await new Promise(r => srv.listen(0, '127.0.0.1', r));
+  const { port } = srv.address();
+  await new Promise(r => srv.close(r));
+  return port;
+}
+
+/* Runs the server until it reports readiness, gives the warnings that follow in
+   the same callback a moment to flush, then stops it. */
+async function boot(env = {}) {
+  const child = spawn(process.execPath, [SERVER], {
+    env: {
+      ...process.env,
+      PORT: String(await freePort()),
+      CONFIG_PATH: path.join(tmpDir('boot-config'), 'apps.json'),
+      WIDGETS_PATH: widgetsDir(),
+      APP_VERSION: '9.9.9',
+      LOG_LEVEL: 'info',
+      TRUST_PROXY: '',
+      TRUSTED_PROXY: '',
+      ...env,
+    },
+    stdio: ['ignore', 'pipe', 'pipe'],
+  });
+
+  let out = '';
+  child.stdout.on('data', d => (out += d));
+  child.stderr.on('data', d => (out += d));
+
+  try {
+    await new Promise((resolve, reject) => {
+      const timer = setTimeout(() => reject(new Error(`never reported ready:\n${out}`)), 15000);
+      child.stdout.on('data', () => {
+        if (!out.includes('server ready')) return;
+        clearTimeout(timer);
+        setTimeout(resolve, 100);
+      });
+      child.on('exit', code => {
+        clearTimeout(timer);
+        reject(new Error(`exited with ${code}:\n${out}`));
+      });
+    });
+  } finally {
+    child.kill('SIGKILL');
+  }
+  return out;
+}
+
+const trustWarnings = out => out.split('\n').filter(l => l.includes('WRN') && l.includes('TRUST_PROXY'));
+
+test('the banner names the port the container listens on, not the API port', async () => {
+  const out = await boot();
+  assert.ok(!out.includes('http://localhost'), 'the guessed URL reached nobody and must be gone');
+  assert.match(out, /Dashboard {2}:80 in the container/);
+});
+
+test('the banner prints the version without a v prefix and without box drawing', async () => {
+  const out = await boot();
+  assert.match(out, /Stackyard 9\.9\.9 · Node v/);
+  assert.ok(!out.includes('v9.9.9'), 'APP_VERSION defaults to "dev", so a v prefix renders "vdev"');
+  for (const ch of ['┌', '┐', '└', '┘', '│', '─', '➜']) {
+    assert.ok(!out.includes(ch), `box drawing misaligns in narrow terminals: found ${ch}`);
+  }
+});
+
+test('the banner lines up its labels and drops the truncated widget sample', async () => {
+  const out = await boot();
+  assert.match(out, /^ {2}Config {5}\S/m);
+  assert.match(out, /^ {2}Icons {6}\S/m);
+  assert.match(out, /^ {2}Widgets {4}2 loaded$/m);
+});
+
+test('one structured readiness record follows the banner', async () => {
+  const out = await boot();
+  const ready = out.split('\n').filter(l => l.includes('msg="server ready"'));
+  assert.equal(ready.length, 1, 'exactly one readiness record');
+  assert.match(ready[0], /INF msg="server ready" version=9\.9\.9 port=\d+ widgets=2 node=v/);
+});
+
+test('the widget registry inventory is not printed at the default level', async () => {
+  const out = await boot();
+  assert.ok(!out.includes('widget registry loaded'), 'the count is already in the banner');
+});
+
+test('the widget registry inventory is still available at debug', async () => {
+  const out = await boot({ LOG_LEVEL: 'debug' });
+  assert.match(out, /DBG msg="widget registry loaded"/);
+  assert.ok(out.includes('alpha'), 'the names are the reason to turn debug on');
+});
+
+test('TRUST_PROXY with TRUSTED_PROXY set warns exactly once', async () => {
+  const out = await boot({ TRUST_PROXY: 'true', TRUSTED_PROXY: '10.0.0.0/8' });
+  const w = trustWarnings(out);
+  assert.equal(w.length, 1, `one warning, got ${w.length}: ${w.join(' | ')}`);
+  assert.match(w[0], /forwarded headers are trusted/);
+});
+
+/* The second condition implies the first, so this case used to print two long
+   warnings about one problem. */
+test('TRUST_PROXY without TRUSTED_PROXY warns exactly once, naming the fix', async () => {
+  const out = await boot({ TRUST_PROXY: 'true' });
+  const w = trustWarnings(out);
+  assert.equal(w.length, 1, `one warning, got ${w.length}: ${w.join(' | ')}`);
+  assert.match(w[0], /set TRUSTED_PROXY to the proxy address/);
+});
+
+test('a correctly configured boot warns about neither', async () => {
+  const out = await boot();
+  assert.deepEqual(trustWarnings(out), []);
+});

api/test/entrypoint-config-check.test.js

@@ -82,6 +82,15 @@ test('a config nginx accepts starts normally', () => {
   assert.ok(r.started, 'the handoff command should have run');
 });
 
+/* -q prints nothing on success, which is two fewer lines on every boot. The
+   check itself is unchanged: set -eu still stops here, and nginx still prints
+   what it rejected. */
+test('the config check is quiet when it passes', () => {
+  const fs = require('node:fs');
+  const entrypoint = fs.readFileSync(require('node:path').join(__dirname, '../../docker-entrypoint.sh'), 'utf8');
+  assert.match(entrypoint, /^nginx -t -q$/m);
+});
+
 test('a config nginx rejects stops the container from starting', () => {
   const r = run({ nginxExit: 1 });
   assert.notEqual(r.status, 0, 'the entrypoint must exit non-zero');

api/test/supervisord-fatal.test.js

@@ -131,6 +131,34 @@ test('the listener only acts on FATAL', () => {
   assert.match(listener, /RESULT 2\\nOK/);
 });
 
+/* ── the boot log stays quiet without losing the safety net ───────────────── */
+
+const listenerBlock = () => supervisord.slice(supervisord.indexOf('[eventlistener:exit-on-fatal]'));
+
+/* This program's stdout is the event listener protocol channel. Pointing it at
+   /dev/stdout makes supervisord copy READY, RESULT and OK into `docker logs`,
+   where they read as noise nobody can act on. */
+test('the listener protocol does not reach the container log', () => {
+  const m = /^stdout_logfile=(\S+)$/m.exec(listenerBlock());
+  assert.ok(m, 'the listener has no stdout_logfile');
+  assert.notEqual(m[1], '/dev/stdout', 'this puts READY, RESULT and OK in docker logs');
+});
+
+/* The other half, and the one that must never be traded away: the "could not be
+   started" message goes to stderr, and it is the plainest explanation an
+   operator gets once supervisord stops narrating at info. */
+test('the listener still reports failure on stderr', () => {
+  assert.match(listenerBlock(), /^stderr_logfile=\/dev\/stderr$/m);
+});
+
+/* At info, supervisord narrates its own startup in eight lines that say nothing
+   an operator acts on. At warn the crash-loop line (`exited: ... not expected`)
+   and configuration failures both survive. `gave up: ... entered FATAL state` is
+   logged at info and is lost, which is why the two messages above exist. */
+test('supervisord logs at warn, not info', () => {
+  assert.match(supervisord, /^loglevel=warn$/m);
+});
+
 /* ── the script reaches the build context ────────────────────────────────────
    The first attempt at this failed CI: .dockerignore excluded `scripts`, so the
    file was never in the build context and COPY could not find it. A bare

docker-entrypoint.sh

@@ -36,7 +36,9 @@ REALIP_CONF="${REALIP_CONF:-/etc/nginx/http.d/realip.conf}"
 } > "$REALIP_CONF"
 
 # Fail fast and loudly rather than starting with a config nginx will reject.
-nginx -t
+# -q keeps the two success lines out of every boot; set -eu still stops here on
+# failure, and nginx still prints what it rejected.
+nginx -t -q
 
 # supervisord always exits 0 on SIGTERM, including the SIGTERM that
 # scripts/exit-on-fatal.py sends when a program can no longer be started. The

supervisord.conf

@@ -4,7 +4,17 @@ user=root
 logfile=/var/log/supervisor/supervisord.log
 logfile_maxbytes=10MB
 logfile_backups=3
-loglevel=info
+; warn, not info: at info supervisord narrates its own startup in eight lines
+; (Set uid, started with pid, spawned, entered RUNNING) that say nothing an
+; operator acts on. What matters survives at warn: `exited: ... not expected`,
+; the line that repeats while a program crash-loops, is logged at warn, and
+; configuration failures are logged at critical.
+;
+; The one loss is `gave up: ... entered FATAL state`, which supervisor logs at
+; info. That case is already covered in plainer language by the two messages
+; this repo prints itself, from scripts/exit-on-fatal.py and
+; docker-entrypoint.sh. Do not restore info without re-reading that trade.
+loglevel=warn
 pidfile=/tmp/supervisord.pid
 
 [program:nginx]
@@ -49,7 +59,11 @@ events=PROCESS_STATE_FATAL
 autostart=true
 autorestart=true
 priority=1
-stdout_logfile=/dev/stdout
+; Not /dev/stdout: this program's stdout is the event listener protocol channel,
+; so supervisord copying it to the child log puts READY, RESULT and OK in
+; `docker logs`. supervisord still reads the protocol over its own pipe.
+; stderr must stay on /dev/stderr; the "could not be started" message goes there.
+stdout_logfile=/dev/null
 stdout_logfile_maxbytes=0
 stderr_logfile=/dev/stderr
 stderr_logfile_maxbytes=0