Skip to content

fix: stop warning about normal things on a fresh start - #539

Merged
fclairamb merged 7 commits into
mainfrom
fix/fresh-start-warnings
Oct 12, 2026
Merged

fclairamb merged 7 commits into
mainfrom
fix/fresh-start-warnings

Conversation

@fclairamb

Copy link
Copy Markdown
Owner

Problem

A fresh server (SQLite, empty data dir, no config) looks broken in its first minute of logs:

WARN SQL query failed operation=SELECT error="SQL logic error: no such table: app_settings (1)"
WARN SQL query failed operation=INSERT error="SQL logic error: no such table: app_settings (1)"
WARN webpush: failed to persist VAPID public key err="set app setting \"webpush.vapid_public_key\": SQL logic error: no such table: app_settings (1)"
WARN JWT secret auto-generated and saved to database
WARN Worker hostname truncated to build the worker slug; ... component=job_worker hostname=alices-macbook-air.local slug=alices-macbook-
WARN Worker hostname truncated to build the worker slug; ... component=check_worker hostname=alices-macbook-air.local slug=alices-macbook-
WARN Using deprecated koanf aggregation retention; set the performance.* parameter instead component=job_worker key=audit.retention_days value=365
WARN Sentry flush timed out, some events may be lost
redis: 2026/10/12 06:28:27 pool.go:770: redis: connection pool: failed to dial after 5 attempts: dial tcp [::1]:6379: connect: connection refused
INFO Configuration loaded runMode="" dbType=sqlite logSQL=false
INFO metrics endpoint disabled, set metrics.scrape_token to enable scraping
INFO Prometheus metrics endpoint enabled path=/metrics tokenConfigured=false

The VAPID one is a real bug, not only noise: the key served during the first run was never stored, so the first restart generated a new one and every browser subscribed in between stopped receiving pushes.

Fix

  • VAPID keys (implements spec 2026-10-12-03 from chore(specs): webhook secret encoding, check-type count, VAPID ordering, idle memory #534): the keys load in Server.Initialize, after the migrations (InitializeWebPush, also called by the scenario harness that skips Initialize). GetOrCreateVAPIDKeys never returns a pair that is not stored: read and write errors are returned, both keys are read in one statement, a new pair is inserted with ON CONFLICT DO NOTHING and re-read, so processes racing on a fresh database share one pair. Half a stored pair is replaced in one statement. New db.Service methods: GetAppSettings, CreateAppSettingsIfAbsent, SetAppSettings. dash0 now drops a push subscription bound to another key before subscribing again, so a browser bitten by the old bug can re-enable push.
  • Retention deprecation warning: it fired for audit.retention_days on every install, because config.Load fills that value with the default (and that key is not deprecated). The job no longer warns. config.Load warns once at boot when a config file sets one of the deprecated aggregation.retention_* keys, never for a default.
  • Sentry flush: no flush and no warning when Sentry was never initialized (the hub only holds sentry-go's disabled no-op client).
  • Worker hostname: reported once per process instead of once per worker. WARN only when another process can register in the same database (a role other than all, or an external Postgres). A single all node on SQLite or embedded Postgres logs it at DEBUG. Docs updated.
  • Library output: go-redis and the MySQL driver write through their own stderr loggers. Both are routed into slog at DEBUG. The other check libraries (sarama, mongo, paho, amqp, clickhouse, gosnmp, go-ldap) are silent by default.
  • Metrics: one line, metrics endpoint disabled, set metrics.scrape_token to enable scraping path=/metrics. The contradicting "enabled ... tokenConfigured=false" line is gone.
  • Run mode: Configuration loaded runMode=production instead of runMode="".
  • JWT secret: generated on first boot only, which is expected, so INFO.
  • WARN credentials encryption disabled is kept: it is real security advice.

After this PR, a fresh 65 s run prints one WARN (credentials encryption disabled), no ERROR, and no line outside slog.

Found and left alone:

  • SP_AUDIT_RETENTION_DAYS=0 is documented as "keep forever", but 0 is rejected by the env tier (Ignoring invalid retention env override) and skipped by applyAuditEnv, so the 365-day default still applies. A negative value does disable the sweep. Separate fix.
  • go-ora writes Oracle server warnings straight to os.Stderr, with no logger hook. Only Oracle checks hit it.
  • chromedp's default error logger is log.Printf, which already goes through slog (at INFO).
  • The OVH delivery callback ordering noted in the spec's "To verify" section.

Test plan

  • go test -short ./... in server/ (249 packages, all ok)
  • go test -run Postgres ./internal/webpush/ (new embedded Postgres test: unmigrated error, concurrent creation, restart)
  • New tests: VAPID unmigrated / persist failure / partial state / 8 concurrent creators on one SQLite file, boot twice on one data dir keeps the key, deprecated-key detection, hostname log level and once-per-process, WorkerSlugMayCollide, RunModeName, silent Sentry flush, single metrics line
  • golangci-lint run ./... (0 issues)
  • dash0 vitest run (154 files, 2533 tests) and eslint on the changed files
  • Fresh server for 65 s (env -i ... SP_DB_TYPE=sqlite SP_DB_DIR=$(mktemp -d) ./sp serve): only the encryption WARN left, no raw output. With SP_LOG_LEVEL=debug, the go-redis lines and the hostname line show up once as DEBUG slog records.

🤖 Generated with Claude Code

fclairamb and others added 6 commits October 12, 2026 07:09
Both libraries print to stderr through their own loggers by default, so a
failing Redis sample check wrote raw "redis: ... pool.go:770" lines outside
the log format. Route them into slog at DEBUG: the failure already reaches
the check result.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
NewServer read and wrote app_settings before the migrations created it.
A fresh database logged two "no such table" SQL warnings and a webpush
warning, and served a key that was never stored, so the first restart
replaced it and broke every subscription made during the first run.

- Load the keys in Server.Initialize, after the migrations
  (InitializeWebPush, also called by the scenario harness).
- GetOrCreateVAPIDKeys never returns a pair that is not stored: read and
  write errors are returned, both keys are read in one statement, a new
  pair is inserted with ON CONFLICT DO NOTHING and re-read, so processes
  racing on a fresh database share one pair. Half a pair is replaced.
- dash0 drops a push subscription bound to another key before
  subscribing again.

Also on the server boot/shutdown path:
- One accurate /metrics line instead of "disabled" followed by "enabled".
- No "Sentry flush timed out" warning when Sentry was never initialized.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…can collide

The check worker and the job worker each warned that the hostname was cut
to build the worker slug, so a laptop hostname such as
alices-macbook-air.local printed the same WARN twice on every start.

The cut only matters when another process can register in the same
database: a role other than `all`, or an external Postgres. Log it once per
process, at WARN in that case and at DEBUG on a single node.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
- The audit cleanup job warned "Using deprecated koanf aggregation
  retention" for audit.retention_days on every install: config.Load fills
  that value with the default, and the key is not deprecated. The warning
  now fires once at boot, only when a config file sets one of the
  deprecated aggregation.retention_* keys.
- "Configuration loaded" logs runMode=production instead of an empty
  string.
- The first-boot JWT secret generation is expected, log it at INFO.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@codecov

codecov Bot commented Oct 12, 2026 •

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 82.81250% with 33 lines in your changes missing coverage. Please review.
✅ Project coverage is 82.74%. Comparing base (b3e6672) to head (2e8c7c6).

Files with missing lines Patch % Lines
server/internal/db/postgres/app_settings.go 56.25% 14 Missing ⚠️
server/internal/app/server.go 80.76% 5 Missing ⚠️
server/internal/db/sqlite/app_settings.go 84.37% 5 Missing ⚠️
server/internal/config/config.go 80.00% 4 Missing ⚠️
server/internal/webpush/vapid.go 89.28% 3 Missing ⚠️
server/internal/checkers/checkmysql/liblog.go 66.66% 1 Missing ⚠️
server/internal/checkers/checkredis/liblog.go 75.00% 1 Missing ⚠️
Additional details and impacted files
@@           Coverage Diff            @@
##             main     #539    +/-   ##
========================================
  Coverage   82.74%   82.74%            
========================================
  Files        1175     1178     +3     
  Lines      121460   121576   +116     
========================================
+ Hits       100497   100602   +105     
- Misses      20956    20967    +11     
  Partials        7        7            
Files with missing lines Coverage Δ
server/internal/app/metrics_auth.go 97.22% <100.00%> (+0.44%) ⬆️
server/internal/checkers/checkmysql/checker.go 47.31% <100.00%> (+0.57%) ⬆️
server/internal/checkworker/worker.go 90.30% <100.00%> (-0.56%) ⬇️
server/internal/config/worker_identity.go 100.00% <100.00%> (ø)
server/internal/db/models/app_setting.go 100.00% <100.00%> (ø)
server/internal/jobs/jobtypes/job_aggregation.go 95.75% <ø> (-0.02%) ⬇️
server/internal/jobs/jobworker/worker.go 78.33% <100.00%> (-0.08%) ⬇️
server/internal/systemconfig/systemconfig.go 96.22% <100.00%> (ø)
server/main.go 33.33% <100.00%> (ø)
server/test/integration/scenario/harness.go 95.60% <100.00%> (+0.02%) ⬆️
... and 7 more

... and 20 files with indirect coverage changes

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@fclairamb
fclairamb merged commit caf64b4 into main Oct 12, 2026
26 checks passed
@fclairamb
fclairamb deleted the fix/fresh-start-warnings branch October 12, 2026 06:00
fclairamb added a commit that referenced this pull request Oct 12, 2026
#539 implemented the same VAPID spec (2026-10-12-03) on main. Its version
is kept for every file this branch only touched for that spec (webpush,
db app_settings, server.go, scenario harness, dash0 subscription hook,
notifications mock); the branch's duplicate implementation and its
useWebPushSubscription.test.ts are dropped.

#537 (SeedOnInstall) and the idle-memory spec (NeedsBrowser) both add a
CheckSpec flag: both are kept. A fresh default install now seeds no browser
sample, so TestStartupBrowserSamplesDisabled runs in test mode, with
http-fake-stable as the enabled control, and the small-hosts docs say so.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
fclairamb added a commit that referenced this pull request Oct 12, 2026
#539 implemented the same VAPID spec (2026-10-12-03) on main. Its version
is kept for every file this branch only touched for that spec (webpush,
db app_settings, server.go, scenario harness, dash0 subscription hook,
notifications mock); the branch's duplicate implementation and its
useWebPushSubscription.test.ts are dropped.

#537 (SeedOnInstall) and the idle-memory spec (NeedsBrowser) both add a
CheckSpec flag: both are kept. A fresh default install now seeds no browser
sample, so TestStartupBrowserSamplesDisabled runs in test mode, with
http-fake-stable as the enabled control, and the small-hosts docs say so.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
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.

1 participant