Skip to content

systemd Type=notify: boot is killed at TimeoutStartSec, and the watchdog ping ignores WATCHDOG_USEC #361

Description

@FrameAutomata

backend/cmd/run.go wires up sd_notify, but only the half that runs after boot has already succeeded. Under Type=notify a slow boot is killed, and a short WatchdogSec kills a healthy process.

1. READY=1 only after the whole boot, with no EXTEND_TIMEOUT_USEC

notifySystemd() is called at backend/cmd/run.go:328 — after db.Init(), chdb.Init(), storage.Init(), migrations.Run(), both backfill.Run* passes, cache.ProjectCache.Init(), every worker start and the port bind. Nothing notifies systemd before that point.

systemd's default TimeoutStartSec= is 90s. A Type=notify unit whose boot spends longer than that in migrations gets SIGTERM at 90s, then Restart= brings it back to run the same migration again — a restart loop where the index never finishes building.

This is exactly the failure #337 described and #351 fixed for Kubernetes, where the chart now budgets periodSeconds: 5 × failureThreshold: 60 = 300s for the startup probe (helm/traceway/values.yaml:48-54). The same boot on systemd still gets 90.

The protocol has the fix built in: a service may send EXTEND_TIMEOUT_USEC= repeatedly during startup, and each message extends the start timeout from the moment it is received. A heartbeat from process start until READY=1 makes the boot survive for as long as it is making progress, without asking operators to guess a TimeoutStartSec for their largest migration.

2. The watchdog ping interval is hardcoded at 15s and ignores WATCHDOG_USEC

notifySystemd() (backend/cmd/run.go:508) starts a time.NewTicker(15 * time.Second) that sends WATCHDOG=1 unconditionally. systemd publishes the deadline it actually expects in WATCHDOG_USEC, and the documented contract is to ping every WATCHDOG_USEC / 2.

So with WatchdogSec=10s the process is pinging at 15s against a 10s deadline and is killed as hung while perfectly healthy — the watchdog turns into an outage. WatchdogSec=20s "works" only until a GC pause or a slow disk pushes one ping past the deadline. The ticker also runs when the watchdog is disabled entirely, and when WATCHDOG_PID names a different process.

daemon.SdWatchdogEnabled(false) (go-systemd v22.6.0, already a direct dependency) returns the interval and handles both the unset and wrong-PID cases, returning 0.

Proposed fix

  • Start an EXTEND_TIMEOUT_USEC= heartbeat at the top of Run(), stop it at READY=1. No-op when NOTIFY_SOCKET is unset, so nothing changes for Docker, Kubernetes or a bare go run.
  • Derive the watchdog interval from SdWatchdogEnabled, ping at half of it, and don't start the goroutine when the watchdog is off.

Both live in backend/cmd/, need no new dependency, and are testable against a real unixgram socket bound to NOTIFY_SOCKET.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions