Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 9 additions & 1 deletion .gitignore
Original file line number Diff line number Diff line change
@@ -1,9 +1,17 @@
# Binaries
hal
/hal

# Test coverage
cover.out

# Databases
sqlite.db*
test-results.json

# SQLite database files and related WAL/SHM files
*.db
*.db-wal
*.db-shm
**/*.db
**/*.db-wal
**/*.db-shm
149 changes: 149 additions & 0 deletions cmd/hal/commands/logs.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,149 @@
package commands

import (
"fmt"
"strconv"
"strings"
"time"

"github.com/dansimau/hal/store"
"github.com/spf13/cobra"
)

// NewLogsCmd creates the logs command
func NewLogsCmd() *cobra.Command {
var fromTime string
var toTime string
var lastDuration string
var entityID string

cmd := &cobra.Command{
Use: "logs",
Aliases: []string{"log"},
Short: "Display HAL log entries",
Long: `Display log entries from the HAL automation system.
Shows logs in chronological order with optional filtering by time range or entity.`,
Example: ` hal logs # Show all logs in chronological order
hal logs --from "2024-01-01" # Show logs from a specific date
hal logs --to "2024-01-31" # Show logs up to a specific date
hal logs --from "2024-01-01" --to "2024-01-31" # Show logs in date range
hal logs --last 5m # Show logs from last 5 minutes
hal logs --last 1h # Show logs from last 1 hour
hal logs --last 1d # Show logs from last 1 day
hal logs --entity-id "light.kitchen" # Show logs for specific entity`,
RunE: func(cmd *cobra.Command, args []string) error {
return runLogsCommand(fromTime, toTime, lastDuration, entityID)
},
}

cmd.Flags().StringVar(&fromTime, "from", "", "Start time for filtering logs (YYYY-MM-DD or YYYY-MM-DD HH:MM:SS)")
cmd.Flags().StringVar(&toTime, "to", "", "End time for filtering logs (YYYY-MM-DD or YYYY-MM-DD HH:MM:SS)")
cmd.Flags().StringVar(&lastDuration, "last", "", "Show logs from last duration (e.g., 5m, 1h, 2d)")
cmd.Flags().StringVar(&entityID, "entity-id", "", "Filter logs by entity ID")

return cmd
}

func runLogsCommand(fromTime, toTime, lastDuration, entityID string) error {
// Open database connection using default path
db, err := store.Open("sqlite.db")
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: Logs Command Ignores Configurable Database Path

The logs command hardcodes the database path to sqlite.db. This means it won't use the configurable database path from the main application, potentially causing it to read from the wrong database or fail if a different path is configured.

Fix in Cursor Fix in Web

if err != nil {
return fmt.Errorf("failed to open database: %w", err)
}

// Build query with filters
query := db.Model(&store.Log{})

// Apply time filters
if lastDuration != "" {
duration, err := parseDuration(lastDuration)
if err != nil {
return fmt.Errorf("invalid duration format: %w", err)
}
since := time.Now().Add(-duration)
query = query.Where("timestamp > ?", since)
} else {
if fromTime != "" {
from, err := parseTime(fromTime)
if err != nil {
return fmt.Errorf("invalid from time format: %w", err)
}
query = query.Where("timestamp >= ?", from)
}
if toTime != "" {
to, err := parseTime(toTime)
if err != nil {
return fmt.Errorf("invalid to time format: %w", err)
}
query = query.Where("timestamp <= ?", to)
}
}

// Apply entity filter
if entityID != "" {
query = query.Where("entity_id = ?", entityID)
}

// Execute query and get results
var logs []store.Log
if err := query.Order("timestamp ASC").Find(&logs).Error; err != nil {
return fmt.Errorf("failed to query logs: %w", err)
}

// Print results
return printLogs(logs)
}

func parseDuration(durationStr string) (time.Duration, error) {
// Handle common duration formats like 5m, 1h, 2d
if strings.HasSuffix(durationStr, "d") {
days, err := strconv.Atoi(strings.TrimSuffix(durationStr, "d"))
if err != nil {
return 0, err
}
return time.Duration(days) * 24 * time.Hour, nil
}

// For other formats (m, h, s), use standard time.ParseDuration
return time.ParseDuration(durationStr)
}

func parseTime(timeStr string) (time.Time, error) {
// Try different time formats
formats := []string{
"2006-01-02 15:04:05",
"2006-01-02 15:04",
"2006-01-02",
}

for _, format := range formats {
if t, err := time.Parse(format, timeStr); err == nil {
return t, nil
}
}

return time.Time{}, fmt.Errorf("unable to parse time: %s (expected formats: YYYY-MM-DD, YYYY-MM-DD HH:MM, or YYYY-MM-DD HH:MM:SS)", timeStr)
}

func printLogs(logs []store.Log) error {
if len(logs) == 0 {
fmt.Println("No logs found")
return nil
}

// Print logs without header to look like a log file
for _, log := range logs {
entityIDStr := ""
if log.EntityID != nil {
entityIDStr = fmt.Sprintf(" [%s]", *log.EntityID)
}

fmt.Printf("%s%s %s\n",
log.Timestamp.Format("2006-01-02 15:04:05"),
entityIDStr,
log.LogText,
)
}

return nil
}
1 change: 1 addition & 0 deletions cmd/hal/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,4 +22,5 @@ func main() {

func init() {
rootCmd.AddCommand(commands.NewStatsCmd())
rootCmd.AddCommand(commands.NewLogsCmd())
}
41 changes: 22 additions & 19 deletions connection.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,12 @@ package hal

import (
"fmt"
"log/slog"
"os"
"sync"
"time"

"github.com/dansimau/hal/hassws"
"github.com/dansimau/hal/logging"
"github.com/dansimau/hal/metrics"
"github.com/dansimau/hal/perf"
"github.com/dansimau/hal/store"
Expand All @@ -29,8 +29,9 @@ type Connection struct {
// Lock to serialize state updates and ensure automations fire in order.
mutex sync.RWMutex

homeAssistant *hassws.Client
metricsService *metrics.Service
homeAssistant *hassws.Client
metricsService *metrics.Service
loggingService *logging.Service

*SunTimes
}
Expand Down Expand Up @@ -58,10 +59,11 @@ func NewConnection(cfg Config) *Connection {
})

return &Connection{
config: cfg,
db: db,
homeAssistant: api,
metricsService: metrics.NewService(db),
config: cfg,
db: db,
homeAssistant: api,
metricsService: metrics.NewService(db),
loggingService: logging.NewService(db),

automations: make(map[string][]Automation),
entities: make(map[string]EntityInterface),
Expand All @@ -82,7 +84,7 @@ func (h *Connection) FindEntities(v any) {
// RegisterAutomations registers automations and binds them to the relevant entities.
func (h *Connection) RegisterAutomations(automations ...Automation) {
for _, automation := range automations {
slog.Info("Registering automation", "Name", automation.Name())
h.loggingService.Info("Registering automation", nil, "Name", automation.Name())

for _, entity := range automation.Entities() {
h.automations[entity.GetID()] = append(h.automations[entity.GetID()], automation)
Expand All @@ -93,7 +95,8 @@ func (h *Connection) RegisterAutomations(automations ...Automation) {
// RegisterEntities registers entities and binds them to the connection.
func (h *Connection) RegisterEntities(entities ...EntityInterface) {
for _, entity := range entities {
slog.Info("Registering entity", "EntityID", entity.GetID())
entityID := entity.GetID()
h.loggingService.Info("Registering entity", &entityID, "EntityID", entityID)
entity.BindConnection(h)
h.entities[entity.GetID()] = entity

Expand All @@ -106,8 +109,9 @@ func (h *Connection) RegisterEntities(entities ...EntityInterface) {

// Start connects to the Home Assistant websocket and starts listening for events.
func (h *Connection) Start() error {
// Start metrics service
// Start services
h.metricsService.Start()
h.loggingService.Start()

if err := h.homeAssistant.Connect(); err != nil {
return err
Expand All @@ -126,12 +130,13 @@ func (h *Connection) Start() error {

func (h *Connection) Close() {
h.metricsService.Stop()
h.loggingService.Stop()
h.homeAssistant.Close()
}

func (h *Connection) syncStates() error {
defer perf.Timer(func(timeTaken time.Duration) {
slog.Info("Initial state sync complete", "duration", timeTaken)
h.loggingService.Info("Initial state sync complete", nil, "duration", timeTaken)
})()

states, err := h.homeAssistant.GetStates()
Expand All @@ -145,7 +150,7 @@ func (h *Connection) syncStates() error {
continue
}

slog.Debug("Setting initial state", "EntityID", state.EntityID, "State", state)
h.loggingService.Debug("Setting initial state", &state.EntityID, "EntityID", state.EntityID, "State", state)

entity.SetState(state)
}
Expand All @@ -157,7 +162,7 @@ func (h *Connection) syncStates() error {
// entity and fire any automations listening for state changes to this entity.
func (h *Connection) StateChangeEvent(event hassws.EventMessage) {
defer perf.Timer(func(timeTaken time.Duration) {
slog.Debug("Tick processing time", "duration", timeTaken)
h.loggingService.Debug("Tick processing time", &event.Event.EventData.EntityID, "duration", timeTaken)
// Record tick processing time metric
h.metricsService.RecordTimer(store.MetricTypeTickProcessingTime, timeTaken, event.Event.EventData.EntityID, "")
})()
Expand All @@ -167,14 +172,12 @@ func (h *Connection) StateChangeEvent(event hassws.EventMessage) {

entity, ok := h.entities[event.Event.EventData.EntityID]
if !ok {
slog.Debug("Entity not registered", "EntityID", event.Event.EventData.EntityID)
h.loggingService.Debug("Entity not registered", &event.Event.EventData.EntityID, "EntityID", event.Event.EventData.EntityID)

return
}

slog.Debug("State changed for",
"EntityID", event.Event.EventData.EntityID,
)
h.loggingService.Debug("State changed for", &event.Event.EventData.EntityID, "EntityID", event.Event.EventData.EntityID)

fmt.Fprintf(os.Stderr, "Diff:\n%s\n", cmp.Diff(event.Event.EventData.OldState, event.Event.EventData.NewState))

Expand All @@ -193,14 +196,14 @@ func (h *Connection) StateChangeEvent(event hassws.EventMessage) {

// Prevent loops by not running automations that originate from hal
if event.Event.Context.UserID == h.config.HomeAssistant.UserID {
slog.Debug("Skipping automation from own action", "EntityID", event.Event.EventData.EntityID)
h.loggingService.Debug("Skipping automation from own action", &event.Event.EventData.EntityID, "EntityID", event.Event.EventData.EntityID)

return
}

// Dispatch automations
for _, automation := range h.automations[event.Event.EventData.EntityID] {
slog.Info("Running automation", "name", automation.Name())
h.loggingService.Info("Running automation", &event.Event.EventData.EntityID, "name", automation.Name())
// Record automation triggered metric
h.metricsService.RecordCounter(store.MetricTypeAutomationTriggered, event.Event.EventData.EntityID, automation.Name())
automation.Action(entity)
Expand Down
4 changes: 2 additions & 2 deletions entity_button.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package hal

import (
"log/slog"
"time"
)

Expand Down Expand Up @@ -39,7 +38,8 @@ func (b *Button) Action(_ EntityInterface) {
b.pressedTimes = 1
}

slog.Info("Button pressed", "entity", b.GetID(), "times", b.pressedTimes)
entityID := b.GetID()
b.connection.loggingService.Info("Button pressed", &entityID, "entity", entityID, "times", b.pressedTimes)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: Button Action Method Fails Without Nil Check

The Button.Action method accesses b.connection.loggingService without a nil check for b.connection. If the connection is nil, this causes a panic. This differs from other entity methods (e.g., Light.TurnOn/TurnOff) that gracefully fall back to slog in similar situations.

Fix in Cursor Fix in Web


b.lastPressed = time.Now()
}
Expand Down
18 changes: 12 additions & 6 deletions entity_input_boolean.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,13 +24,15 @@ func (s *InputBoolean) IsOn() bool {
}

func (s *InputBoolean) TurnOn(attributes ...map[string]any) error {
entityID := s.GetID()
if s.connection == nil {
slog.Error("InputBoolean not registered", "entity", s.GetID())
// Use slog directly when connection is nil
slog.Error("InputBoolean not registered", "entity", entityID)

return ErrEntityNotRegistered
}

slog.Debug("Turning on virtual switch", "entity", s.GetID())
s.connection.loggingService.Debug("Turning on virtual switch", &entityID, "entity", entityID)

data := map[string]any{
"entity_id": []string{s.GetID()},
Expand All @@ -49,20 +51,23 @@ func (s *InputBoolean) TurnOn(attributes ...map[string]any) error {
Data: data,
})
if err != nil {
slog.Error("Error turning on virtual switch", "entity", s.GetID(), "error", err)
entityID := s.GetID()
s.connection.loggingService.Error("Error turning on virtual switch", &entityID, "entity", entityID, "error", err)
}

return err
}

func (s *InputBoolean) TurnOff() error {
entityID := s.GetID()
if s.connection == nil {
slog.Error("InputBoolean not registered", "entity", s.GetID())
// Use slog directly when connection is nil
slog.Error("InputBoolean not registered", "entity", entityID)

return ErrEntityNotRegistered
}

slog.Info("Turning off virtual switch", "entity", s.GetID())
s.connection.loggingService.Info("Turning off virtual switch", &entityID, "entity", entityID)

_, err := s.connection.CallService(hassws.CallServiceRequest{
Type: hassws.MessageTypeCallService,
Expand All @@ -73,7 +78,8 @@ func (s *InputBoolean) TurnOff() error {
},
})
if err != nil {
slog.Error("Error turning off virtual switch", "entity", s.GetID(), "error", err)
entityID := s.GetID()
s.connection.loggingService.Error("Error turning off virtual switch", &entityID, "entity", entityID, "error", err)
}

return err
Expand Down
Loading
Loading