Skip to content

fix(log): quieter startup and a ready line with the URL - #538

Merged
fclairamb merged 4 commits into
mainfrom
feat/log-quieter-startup
Oct 12, 2026
Merged

fclairamb merged 4 commits into
mainfrom
feat/log-quieter-startup

Conversation

@fclairamb

Copy link
Copy Markdown
Owner

Problem

A fresh server (SQLite, empty data dir, default env) printed 541 lines in its first minute, 524 of them at INFO, and never said which URL to open.

Most of it was routine work logged at INFO: two lines per check run that did not even name the check, a start and stop line per runner (25 of each), one line per seeded sample (about 120), one line per job, and a dozen "X disabled" or "Ensured X exists" lines on every boot.

Fix

  • Status changes, not runs. A check run is DEBUG now. The INFO line comes from the incident pipeline, where the transition is already computed, so there is no extra query: Check down name="Local Redis" slug=redis-localhost previous=validating error="ping failed: dial tcp [::1]:6379: connect: connection refused". It fires for down, back up, warning, and leaving stale (also inside a maintenance window).
  • Three transitions stay DEBUG: a brand-new check whose first result is up, entering validating, and validating back to up. Validating is the confirmation window before down. It notifies nobody, and the Check down line follows once it is confirmed. A brand-new check that fails is logged when it goes down.
  • Workers: one INFO line each (Job worker started runners=2, Check worker started runners=25 region=default), written before the ready line. Runner, fetcher, express, passive evaluator, queue sampler, per-job, per-run, multi-step and the per-minute "Processing stats" lines are DEBUG. A deported agent keeps an INFO Check worker started once it has registered.
  • Sample seeding (job_startup.go, levels and messages only): per-type and per-sample lines are DEBUG, one INFO Loaded sample checks total=72. The (non-fatal) failures move from INFO to WARN. Created default organization and Created admin user stay INFO.
  • Boot chatter to DEBUG: OpenTelemetry, Sentry and profiler disabled, AI-authored checks disabled, the SQLite advisory-lock note, the CLI OAuth seed, self-stats, every "Ensuring/Ensured ... job", "Startup job completed", "Worker region validated", "Starting HTTP server".
  • INFO only when non-default: memory guardrails (any non-default source), User-Agent (SP_USERAGENT set), both egress-policy lines (SP_EGRESS_ALLOW_PRIVATE set), the SQLite vacuum line (1 s or more), the user-token hashing (rows > 0).
  • Housekeeping jobs: aggregation, state cleanup and the watchdog's "no anomalies" are DEBUG. The jobs, audit-events and support-thread purges are INFO only when they deleted something.
  • Maintenance: "Skipping incident processing: check is in maintenance window" fires on every result during a window, so it is DEBUG.
  • Shutdown: Shutting down server and All runners stopped stay INFO. Every per-worker stop line is DEBUG.
  • Ready line. The HTTP listener is now bound before serving, so a bind failure is reported right away and the line is only written once the port is ours: SolidPing is ready url=http://localhost:4986 listen=[::]:4986 version=dev database="sqlite /data/solidping.db". url is the configured base URL when one is set (the built-in http://localhost:4000 default counts as unset), otherwise derived from the listen address (:4000, 0.0.0.0:4000, [::]:4000 read as localhost). That rule is the pure readyURL with a table test. database is the type plus the SQLite path or the Postgres host:port/dbname. The DSN is never printed, and a DSN that does not parse cleanly prints the type only.
  • First login. While the seeded admin still has must_change_password, a second line: First login with the default admin account, you will be asked to change the password email=admin@solidping.io password=solidpass. The password is the defaults.Password constant, which is never configurable. Only the startup seed sets that flag, and the forced change clears it. Neither line is printed in agent mode or without an HTTP listener (mcp --stdio).
  • The showcase boot marker (web/dash0/showcase) now waits for SolidPing is ready. The Linux install page says what the default log level shows.

Test plan

Same command before and after, from an empty dir: env -i HOME=$HOME PATH=$PATH PORT=4986 SP_DB_TYPE=sqlite SP_DB_DIR=$(mktemp -d) ./sp serve, stopped with SIGINT after 60 s.

before (main) after
total lines 541 28
INFO lines 524 15
INFO from start to the ready line (incl. first-login line) 179 (to "Starting HTTP server") 13
INFO between ready and shutdown 292 0
INFO at shutdown 53 2

The 9 WARN lines and 4 raw redis: lines left are the ones owned by the other logging PRs.

  • 60 s fresh run before and after, counts above
  • 300 s fresh run after: after the ready line, the only INFO lines are Check down for the failing samples once their 120 s confirmation passed (26 of them)
  • New table tests: TestReadyURL, TestPostgresTarget, TestDatabaseDescription, TestSeedAdminEmail, TestStatusChangeLog, plus small ones for the level helpers
  • TestMCPStdioCommandFreshDatabase asserts an INFO startup line that still exists and that stdio prints no ready line
  • ~/go/bin/golangci-lint run ./...: 0 issues
  • go test ./... -short (make test): all green

🤖 Generated with Claude Code

A fresh server printed 541 lines in its first minute (524 at INFO) and
never said which URL to open. Now: 28 lines, 15 at INFO.

- Check runs are DEBUG. The incident pipeline logs one INFO line when a
  check changes status, naming it: "Check down name=... slug=...
  previous=... error=...". A brand-new check coming up, entering
  validating and validating back to up stay DEBUG.
- Runner, per-job, per-run, per-sample and boot status lines are DEBUG.
  Each worker keeps one INFO "started" line. Boot settings log at INFO
  only when they are not the defaults.
- Once the HTTP listener is bound: "SolidPing is ready" with the URL,
  version and database (never credentials), plus the first-login line
  while the seeded admin still has to change its password.

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 85.87361% with 38 lines in your changes missing coverage. Please review.
✅ Project coverage is 82.81%. Comparing base (caf64b4) to head (3a60ed0).
⚠️ Report is 1 commits behind head on main.

Files with missing lines Patch % Lines
server/internal/jobs/jobtypes/job_startup.go 73.23% 19 Missing ⚠️
server/internal/app/server.go 41.17% 10 Missing ⚠️
server/internal/checkworker/worker.go 86.95% 3 Missing ⚠️
server/main.go 71.42% 2 Missing ⚠️
server/internal/app/ready.go 98.27% 1 Missing ⚠️
server/internal/handlers/incidents/status_log.go 96.55% 1 Missing ⚠️
server/internal/jobs/jobtypes/job_state_cleanup.go 66.66% 1 Missing ⚠️
...rver/internal/jobs/jobtypes/job_support_cleanup.go 50.00% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #538      +/-   ##
==========================================
+ Coverage   82.76%   82.81%   +0.05%     
==========================================
  Files        1178     1181       +3     
  Lines      121576   121663      +87     
==========================================
+ Hits       100617   100752     +135     
+ Misses      20952    20904      -48     
  Partials        7        7              
Files with missing lines Coverage Δ
server/internal/app/aichecks.go 80.00% <100.00%> (ø)
server/internal/app/cli_oauth_seed.go 79.16% <100.00%> (ø)
server/internal/checkworker/egress.go 100.00% <100.00%> (ø)
server/internal/checkworker/passive_evaluator.go 91.89% <100.00%> (+0.90%) ⬆️
server/internal/checkworker/worker_steps.go 82.38% <100.00%> (ø)
server/internal/config/config.go 93.03% <100.00%> (+0.04%) ⬆️
server/internal/db/dblock/dblock.go 81.08% <100.00%> (-5.41%) ⬇️
server/internal/db/sqlite/sqlite.go 89.66% <100.00%> (+0.03%) ⬆️
server/internal/db/usertokenhash.go 81.03% <100.00%> (+1.03%) ⬆️
server/internal/handlers/incidents/service.go 83.11% <100.00%> (+0.02%) ⬆️
... and 19 more

... and 10 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.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@fclairamb fclairamb changed the title feat(log): quieter startup and a ready line with the URL fix(log): quieter startup and a ready line with the URL Oct 12, 2026
@fclairamb
fclairamb enabled auto-merge (squash) October 12, 2026 06:14
@fclairamb
fclairamb merged commit bbe682a into main Oct 12, 2026
26 checks passed
@fclairamb
fclairamb deleted the feat/log-quieter-startup branch October 12, 2026 06:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant