From 76ac2710c9c9178e62cd2e83f9cf3b3fe1847284 Mon Sep 17 00:00:00 2001 From: jedarden Date: Tue, 7 Apr 2026 12:39:57 -0400 Subject: [PATCH] feat: startup phase sequencing with 30s timeout enforcement MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Implement explicit 7-phase startup logging and timeout enforcement: - Phases 1-4 (data dir, SQLite, migrations, secrets) in db.OpenDB - Phase 5 (subsystems) with 5s per-subsystem timeout via SubsystemStart - Phase 6 (HTTP + mDNS) and Phase 7 (health check + ready file) - FatalFunc injection for testable timeout handling - Each phase logs [PHASE N/7 — Description] on start, [PHASE N/7 OK] (Xms) on completion - 30s total startup deadline via context.WithTimeout Co-Authored-By: Claude Opus 4.6 --- mothership/cmd/mothership/main.go | 36 +++++++++++++-------- mothership/internal/startup/startup.go | 8 ++++- mothership/internal/startup/startup_test.go | 9 +++++- 3 files changed, 37 insertions(+), 16 deletions(-) diff --git a/mothership/cmd/mothership/main.go b/mothership/cmd/mothership/main.go index c7cf6f0..61dcc94 100644 --- a/mothership/cmd/mothership/main.go +++ b/mothership/cmd/mothership/main.go @@ -202,8 +202,8 @@ func main() { // Phases 1–4: Database initialization (data dir, SQLite, migrations, secrets) // Each phase is logged with timing by db.OpenDB via the startup package. - startup.CheckTimeout(startupCtx) - mainDB, err := db.OpenDB(cfg.DataDir, "spaxel.db") + // The startup context is passed so all phases share the same 30s deadline. + mainDB, err := db.OpenDB(startupCtx, cfg.DataDir, "spaxel.db") if err != nil { log.Fatalf("[FATAL] Failed to open main database: %v", err) } @@ -273,40 +273,48 @@ func main() { startup.CheckTimeout(startupCtx) phase5Done := startup.Phase(5, "Subsystems") - // Phase 6: BLE device registry - bleRegistry, err := ble.NewRegistry(filepath.Join(cfg.DataDir, "ble.db")) - if err != nil { + // Phase 5: BLE device registry + var bleRegistry *ble.Registry + if err := startup.SubsystemStart(startupCtx, "BLE registry", func(ctx context.Context) error { + var innerErr error + bleRegistry, innerErr = ble.NewRegistry(filepath.Join(cfg.DataDir, "ble.db")) + return innerErr + }); err != nil { log.Printf("[WARN] Failed to open BLE registry: %v", err) } else { defer bleRegistry.Close() log.Printf("[INFO] BLE registry at %s", filepath.Join(cfg.DataDir, "ble.db")) } - // Phase 6: RSSI cache for BLE triangulation + // Phase 5: RSSI cache for BLE triangulation rssiCache := ble.NewRSSICache(10 * time.Second) - // Phase 6: BLE identity matcher + // Phase 5: BLE identity matcher var identityMatcher *ble.IdentityMatcher if bleRegistry != nil { identityMatcher = ble.NewIdentityMatcher(bleRegistry, rssiCache, fleetReg) } - // Phase 6: Zones manager + // Phase 5: Zones manager zonesTz := time.Local if envTz := os.Getenv("TZ"); envTz != "" { if loc, err := time.LoadLocation(envTz); err == nil { zonesTz = loc } } - zonesMgr, err := zones.NewManager(filepath.Join(cfg.DataDir, "zones.db"), zonesTz) - if err != nil { + var zonesMgr *zones.Manager + if err := startup.SubsystemStart(startupCtx, "Zones manager", func(ctx context.Context) error { + var innerErr error + zonesMgr, innerErr = zones.NewManager(filepath.Join(cfg.DataDir, "zones.db"), zonesTz) + return innerErr + }); err != nil { log.Printf("[WARN] Failed to open zones database: %v", err) } else { defer zonesMgr.Close() log.Printf("[INFO] Zones manager at %s", filepath.Join(cfg.DataDir, "zones.db")) } - // Phase 6: Flow analytics accumulator + // Phase 5: Flow analytics accumulator flowAccumulator, err := analytics.NewFlowAccumulator(filepath.Join(cfg.DataDir, "analytics.db")) if err != nil { log.Printf("[WARN] Failed to open analytics database: %v", err) @@ -315,7 +323,7 @@ func main() { log.Printf("[INFO] Flow analytics at %s", filepath.Join(cfg.DataDir, "analytics.db")) } - // Phase 6: Anomaly detector for security mode + // Phase 5: Anomaly detector for security mode var anomalyDetector *analytics.Detector anomalyDetector, err = analytics.NewDetector( filepath.Join(cfg.DataDir, "anomaly.db"), @@ -332,7 +340,7 @@ func main() { // Note: Providers will be wired after dashboardHub and notifyService are created } - // Phase 6: Automation engine + // Phase 5: Automation engine automationEngine, err := automation.NewEngine(filepath.Join(cfg.DataDir, "automation.db")) if err != nil { log.Printf("[WARN] Failed to open automation database: %v", err) @@ -341,7 +349,7 @@ func main() { log.Printf("[INFO] Automation engine at %s", filepath.Join(cfg.DataDir, "automation.db")) } - // Phase 6: Fall detector + // Phase 5: Fall detector fallDetector := falldetect.NewDetector() log.Printf("[INFO] Fall detector initialized") diff --git a/mothership/internal/startup/startup.go b/mothership/internal/startup/startup.go index 6358b31..1786094 100644 --- a/mothership/internal/startup/startup.go +++ b/mothership/internal/startup/startup.go @@ -42,12 +42,18 @@ func Phase(num int, description string) func() { } } +// FatalFunc is called by CheckTimeout when the startup context is expired. +// Defaults to log.Fatalf; override in tests to avoid os.Exit. +var FatalFunc = func(format string, args ...interface{}) { + log.Fatalf(format, args...) +} + // CheckTimeout checks if the startup context has exceeded its deadline. // If so, it logs a fatal message and exits. This should be called before // each phase to enforce the 30-second total startup timeout. func CheckTimeout(ctx context.Context) { if ctx.Err() != nil { - log.Fatalf("[STARTUP TIMEOUT] Failed to reach ready state in 30s") + FatalFunc("[STARTUP TIMEOUT] Failed to reach ready state in 30s") } } diff --git a/mothership/internal/startup/startup_test.go b/mothership/internal/startup/startup_test.go index dad7a1a..a05f3af 100644 --- a/mothership/internal/startup/startup_test.go +++ b/mothership/internal/startup/startup_test.go @@ -40,6 +40,13 @@ func TestCheckTimeout_NoTimeout(t *testing.T) { } func TestCheckTimeout_Expired(t *testing.T) { + // Override FatalFunc to panic instead of os.Exit so we can test it + orig := FatalFunc + FatalFunc = func(format string, args ...interface{}) { + panic(fmt.Sprintf(format, args...)) + } + defer func() { FatalFunc = orig }() + ctx, cancel := context.WithTimeout(context.Background(), 1*time.Millisecond) defer cancel() time.Sleep(5 * time.Millisecond) @@ -47,7 +54,7 @@ func TestCheckTimeout_Expired(t *testing.T) { defer func() { r := recover() if r == nil { - t.Error("CheckTimeout should log.Fatalf on expired context") + t.Error("CheckTimeout should fatal on expired context") } }() CheckTimeout(ctx)