StartOS package: run satd with RUST_LOG=info

CHANGELOG.md

@@ -25,6 +25,7 @@ item below is (or will be) written up in full in the in-development
 - A `-reindex` reads only the block headers when it scans the block files, at most 4 KiB per block, where it read every file whole. On mainnet that read the whole chain, about 700 GB, before the first block connected, and a reindex continued after a stop read it again on every start (#916).
 - SIGTERM or SIGINT during `-reindex`, `-reindex-chainstate` or `-upgradechainstate` now stops the replay at once: satd abandons the block it is connecting, flushes what it had connected, keeps the rebuild marker and exits 0, within `-maxshutdownsecs`. There was no handler until startup finished, so the signal killed the replay mid-batch, or, with satd as PID 1 of its PID namespace (a container with no init), was dropped until the supervisor's SIGKILL. Anywhere else in startup a stop signal still ends satd at once, now as PID 1 too. A shutdown also logs each wait, for the block connector and the UTXO cache flush, before it starts (#907).
 - A full `-reindex` no longer appends a second copy of the genesis block to the last block file. It indexes the genesis record `blk00000.dat` begins with, so the reindex writes nothing to the block files, which on a switch from Bitcoin Core are Core's (#931).
+- StartOS package: the service log now shows satd's INFO lines (sync progress, a reindex's phases, the steps of a shutdown). StartOS starts every service with `RUST_LOG=warn`, which satd honors, so the log carried warnings only.
 - `getrawaddrman` could report an address in a bucket Core's formulas would never give it. When two addresses derived the same slot, the second moved to the next free slot of the whole table, which from a bucket's last position is the next bucket's first. It now moves within its own bucket, as Core keeps every address in the bucket its formula gives; only a full bucket spills over.
 
 ## Releases

contrib/packaging/startos/startos/main.ts

@@ -154,6 +154,11 @@ export const main = sdk.setupMain(async ({ effects }) => {
         // `--chain=` because there are bare flags for the test networks but
         // none for mainnet.
         command: ['satd', `--datadir=${rootDir}`, `--chain=${network}`],
+        // StartOS runs every daemon with its own RUST_LOG
+        // (`warn,start_core=debug`), and satd honors RUST_LOG over its
+        // default of `info`. Without this the service log shows warnings
+        // only: no sync progress, no reindex phases, no shutdown steps.
+        env: { RUST_LOG: 'info' },
         user: 'satd',
         // A node writing out its chainstate should not be killed mid-flush.
         sigtermTimeout: 600_000,

contrib/packaging/startos/test/logging.test.ts

@@ -0,0 +1,39 @@
+import { match, ok } from 'node:assert/strict'
+import { readFileSync } from 'node:fs'
+import { test } from 'node:test'
+import { upstream } from './upstream.ts'
+
+const read = (p: string) =>
+  readFileSync(new URL(p, import.meta.url), 'utf8')
+    .replace(/\/\*[\s\S]*?\*\//g, '')
+    .replace(/(^|[^:])\/\/.*$/gm, '$1')
+
+/**
+ * StartOS starts every daemon with RUST_LOG=warn,start_core=debug in its
+ * environment, and satd reads RUST_LOG in preference to its own default of
+ * info. A package that passes no RUST_LOG gets a service log of warnings
+ * only: on a StartOS server the log said nothing of sync progress, a
+ * reindex's phases or the steps of a shutdown.
+ */
+test('satd runs with RUST_LOG=info, not the RUST_LOG StartOS hands it', () => {
+  const main = read('../startos/main.ts')
+  const start = main.indexOf(".addDaemon('satd',")
+  ok(start >= 0, "main.ts has no addDaemon('satd', …)")
+  // Up to the next step of the chain (.addHealthCheck, .addOneshot, …).
+  const rest = main.slice(start + 1)
+  const next = rest.search(/\.add[A-Z]\w*\(/)
+  const daemon = next < 0 ? rest : rest.slice(0, next)
+  match(daemon, /env:\s*\{[^}]*RUST_LOG:\s*'info'/)
+})
+
+const config = upstream('satd/src/config.rs')
+test(
+  'satd takes its log filter from RUST_LOG',
+  { skip: config === null && 'satd source not present' },
+  () => {
+    ok(
+      config!.includes('std::env::var("RUST_LOG")'),
+      'satd no longer reads RUST_LOG; the env line in main.ts may be moot',
+    )
+  },
+)

docs/release-notes/0.6.1-pre.md

@@ -209,6 +209,14 @@ block connector to finish the block in hand, and for the UTXO cache flush,
 each with its share of `-maxshutdownsecs`. A stop that runs long says in its
 last log line what it is waiting on.
 
+### The StartOS service log shows satd's progress
+
+StartOS starts every service with `RUST_LOG=warn,start_core=debug` in its
+environment, and satd takes its log filter from `RUST_LOG`. Under the StartOS
+package, satd's log therefore carried warnings only: no sync progress, none of
+the reindex phases or stop messages above. The package now runs satd with
+`RUST_LOG=info`, satd's default everywhere else.
+
 ## RPC
 
 ### `getrawaddrman` keeps each address in its own bucket