From a9e6722fab1922c43a87414db395cdcde737830f Mon Sep 17 00:00:00 2001 From: Claude Date: Sat, 18 Jul 2026 14:53:10 +0000 Subject: [PATCH 1/5] Add test coverage for entities, timers, store, and CLI helpers Raises overall coverage (-coverpkg=./...) from ~63% to ~70% by adding tests for previously uncovered code paths: - homeassistant.State.Update (0% -> 100%) - Button, LightSensor entity logic - Light/LightGroup/InputBoolean service calls via the mock HA server (registered happy paths, not just the unregistered error case) - halautomations.Timer builder and conditional firing - store async writer flush/close lifecycle - CLI helpers parseDuration, parseTime, and compileGlobs Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01MCZq8eURnwy99CRfcb71CA --- automations/timer_test.go | 108 ++++++++++++++ cmd/hal/commands/events_internal_test.go | 64 +++++++++ cmd/hal/commands/logs_internal_test.go | 78 ++++++++++ entity_button_test.go | 78 ++++++++++ entity_input_boolean_registered_test.go | 49 +++++++ entity_light_registered_test.go | 173 +++++++++++++++++++++++ entity_light_sensor_test.go | 46 ++++++ homeassistant/state_test.go | 99 +++++++++++++ store/async_writer_test.go | 83 +++++++++++ 9 files changed, 778 insertions(+) create mode 100644 automations/timer_test.go create mode 100644 cmd/hal/commands/events_internal_test.go create mode 100644 cmd/hal/commands/logs_internal_test.go create mode 100644 entity_button_test.go create mode 100644 entity_input_boolean_registered_test.go create mode 100644 entity_light_registered_test.go create mode 100644 entity_light_sensor_test.go create mode 100644 homeassistant/state_test.go create mode 100644 store/async_writer_test.go diff --git a/automations/timer_test.go b/automations/timer_test.go new file mode 100644 index 0000000..0dc4d31 --- /dev/null +++ b/automations/timer_test.go @@ -0,0 +1,108 @@ +package halautomations_test + +import ( + "context" + "sync/atomic" + "testing" + "time" + + "github.com/dansimau/hal" + halautomations "github.com/dansimau/hal/automations" + "gotest.tools/v3/assert" +) + +func TestTimerBuilder(t *testing.T) { + t.Parallel() + + entity := hal.NewEntity("test.entity") + + timer := halautomations.NewTimer("test timer"). + Duration(time.Millisecond). + WithEntities(entity). + Run(func(_ context.Context) {}) + + assert.Equal(t, timer.Name(), "test timer") + assert.Equal(t, len(timer.Entities()), 1) + assert.Equal(t, timer.Entities()[0].GetID(), "test.entity") +} + +func TestTimerRunsActionAfterDelay(t *testing.T) { + t.Parallel() + + var ran atomic.Bool + + timer := halautomations.NewTimer("test timer"). + Duration(10 * time.Millisecond). + Run(func(_ context.Context) { + ran.Store(true) + }) + + // Action with a passing (nil) condition set starts the timer. + timer.Action(context.Background(), hal.NewEntity("test.entity")) + + assert.NilError(t, waitForBool(&ran, time.Second)) +} + +func TestTimerConditionBlocksStart(t *testing.T) { + t.Parallel() + + var ran atomic.Bool + + timer := halautomations.NewTimer("test timer"). + Duration(10 * time.Millisecond). + Condition(func() bool { return false }). + Run(func(_ context.Context) { + ran.Store(true) + }) + + // Condition is false, so Action should stop (never start) the timer. + timer.Action(context.Background(), hal.NewEntity("test.entity")) + + time.Sleep(50 * time.Millisecond) + assert.Equal(t, ran.Load(), false) +} + +func TestTimerConditionRecheckedBeforeAction(t *testing.T) { + t.Parallel() + + var ( + ran atomic.Bool + allowed atomic.Bool + ) + + allowed.Store(true) + + timer := halautomations.NewTimer("test timer"). + Duration(10 * time.Millisecond). + Condition(func() bool { return allowed.Load() }). + Run(func(_ context.Context) { + ran.Store(true) + }) + + // Condition passes, so the timer starts... + timer.Action(context.Background(), hal.NewEntity("test.entity")) + + // ...but flips to false before it fires, so runAction must bail out. + allowed.Store(false) + + time.Sleep(50 * time.Millisecond) + assert.Equal(t, ran.Load(), false) +} + +// waitForBool polls the flag until it is true or the timeout elapses. +func waitForBool(flag *atomic.Bool, timeout time.Duration) error { + deadline := time.After(timeout) + + for { + select { + case <-deadline: + return context.DeadlineExceeded + default: + if flag.Load() { + return nil + } + + time.Sleep(time.Millisecond) + } + } +} diff --git a/cmd/hal/commands/events_internal_test.go b/cmd/hal/commands/events_internal_test.go new file mode 100644 index 0000000..fe8df34 --- /dev/null +++ b/cmd/hal/commands/events_internal_test.go @@ -0,0 +1,64 @@ +package commands + +import ( + "testing" + + "gotest.tools/v3/assert" +) + +func TestCompileGlobs(t *testing.T) { + t.Parallel() + + t.Run("returns empty slice for no patterns", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs(nil) + assert.NilError(t, err) + assert.Equal(t, len(res), 0) + }) + + t.Run("substring match without wildcards", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs([]string{"camera"}) + assert.NilError(t, err) + assert.Equal(t, len(res), 1) + assert.Assert(t, res[0].MatchString(`{"entity_id":"camera.front"}`)) + assert.Assert(t, !res[0].MatchString(`{"entity_id":"light.kitchen"}`)) + }) + + t.Run("star wildcard matches across characters", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs([]string{"*sun.sun*"}) + assert.NilError(t, err) + assert.Assert(t, res[0].MatchString(`{"entity_id":"sun.sun","state":"above_horizon"}`)) + assert.Assert(t, !res[0].MatchString(`{"entity_id":"moon.moon"}`)) + }) + + t.Run("question mark matches single character", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs([]string{"a?c"}) + assert.NilError(t, err) + assert.Assert(t, res[0].MatchString("abc")) + assert.Assert(t, res[0].MatchString("axc")) + assert.Assert(t, !res[0].MatchString("ac")) + }) + + t.Run("matches across newlines", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs([]string{"foo*bar"}) + assert.NilError(t, err) + assert.Assert(t, res[0].MatchString("foo\nbar")) + }) + + t.Run("compiles multiple patterns", func(t *testing.T) { + t.Parallel() + + res, err := compileGlobs([]string{"foo", "bar"}) + assert.NilError(t, err) + assert.Equal(t, len(res), 2) + }) +} diff --git a/cmd/hal/commands/logs_internal_test.go b/cmd/hal/commands/logs_internal_test.go new file mode 100644 index 0000000..10efb15 --- /dev/null +++ b/cmd/hal/commands/logs_internal_test.go @@ -0,0 +1,78 @@ +package commands + +import ( + "testing" + "time" + + "gotest.tools/v3/assert" +) + +func TestParseDuration(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + input string + want time.Duration + wantErr bool + }{ + {name: "days", input: "2d", want: 48 * time.Hour}, + {name: "single day", input: "1d", want: 24 * time.Hour}, + {name: "hours", input: "3h", want: 3 * time.Hour}, + {name: "minutes", input: "5m", want: 5 * time.Minute}, + {name: "seconds", input: "30s", want: 30 * time.Second}, + {name: "invalid days", input: "xd", wantErr: true}, + {name: "invalid format", input: "abc", wantErr: true}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + got, err := parseDuration(tt.input) + if tt.wantErr { + assert.Assert(t, err != nil) + + return + } + + assert.NilError(t, err) + assert.Equal(t, got, tt.want) + }) + } +} + +func TestParseTime(t *testing.T) { + t.Parallel() + + t.Run("parses date only", func(t *testing.T) { + t.Parallel() + + got, err := parseTime("2024-01-15") + assert.NilError(t, err) + assert.Equal(t, got, time.Date(2024, 1, 15, 0, 0, 0, 0, time.UTC)) + }) + + t.Run("parses date and time", func(t *testing.T) { + t.Parallel() + + got, err := parseTime("2024-01-15 13:45") + assert.NilError(t, err) + assert.Equal(t, got, time.Date(2024, 1, 15, 13, 45, 0, 0, time.UTC)) + }) + + t.Run("parses date and time with seconds", func(t *testing.T) { + t.Parallel() + + got, err := parseTime("2024-01-15 13:45:30") + assert.NilError(t, err) + assert.Equal(t, got, time.Date(2024, 1, 15, 13, 45, 30, 0, time.UTC)) + }) + + t.Run("returns error for invalid input", func(t *testing.T) { + t.Parallel() + + _, err := parseTime("not-a-date") + assert.Assert(t, err != nil) + }) +} diff --git a/entity_button_test.go b/entity_button_test.go new file mode 100644 index 0000000..95736b5 --- /dev/null +++ b/entity_button_test.go @@ -0,0 +1,78 @@ +package hal_test + +import ( + "testing" + + "github.com/dansimau/hal" + "github.com/dansimau/hal/homeassistant" + "gotest.tools/v3/assert" +) + +func TestNewButton(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + assert.Equal(t, button.GetID(), "event.button") +} + +func TestButton_Name(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + assert.Equal(t, button.Name(), "event.button") +} + +func TestButton_Entities(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + entities := button.Entities() + + assert.Equal(t, len(entities), 1) + assert.Equal(t, entities[0].GetID(), "event.button") +} + +func TestButton_Action(t *testing.T) { + t.Parallel() + + t.Run("ignores non-initial-press events", func(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + button.SetState(homeassistant.State{ + Attributes: map[string]any{"event_type": "long_press"}, + }) + + button.Action(button) + + assert.Equal(t, button.PressedTimes(), int32(0)) + }) + + t.Run("counts an initial press", func(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + button.SetState(homeassistant.State{ + Attributes: map[string]any{"event_type": "initial_press"}, + }) + + button.Action(button) + + assert.Equal(t, button.PressedTimes(), int32(1)) + }) + + t.Run("counts rapid repeat presses cumulatively", func(t *testing.T) { + t.Parallel() + + button := hal.NewButton("event.button") + button.SetState(homeassistant.State{ + Attributes: map[string]any{"event_type": "initial_press"}, + }) + + button.Action(button) + button.Action(button) + button.Action(button) + + assert.Equal(t, button.PressedTimes(), int32(3)) + }) +} diff --git a/entity_input_boolean_registered_test.go b/entity_input_boolean_registered_test.go new file mode 100644 index 0000000..c76a4d5 --- /dev/null +++ b/entity_input_boolean_registered_test.go @@ -0,0 +1,49 @@ +package hal_test + +import ( + "testing" + + "github.com/dansimau/hal" + "github.com/dansimau/hal/testutil" + "github.com/davecgh/go-spew/spew" +) + +func TestInputBoolean_TurnOn_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + sw := hal.NewInputBoolean("input_boolean.test") + conn.RegisterEntities(sw) + + if err := sw.TurnOn(map[string]any{"custom": "value"}); err != nil { + t.Fatalf("TurnOn returned error: %v", err) + } + + testutil.WaitFor(t, "switch turned on", func() bool { + return sw.IsOn() + }, func() { + spew.Dump(sw.GetID(), sw.GetState()) + }) +} + +func TestInputBoolean_TurnOff_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + sw := hal.NewInputBoolean("input_boolean.test") + conn.RegisterEntities(sw) + + if err := sw.TurnOff(); err != nil { + t.Fatalf("TurnOff returned error: %v", err) + } + + testutil.WaitFor(t, "switch turned off", func() bool { + return sw.IsOff() + }, func() { + spew.Dump(sw.GetID(), sw.GetState()) + }) +} diff --git a/entity_light_registered_test.go b/entity_light_registered_test.go new file mode 100644 index 0000000..6455c32 --- /dev/null +++ b/entity_light_registered_test.go @@ -0,0 +1,173 @@ +package hal_test + +import ( + "context" + "testing" + + "github.com/dansimau/hal" + "github.com/dansimau/hal/homeassistant" + "github.com/dansimau/hal/testutil" + "github.com/davecgh/go-spew/spew" +) + +// TestLight_TurnOn_Registered exercises the happy path where a registered light +// calls the (mock) Home Assistant service and receives the echoed state change. +func TestLight_TurnOn_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + light := hal.NewLight("light.test") + conn.RegisterEntities(light) + + err := light.TurnOn(map[string]any{"brightness": float64(200)}) + if err != nil { + t.Fatalf("TurnOn returned error: %v", err) + } + + testutil.WaitFor(t, "light turned on", func() bool { + return light.GetState().State == "on" + }, func() { + spew.Dump(light.GetID(), light.GetState()) + }) +} + +func TestLight_TurnOff_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + light := hal.NewLight("light.test") + conn.RegisterEntities(light) + + err := light.TurnOff() + if err != nil { + t.Fatalf("TurnOff returned error: %v", err) + } + + testutil.WaitFor(t, "light turned off", func() bool { + return light.GetState().State == "off" + }, func() { + spew.Dump(light.GetID(), light.GetState()) + }) +} + +func TestLight_TurnOnContext_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + light := hal.NewLight("light.test") + conn.RegisterEntities(light) + + err := light.TurnOnContext(context.Background(), map[string]any{"brightness": float64(128)}) + if err != nil { + t.Fatalf("TurnOnContext returned error: %v", err) + } + + testutil.WaitFor(t, "light turned on", func() bool { + return light.GetState().State == "on" + }, func() { + spew.Dump(light.GetID(), light.GetState()) + }) +} + +func TestLight_TurnOffContext_Registered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + light := hal.NewLight("light.test") + conn.RegisterEntities(light) + + err := light.TurnOffContext(context.Background()) + if err != nil { + t.Fatalf("TurnOffContext returned error: %v", err) + } + + testutil.WaitFor(t, "light turned off", func() bool { + return light.GetState().State == "off" + }, func() { + spew.Dump(light.GetID(), light.GetState()) + }) +} + +// TestLightGroup_ServicesRegistered exercises LightGroup fan-out over registered +// lights against the mock server. +func TestLightGroup_ServicesRegistered(t *testing.T) { + t.Parallel() + + conn, _, cleanup := testutil.NewClientServer(t) + defer cleanup() + + light1 := hal.NewLight("light.one") + light2 := hal.NewLight("light.two") + conn.RegisterEntities(light1, light2) + + group := hal.LightGroup{light1, light2} + + if err := group.TurnOnContext(context.Background(), map[string]any{"brightness": float64(255)}); err != nil { + t.Fatalf("group TurnOnContext returned error: %v", err) + } + + testutil.WaitFor(t, "both lights on", func() bool { + return light1.GetState().State == "on" && light2.GetState().State == "on" + }, func() { + spew.Dump(light1.GetState(), light2.GetState()) + }) + + if !group.IsOn() { + t.Error("expected group IsOn to be true") + } + + if err := group.TurnOffContext(context.Background()); err != nil { + t.Fatalf("group TurnOffContext returned error: %v", err) + } + + testutil.WaitFor(t, "both lights off", func() bool { + return light1.GetState().State == "off" && light2.GetState().State == "off" + }, func() { + spew.Dump(light1.GetState(), light2.GetState()) + }) + + if !group.IsOff() { + t.Error("expected group IsOff to be true") + } +} + +// TestLightGroup_IsOff verifies IsOff logic without a connection. +func TestLightGroup_IsOff(t *testing.T) { + t.Parallel() + + t.Run("returns true when all lights off", func(t *testing.T) { + t.Parallel() + + light1 := hal.NewLight("light.one") + light2 := hal.NewLight("light.two") + light1.SetState(homeassistant.State{State: "off"}) + light2.SetState(homeassistant.State{State: "off"}) + + group := hal.LightGroup{light1, light2} + if !group.IsOff() { + t.Error("expected IsOff to be true") + } + }) + + t.Run("returns false when any light on", func(t *testing.T) { + t.Parallel() + + light1 := hal.NewLight("light.one") + light2 := hal.NewLight("light.two") + light1.SetState(homeassistant.State{State: "off"}) + light2.SetState(homeassistant.State{State: "on"}) + + group := hal.LightGroup{light1, light2} + if group.IsOff() { + t.Error("expected IsOff to be false") + } + }) +} diff --git a/entity_light_sensor_test.go b/entity_light_sensor_test.go new file mode 100644 index 0000000..1dfe704 --- /dev/null +++ b/entity_light_sensor_test.go @@ -0,0 +1,46 @@ +package hal_test + +import ( + "testing" + + "github.com/dansimau/hal" + "github.com/dansimau/hal/homeassistant" + "gotest.tools/v3/assert" +) + +func TestNewLightSensor(t *testing.T) { + t.Parallel() + + sensor := hal.NewLightSensor("sensor.light_level") + assert.Equal(t, sensor.GetID(), "sensor.light_level") +} + +func TestLightSensor_Level(t *testing.T) { + t.Parallel() + + t.Run("returns parsed integer level", func(t *testing.T) { + t.Parallel() + + sensor := hal.NewLightSensor("sensor.light_level") + sensor.SetState(homeassistant.State{State: "42"}) + + assert.Equal(t, sensor.Level(), 42) + }) + + t.Run("returns 0 when state is not a number", func(t *testing.T) { + t.Parallel() + + sensor := hal.NewLightSensor("sensor.light_level") + sensor.SetState(homeassistant.State{State: "unavailable"}) + + assert.Equal(t, sensor.Level(), 0) + }) + + t.Run("returns 0 when state is empty", func(t *testing.T) { + t.Parallel() + + sensor := hal.NewLightSensor("sensor.light_level") + + assert.Equal(t, sensor.Level(), 0) + }) +} diff --git a/homeassistant/state_test.go b/homeassistant/state_test.go new file mode 100644 index 0000000..89c78db --- /dev/null +++ b/homeassistant/state_test.go @@ -0,0 +1,99 @@ +package homeassistant_test + +import ( + "testing" + "time" + + "github.com/dansimau/hal/homeassistant" + "gotest.tools/v3/assert" +) + +func TestState_Update(t *testing.T) { + t.Parallel() + + t.Run("updates state when new state is non-empty", func(t *testing.T) { + t.Parallel() + + s := homeassistant.State{State: "off"} + s.Update(homeassistant.State{State: "on"}) + + assert.Equal(t, s.State, "on") + }) + + t.Run("leaves state unchanged when new state is empty", func(t *testing.T) { + t.Parallel() + + s := homeassistant.State{State: "on"} + s.Update(homeassistant.State{State: ""}) + + assert.Equal(t, s.State, "on") + }) + + t.Run("merges attributes into existing map", func(t *testing.T) { + t.Parallel() + + s := homeassistant.State{ + Attributes: map[string]any{"brightness": float64(100)}, + } + s.Update(homeassistant.State{ + Attributes: map[string]any{"color": "red"}, + }) + + assert.Equal(t, s.Attributes["brightness"], float64(100)) + assert.Equal(t, s.Attributes["color"], "red") + }) + + t.Run("overwrites existing attribute values", func(t *testing.T) { + t.Parallel() + + s := homeassistant.State{ + Attributes: map[string]any{"brightness": float64(100)}, + } + s.Update(homeassistant.State{ + Attributes: map[string]any{"brightness": float64(200)}, + }) + + assert.Equal(t, s.Attributes["brightness"], float64(200)) + }) + + t.Run("initialises attributes map when nil", func(t *testing.T) { + t.Parallel() + + s := homeassistant.State{} + s.Update(homeassistant.State{ + Attributes: map[string]any{"brightness": float64(50)}, + }) + + assert.Equal(t, s.Attributes["brightness"], float64(50)) + }) + + t.Run("updates timestamps when set", func(t *testing.T) { + t.Parallel() + + changed := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) + reported := time.Date(2026, 1, 2, 3, 4, 6, 0, time.UTC) + updated := time.Date(2026, 1, 2, 3, 4, 7, 0, time.UTC) + + s := homeassistant.State{} + s.Update(homeassistant.State{ + LastChanged: changed, + LastReported: reported, + LastUpdated: updated, + }) + + assert.Equal(t, s.LastChanged, changed) + assert.Equal(t, s.LastReported, reported) + assert.Equal(t, s.LastUpdated, updated) + }) + + t.Run("leaves timestamps unchanged when zero", func(t *testing.T) { + t.Parallel() + + changed := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) + + s := homeassistant.State{LastChanged: changed} + s.Update(homeassistant.State{}) + + assert.Equal(t, s.LastChanged, changed) + }) +} diff --git a/store/async_writer_test.go b/store/async_writer_test.go new file mode 100644 index 0000000..0851f12 --- /dev/null +++ b/store/async_writer_test.go @@ -0,0 +1,83 @@ +package store_test + +import ( + "testing" + "time" + + "github.com/dansimau/hal/store" + "gorm.io/gorm" +) + +// TestStoreEnqueueWrite verifies that a write enqueued through the Store's async +// writer is eventually persisted, and that WaitForWrites blocks until it is. +func TestStoreEnqueueWrite(t *testing.T) { + t.Parallel() + + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open database: %v", err) + } + defer db.Close() + + db.EnqueueWrite(func(tx *gorm.DB) error { + return tx.Create(&store.Log{ + Timestamp: time.Now(), + Level: "INFO", + LogText: "hello", + }).Error + }) + + db.WaitForWrites() + + var count int64 + if err := db.Model(&store.Log{}).Count(&count).Error; err != nil { + t.Fatalf("Failed to count logs: %v", err) + } + + if count != 1 { + t.Errorf("Expected 1 log, got %d", count) + } +} + +// TestStoreCloseFlushesWrites verifies that Close drains queued writes before +// shutting the store down. +func TestStoreCloseFlushesWrites(t *testing.T) { + t.Parallel() + + // Use a file-backed database so it survives closing the connection, letting + // us re-open and assert the write was flushed during Close. + path := t.TempDir() + "/flush.db" + + db, err := store.Open(path) + if err != nil { + t.Fatalf("Failed to open database: %v", err) + } + + db.EnqueueWrite(func(tx *gorm.DB) error { + return tx.Create(&store.Log{ + Timestamp: time.Now(), + Level: "INFO", + LogText: "flushed", + }).Error + }) + + // Close should drain the queue before closing the DB. + if err := db.Close(); err != nil { + t.Fatalf("Failed to close store: %v", err) + } + + reopened, err := store.Open(path) + if err != nil { + t.Fatalf("Failed to reopen database: %v", err) + } + defer reopened.Close() + + var count int64 + if err := reopened.Model(&store.Log{}).Count(&count).Error; err != nil { + t.Fatalf("Failed to count logs: %v", err) + } + + if count != 1 { + t.Errorf("Expected 1 flushed log, got %d", count) + } +} From d2956d5b6c02615c72a49ced910f377802a69093 Mon Sep 17 00:00:00 2001 From: Claude Date: Sat, 18 Jul 2026 16:09:46 +0000 Subject: [PATCH 2/5] Add hassws client tests and fix latent client/server bugs Lifts hassws package coverage from 3.1% to ~84% by adding a white-box test suite that drives a real hassws.Client against the existing mock WebSocket server: connect/auth (happy, dial-fail, auth-invalid), CallService, GetStates, SubscribeEvents(Raw), heartbeat keepalive, stale connection, forced disconnect, and graceful server close, plus pure-unit tests for the message-id, state, channel-read, and not-connected paths. Bug fixes surfaced while writing these tests: - client: sendMessageStreamResponses leaked the response listener when the underlying send failed; it now removes the listener on error. - client: Close/shutdown/read/send panicked on a nil conn when called before Connect; they now no-op or return ErrNotConnected. - client: renamed the misspelled readMesssageFromChannel to readMessageFromChannel. - message_types: removed the unused MessageTypeAuthChallenge/AuthRequest/ AuthResponse constants (the auth flow uses string literals). - server (mock): serialized all client-connection writes (auth handshake, Close, shutdown, socket assignment) under the same lock as SendMessage. Gorilla forbids concurrent writers, and the unsynchronized paths raced under -race once the client was driven directly. Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01MCZq8eURnwy99CRfcb71CA --- hassws/client.go | 31 ++- hassws/client_test.go | 454 ++++++++++++++++++++++++++++++++++++++++ hassws/message_types.go | 3 - hassws/server.go | 24 ++- 4 files changed, 502 insertions(+), 10 deletions(-) create mode 100644 hassws/client_test.go diff --git a/hassws/client.go b/hassws/client.go index 2d5619e..789d6a2 100644 --- a/hassws/client.go +++ b/hassws/client.go @@ -179,11 +179,22 @@ func (c *Client) authenticate() error { func (c *Client) Close() error { c.setState(stateDisconnected) + // Closing a client that was never connected (or already shut down) is a + // no-op rather than a nil-pointer panic. + if c.conn == nil { + return nil + } + return c.writeMessage(c.conn, websocket.CloseMessage, websocket.FormatCloseMessage(websocket.CloseNormalClosure, "bye")) } func (c *Client) shutdown() error { c.setState(stateDisconnected) + + if c.conn == nil { + return nil + } + return c.conn.Close() } @@ -381,6 +392,10 @@ func (c *Client) nextMsgID() int { // Read a message from the websocket and unmarshal it into the target. func (c *Client) read(target any) error { + if c.conn == nil { + return ErrNotConnected + } + _, msgBytes, err := c.conn.ReadMessage() if err != nil { return err @@ -413,6 +428,10 @@ func (c *Client) send(msg any) error { return err } + if c.conn == nil { + return ErrNotConnected + } + logger.DebugJSON("Writing message", "", string(msgBytes)) return c.writeMessage(c.conn, websocket.TextMessage, msgBytes) @@ -449,6 +468,10 @@ func (c *Client) sendMessageStreamResponses(msgBytes []byte) (ch chan []byte, er ch = c.addMessageResponseListener(msgID) if err := c.send(msg); err != nil { + // Send failed, so no response will ever arrive; drop the listener we + // just registered instead of leaking it in the responses map. + c.removeMessageResponseListener(msgID) + return nil, err } @@ -467,11 +490,11 @@ func (c *Client) sendMessageWaitResponse(msgBytes []byte) (response []byte, err close(responseChan) }() - return c.readMesssageFromChannel(responseChan) + return c.readMessageFromChannel(responseChan) } // Read a message from a listener channel. -func (c *Client) readMesssageFromChannel(ch chan []byte) (response []byte, err error) { +func (c *Client) readMessageFromChannel(ch chan []byte) (response []byte, err error) { select { case res := <-ch: return res, nil @@ -499,7 +522,7 @@ func (c *Client) SubscribeEvents(eventType string, handler func(EventMessage)) e } // First message contains the initial response about the subscription - resBytes, err := c.readMesssageFromChannel(responseChan) + resBytes, err := c.readMessageFromChannel(responseChan) if err != nil { close(responseChan) @@ -559,7 +582,7 @@ func (c *Client) SubscribeEventsRaw(eventType string, handler func([]byte)) erro return err } - resBytes, err := c.readMesssageFromChannel(responseChan) + resBytes, err := c.readMessageFromChannel(responseChan) if err != nil { close(responseChan) diff --git a/hassws/client_test.go b/hassws/client_test.go new file mode 100644 index 0000000..0fc893e --- /dev/null +++ b/hassws/client_test.go @@ -0,0 +1,454 @@ +package hassws + +import ( + "bytes" + "sync" + "sync/atomic" + "testing" + "time" + + "github.com/dansimau/hal/homeassistant" + "gotest.tools/v3/assert" +) + +const testUserID = "d8e8fca2dc0f896fd7cb4cb0031ba249" + +// newTestClient creates a mock server and a client configured to reach it. The +// client is NOT connected yet, so callers can set up callbacks (e.g. +// SetOnDisconnected) before connecting. The server is closed on test cleanup. +func newTestClient(t *testing.T, cfg ClientConfig) (*Client, *Server) { + t.Helper() + + server, err := NewServer(map[string]string{"test-token": testUserID}) + assert.NilError(t, err) + + t.Cleanup(func() { _ = server.Close() }) + + if cfg.Host == "" { + cfg.Host = server.ListenAddress() + } + + if cfg.Token == "" { + cfg.Token = "test-token" + } + + return NewClient(cfg), server +} + +// connect connects the client and registers a graceful close on cleanup. +func connect(t *testing.T, c *Client) { + t.Helper() + + assert.NilError(t, c.Connect()) + + t.Cleanup(func() { _ = c.Close() }) +} + +// waitForCond polls fn until it returns true or the timeout elapses. +func waitForCond(t *testing.T, name string, fn func() bool) { + t.Helper() + + deadline := time.After(3 * time.Second) + + for { + select { + case <-deadline: + t.Fatalf("timed out waiting for: %s", name) + default: + if fn() { + return + } + + time.Sleep(20 * time.Millisecond) + } + } +} + +// --- Pure unit tests (no connection) --- + +func TestNextMsgID(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + assert.Equal(t, c.nextMsgID(), 1) + assert.Equal(t, c.nextMsgID(), 2) + assert.Equal(t, c.nextMsgID(), 3) +} + +func TestGetStateDefaultAndSet(t *testing.T) { + t.Parallel() + + // A zero-value client has never had its state set; getState must not panic + // and should report disconnected. + c := &Client{} + assert.Equal(t, c.getState(), stateDisconnected) + + c.setState(stateConnected) + assert.Equal(t, c.getState(), stateConnected) + + c.setState(stateConnecting) + assert.Equal(t, c.getState(), stateConnecting) +} + +func TestCallServiceNotConnected(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + _, err := c.CallService(CallServiceRequest{ + Type: MessageTypeCallService, + Domain: "light", + Service: "turn_on", + Data: map[string]any{"entity_id": []string{"light.test"}}, + }) + assert.ErrorIs(t, err, ErrNotConnected) +} + +func TestGetStatesNotConnected(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + _, err := c.GetStates() + assert.ErrorIs(t, err, ErrNotConnected) +} + +func TestSendMarshalError(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + // channels cannot be marshalled to JSON, so send returns the marshal error + // before ever touching the connection. + err := c.send(make(chan int)) + assert.Assert(t, err != nil) +} + +func TestSendNotConnected(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + // A marshalable message on a client that never connected must return + // ErrNotConnected rather than panicking on a nil conn. + err := c.send(CommandMessage{ID: 1, Type: MessageTypePing}) + assert.ErrorIs(t, err, ErrNotConnected) +} + +func TestSendMessageStreamResponsesInvalidJSON(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + _, err := c.sendMessageStreamResponses([]byte("not json")) + assert.Assert(t, err != nil) +} + +// TestSendMessageStreamResponsesRemovesListenerOnSendFailure is a regression +// test: when the underlying send fails, the response listener registered for the +// message must be removed instead of leaking in the responses map. +func TestSendMessageStreamResponsesRemovesListenerOnSendFailure(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + // Not connected, so send fails with ErrNotConnected after the listener was + // registered. + _, err := c.sendMessageStreamResponses([]byte(`{"type":"ping"}`)) + assert.ErrorIs(t, err, ErrNotConnected) + + c.mutex.RLock() + remaining := len(c.responses) + c.mutex.RUnlock() + + assert.Equal(t, remaining, 0) +} + +func TestReadMessageFromChannel(t *testing.T) { + t.Parallel() + + t.Run("returns a buffered message", func(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + ch := make(chan []byte, 1) + ch <- []byte("hello") + + res, err := c.readMessageFromChannel(ch) + assert.NilError(t, err) + assert.Equal(t, string(res), "hello") + }) + + t.Run("times out on an empty channel", func(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + _, err := c.readMessageFromChannel(make(chan []byte)) + assert.ErrorIs(t, err, ErrReadTimeout) + }) +} + +func TestCloseWithoutConnect(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + // Closing a client that never connected is a no-op, not a nil-pointer panic. + assert.NilError(t, c.Close()) + assert.Equal(t, c.getState(), stateDisconnected) +} + +func TestReadWithoutConnect(t *testing.T) { + t.Parallel() + + c := NewClient(ClientConfig{}) + + err := c.read(&AuthChallenge{}) + assert.ErrorIs(t, err, ErrNotConnected) +} + +// --- Integration tests (drive the mock server) --- + +func TestConnectAndAuthenticate(t *testing.T) { + t.Parallel() + + client, _ := newTestClient(t, ClientConfig{}) + connect(t, client) + + assert.Equal(t, client.getState(), stateConnected) +} + +func TestConnectDialError(t *testing.T) { + t.Parallel() + + // Nothing listening on this address, so the dial fails. + client := NewClient(ClientConfig{Host: "127.0.0.1:1", Token: "test-token"}) + + err := client.Connect() + assert.Assert(t, err != nil) + assert.Equal(t, client.getState(), stateDisconnected) +} + +func TestConnectAuthInvalid(t *testing.T) { + t.Parallel() + + server, err := NewServer(map[string]string{"real-token": testUserID}) + assert.NilError(t, err) + + t.Cleanup(func() { _ = server.Close() }) + + client := NewClient(ClientConfig{Host: server.ListenAddress(), Token: "wrong-token"}) + + err = client.Connect() + assert.ErrorIs(t, err, ErrAuthInvalid) + assert.Equal(t, client.getState(), stateDisconnected) +} + +func TestCallService(t *testing.T) { + t.Parallel() + + client, _ := newTestClient(t, ClientConfig{}) + connect(t, client) + + resp, err := client.CallService(CallServiceRequest{ + Type: MessageTypeCallService, + Domain: "light", + Service: "turn_on", + Data: map[string]any{"entity_id": []string{"light.test"}}, + }) + assert.NilError(t, err) + assert.Equal(t, resp.Success, true) +} + +func TestGetStates(t *testing.T) { + t.Parallel() + + client, _ := newTestClient(t, ClientConfig{}) + connect(t, client) + + // The mock server always returns an empty state list. + states, err := client.GetStates() + assert.NilError(t, err) + assert.Equal(t, len(states), 0) +} + +func TestSubscribeEvents(t *testing.T) { + t.Parallel() + + client, server := newTestClient(t, ClientConfig{}) + connect(t, client) + + var ( + mu sync.Mutex + received []EventMessage + ) + + err := client.SubscribeEvents("", func(m EventMessage) { + mu.Lock() + received = append(received, m) + mu.Unlock() + }) + assert.NilError(t, err) + + waitForCond(t, "subscription registered", func() bool { + return server.GetSubscriptionCount() >= 1 + }) + + server.SendEvent(homeassistant.Event{ + EventType: "state_changed", + EventData: homeassistant.EventData{ + EntityID: "light.test", + NewState: &homeassistant.State{State: "on"}, + }, + }) + + waitForCond(t, "event delivered to handler", func() bool { + mu.Lock() + defer mu.Unlock() + + return len(received) == 1 + }) + + mu.Lock() + defer mu.Unlock() + + assert.Equal(t, received[0].Event.EventData.EntityID, "light.test") +} + +func TestSubscribeEventsRaw(t *testing.T) { + t.Parallel() + + client, server := newTestClient(t, ClientConfig{}) + connect(t, client) + + var ( + mu sync.Mutex + received [][]byte + ) + + err := client.SubscribeEventsRaw("", func(b []byte) { + mu.Lock() + received = append(received, b) + mu.Unlock() + }) + assert.NilError(t, err) + + waitForCond(t, "subscription registered", func() bool { + return server.GetSubscriptionCount() >= 1 + }) + + server.SendEvent(homeassistant.Event{ + EventType: "state_changed", + EventData: homeassistant.EventData{ + EntityID: "light.test", + NewState: &homeassistant.State{State: "on"}, + }, + }) + + waitForCond(t, "raw event delivered to handler", func() bool { + mu.Lock() + defer mu.Unlock() + + return len(received) == 1 + }) + + mu.Lock() + defer mu.Unlock() + + assert.Assert(t, bytes.Contains(received[0], []byte("light.test"))) +} + +// TestHeartbeatKeepsConnectionAlive verifies that the heartbeat pings (and the +// pong responses that reset the read deadline) keep a quiet connection alive +// well past the read timeout. +func TestHeartbeatKeepsConnectionAlive(t *testing.T) { + t.Parallel() + + client, _ := newTestClient(t, ClientConfig{ + PingInterval: 100 * time.Millisecond, + ReadTimeout: 600 * time.Millisecond, + }) + connect(t, client) + + // Wait through several ping intervals. If pings/pongs were not flowing, the + // read deadline would fire and the client would disconnect. + time.Sleep(400 * time.Millisecond) + + assert.Equal(t, client.getState(), stateConnected) +} + +// TestStaleConnectionTriggersDisconnect verifies that when the server stops +// responding (no pongs), the read deadline expires and the client disconnects. +func TestStaleConnectionTriggersDisconnect(t *testing.T) { + t.Parallel() + + client, server := newTestClient(t, ClientConfig{ + PingInterval: 100 * time.Millisecond, + ReadTimeout: 300 * time.Millisecond, + }) + + server.SetRespondToPings(false) + + var disconnected atomic.Bool + + // Set the callback before connecting so the listen goroutine observes it. + client.SetOnDisconnected(func() { disconnected.Store(true) }) + + assert.NilError(t, client.Connect()) + + t.Cleanup(func() { _ = client.Close() }) + + waitForCond(t, "disconnect on stale connection", func() bool { + return disconnected.Load() + }) + + assert.Equal(t, client.getState(), stateDisconnected) +} + +// TestForcedDisconnect verifies that an ungraceful socket close is detected and +// surfaces through the onDisconnected callback. +func TestForcedDisconnect(t *testing.T) { + t.Parallel() + + client, server := newTestClient(t, ClientConfig{}) + + var disconnected atomic.Bool + + client.SetOnDisconnected(func() { disconnected.Store(true) }) + + assert.NilError(t, client.Connect()) + + t.Cleanup(func() { _ = client.Close() }) + + assert.NilError(t, server.DisconnectClient()) + + waitForCond(t, "disconnect detected", func() bool { + return disconnected.Load() + }) + + assert.Equal(t, client.getState(), stateDisconnected) +} + +// TestGracefulServerClose verifies that a normal websocket close frame from the +// server drives the client's shutdown path. +func TestGracefulServerClose(t *testing.T) { + t.Parallel() + + client, server := newTestClient(t, ClientConfig{}) + + var disconnected atomic.Bool + + client.SetOnDisconnected(func() { disconnected.Store(true) }) + + assert.NilError(t, client.Connect()) + + assert.NilError(t, server.Close()) + + waitForCond(t, "disconnect after graceful close", func() bool { + return disconnected.Load() + }) + + assert.Equal(t, client.getState(), stateDisconnected) +} diff --git a/hassws/message_types.go b/hassws/message_types.go index 57048e6..2fee195 100644 --- a/hassws/message_types.go +++ b/hassws/message_types.go @@ -7,9 +7,6 @@ import ( ) const ( - MessageTypeAuthChallenge MessageType = "auth_challenge" - MessageTypeAuthRequest MessageType = "auth_request" - MessageTypeAuthResponse MessageType = "auth_response" MessageTypeCallService MessageType = "call_service" MessageTypeEvent MessageType = "event" MessageTypeGetStates MessageType = "get_states" diff --git a/hassws/server.go b/hassws/server.go index 658b5c9..6d1a0b2 100644 --- a/hassws/server.go +++ b/hassws/server.go @@ -78,7 +78,10 @@ func (s *Server) handler(w http.ResponseWriter, r *http.Request) { return } + s.lock.Lock() s.websocket = conn + s.lock.Unlock() + defer conn.Close() if err := s.handleAuthentication(conn); err != nil { @@ -220,13 +223,23 @@ func (s *Server) listen() { } } +// writeJSON serializes a JSON write to the client connection under the same +// lock as SendMessage. Gorilla forbids concurrent writers, so every write path +// (auth handshake, SendMessage, Close) must share this lock to stay race-free. +func (s *Server) writeJSON(conn *websocket.Conn, v any) error { + s.lock.Lock() + defer s.lock.Unlock() + + return conn.WriteJSON(v) +} + func (s *Server) handleAuthentication(conn *websocket.Conn) error { // Send auth_required message authChallenge := AuthChallenge{ Type: "auth_required", HAVersion: "2024.1.0", } - if err := conn.WriteJSON(authChallenge); err != nil { + if err := s.writeJSON(conn, authChallenge); err != nil { return err } @@ -244,7 +257,7 @@ func (s *Server) handleAuthentication(conn *websocket.Conn) error { Message: "Invalid access token", HAVersion: "2024.1.0", } - return conn.WriteJSON(authResp) + return s.writeJSON(conn, authResp) } // Store authenticated user ID @@ -255,10 +268,13 @@ func (s *Server) handleAuthentication(conn *websocket.Conn) error { HAVersion: "2024.1.0", } - return conn.WriteJSON(authResp) + return s.writeJSON(conn, authResp) } func (s *Server) Close() error { + s.lock.Lock() + defer s.lock.Unlock() + return s.websocket.WriteMessage( websocket.CloseMessage, websocket.FormatCloseMessage(websocket.CloseNormalClosure, "bye"), @@ -284,9 +300,11 @@ func (s *Server) DisconnectClient() error { func (s *Server) shutdown() error { var errs []error + s.lock.Lock() if s.websocket != nil { errs = append(errs, s.websocket.Close()) } + s.lock.Unlock() if s.http != nil { errs = append(errs, s.http.Close()) From 38957d49e77fef9f1fd0620d485870cd8726d30e Mon Sep 17 00:00:00 2001 From: Claude Date: Sat, 18 Jul 2026 18:46:59 +0000 Subject: [PATCH 3/5] Extend test coverage across logger, commands, perf, and entities Raises the cross-package total (make test metric, -coverpkg=./...) from ~72% to ~84% by covering previously untested code: - logger (34.6% -> 85%): colorDiff/prettifyJSON, InfoDiff/DebugJSON, the *Context wrappers and context extraction helpers, Start/Stop lifecycle, pruneLogs, and the global convenience wrappers. - cmd/hal/commands (24% -> 70%): command constructors, printLogs, printEntitiesTable, printEntityStateJSON, makeEmitter, prune-flag validation, and the runEntities/runLogs/runShowEntity/runPruneLogs paths (driven against a throwaway DB via a temp working dir). - perf (0% -> 100%): Timer. - root hal: findEntities/FindEntities reflection walker and the service-call error branches of Light/LightGroup/InputBoolean when the connection is not connected. - automations: PrintDebug and the sensor-lights builder methods (WithCondition, WithConditionScene, TurnsOnLights/OffLights, SetScene). Tests only; no production code changed. Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01MCZq8eURnwy99CRfcb71CA --- automations/builders_test.go | 51 ++++++ cmd/hal/commands/commands_test.go | 213 ++++++++++++++++++++++++ entities_internal_test.go | 79 +++++++++ entity_service_error_test.go | 54 ++++++ logger/context_diff_test.go | 268 ++++++++++++++++++++++++++++++ perf/timer_test.go | 25 +++ 6 files changed, 690 insertions(+) create mode 100644 automations/builders_test.go create mode 100644 cmd/hal/commands/commands_test.go create mode 100644 entities_internal_test.go create mode 100644 entity_service_error_test.go create mode 100644 logger/context_diff_test.go create mode 100644 perf/timer_test.go diff --git a/automations/builders_test.go b/automations/builders_test.go new file mode 100644 index 0000000..04e3791 --- /dev/null +++ b/automations/builders_test.go @@ -0,0 +1,51 @@ +package halautomations_test + +import ( + "context" + "testing" + + "github.com/dansimau/hal" + halautomations "github.com/dansimau/hal/automations" + "gotest.tools/v3/assert" +) + +func TestPrintDebug(t *testing.T) { + t.Parallel() + + light := hal.NewLight("light.a") + pd := halautomations.NewPrintDebug("debug", light) + + assert.Equal(t, pd.Name(), "debug") + assert.Equal(t, len(pd.Entities()), 1) + assert.Equal(t, pd.Entities()[0].GetID(), "light.a") + + // Action just logs the current state; call it to cover the loop. + pd.Action(context.Background(), light) +} + +func TestSensorLightsBuilders(t *testing.T) { + t.Parallel() + + sensor := hal.NewBinarySensor("binary_sensor.a") + onLight := hal.NewLight("light.on") + offLight := hal.NewLight("light.off") + + a := halautomations.NewSensorsTriggerLights(). + WithName("test"). + WithSensors(sensor). + TurnsOnLights(onLight). + TurnsOffLights(offLight). + WithCondition(func() bool { return true }). + WithConditionScene(func() bool { return false }, map[string]any{"brightness": 10}). + SetScene(map[string]any{"brightness": 200}) + + assert.Equal(t, a.Name(), "test") + + ids := make(map[string]bool) + for _, e := range a.Entities() { + ids[e.GetID()] = true + } + + assert.Assert(t, ids["binary_sensor.a"]) + assert.Assert(t, ids["light.on"]) +} diff --git a/cmd/hal/commands/commands_test.go b/cmd/hal/commands/commands_test.go new file mode 100644 index 0000000..c3ee334 --- /dev/null +++ b/cmd/hal/commands/commands_test.go @@ -0,0 +1,213 @@ +package commands + +import ( + "os" + "strings" + "testing" + "time" + + "github.com/dansimau/hal/homeassistant" + "github.com/dansimau/hal/store" + "gotest.tools/v3/assert" +) + +// chdirTemp switches into a fresh temp dir for the duration of the test so +// commands that open the hardcoded "sqlite.db" path operate on a throwaway +// database. os.Chdir is process-wide, so these tests must not run in parallel. +func chdirTemp(t *testing.T) { + t.Helper() + + oldWd, err := os.Getwd() + assert.NilError(t, err) + + assert.NilError(t, os.Chdir(t.TempDir())) + + t.Cleanup(func() { _ = os.Chdir(oldWd) }) +} + +func TestNewLogsCmd(t *testing.T) { + cmd := NewLogsCmd() + + assert.Equal(t, cmd.Use, "logs") + assert.Assert(t, len(cmd.Aliases) > 0) + assert.Assert(t, cmd.Flags().Lookup("from") != nil) + assert.Assert(t, cmd.Flags().Lookup("last") != nil) + assert.Assert(t, cmd.Flags().Lookup("entity-id") != nil) +} + +func TestNewEntitiesCmd(t *testing.T) { + cmd := NewEntitiesCmd() + + assert.Equal(t, cmd.Use, "entities") + assert.Assert(t, len(cmd.Commands()) > 0) // has the "show" subcommand +} + +func TestNewPruneCmd(t *testing.T) { + cmd := NewPruneCmd() + + assert.Equal(t, cmd.Use, "prune") + assert.Assert(t, len(cmd.Commands()) > 0) // has the "logs" subcommand +} + +func TestNewEventsCmd(t *testing.T) { + cmd := NewEventsCmd() + + assert.Equal(t, cmd.Use, "events") + assert.Assert(t, cmd.Flags().Lookup("exclude") != nil) + assert.Assert(t, cmd.Flags().Lookup("jq") != nil) +} + +func TestPruneLogsCmdValidation(t *testing.T) { + t.Run("requires a flag", func(t *testing.T) { + cmd := NewPruneLogsCmd() + cmd.SetArgs([]string{}) + + err := cmd.Execute() + assert.ErrorContains(t, err, "either --last or --before") + }) + + t.Run("rejects both flags", func(t *testing.T) { + cmd := NewPruneLogsCmd() + cmd.SetArgs([]string{"--last", "1d", "--before", "2024-01-01"}) + + err := cmd.Execute() + assert.ErrorContains(t, err, "cannot use both") + }) +} + +func TestPrintLogs(t *testing.T) { + t.Run("empty prints message", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, printLogs(nil, true)) + }) + assert.Assert(t, strings.Contains(out, "No logs found")) + }) + + t.Run("renders entries", func(t *testing.T) { + logs := []store.Log{ + {Timestamp: time.Now(), Level: "INFO", EntityID: "light.kitchen", LogText: "single line"}, + {Timestamp: time.Now(), Level: "ERROR", LogText: "first line\nsecond line"}, + } + + out := captureOutput(func() { + assert.NilError(t, printLogs(logs, true)) + }) + + assert.Assert(t, strings.Contains(out, "single line")) + assert.Assert(t, strings.Contains(out, "light.kitchen")) + assert.Assert(t, strings.Contains(out, "second line")) + }) +} + +func TestPrintEntitiesTable(t *testing.T) { + t.Run("empty prints message", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, printEntitiesTable(nil)) + }) + assert.Assert(t, strings.Contains(out, "No entities found")) + }) + + t.Run("renders rows", func(t *testing.T) { + entities := []EntitySummary{ + {ID: "light.kitchen", LastUpdate: time.Now(), LogCount: 5}, + } + + out := captureOutput(func() { + assert.NilError(t, printEntitiesTable(entities)) + }) + + assert.Assert(t, strings.Contains(out, "light.kitchen")) + }) +} + +func TestPrintEntityStateJSON(t *testing.T) { + entity := store.Entity{ + ID: "light.kitchen", + State: &homeassistant.State{ + EntityID: "light.kitchen", + State: "on", + }, + } + + out := captureOutput(func() { + assert.NilError(t, printEntityStateJSON(entity)) + }) + + assert.Assert(t, strings.Contains(out, "light.kitchen")) + assert.Assert(t, strings.Contains(out, "on")) +} + +func TestMakeEmitterPlain(t *testing.T) { + emit, cleanup, err := makeEmitter("") + assert.NilError(t, err) + defer cleanup() + + out := captureOutput(func() { + emit([]byte(`{"a":1}`)) // valid JSON, gets indented + emit([]byte("not json")) // invalid, written as-is + }) + + assert.Assert(t, strings.Contains(out, "\"a\": 1")) + assert.Assert(t, strings.Contains(out, "not json")) +} + +func TestRunEntitiesCommandEmpty(t *testing.T) { + chdirTemp(t) + + out := captureOutput(func() { + assert.NilError(t, runEntitiesCommand()) + }) + + assert.Assert(t, strings.Contains(out, "No entities found")) +} + +func TestRunLogsCommandEmpty(t *testing.T) { + chdirTemp(t) + + out := captureOutput(func() { + assert.NilError(t, runLogsCommand("", "", "", "", true)) + }) + + assert.Assert(t, strings.Contains(out, "No logs found")) +} + +func TestRunLogsCommandInvalidDuration(t *testing.T) { + chdirTemp(t) + + err := runLogsCommand("", "", "notaduration", "", true) + assert.ErrorContains(t, err, "invalid duration") +} + +func TestRunShowEntityCommandNotFound(t *testing.T) { + chdirTemp(t) + + err := runShowEntityCommand("light.missing") + assert.ErrorContains(t, err, "entity not found") +} + +func TestRunPruneLogsCommand(t *testing.T) { + t.Run("by duration", func(t *testing.T) { + chdirTemp(t) + + out := captureOutput(func() { + assert.NilError(t, runPruneLogsCommand("1d", "")) + }) + assert.Assert(t, strings.Contains(out, "Deleted")) + }) + + t.Run("by before date", func(t *testing.T) { + chdirTemp(t) + + out := captureOutput(func() { + assert.NilError(t, runPruneLogsCommand("", "2024-01-01")) + }) + assert.Assert(t, strings.Contains(out, "Deleted")) + }) + + t.Run("invalid duration", func(t *testing.T) { + chdirTemp(t) + + err := runPruneLogsCommand("bogus", "") + assert.ErrorContains(t, err, "invalid duration") + }) +} diff --git a/entities_internal_test.go b/entities_internal_test.go new file mode 100644 index 0000000..de29547 --- /dev/null +++ b/entities_internal_test.go @@ -0,0 +1,79 @@ +package hal + +import "testing" + +func TestFindEntities(t *testing.T) { + t.Parallel() + + type nested struct { + Extra *Light + } + + type home struct { + Light *Light + Sensor *BinarySensor + secret *Light // unexported: must be skipped + Nested nested + Group []*Light + ByName map[string]*Light + NilPtr *Light // nil: must be skipped + } + + h := home{ + Light: NewLight("light.a"), + Sensor: NewBinarySensor("binary_sensor.b"), + secret: NewLight("light.secret"), + Nested: nested{Extra: NewLight("light.c")}, + Group: []*Light{NewLight("light.d")}, + ByName: map[string]*Light{"x": NewLight("light.e")}, + } + + // Reference the unexported field so it is not flagged as unused. + _ = h.secret + + found := findEntities(&h) + + ids := make(map[string]bool) + for _, e := range found { + ids[e.GetID()] = true + } + + for _, want := range []string{"light.a", "binary_sensor.b", "light.c", "light.d", "light.e"} { + if !ids[want] { + t.Errorf("expected to find %q, got %v", want, ids) + } + } + + if ids["light.secret"] { + t.Error("unexported field should not be discovered") + } + + if len(found) != 5 { + t.Errorf("expected 5 entities, got %d (%v)", len(found), ids) + } +} + +func TestFindEntitiesNonStruct(t *testing.T) { + t.Parallel() + + // A non-struct value yields no entities and must not panic. + if got := findEntities(42); len(got) != 0 { + t.Errorf("expected no entities for non-struct, got %d", len(got)) + } +} + +func TestConnectionFindEntities(t *testing.T) { + t.Parallel() + + conn := NewConnection(Config{DatabasePath: ":memory:"}) + + type home struct { + Light *Light + } + + conn.FindEntities(&home{Light: NewLight("light.z")}) + + if _, ok := conn.entities["light.z"]; !ok { + t.Error("expected light.z to be registered") + } +} diff --git a/entity_service_error_test.go b/entity_service_error_test.go new file mode 100644 index 0000000..a939be1 --- /dev/null +++ b/entity_service_error_test.go @@ -0,0 +1,54 @@ +package hal_test + +import ( + "context" + "testing" + + "github.com/dansimau/hal" + "gotest.tools/v3/assert" +) + +// TestEntityServiceCallErrors exercises the service-call error branches: the +// entities are registered (so the nil-connection guard passes) but the +// connection's client is never connected, so CallService returns an error. +func TestEntityServiceCallErrors(t *testing.T) { + t.Parallel() + + conn := hal.NewConnection(hal.Config{DatabasePath: ":memory:"}) + + light := hal.NewLight("light.err") + sw := hal.NewInputBoolean("input_boolean.err") + conn.RegisterEntities(light, sw) + + ctx := context.Background() + + assert.Assert(t, light.TurnOn() != nil) + assert.Assert(t, light.TurnOnContext(ctx) != nil) + assert.Assert(t, light.TurnOff() != nil) + assert.Assert(t, light.TurnOffContext(ctx) != nil) + + assert.Assert(t, sw.TurnOn() != nil) + assert.Assert(t, sw.TurnOff() != nil) +} + +// TestLightGroupServiceCallErrors exercises the LightGroup error aggregation +// paths against registered-but-disconnected lights. +func TestLightGroupServiceCallErrors(t *testing.T) { + t.Parallel() + + conn := hal.NewConnection(hal.Config{DatabasePath: ":memory:"}) + + light1 := hal.NewLight("light.g1") + light2 := hal.NewLight("light.g2") + conn.RegisterEntities(light1, light2) + + group := hal.LightGroup{light1, light2} + + ctx := context.Background() + + // Two failing lights exercise the errors.Join branch. + assert.Assert(t, group.TurnOn() != nil) + assert.Assert(t, group.TurnOnContext(ctx) != nil) + assert.Assert(t, group.TurnOff() != nil) + assert.Assert(t, group.TurnOffContext(ctx) != nil) +} diff --git a/logger/context_diff_test.go b/logger/context_diff_test.go new file mode 100644 index 0000000..849e2bf --- /dev/null +++ b/logger/context_diff_test.go @@ -0,0 +1,268 @@ +package logger + +import ( + "context" + "log/slog" + "strings" + "testing" + "time" + + "github.com/dansimau/hal/store" +) + +func TestColorDiff(t *testing.T) { + diff := "context line\n+added line\n-removed line" + + out := colorDiff(diff) + + // Regardless of whether color codes are emitted, the original text must be + // preserved and all three line kinds handled without panicking. + if !strings.Contains(out, "added line") { + t.Errorf("expected output to contain added line, got %q", out) + } + if !strings.Contains(out, "removed line") { + t.Errorf("expected output to contain removed line, got %q", out) + } + if !strings.Contains(out, "context line") { + t.Errorf("expected output to contain context line, got %q", out) + } +} + +func TestPrettifyJSON(t *testing.T) { + t.Run("valid JSON is indented", func(t *testing.T) { + colored, plain := prettifyJSON(`{"a":1,"b":2}`) + + if !strings.Contains(plain, "\n") { + t.Errorf("expected plain output to be indented, got %q", plain) + } + if colored == "" { + t.Error("expected colored output to be non-empty") + } + }) + + t.Run("invalid JSON returns original for both", func(t *testing.T) { + colored, plain := prettifyJSON("not json") + + if colored != "not json" || plain != "not json" { + t.Errorf("expected original string for invalid JSON, got colored=%q plain=%q", colored, plain) + } + }) +} + +func TestInfoDiffWritesToDatabase(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + service := NewServiceWithDB(db) + + service.InfoDiff("state changed", "light.kitchen", "-old\n+new", "reason", "manual") + + db.WaitForWrites() + + var logs []store.Log + if err := db.Find(&logs).Error; err != nil { + t.Fatalf("Failed to query logs: %v", err) + } + + if len(logs) != 1 { + t.Fatalf("expected 1 log, got %d", len(logs)) + } + if !strings.Contains(logs[0].LogText, "state changed") { + t.Errorf("expected message in log text, got %q", logs[0].LogText) + } + if !strings.Contains(logs[0].LogText, "+new") { + t.Errorf("expected diff in log text, got %q", logs[0].LogText) + } + if logs[0].EntityID != "light.kitchen" { + t.Errorf("expected entity id, got %q", logs[0].EntityID) + } +} + +func TestDebugJSONWritesToDatabase(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + service := NewServiceWithDB(db) + service.SetLevel(slog.LevelDebug) + + service.DebugJSON("payload", "sensor.temp", `{"value":21}`) + + db.WaitForWrites() + + var logs []store.Log + if err := db.Find(&logs).Error; err != nil { + t.Fatalf("Failed to query logs: %v", err) + } + + if len(logs) != 1 { + t.Fatalf("expected 1 log, got %d", len(logs)) + } + if !strings.Contains(logs[0].LogText, "payload") { + t.Errorf("expected message in log text, got %q", logs[0].LogText) + } + if !strings.Contains(logs[0].LogText, "\"value\": 21") { + t.Errorf("expected indented JSON in log text, got %q", logs[0].LogText) + } +} + +func TestDebugJSONBelowLevelIsNotWritten(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + // Default level is Info, so a Debug-level entry must be dropped. + service := NewServiceWithDB(db) + + service.DebugJSON("payload", "sensor.temp", `{"value":21}`) + + db.WaitForWrites() + + var count int64 + if err := db.Model(&store.Log{}).Count(&count).Error; err != nil { + t.Fatalf("Failed to count logs: %v", err) + } + if count != 0 { + t.Errorf("expected no logs below level, got %d", count) + } +} + +func TestInfoDiffBuffersWithoutDatabase(t *testing.T) { + // No database configured, so the entry lands in the in-memory buffer. + service := NewService() + + service.InfoDiff("buffered diff", "light.x", "-a\n+b") + + service.mu.RLock() + count := service.bufferCount + service.mu.RUnlock() + + if count != 1 { + t.Errorf("expected 1 buffered log, got %d", count) + } +} + +func TestContextLoggingWrites(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + service := NewServiceWithDB(db) + service.SetLevel(slog.LevelDebug) + + ctx := context.Background() + service.InfoContext(ctx, "info with ctx") + service.ErrorContext(ctx, "error with ctx") + service.DebugContext(ctx, "debug with ctx") + service.WarnContext(ctx, "warn with ctx") + + db.WaitForWrites() + + var count int64 + if err := db.Model(&store.Log{}).Count(&count).Error; err != nil { + t.Fatalf("Failed to count logs: %v", err) + } + if count != 4 { + t.Errorf("expected 4 context logs, got %d", count) + } +} + +func TestContextExtractionHelpers(t *testing.T) { + // A background context carries neither value. + if got := getEntityIDFromContext(context.Background()); got != "" { + t.Errorf("expected empty entity id, got %q", got) + } + if got := getAutomationNameFromContext(context.Background()); got != "" { + t.Errorf("expected empty automation name, got %q", got) + } +} + +func TestServiceStartStopLifecycle(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + service := NewServiceWithDB(db) + + service.Start() + service.Stop() + // Second stop is a no-op (already stopped). + service.Stop() + // Starting again must recreate the stop channel and not panic. + service.Start() + service.Stop() +} + +func TestServiceStartWithoutDatabase(t *testing.T) { + service := NewService() + + // Without a database the pruning goroutine is not started, but Start/Stop + // must still be safe to call. + service.Start() + service.Stop() +} + +func TestServicePruneLogsRemovesExpired(t *testing.T) { + db, err := store.Open(":memory:") + if err != nil { + t.Fatalf("Failed to open test database: %v", err) + } + + service := NewServiceWithDB(db) + service.pruneInterval = 30 * time.Millisecond + service.retentionTime = time.Hour + + // One expired log and one fresh log inserted directly. + if err := db.Create(&store.Log{Timestamp: time.Now().Add(-2 * time.Hour), Level: "INFO", LogText: "old"}).Error; err != nil { + t.Fatalf("Failed to insert old log: %v", err) + } + if err := db.Create(&store.Log{Timestamp: time.Now(), Level: "INFO", LogText: "new"}).Error; err != nil { + t.Fatalf("Failed to insert new log: %v", err) + } + + service.Start() + defer service.Stop() + + // Wait for a prune tick to fire and its async delete to complete. + deadline := time.After(3 * time.Second) + for { + db.WaitForWrites() + + var count int64 + if err := db.Model(&store.Log{}).Count(&count).Error; err != nil { + t.Fatalf("Failed to count logs: %v", err) + } + if count == 1 { + return + } + + select { + case <-deadline: + t.Fatalf("timed out waiting for prune; expected 1 log, got %d", count) + default: + time.Sleep(20 * time.Millisecond) + } + } +} + +func TestGlobalDiffAndContextWrappers(t *testing.T) { + // Exercise the package-level convenience wrappers. The default logger has no + // database in tests, so these just need to run without panicking. + InfoDiff("global diff", "light.x", "-a\n+b") + DebugJSON("global json", "light.x", `{"k":"v"}`) + + ctx := context.Background() + InfoContext(ctx, "global info ctx") + ErrorContext(ctx, "global error ctx") + DebugContext(ctx, "global debug ctx") + WarnContext(ctx, "global warn ctx") + + StartDefault() + StopDefault() +} diff --git a/perf/timer_test.go b/perf/timer_test.go new file mode 100644 index 0000000..4de6f7d --- /dev/null +++ b/perf/timer_test.go @@ -0,0 +1,25 @@ +package perf_test + +import ( + "testing" + "time" + + "github.com/dansimau/hal/perf" +) + +func TestTimer(t *testing.T) { + t.Parallel() + + var got time.Duration + + stop := perf.Timer(func(timeTaken time.Duration) { + got = timeTaken + }) + + time.Sleep(5 * time.Millisecond) + stop() + + if got <= 0 { + t.Errorf("expected a positive elapsed duration, got %v", got) + } +} From 3c0f5c0a5fe113182396b1cdfa2c345d720615b6 Mon Sep 17 00:00:00 2001 From: Daniel Simmons Date: Sat, 18 Jul 2026 21:58:00 +0200 Subject: [PATCH 4/5] Fix context-key logging bug and add complementary test coverage Fix a latent bug and layer additional coverage on top of the parallel "Extend test coverage" commit already on this branch. Bug: the context-aware loggers (logger.InfoContext/ErrorContext/etc.) extracted the entity ID and automation name using a function-local contextKey type, while hal.NewAutomationContext stored them under hal.contextKey. context.Value matches keys by dynamic type as well as value, so the types never compared equal and every DB log written from an automation context silently dropped its entity ID and automation name. Moved the canonical keys to exported logger.EntityIDKey/ AutomationNameKey and pointed hal/context.go at them. Complementary tests (deduped against the parallel coverage commit; overlapping files were reconciled to keep the more thorough version): - logger: populated-context regression guards for the fix (metadata reaches the DB; explicit "automation" arg not overridden by context), writeLogText level filtering, and the pruneLogs delete-error branch. - hal: nil-connection ErrEntityNotRegistered for the *Context light methods; initial state sync (syncStates) via a new SetStates hook on the mock hassws.Server; Timer New/Cancel/IsRunning/reset (mock clock). - store: AsyncWriter edge paths (enqueue before start / after shutdown, double start, error logging). - cmd/hal/commands: fuller runLogs/runEntities/runShowEntity command paths (entity/from-to filters, invalid inputs, found + seeded rows). Co-Authored-By: Claude Opus 4.8 (1M context) --- cmd/hal/commands/commands_coverage_test.go | 315 +++++++++++++++++++++ cmd/hal/commands/commands_test.go | 213 -------------- connection_sync_test.go | 71 +++++ context.go | 28 +- entity_context_notregistered_test.go | 61 ++++ hassws/client_test.go | 17 +- hassws/server.go | 30 +- logger/context_extra_test.go | 145 ++++++++++ logger/service.go | 25 +- store/async_writer_coverage_test.go | 96 +++++++ timer_coverage_test.go | 84 ++++++ 11 files changed, 844 insertions(+), 241 deletions(-) create mode 100644 cmd/hal/commands/commands_coverage_test.go delete mode 100644 cmd/hal/commands/commands_test.go create mode 100644 connection_sync_test.go create mode 100644 entity_context_notregistered_test.go create mode 100644 logger/context_extra_test.go create mode 100644 store/async_writer_coverage_test.go create mode 100644 timer_coverage_test.go diff --git a/cmd/hal/commands/commands_coverage_test.go b/cmd/hal/commands/commands_coverage_test.go new file mode 100644 index 0000000..a4c9f42 --- /dev/null +++ b/cmd/hal/commands/commands_coverage_test.go @@ -0,0 +1,315 @@ +package commands + +import ( + "os" + "strings" + "testing" + "time" + + "github.com/dansimau/hal/homeassistant" + "github.com/dansimau/hal/store" + "github.com/spf13/cobra" + "gotest.tools/v3/assert" +) + +// seedDBInDir creates a fresh sqlite.db inside dir, runs seed against it, and +// closes it so the command under test (which opens "sqlite.db" relative to cwd) +// can open it independently. +func seedDBInDir(t *testing.T, dir string, seed func(db *store.Store)) { + t.Helper() + + db, err := store.Open(dir + "/sqlite.db") + assert.NilError(t, err) + + if seed != nil { + seed(db) + db.WaitForWrites() + } + + assert.NilError(t, db.Close()) +} + +// chdir switches into dir for the duration of the test and restores the +// previous working directory on cleanup. +func chdir(t *testing.T, dir string) { + t.Helper() + + orig, err := os.Getwd() + assert.NilError(t, err) + + assert.NilError(t, os.Chdir(dir)) + t.Cleanup(func() { + assert.NilError(t, os.Chdir(orig)) + }) +} + +func TestNewEntitiesCmd(t *testing.T) { + cmd := NewEntitiesCmd() + assert.Equal(t, cmd.Use, "entities") + assert.Assert(t, len(cmd.Aliases) > 0) + + // The "show" subcommand is wired up. + var show *cobra.Command + for _, c := range cmd.Commands() { + if strings.HasPrefix(c.Use, "show") { + show = c + } + } + assert.Assert(t, show != nil) +} + +func TestPrintEntitiesTable(t *testing.T) { + t.Run("empty", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, printEntitiesTable(nil)) + }) + assert.Assert(t, strings.Contains(out, "No entities found")) + }) + + t.Run("with rows", func(t *testing.T) { + entities := []EntitySummary{ + {ID: "light.kitchen", LastUpdate: time.Date(2024, 1, 2, 3, 4, 5, 0, time.UTC), LogCount: 7}, + } + out := captureOutput(func() { + assert.NilError(t, printEntitiesTable(entities)) + }) + assert.Assert(t, strings.Contains(out, "light.kitchen")) + assert.Assert(t, strings.Contains(out, "2024-01-02 03:04:05")) + assert.Assert(t, strings.Contains(out, "7")) + }) +} + +func TestPrintEntityStateJSON(t *testing.T) { + entity := store.Entity{ + ID: "light.kitchen", + State: &homeassistant.State{ + EntityID: "light.kitchen", + State: "on", + }, + } + out := captureOutput(func() { + assert.NilError(t, printEntityStateJSON(entity)) + }) + assert.Assert(t, strings.Contains(out, "light.kitchen")) + assert.Assert(t, strings.Contains(out, "on")) +} + +func TestRunEntitiesCommand(t *testing.T) { + dir := t.TempDir() + seedDBInDir(t, dir, func(db *store.Store) { + assert.NilError(t, db.Create(&store.Entity{ + ID: "light.kitchen", + State: &homeassistant.State{EntityID: "light.kitchen", State: "on"}, + }).Error) + assert.NilError(t, db.Create(&store.Log{ + Timestamp: time.Now(), Level: "INFO", EntityID: "light.kitchen", LogText: "hi", + }).Error) + }) + chdir(t, dir) + + out := captureOutput(func() { + assert.NilError(t, runEntitiesCommand()) + }) + assert.Assert(t, strings.Contains(out, "light.kitchen")) +} + +func TestRunShowEntityCommand(t *testing.T) { + dir := t.TempDir() + seedDBInDir(t, dir, func(db *store.Store) { + assert.NilError(t, db.Create(&store.Entity{ + ID: "light.kitchen", + State: &homeassistant.State{EntityID: "light.kitchen", State: "on"}, + }).Error) + }) + chdir(t, dir) + + out := captureOutput(func() { + assert.NilError(t, runShowEntityCommand("light.kitchen")) + }) + assert.Assert(t, strings.Contains(out, "on")) + + // Unknown entity is an error. + err := runShowEntityCommand("light.missing") + assert.Assert(t, err != nil) +} + +func TestNewLogsCmd(t *testing.T) { + cmd := NewLogsCmd() + assert.Equal(t, cmd.Use, "logs") + // All documented flags are registered. + for _, name := range []string{"from", "to", "last", "entity-id", "no-color"} { + assert.Assert(t, cmd.Flags().Lookup(name) != nil, "missing flag %q", name) + } +} + +func TestPrintLogs(t *testing.T) { + t.Run("empty", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, printLogs(nil, true)) + }) + assert.Assert(t, strings.Contains(out, "No logs found")) + }) + + t.Run("renders levels, entity and multiline diff", func(t *testing.T) { + ts := time.Date(2024, 5, 6, 7, 8, 9, 0, time.UTC) + logs := []store.Log{ + {Timestamp: ts, Level: "INFO", EntityID: "light.kitchen", LogText: "turned on foo=bar"}, + {Timestamp: ts, Level: "ERROR", LogText: "boom"}, + {Timestamp: ts, Level: "WARN", LogText: "state changed\n-off\n+on"}, + {Timestamp: ts, Level: "DEBUG", LogText: "payload\n{\"k\": 1}"}, + } + // noColor=true so output is plain and easy to assert on. + out := captureOutput(func() { + assert.NilError(t, printLogs(logs, true)) + }) + assert.Assert(t, strings.Contains(out, "2024-05-06 07:08:09")) + assert.Assert(t, strings.Contains(out, "INFO")) + assert.Assert(t, strings.Contains(out, "[light.kitchen]")) + assert.Assert(t, strings.Contains(out, "turned on foo=bar")) + assert.Assert(t, strings.Contains(out, "-off")) + assert.Assert(t, strings.Contains(out, "+on")) + assert.Assert(t, strings.Contains(out, "\"k\": 1")) + }) +} + +func TestRunLogsCommand(t *testing.T) { + dir := t.TempDir() + seedDBInDir(t, dir, func(db *store.Store) { + assert.NilError(t, db.Create(&store.Log{ + Timestamp: time.Now(), Level: "INFO", EntityID: "light.kitchen", LogText: "recent", + }).Error) + assert.NilError(t, db.Create(&store.Log{ + Timestamp: time.Now().Add(-48 * time.Hour), Level: "INFO", LogText: "old", + }).Error) + }) + chdir(t, dir) + + t.Run("last filter", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, runLogsCommand("", "", "1h", "", true)) + }) + assert.Assert(t, strings.Contains(out, "recent")) + assert.Assert(t, !strings.Contains(out, "old")) + }) + + t.Run("entity filter", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, runLogsCommand("", "", "", "light.kitchen", true)) + }) + assert.Assert(t, strings.Contains(out, "recent")) + }) + + t.Run("from/to range", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, runLogsCommand("2000-01-01", "2100-01-01", "", "", true)) + }) + assert.Assert(t, strings.Contains(out, "recent")) + assert.Assert(t, strings.Contains(out, "old")) + }) + + t.Run("invalid duration", func(t *testing.T) { + err := runLogsCommand("", "", "notaduration", "", true) + assert.Assert(t, err != nil) + }) + + t.Run("invalid from", func(t *testing.T) { + err := runLogsCommand("nope", "", "", "", true) + assert.Assert(t, err != nil) + }) + + t.Run("invalid to", func(t *testing.T) { + err := runLogsCommand("", "nope", "", "", true) + assert.Assert(t, err != nil) + }) +} + +func TestNewPruneCmd(t *testing.T) { + cmd := NewPruneCmd() + assert.Equal(t, cmd.Use, "prune") + + // "logs" subcommand exists. + var logsCmd *cobra.Command + for _, c := range cmd.Commands() { + if c.Use == "logs" { + logsCmd = c + } + } + assert.Assert(t, logsCmd != nil) +} + +func TestPruneLogsCmdFlagValidation(t *testing.T) { + t.Run("requires a flag", func(t *testing.T) { + cmd := NewPruneLogsCmd() + cmd.SetArgs(nil) + err := cmd.Execute() + assert.Assert(t, err != nil) + assert.Assert(t, strings.Contains(err.Error(), "required")) + }) + + t.Run("rejects both flags", func(t *testing.T) { + cmd := NewPruneLogsCmd() + cmd.SetArgs([]string{"--last", "1d", "--before", "2024-01-01"}) + err := cmd.Execute() + assert.Assert(t, err != nil) + assert.Assert(t, strings.Contains(err.Error(), "cannot use both")) + }) +} + +func TestRunPruneLogsCommand(t *testing.T) { + dir := t.TempDir() + seedDBInDir(t, dir, func(db *store.Store) { + assert.NilError(t, db.Create(&store.Log{ + Timestamp: time.Now().Add(-48 * time.Hour), Level: "INFO", LogText: "old", + }).Error) + assert.NilError(t, db.Create(&store.Log{ + Timestamp: time.Now(), Level: "INFO", LogText: "new", + }).Error) + }) + chdir(t, dir) + + t.Run("prune by last", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, runPruneLogsCommand("1d", "")) + }) + assert.Assert(t, strings.Contains(out, "Deleted 1 log entries")) + }) + + t.Run("invalid duration", func(t *testing.T) { + err := runPruneLogsCommand("notaduration", "") + assert.Assert(t, err != nil) + }) + + t.Run("invalid before", func(t *testing.T) { + err := runPruneLogsCommand("", "not-a-date") + assert.Assert(t, err != nil) + }) + + t.Run("prune by before", func(t *testing.T) { + out := captureOutput(func() { + assert.NilError(t, runPruneLogsCommand("", "2100-01-01")) + }) + // The "new" row remains after the "last" prune; before=2100 removes it. + assert.Assert(t, strings.Contains(out, "Deleted 1 log entries")) + }) +} + +func TestNewEventsCmd(t *testing.T) { + cmd := NewEventsCmd() + assert.Equal(t, cmd.Use, "events") + assert.Assert(t, cmd.Flags().Lookup("exclude") != nil) + assert.Assert(t, cmd.Flags().Lookup("jq") != nil) +} + +func TestMakeEmitterPrettyPrints(t *testing.T) { + emit, cleanup, err := makeEmitter("") + assert.NilError(t, err) + defer cleanup() + + out := captureOutput(func() { + emit([]byte(`{"a":1}`)) + // Invalid JSON is written through unchanged rather than dropped. + emit([]byte(`not json`)) + }) + assert.Assert(t, strings.Contains(out, "\"a\": 1")) + assert.Assert(t, strings.Contains(out, "not json")) +} diff --git a/cmd/hal/commands/commands_test.go b/cmd/hal/commands/commands_test.go deleted file mode 100644 index c3ee334..0000000 --- a/cmd/hal/commands/commands_test.go +++ /dev/null @@ -1,213 +0,0 @@ -package commands - -import ( - "os" - "strings" - "testing" - "time" - - "github.com/dansimau/hal/homeassistant" - "github.com/dansimau/hal/store" - "gotest.tools/v3/assert" -) - -// chdirTemp switches into a fresh temp dir for the duration of the test so -// commands that open the hardcoded "sqlite.db" path operate on a throwaway -// database. os.Chdir is process-wide, so these tests must not run in parallel. -func chdirTemp(t *testing.T) { - t.Helper() - - oldWd, err := os.Getwd() - assert.NilError(t, err) - - assert.NilError(t, os.Chdir(t.TempDir())) - - t.Cleanup(func() { _ = os.Chdir(oldWd) }) -} - -func TestNewLogsCmd(t *testing.T) { - cmd := NewLogsCmd() - - assert.Equal(t, cmd.Use, "logs") - assert.Assert(t, len(cmd.Aliases) > 0) - assert.Assert(t, cmd.Flags().Lookup("from") != nil) - assert.Assert(t, cmd.Flags().Lookup("last") != nil) - assert.Assert(t, cmd.Flags().Lookup("entity-id") != nil) -} - -func TestNewEntitiesCmd(t *testing.T) { - cmd := NewEntitiesCmd() - - assert.Equal(t, cmd.Use, "entities") - assert.Assert(t, len(cmd.Commands()) > 0) // has the "show" subcommand -} - -func TestNewPruneCmd(t *testing.T) { - cmd := NewPruneCmd() - - assert.Equal(t, cmd.Use, "prune") - assert.Assert(t, len(cmd.Commands()) > 0) // has the "logs" subcommand -} - -func TestNewEventsCmd(t *testing.T) { - cmd := NewEventsCmd() - - assert.Equal(t, cmd.Use, "events") - assert.Assert(t, cmd.Flags().Lookup("exclude") != nil) - assert.Assert(t, cmd.Flags().Lookup("jq") != nil) -} - -func TestPruneLogsCmdValidation(t *testing.T) { - t.Run("requires a flag", func(t *testing.T) { - cmd := NewPruneLogsCmd() - cmd.SetArgs([]string{}) - - err := cmd.Execute() - assert.ErrorContains(t, err, "either --last or --before") - }) - - t.Run("rejects both flags", func(t *testing.T) { - cmd := NewPruneLogsCmd() - cmd.SetArgs([]string{"--last", "1d", "--before", "2024-01-01"}) - - err := cmd.Execute() - assert.ErrorContains(t, err, "cannot use both") - }) -} - -func TestPrintLogs(t *testing.T) { - t.Run("empty prints message", func(t *testing.T) { - out := captureOutput(func() { - assert.NilError(t, printLogs(nil, true)) - }) - assert.Assert(t, strings.Contains(out, "No logs found")) - }) - - t.Run("renders entries", func(t *testing.T) { - logs := []store.Log{ - {Timestamp: time.Now(), Level: "INFO", EntityID: "light.kitchen", LogText: "single line"}, - {Timestamp: time.Now(), Level: "ERROR", LogText: "first line\nsecond line"}, - } - - out := captureOutput(func() { - assert.NilError(t, printLogs(logs, true)) - }) - - assert.Assert(t, strings.Contains(out, "single line")) - assert.Assert(t, strings.Contains(out, "light.kitchen")) - assert.Assert(t, strings.Contains(out, "second line")) - }) -} - -func TestPrintEntitiesTable(t *testing.T) { - t.Run("empty prints message", func(t *testing.T) { - out := captureOutput(func() { - assert.NilError(t, printEntitiesTable(nil)) - }) - assert.Assert(t, strings.Contains(out, "No entities found")) - }) - - t.Run("renders rows", func(t *testing.T) { - entities := []EntitySummary{ - {ID: "light.kitchen", LastUpdate: time.Now(), LogCount: 5}, - } - - out := captureOutput(func() { - assert.NilError(t, printEntitiesTable(entities)) - }) - - assert.Assert(t, strings.Contains(out, "light.kitchen")) - }) -} - -func TestPrintEntityStateJSON(t *testing.T) { - entity := store.Entity{ - ID: "light.kitchen", - State: &homeassistant.State{ - EntityID: "light.kitchen", - State: "on", - }, - } - - out := captureOutput(func() { - assert.NilError(t, printEntityStateJSON(entity)) - }) - - assert.Assert(t, strings.Contains(out, "light.kitchen")) - assert.Assert(t, strings.Contains(out, "on")) -} - -func TestMakeEmitterPlain(t *testing.T) { - emit, cleanup, err := makeEmitter("") - assert.NilError(t, err) - defer cleanup() - - out := captureOutput(func() { - emit([]byte(`{"a":1}`)) // valid JSON, gets indented - emit([]byte("not json")) // invalid, written as-is - }) - - assert.Assert(t, strings.Contains(out, "\"a\": 1")) - assert.Assert(t, strings.Contains(out, "not json")) -} - -func TestRunEntitiesCommandEmpty(t *testing.T) { - chdirTemp(t) - - out := captureOutput(func() { - assert.NilError(t, runEntitiesCommand()) - }) - - assert.Assert(t, strings.Contains(out, "No entities found")) -} - -func TestRunLogsCommandEmpty(t *testing.T) { - chdirTemp(t) - - out := captureOutput(func() { - assert.NilError(t, runLogsCommand("", "", "", "", true)) - }) - - assert.Assert(t, strings.Contains(out, "No logs found")) -} - -func TestRunLogsCommandInvalidDuration(t *testing.T) { - chdirTemp(t) - - err := runLogsCommand("", "", "notaduration", "", true) - assert.ErrorContains(t, err, "invalid duration") -} - -func TestRunShowEntityCommandNotFound(t *testing.T) { - chdirTemp(t) - - err := runShowEntityCommand("light.missing") - assert.ErrorContains(t, err, "entity not found") -} - -func TestRunPruneLogsCommand(t *testing.T) { - t.Run("by duration", func(t *testing.T) { - chdirTemp(t) - - out := captureOutput(func() { - assert.NilError(t, runPruneLogsCommand("1d", "")) - }) - assert.Assert(t, strings.Contains(out, "Deleted")) - }) - - t.Run("by before date", func(t *testing.T) { - chdirTemp(t) - - out := captureOutput(func() { - assert.NilError(t, runPruneLogsCommand("", "2024-01-01")) - }) - assert.Assert(t, strings.Contains(out, "Deleted")) - }) - - t.Run("invalid duration", func(t *testing.T) { - chdirTemp(t) - - err := runPruneLogsCommand("bogus", "") - assert.ErrorContains(t, err, "invalid duration") - }) -} diff --git a/connection_sync_test.go b/connection_sync_test.go new file mode 100644 index 0000000..ab83f4f --- /dev/null +++ b/connection_sync_test.go @@ -0,0 +1,71 @@ +package hal + +import ( + "testing" + + "github.com/dansimau/hal/hassws" + "github.com/dansimau/hal/homeassistant" + "gotest.tools/v3/assert" +) + +// TestSyncStatesAppliesInitialState verifies that on connect the framework +// fetches all states from Home Assistant and applies them to registered +// entities (the previously-untested half of syncStates), while skipping states +// for entities that are not registered. +func TestSyncStatesAppliesInitialState(t *testing.T) { + t.Parallel() + + server, err := hassws.NewServer(map[string]string{"test-token": testUserID}) + assert.NilError(t, err) + + conn := NewConnection(Config{ + HomeAssistant: HomeAssistantConfig{ + Host: server.ListenAddress(), + Token: "test-token", + UserID: testUserID, + }, + DatabasePath: ":memory:", + }) + + light := NewLight("light.kitchen") + conn.RegisterEntities(light) + + // The server reports state for a registered entity and an unregistered one. + // The unregistered entity exercises the `continue` branch in syncStates. + server.SetStates([]homeassistant.State{ + { + EntityID: "light.kitchen", + State: "on", + Attributes: map[string]any{"brightness": float64(200)}, + }, + { + EntityID: "sensor.not_registered", + State: "42", + }, + }) + + go func() { + if err := conn.Start(); err != nil { + t.Errorf("Start() failed: %v", err) + } + }() + + defer func() { + conn.Close() + server.Close() + }() + + // The registered light's state should be populated by the initial sync. + waitFor(t, "light state synced from initial GetStates", func() bool { + return light.GetState().State == "on" + }, func() { + t.Logf("light state: %+v", light.GetState()) + }) + + assert.Equal(t, light.GetState().State, "on") + assert.Equal(t, light.GetBrightness(), float64(200)) + + // The unregistered entity must not have been created. + _, ok := conn.entities["sensor.not_registered"] + assert.Assert(t, !ok) +} diff --git a/context.go b/context.go index f618403..78f39a4 100644 --- a/context.go +++ b/context.go @@ -1,28 +1,28 @@ package hal -import "context" +import ( + "context" -type contextKey string - -const ( - // EntityIDKey is the context key for storing the triggering entity ID - EntityIDKey contextKey = "entity_id" - - // AutomationNameKey is the context key for storing the automation name - AutomationNameKey contextKey = "automation_name" + "github.com/dansimau/hal/logger" ) -// NewAutomationContext creates a context with automation metadata +// NewAutomationContext creates a context with automation metadata. +// +// Values are stored under the keys defined in the logger package so that the +// context-aware loggers (logger.InfoContext, etc.) can read the entity ID and +// automation name back. These keys must be shared: context.Value compares keys +// by dynamic type as well as value, so a key defined in this package would not +// match one defined in the logger package even with the same underlying string. func NewAutomationContext(triggerEntityID string, automationName string) context.Context { ctx := context.Background() - ctx = context.WithValue(ctx, EntityIDKey, triggerEntityID) - ctx = context.WithValue(ctx, AutomationNameKey, automationName) + ctx = context.WithValue(ctx, logger.EntityIDKey, triggerEntityID) + ctx = context.WithValue(ctx, logger.AutomationNameKey, automationName) return ctx } // GetEntityIDFromContext extracts the entity ID from context func GetEntityIDFromContext(ctx context.Context) string { - if entityID, ok := ctx.Value(EntityIDKey).(string); ok { + if entityID, ok := ctx.Value(logger.EntityIDKey).(string); ok { return entityID } return "" @@ -30,7 +30,7 @@ func GetEntityIDFromContext(ctx context.Context) string { // GetAutomationNameFromContext extracts the automation name from context func GetAutomationNameFromContext(ctx context.Context) string { - if name, ok := ctx.Value(AutomationNameKey).(string); ok { + if name, ok := ctx.Value(logger.AutomationNameKey).(string); ok { return name } return "" diff --git a/entity_context_notregistered_test.go b/entity_context_notregistered_test.go new file mode 100644 index 0000000..c2a2827 --- /dev/null +++ b/entity_context_notregistered_test.go @@ -0,0 +1,61 @@ +package hal_test + +import ( + "context" + "testing" + + "github.com/dansimau/hal" + "gotest.tools/v3/assert" +) + +// When an entity is not bound to a connection, any method that would call a +// Home Assistant service must return ErrEntityNotRegistered rather than +// dereferencing a nil connection. The non-context variants are covered +// elsewhere; these exercise the context-aware variants. + +func TestLight_TurnOnContext_NotRegistered(t *testing.T) { + t.Parallel() + + light := hal.NewLight("light.test") + err := light.TurnOnContext(context.Background()) + assert.Equal(t, err, hal.ErrEntityNotRegistered) + + // With attributes too. + err = light.TurnOnContext(context.Background(), map[string]any{"brightness": 128}) + assert.Equal(t, err, hal.ErrEntityNotRegistered) +} + +func TestLight_TurnOffContext_NotRegistered(t *testing.T) { + t.Parallel() + + light := hal.NewLight("light.test") + err := light.TurnOffContext(context.Background()) + assert.Equal(t, err, hal.ErrEntityNotRegistered) +} + +func TestLightGroup_TurnOnContext_NotRegistered(t *testing.T) { + t.Parallel() + + lg := hal.LightGroup{hal.NewLight("light.1"), hal.NewLight("light.2")} + err := lg.TurnOnContext(context.Background()) + // Two unregistered lights produce a joined error mentioning the cause. + assert.ErrorContains(t, err, "entity not registered") +} + +func TestLightGroup_TurnOffContext_NotRegistered(t *testing.T) { + t.Parallel() + + lg := hal.LightGroup{hal.NewLight("light.1"), hal.NewLight("light.2")} + err := lg.TurnOffContext(context.Background()) + assert.ErrorContains(t, err, "entity not registered") +} + +// A single-member group returns the underlying error unwrapped, so +// errors.Is still matches ErrEntityNotRegistered. +func TestLightGroup_TurnOnContext_SingleMemberNotRegistered(t *testing.T) { + t.Parallel() + + lg := hal.LightGroup{hal.NewLight("light.only")} + err := lg.TurnOnContext(context.Background()) + assert.Equal(t, err, hal.ErrEntityNotRegistered) +} diff --git a/hassws/client_test.go b/hassws/client_test.go index 0fc893e..c2945af 100644 --- a/hassws/client_test.go +++ b/hassws/client_test.go @@ -265,13 +265,26 @@ func TestCallService(t *testing.T) { func TestGetStates(t *testing.T) { t.Parallel() - client, _ := newTestClient(t, ClientConfig{}) + client, server := newTestClient(t, ClientConfig{}) connect(t, client) - // The mock server always returns an empty state list. + // By default the mock server returns an empty state list. states, err := client.GetStates() assert.NilError(t, err) assert.Equal(t, len(states), 0) + + // Tests can populate the states the server serves. + server.SetStates([]homeassistant.State{ + {EntityID: "light.kitchen", State: "on", Attributes: map[string]any{"brightness": float64(200)}}, + {EntityID: "sensor.temp", State: "21"}, + }) + + states, err = client.GetStates() + assert.NilError(t, err) + assert.Equal(t, len(states), 2) + assert.Equal(t, states[0].EntityID, "light.kitchen") + assert.Equal(t, states[0].State, "on") + assert.Equal(t, states[1].EntityID, "sensor.temp") } func TestSubscribeEvents(t *testing.T) { diff --git a/hassws/server.go b/hassws/server.go index 6d1a0b2..5140284 100644 --- a/hassws/server.go +++ b/hassws/server.go @@ -39,9 +39,21 @@ type Server struct { // stops delivering data, exercising the client's staleness detection. respondToPings atomic.Bool + // states are the entity states returned in response to GetStates requests. + // Tests set these via SetStates to exercise the client's initial state sync. + states []homeassistant.State + lock sync.RWMutex } +// SetStates sets the entity states the server returns for GetStates requests. +func (s *Server) SetStates(states []homeassistant.State) { + s.lock.Lock() + defer s.lock.Unlock() + + s.states = states +} + func NewServer(validUsers map[string]string) (*Server, error) { server := &Server{ http: &http.Server{ @@ -197,14 +209,24 @@ func (s *Server) listen() { }) case MessageTypeGetStates: + s.lock.RLock() + states := s.states + s.lock.RUnlock() + + if states == nil { + states = []homeassistant.State{} + } + + result, err := json.Marshal(states) + if err != nil { + panic(err) + } + s.SendMessage(CommandResponse{ ID: cmd.ID, Type: MessageTypeResult, Success: true, - // TODO: Either keep state on the server site, or allow testers - // to set it. For now we just leave it empty so tests don't - // crash. - Result: json.RawMessage("[]"), + Result: result, }) case MessageTypePing: diff --git a/logger/context_extra_test.go b/logger/context_extra_test.go new file mode 100644 index 0000000..21b1a83 --- /dev/null +++ b/logger/context_extra_test.go @@ -0,0 +1,145 @@ +package logger + +import ( + "context" + "log/slog" + "strings" + "testing" + "time" + + "github.com/dansimau/hal/store" + "gotest.tools/v3/assert" +) + +// newExtraDebugService returns a service backed by an in-memory database with +// the level lowered to Debug so every log reaches the database. +func newExtraDebugService(t *testing.T) (*Service, *store.Store) { + t.Helper() + + db, err := store.Open(":memory:") + assert.NilError(t, err) + + s := NewServiceWithDB(db) + s.SetLevel(slog.LevelDebug) + + return s, db +} + +func extraFindLogs(t *testing.T, db *store.Store) []store.Log { + t.Helper() + + db.WaitForWrites() + + var logs []store.Log + assert.NilError(t, db.Order("id ASC").Find(&logs).Error) + + return logs +} + +// TestContextLoggersExtractMetadata is the regression guard for the context-key +// fix: values stored under the exported keys (as hal.NewAutomationContext does) +// must be read back and written to the database. Before the fix the loggers read +// a function-local key type that never matched, silently dropping the metadata. +func TestContextLoggersExtractMetadata(t *testing.T) { + s, db := newExtraDebugService(t) + + ctx := context.WithValue(context.Background(), EntityIDKey, "light.hall") + ctx = context.WithValue(ctx, AutomationNameKey, "motion_lights") + + s.InfoContext(ctx, "running") + s.WarnContext(ctx, "careful") + s.ErrorContext(ctx, "boom") + s.DebugContext(ctx, "trace") + + logs := extraFindLogs(t, db) + assert.Equal(t, len(logs), 4) + + for _, log := range logs { + assert.Equal(t, log.EntityID, "light.hall") + assert.Assert(t, strings.Contains(log.LogText, "automation=motion_lights"), + "expected automation in %q", log.LogText) + } +} + +// TestContextLoggersDoNotDuplicateAutomation verifies an explicit "automation" +// arg supplied by the caller is not overridden or duplicated by the context. +func TestContextLoggersDoNotDuplicateAutomation(t *testing.T) { + s, db := newExtraDebugService(t) + + ctx := context.WithValue(context.Background(), AutomationNameKey, "motion_lights") + + s.InfoContext(ctx, "running", "automation", "explicit") + + logs := extraFindLogs(t, db) + assert.Equal(t, len(logs), 1) + assert.Assert(t, strings.Contains(logs[0].LogText, "automation=explicit")) + assert.Assert(t, !strings.Contains(logs[0].LogText, "motion_lights")) +} + +// TestErrorContextDoesNotOverrideExplicitAutomation is the ErrorContext analogue: +// a context automation name must not override an explicit "automation" arg. +func TestErrorContextDoesNotOverrideExplicitAutomation(t *testing.T) { + s, db := newExtraDebugService(t) + + ctx := context.WithValue(context.Background(), AutomationNameKey, "context_automation") + + s.ErrorContext(ctx, "boom", "automation", "foo") + + logs := extraFindLogs(t, db) + assert.Equal(t, len(logs), 1) + assert.Equal(t, logs[0].Level, slog.LevelError.String()) + assert.Assert(t, strings.Contains(logs[0].LogText, "automation=foo")) + assert.Assert(t, !strings.Contains(logs[0].LogText, "context_automation")) +} + +func TestWriteLogTextRespectsLevel(t *testing.T) { + db, err := store.Open(":memory:") + assert.NilError(t, err) + + s := NewServiceWithDB(db) + s.SetLevel(slog.LevelInfo) + + // Below the configured level: dropped. + s.writeLogText(slog.LevelDebug, "e1", "debug text") + // At/above level: written. + s.writeLogText(slog.LevelInfo, "e2", "info text") + + logs := extraFindLogs(t, db) + assert.Equal(t, len(logs), 1) + assert.Equal(t, logs[0].EntityID, "e2") + assert.Equal(t, logs[0].LogText, "info text") +} + +// TestPruneLogsHandlesDeleteError covers the branch where the periodic delete +// itself fails. Dropping the logs table makes the DELETE error ("no such +// table"), which pruneLogs must log without panicking. +func TestPruneLogsHandlesDeleteError(t *testing.T) { + db, err := store.Open(":memory:") + assert.NilError(t, err) + + s := NewServiceWithDB(db) + s.retentionTime = time.Hour + s.pruneInterval = 5 * time.Millisecond + + // Remove the table the prune delete targets so the delete returns an error. + assert.NilError(t, db.Migrator().DropTable(&store.Log{})) + + stopChan := make(chan struct{}) + done := make(chan struct{}) + go func() { + s.pruneLogs(stopChan) + close(done) + }() + + // Give the ticker time to fire at least once and let the failing delete run + // through the async writer. + time.Sleep(30 * time.Millisecond) + db.WaitForWrites() + + close(stopChan) + select { + case <-done: + case <-time.After(time.Second): + t.Fatal("pruneLogs did not return after stop channel was closed") + } +} diff --git a/logger/service.go b/logger/service.go index 4595a8d..ac04ce3 100644 --- a/logger/service.go +++ b/logger/service.go @@ -360,12 +360,24 @@ func (s *Service) WarnContext(ctx context.Context, msg string, args ...any) { s.Warn(msg, entityID, args...) } +// contextKey is the type for context keys used to attach automation metadata. +type contextKey string + +const ( + // EntityIDKey is the context key for the triggering entity ID. It is the + // canonical key: callers (e.g. hal.NewAutomationContext) must store values + // under it so the *Context loggers can read them back across packages. + // A function-local key type would never compare equal to the caller's, so + // these must live at package scope. + EntityIDKey contextKey = "entity_id" + + // AutomationNameKey is the context key for the automation name. + AutomationNameKey contextKey = "automation_name" +) + // getEntityIDFromContext extracts the entity ID from context func getEntityIDFromContext(ctx context.Context) string { - type contextKey string - const entityIDKey contextKey = "entity_id" - - if entityID, ok := ctx.Value(entityIDKey).(string); ok { + if entityID, ok := ctx.Value(EntityIDKey).(string); ok { return entityID } return "" @@ -373,10 +385,7 @@ func getEntityIDFromContext(ctx context.Context) string { // getAutomationNameFromContext extracts the automation name from context func getAutomationNameFromContext(ctx context.Context) string { - type contextKey string - const automationNameKey contextKey = "automation_name" - - if name, ok := ctx.Value(automationNameKey).(string); ok { + if name, ok := ctx.Value(AutomationNameKey).(string); ok { return name } return "" diff --git a/store/async_writer_coverage_test.go b/store/async_writer_coverage_test.go new file mode 100644 index 0000000..977dee5 --- /dev/null +++ b/store/async_writer_coverage_test.go @@ -0,0 +1,96 @@ +package store_test + +import ( + "errors" + "sync" + "testing" + + "github.com/dansimau/hal/store" + "gorm.io/gorm" + "gotest.tools/v3/assert" +) + +// gormDB returns a bare *gorm.DB (via a Store) usable for constructing a +// standalone AsyncWriter in tests. +func gormDB(t *testing.T) *gorm.DB { + t.Helper() + + s, err := store.Open(":memory:") + assert.NilError(t, err) + t.Cleanup(func() { _ = s.Close() }) + + return s.DB +} + +func TestAsyncWriterEnqueueBeforeStartRunsSynchronously(t *testing.T) { + t.Parallel() + + aw := store.NewAsyncWriter(gormDB(t)) + + // Not started: Enqueue executes the operation inline. + var ran bool + aw.Enqueue(func(*gorm.DB) error { + ran = true + return nil + }) + assert.Assert(t, ran) + + // An error from a synchronous op is swallowed (logged), not propagated. + aw.Enqueue(func(*gorm.DB) error { + return errors.New("sync failure") + }) +} + +func TestAsyncWriterDoubleStartIsNoOp(t *testing.T) { + t.Parallel() + + aw := store.NewAsyncWriter(gormDB(t)) + aw.Start() + // Second Start returns early without spawning another goroutine. + aw.Start() + aw.Shutdown() +} + +func TestAsyncWriterProcessesAndLogsErrors(t *testing.T) { + t.Parallel() + + aw := store.NewAsyncWriter(gormDB(t)) + aw.Start() + + var mu sync.Mutex + ran := 0 + for range 3 { + aw.Enqueue(func(*gorm.DB) error { + mu.Lock() + ran++ + mu.Unlock() + // Returning an error exercises the async error-logging branch. + return errors.New("async failure") + }) + } + + aw.WaitForWrites() + + mu.Lock() + assert.Equal(t, ran, 3) + mu.Unlock() + + aw.Shutdown() +} + +func TestAsyncWriterEnqueueAfterShutdownRunsSynchronously(t *testing.T) { + t.Parallel() + + aw := store.NewAsyncWriter(gormDB(t)) + aw.Start() + aw.Shutdown() + + // After shutdown the context is cancelled; Enqueue falls back to running the + // operation synchronously as a last resort. + var ran bool + aw.Enqueue(func(*gorm.DB) error { + ran = true + return nil + }) + assert.Assert(t, ran) +} diff --git a/timer_coverage_test.go b/timer_coverage_test.go new file mode 100644 index 0000000..6601e6e --- /dev/null +++ b/timer_coverage_test.go @@ -0,0 +1,84 @@ +package hal_test + +import ( + "context" + "sync/atomic" + "testing" + "time" + + "github.com/benbjohnson/clock" + "github.com/dansimau/hal" + "gotest.tools/v3/assert" +) + +func TestTimerNewAndIsRunning(t *testing.T) { + t.Parallel() + + mock := clock.NewMock() + timer := hal.NewTimer(mock) + + // A freshly constructed timer is not running. + assert.Assert(t, !timer.IsRunning()) + + var fired atomic.Bool + timer.StartContext(context.Background(), func(context.Context) { + fired.Store(true) + }, time.Minute) + + // Running until the mock clock advances past the duration. + assert.Assert(t, timer.IsRunning()) + assert.Assert(t, !fired.Load()) + + mock.Add(time.Minute) + + assert.Assert(t, fired.Load()) + // After firing, the timer reports it is no longer running. + assert.Assert(t, !timer.IsRunning()) +} + +func TestTimerCancel(t *testing.T) { + t.Parallel() + + mock := clock.NewMock() + timer := hal.NewTimer(mock) + + // Cancel before start is a no-op (timer is nil internally). + timer.Cancel() + assert.Assert(t, !timer.IsRunning()) + + var fired atomic.Bool + timer.StartContext(context.Background(), func(context.Context) { + fired.Store(true) + }, time.Minute) + assert.Assert(t, timer.IsRunning()) + + timer.Cancel() + assert.Assert(t, !timer.IsRunning()) + + // Advancing past the original duration must not fire the cancelled timer. + mock.Add(2 * time.Minute) + assert.Assert(t, !fired.Load()) +} + +func TestTimerResetPicksUpLatestCallback(t *testing.T) { + t.Parallel() + + mock := clock.NewMock() + timer := hal.NewTimer(mock) + + var first, second atomic.Bool + timer.StartContext(context.Background(), func(context.Context) { + first.Store(true) + }, time.Minute) + + // Restart with a new callback before the first fires; the reset timer must + // invoke the latest callback, not the original one. + timer.StartContext(context.Background(), func(context.Context) { + second.Store(true) + }, time.Minute) + + mock.Add(time.Minute) + + assert.Assert(t, !first.Load()) + assert.Assert(t, second.Load()) +} From 561370a8ca6d63d83bd3081d2ce6b32fdc29ae3e Mon Sep 17 00:00:00 2001 From: Claude Date: Sat, 18 Jul 2026 20:25:22 +0000 Subject: [PATCH 5/5] Fix racy fallback in AsyncWriter.Enqueue after shutdown MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Enqueue's two-case select raced between the buffered queue send and ctx.Done(): after Shutdown the context is cancelled but the queue can still accept a send, so Go picked between them at random. When the send won, the op was queued to a channel the (already-exited) worker never drains — silently dropping the write, and wedging WaitForWrites forever since its sentinel op never runs. Check ctx.Done() in a non-blocking select before attempting the queue send so a shutting-down writer deterministically runs the op inline, as the code already intended. Fixes the flaky TestAsyncWriterEnqueueAfterShutdownRunsSynchronously. Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01MCZq8eURnwy99CRfcb71CA --- store/async_writer.go | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/store/async_writer.go b/store/async_writer.go index f49b143..8a877f8 100644 --- a/store/async_writer.go +++ b/store/async_writer.go @@ -94,6 +94,22 @@ func (aw *AsyncWriter) Enqueue(op WriteOperation) { } aw.mu.Unlock() + // If the writer is already shutting down, run synchronously as a last resort. + // This must be checked before the queue send below: once the context is + // cancelled the worker has stopped draining the queue, so an op that landed + // in the (still-writable) buffered queue would never run. A plain two-case + // select would pick between the ready queue-send and ctx.Done() at random, + // which both drops writes and can wedge WaitForWrites forever. + select { + case <-aw.ctx.Done(): + if err := op(aw.db); err != nil { + slog.Error("Database write failed (writer shutdown)", "error", err) + } + + return + default: + } + select { case aw.queue <- op: // Write queued successfully