From b8796711f0971238f0986b0866be8f8d8065c705 Mon Sep 17 00:00:00 2001 From: jms-guy Date: Sat, 11 Oct 2025 20:30:32 -0400 Subject: [PATCH 1/5] service context restructuring --- .../internal/events/event_controller.go | 35 ++++++++++++------- cmd/service/internal/events/events_linux.go | 25 +++++-------- cmd/service/internal/events/events_windows.go | 2 +- cmd/service/service_linux.go | 18 ++++++---- cmd/service/service_setup.go | 8 +++-- cmd/service/service_windows.go | 29 +++++++-------- 6 files changed, 62 insertions(+), 55 deletions(-) diff --git a/cmd/service/internal/events/event_controller.go b/cmd/service/internal/events/event_controller.go index 9205d4d..11d5d16 100644 --- a/cmd/service/internal/events/event_controller.go +++ b/cmd/service/internal/events/event_controller.go @@ -26,8 +26,9 @@ type Command struct { } type EventController struct { - PsProcess *exec.Cmd // Powershell process for Windows event monitoring - cancel context.CancelFunc // Event monitoring cancel context + PsProcess *exec.Cmd // Powershell process for Windows event monitoring + RunCtx context.Context + Cancel context.CancelFunc // Event monitoring cancel context Config *config.Config // Struct built from config file wakaHeartbeatTicker *time.Ticker // Ticker for WakaTime enabled heartbeats heartbeatMu sync.Mutex // Mutex for WakaTime heartbeat ticker @@ -82,10 +83,26 @@ func (e *EventController) HandleConnection(serviceCtx context.Context, logger *l // Stops the currently running process monitoring script, and starts a new one with updated program list func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository) { - e.StopProcessMonitor() e.StopHeartbeats() - programs, err := pr.GetAllPrograms(ctx) + if e.Cancel != nil { + e.Cancel() + runCtx, runCancel := context.WithCancel(ctx) + e.RunCtx = runCtx + e.Cancel = runCancel + } + + e.StopProcessMonitor() + + newConfig, err := config.Load() + if err != nil { + logger.Printf("ERROR: Failed to load config: %s", err) + return + } + + e.Config = newConfig + + programs, err := pr.GetAllPrograms(context.Background()) if err != nil { logger.Printf("ERROR: Failed to get programs: %s", err) return @@ -107,17 +124,9 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log toTrack = append(toTrack, program.Name) } - go e.MonitorProcesses(ctx, logger, sm, pr, a, h, toTrack) - } - - newConfig, err := config.Load() - if err != nil { - logger.Printf("ERROR: Failed to load config: %s", err) - return + go e.MonitorProcesses(e.RunCtx, logger, sm, pr, a, h, toTrack) } - e.Config = newConfig - if e.Config.WakaTime.Enabled { e.StartHeartbeats(ctx, logger, sm) } diff --git a/cmd/service/internal/events/events_linux.go b/cmd/service/internal/events/events_linux.go index 64dd245..3592421 100644 --- a/cmd/service/internal/events/events_linux.go +++ b/cmd/service/internal/events/events_linux.go @@ -20,27 +20,23 @@ import ( // Main process monitoring function for Linux version func (e *EventController) MonitorProcesses(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository, programs []string) { - if e.cancel != nil { - e.cancel() - e.cancel = nil - } - ticker := time.NewTicker(1 * time.Second) defer ticker.Stop() for { select { case <-ctx.Done(): + logger.Println("INFO: Monitor context cancelled") return case <-ticker.C: - livePIDS := e.checkForProcessStartEvents(ctx, logger, sm, a) - e.checkForProcessStopEvents(ctx, logger, sm, pr, a, h, livePIDS) + livePIDS := e.checkForProcessStartEvents(logger, sm, a) + e.checkForProcessStopEvents(logger, sm, pr, a, h, livePIDS) } } } // Polls /proc and loops over PID entries, looking for any new PIDS belonging to tracked programs -func (e *EventController) checkForProcessStartEvents(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, a repository.ActiveRepository) map[int]struct{} { +func (e *EventController) checkForProcessStartEvents(logger *log.Logger, sm *sessions.SessionManager, a repository.ActiveRepository) map[int]struct{} { entries, err := os.ReadDir("/proc") // Read /proc if err != nil { logger.Printf("ERROR: Couldn't read /proc: %s", err) @@ -79,7 +75,7 @@ func (e *EventController) checkForProcessStartEvents(ctx context.Context, logger } sm.Mu.Unlock() - sm.CreateSession(ctx, logger, a, identity, pid) + sm.CreateSession(context.Background(), logger, a, identity, pid) } return live @@ -87,7 +83,7 @@ func (e *EventController) checkForProcessStartEvents(ctx context.Context, logger // Takes the PID entries found in the previous check function, and compares them against map of active PIDs, to determine if // any active sessions need ending -func (e *EventController) checkForProcessStopEvents(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository, livePIDs map[int]struct{}) { +func (e *EventController) checkForProcessStopEvents(logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository, livePIDs map[int]struct{}) { if livePIDs == nil { livePIDs = map[int]struct{}{} } @@ -119,16 +115,11 @@ func (e *EventController) checkForProcessStopEvents(ctx context.Context, logger sm.Mu.Unlock() for _, eend := range ends { - sm.EndSession(ctx, logger, pr, a, h, eend.program, eend.pid) + sm.EndSession(context.Background(), logger, pr, a, h, eend.program, eend.pid) } } -func (e *EventController) StopProcessMonitor() { - if e.cancel != nil { - e.cancel() - e.cancel = nil - } -} +func (e *EventController) StopProcessMonitor() {} // Read process /proc/{pid}/exe path to get program name func readExePath(pid int) (string, error) { diff --git a/cmd/service/internal/events/events_windows.go b/cmd/service/internal/events/events_windows.go index 99b6a7f..904f275 100644 --- a/cmd/service/internal/events/events_windows.go +++ b/cmd/service/internal/events/events_windows.go @@ -59,7 +59,7 @@ func (e *EventController) startProcessMonitor(ctx context.Context, logger *log.L time.Sleep(100 * time.Millisecond) // Pause to allow tempfile to finish writing before it attempts to execute args := []string{"-ExecutionPolicy", "Bypass", "-File", tempFile.Name(), "-Programs", programList} - cmd := exec.Command("powershell", args...) + cmd := exec.CommandContext(ctx, "powershell", args...) e.PsProcess = cmd var stderr bytes.Buffer diff --git a/cmd/service/service_linux.go b/cmd/service/service_linux.go index 805314c..647115f 100644 --- a/cmd/service/service_linux.go +++ b/cmd/service/service_linux.go @@ -47,10 +47,14 @@ func (s *timekeepService) Manage() (string, error) { } } - ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + serviceCtx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) defer stop() - programs, err := s.prRepo.GetAllPrograms(ctx) + runCtx, runCancel := context.WithCancel(serviceCtx) + s.eventCtrl.RunCtx = runCtx + s.eventCtrl.Cancel = runCancel + + programs, err := s.prRepo.GetAllPrograms(context.Background()) if err != nil { return "ERROR: Failed to get programs", err } @@ -70,19 +74,19 @@ func (s *timekeepService) Manage() (string, error) { toTrack = append(toTrack, program.Name) } - go s.eventCtrl.MonitorProcesses(ctx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) + go s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } if s.eventCtrl.Config.WakaTime.Enabled { - s.eventCtrl.StartHeartbeats(ctx, s.logger.Logger, s.sessions) + s.eventCtrl.StartHeartbeats(runCtx, s.logger.Logger, s.sessions) } - go s.transport.Listen(ctx, s.logger.Logger, s.eventCtrl, s.sessions, s.prRepo, s.asRepo, s.hsRepo) + go s.transport.Listen(serviceCtx, s.logger.Logger, s.eventCtrl, s.sessions, s.prRepo, s.asRepo, s.hsRepo) - <-ctx.Done() + <-serviceCtx.Done() s.logger.Logger.Println("INFO: Received shutdown signal") - s.closeService(ctx) + s.closeService() return "INFO: Daemon stopped.", nil } diff --git a/cmd/service/service_setup.go b/cmd/service/service_setup.go index 3b6029c..3dbd498 100644 --- a/cmd/service/service_setup.go +++ b/cmd/service/service_setup.go @@ -91,18 +91,20 @@ func NewTimekeepService(pr repository.ProgramRepository, ar repository.ActiveRep } // Service shutdown function -func (s *timekeepService) closeService(ctx context.Context) { +func (s *timekeepService) closeService() { if s.eventCtrl.Config.WakaTime.Enabled { // Stop WakaTime heartbeats s.eventCtrl.StopHeartbeats() } s.eventCtrl.StopProcessMonitor() // Stop any current monitoring function - s.logger.FileCleanup() // Close open logging file s.sessions.Mu.Lock() for program, tracked := range s.sessions.Programs { // End any active sessions if len(tracked.PIDs) != 0 { - s.sessions.MoveSessionToHistory(ctx, s.logger.Logger, s.prRepo, s.asRepo, s.hsRepo, program) + s.sessions.MoveSessionToHistory(context.Background(), s.logger.Logger, s.prRepo, s.asRepo, s.hsRepo, program) } } + + s.logger.FileCleanup() // Close open logging file + s.sessions.Mu.Unlock() } diff --git a/cmd/service/service_windows.go b/cmd/service/service_windows.go index d2d70a8..8fddcee 100644 --- a/cmd/service/service_windows.go +++ b/cmd/service/service_windows.go @@ -41,10 +41,14 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta status <- svc.Status{State: svc.StartPending} - ctx, cancel := context.WithCancel(context.Background()) + serviceCtx, cancel := context.WithCancel(context.Background()) defer cancel() - programs, err := s.prRepo.GetAllPrograms(ctx) + runCtx, runCancel := context.WithCancel(serviceCtx) + s.eventCtrl.RunCtx = runCtx + s.eventCtrl.Cancel = runCancel + + programs, err := s.prRepo.GetAllPrograms(context.Background()) if err != nil { s.logger.Logger.Printf("ERROR: Failed to get programs: %s", err) status <- svc.Status{State: svc.Stopped} @@ -66,14 +70,14 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta toTrack = append(toTrack, program.Name) } - s.eventCtrl.MonitorProcesses(ctx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) + go s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } if s.eventCtrl.Config.WakaTime.Enabled { - s.eventCtrl.StartHeartbeats(ctx, s.logger.Logger, s.sessions) + s.eventCtrl.StartHeartbeats(runCtx, s.logger.Logger, s.sessions) } - go s.transport.Listen(ctx, s.logger.Logger, s.eventCtrl, s.sessions, s.prRepo, s.asRepo, s.hsRepo) + go s.transport.Listen(serviceCtx, s.logger.Logger, s.eventCtrl, s.sessions, s.prRepo, s.asRepo, s.hsRepo) status <- svc.Status{State: svc.Running, Accepts: cmdsAccepted} @@ -87,26 +91,25 @@ loop: status <- c.CurrentStatus case svc.Stop, svc.Shutdown: // Service needs to be stopped or shutdown + status <- svc.Status{State: svc.StopPending} s.logger.Logger.Println("INFO: Received stop signal") + s.closeService() + s.eventCtrl.Cancel() cancel() - s.closeService(ctx) break loop case svc.Pause: // Service needs to be paused, without shutdown + status <- svc.Status{State: svc.Paused, Accepts: cmdsAccepted} s.logger.Logger.Println("INFO: Pausing service") if s.eventCtrl.Config.WakaTime.Enabled { s.eventCtrl.StopHeartbeats() } s.eventCtrl.StopProcessMonitor() - status <- svc.Status{State: svc.Paused, Accepts: cmdsAccepted} case svc.Continue: // Resume paused execution state of service - s.logger.Logger.Println("INFO: Resuming service") - s.eventCtrl.RefreshProcessMonitor(ctx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo) - if s.eventCtrl.Config.WakaTime.Enabled { - s.eventCtrl.StartHeartbeats(ctx, s.logger.Logger, s.sessions) - } status <- svc.Status{State: svc.Running, Accepts: cmdsAccepted} + s.logger.Logger.Println("INFO: Resuming service") + s.eventCtrl.RefreshProcessMonitor(serviceCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo) default: s.logger.Logger.Printf("ERROR: Unexpected service control request #%d", c) @@ -114,7 +117,5 @@ loop: } } - status <- svc.Status{State: svc.StopPending} - return false, 0 } From acf9ede21ee30b31ebf2d55d0eaf4ba1eadc5104 Mon Sep 17 00:00:00 2001 From: jms-guy Date: Sat, 11 Oct 2025 20:47:39 -0400 Subject: [PATCH 2/5] debug and info logging statements --- cmd/service/internal/events/event_controller.go | 6 ++++++ cmd/service/internal/events/events_windows.go | 1 + cmd/service/service_linux.go | 2 +- cmd/service/service_setup.go | 7 ++++++- cmd/service/service_windows.go | 2 +- 5 files changed, 15 insertions(+), 3 deletions(-) diff --git a/cmd/service/internal/events/event_controller.go b/cmd/service/internal/events/event_controller.go index 11d5d16..8044f95 100644 --- a/cmd/service/internal/events/event_controller.go +++ b/cmd/service/internal/events/event_controller.go @@ -83,6 +83,7 @@ func (e *EventController) HandleConnection(serviceCtx context.Context, logger *l // Stops the currently running process monitoring script, and starts a new one with updated program list func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository) { + logger.Println("DEBUG: Refresh: Stopping heartbeats") e.StopHeartbeats() if e.Cancel != nil { @@ -92,6 +93,7 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log e.Cancel = runCancel } + logger.Println("DEBUG: Refresh: Stopping process monitor") e.StopProcessMonitor() newConfig, err := config.Load() @@ -102,12 +104,14 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log e.Config = newConfig + logger.Println("DEBUG: Refresh: Getting programs") programs, err := pr.GetAllPrograms(context.Background()) if err != nil { logger.Printf("ERROR: Failed to get programs: %s", err) return } + logger.Println("DEBUG: Refresh: Looping programs") if len(programs) > 0 { toTrack := []string{} for _, program := range programs { @@ -124,10 +128,12 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log toTrack = append(toTrack, program.Name) } + logger.Println("DEBUG: Refresh: Starting process monitor") go e.MonitorProcesses(e.RunCtx, logger, sm, pr, a, h, toTrack) } if e.Config.WakaTime.Enabled { + logger.Println("DEBUG: Refresh: Starting heartbeats") e.StartHeartbeats(ctx, logger, sm) } diff --git a/cmd/service/internal/events/events_windows.go b/cmd/service/internal/events/events_windows.go index 904f275..4165d25 100644 --- a/cmd/service/internal/events/events_windows.go +++ b/cmd/service/internal/events/events_windows.go @@ -65,6 +65,7 @@ func (e *EventController) startProcessMonitor(ctx context.Context, logger *log.L var stderr bytes.Buffer cmd.Stderr = &stderr + logger.Println("INFO: Executing monitor script") if err := cmd.Start(); err != nil { logger.Printf("ERROR: Failed to start PowerShell monitor: %s", err) e.PsProcess = nil diff --git a/cmd/service/service_linux.go b/cmd/service/service_linux.go index 647115f..c0f655b 100644 --- a/cmd/service/service_linux.go +++ b/cmd/service/service_linux.go @@ -86,7 +86,7 @@ func (s *timekeepService) Manage() (string, error) { <-serviceCtx.Done() s.logger.Logger.Println("INFO: Received shutdown signal") - s.closeService() + s.closeService(s.logger.Logger) return "INFO: Daemon stopped.", nil } diff --git a/cmd/service/service_setup.go b/cmd/service/service_setup.go index 3dbd498..04f7c27 100644 --- a/cmd/service/service_setup.go +++ b/cmd/service/service_setup.go @@ -2,6 +2,7 @@ package main import ( "context" + "log" "github.com/jms-guy/timekeep/cmd/service/internal/daemons" "github.com/jms-guy/timekeep/cmd/service/internal/events" @@ -91,15 +92,19 @@ func NewTimekeepService(pr repository.ProgramRepository, ar repository.ActiveRep } // Service shutdown function -func (s *timekeepService) closeService() { +func (s *timekeepService) closeService(logger *log.Logger) { + logger.Println("INFO: Closing service") if s.eventCtrl.Config.WakaTime.Enabled { // Stop WakaTime heartbeats + logger.Println("INFO: Stopping heartbeats") s.eventCtrl.StopHeartbeats() } + logger.Println("INFO: Stopping process monitor") s.eventCtrl.StopProcessMonitor() // Stop any current monitoring function s.sessions.Mu.Lock() for program, tracked := range s.sessions.Programs { // End any active sessions if len(tracked.PIDs) != 0 { + logger.Println("INFO: Ending active sessions") s.sessions.MoveSessionToHistory(context.Background(), s.logger.Logger, s.prRepo, s.asRepo, s.hsRepo, program) } } diff --git a/cmd/service/service_windows.go b/cmd/service/service_windows.go index 8fddcee..e337d41 100644 --- a/cmd/service/service_windows.go +++ b/cmd/service/service_windows.go @@ -93,7 +93,7 @@ loop: case svc.Stop, svc.Shutdown: // Service needs to be stopped or shutdown status <- svc.Status{State: svc.StopPending} s.logger.Logger.Println("INFO: Received stop signal") - s.closeService() + s.closeService(s.logger.Logger) s.eventCtrl.Cancel() cancel() break loop From d384c016835ead4a5eac20b2ad66890111106b58 Mon Sep 17 00:00:00 2001 From: jms-guy Date: Tue, 14 Oct 2025 14:10:06 -0400 Subject: [PATCH 3/5] update, refresh context and blocking fixed and done --- .../internal/events/event_controller.go | 86 ++++++++++++++----- .../internal/events/events_wakatime.go | 3 +- cmd/service/internal/events/events_windows.go | 8 ++ cmd/service/internal/events/premonitor.ps1 | 56 ++++++++++++ cmd/service/internal/sessions/sessions.go | 17 +++- cmd/service/service_windows.go | 7 +- 6 files changed, 149 insertions(+), 28 deletions(-) create mode 100644 cmd/service/internal/events/premonitor.ps1 diff --git a/cmd/service/internal/events/event_controller.go b/cmd/service/internal/events/event_controller.go index 8044f95..1dbe090 100644 --- a/cmd/service/internal/events/event_controller.go +++ b/cmd/service/internal/events/event_controller.go @@ -13,6 +13,7 @@ import ( "github.com/jms-guy/timekeep/cmd/service/internal/sessions" "github.com/jms-guy/timekeep/internal/config" + "github.com/jms-guy/timekeep/internal/database" "github.com/jms-guy/timekeep/internal/repository" ) @@ -83,18 +84,22 @@ func (e *EventController) HandleConnection(serviceCtx context.Context, logger *l // Stops the currently running process monitoring script, and starts a new one with updated program list func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository) { + logger.Printf("DEBUG: Refresh: Incoming context: %v", ctx) + logger.Println("DEBUG: Refresh: Stopping heartbeats") e.StopHeartbeats() + logger.Println("DEBUG: Refresh: Stopping process monitor") + e.StopProcessMonitor() + if e.Cancel != nil { + logger.Println("DEBUG: Refresh: Cancelling old context") e.Cancel() - runCtx, runCancel := context.WithCancel(ctx) - e.RunCtx = runCtx - e.Cancel = runCancel } - - logger.Println("DEBUG: Refresh: Stopping process monitor") - e.StopProcessMonitor() + runCtx, runCancel := context.WithCancel(ctx) + logger.Printf("DEBUG: Refresh: Created new runCtx: %v", runCtx) + e.RunCtx = runCtx + e.Cancel = runCancel newConfig, err := config.Load() if err != nil { @@ -111,22 +116,10 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log return } - logger.Println("DEBUG: Refresh: Looping programs") + logger.Println("DEBUG: Refresh: Updating sessions") if len(programs) > 0 { - toTrack := []string{} - for _, program := range programs { - category := "" - project := "" - if program.Category.Valid { - category = program.Category.String - } - if program.Project.Valid { - project = program.Project.String - } - sm.EnsureProgram(program.Name, category, project) - - toTrack = append(toTrack, program.Name) - } + toTrack := updateSessionsMapOnRefresh(logger, sm, programs) + logger.Printf("DEBUG: Refresh: updateSessionsMapOnRefresh returned %d programs to track", len(toTrack)) logger.Println("DEBUG: Refresh: Starting process monitor") go e.MonitorProcesses(e.RunCtx, logger, sm, pr, a, h, toTrack) @@ -134,8 +127,57 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log if e.Config.WakaTime.Enabled { logger.Println("DEBUG: Refresh: Starting heartbeats") - e.StartHeartbeats(ctx, logger, sm) + e.StartHeartbeats(e.RunCtx, logger, sm) } logger.Printf("INFO: Process monitor refresh with %d programs", len(programs)) } + +// Takes list of programs from database, and updates session map by adding/removing/altering based on any changes from last database grab +func updateSessionsMapOnRefresh(logger *log.Logger, sm *sessions.SessionManager, programs []database.TrackedProgram) []string { + desired := make(map[string]struct{}, len(programs)) + toTrack := make([]string, 0, len(programs)) + + logger.Printf("DEBUG: updateSessionsMapOnRefresh called with %d programs", len(programs)) + + sm.Mu.Lock() + currentKeys := make([]string, 0, len(sm.Programs)) + for k := range sm.Programs { + currentKeys = append(currentKeys, k) + } + + logger.Printf("DEBUG: Current session map has %d programs", len(sm.Programs)) + + for _, p := range programs { + name := p.Name + cat := "" + if p.Category.Valid { + cat = p.Category.String + } + proj := "" + if p.Project.Valid { + proj = p.Project.String + } + + logger.Printf("DEBUG: Processing program: %s", name) + sm.EnsureProgram(name, cat, proj) + desired[name] = struct{}{} + toTrack = append(toTrack, name) + } + + if len(desired) == 0 { + for _, k := range currentKeys { + delete(sm.Programs, k) + } + } else { + for _, k := range currentKeys { + if _, keep := desired[k]; !keep { + delete(sm.Programs, k) + } + } + } + sm.Mu.Unlock() + + logger.Printf("DEBUG: Returning %d programs to track", len(toTrack)) + return toTrack +} diff --git a/cmd/service/internal/events/events_wakatime.go b/cmd/service/internal/events/events_wakatime.go index 501d3c8..7647e15 100644 --- a/cmd/service/internal/events/events_wakatime.go +++ b/cmd/service/internal/events/events_wakatime.go @@ -65,7 +65,7 @@ func (e *EventController) sendHeartbeats(ctx context.Context, logger *log.Logger if err := e.sendWakaHeartbeat(ctx, logger, program, tracked.Category, tracked.Project); err != nil { return err } - logger.Printf("INFO: WakaTime heartbeat sent for %s, category %s", program, tracked.Category) + logger.Printf("INFO: WakaTime heartbeat sent for %s, category %s, project %s", program, tracked.Category, tracked.Project) continue } logger.Printf("INFO: WakaTime heartbeat skipped for %s, no category set", program) @@ -87,6 +87,7 @@ func (e *EventController) sendWakaHeartbeat(ctx context.Context, logger *log.Log if project != "" { projectToUse = project } + logger.Printf("INFO: Sending WakaTime heartbeat for %s, category %s, project %s", program, category, projectToUse) args := []string{ "--key", e.Config.WakaTime.APIKey, diff --git a/cmd/service/internal/events/events_windows.go b/cmd/service/internal/events/events_windows.go index 4165d25..336ed4b 100644 --- a/cmd/service/internal/events/events_windows.go +++ b/cmd/service/internal/events/events_windows.go @@ -27,6 +27,14 @@ func (e *EventController) MonitorProcesses(ctx context.Context, logger *log.Logg // Runs the powershell WMI script, to monitor process events func (e *EventController) startProcessMonitor(ctx context.Context, logger *log.Logger, programs []string) { + // Check if context is already cancelled + select { + case <-ctx.Done(): + logger.Println("INFO: Context already cancelled, not starting monitor") + return + default: + } + programList := strings.Join(programs, ",") scriptTempDir := filepath.Join("C:\\", "ProgramData", "TimeKeep", "scripts_temp") diff --git a/cmd/service/internal/events/premonitor.ps1 b/cmd/service/internal/events/premonitor.ps1 new file mode 100644 index 0000000..c4186e1 --- /dev/null +++ b/cmd/service/internal/events/premonitor.ps1 @@ -0,0 +1,56 @@ +<# + This script runs before the main process monitoring script. It queries for processes that belong to programs being tracked + that are already running, and sends the service a synthetic "process_start" event, immediately opening an active session for + that program. +#> +param( + [string]$Programs +) + +# Fail fast on errors +$ErrorActionPreference = "Stop" + +# Connect to named pipe opened by service +$pipe = New-Object System.IO.Pipes.NamedPipeClientStream(".", "Timekeep", "Out") +$pipe.Connect() +$writer = New-Object System.IO.StreamWriter($pipe) +$writer.AutoFlush = $true + +try { + $tracked = $Programs -split "," + + if (-not $tracked -or $tracked.Count -eq 0) { + exit 0 + } + + # Build a set for quick membership checks + $set = @{} + foreach ($n in $tracked) { $set[$n] = $true } + + # Enumerate current processes and emit synthetic start events + Get-CimInstance Win32_Process | ForEach-Object { + $name = $_.Name + if ($name -and $set.ContainsKey($name.ToLower())) { + $data = @{ + action = "process_start" + name = $name + pid = [int]$_.ProcessId + } + $writer.WriteLine(($data | ConvertTo-Json -Compress)) + } + } +} +catch { + # Surface errors to logs + $err = @{ + action = "ps_error" + message = $_.Exception.Message + } + $writer.WriteLine(($err | ConvertTo-Json -Compress)) + exit 1 +} +finally { + $writer.Flush() + $writer.Dispose() + $pipe.Dispose() +} \ No newline at end of file diff --git a/cmd/service/internal/sessions/sessions.go b/cmd/service/internal/sessions/sessions.go index aee9113..fc36fc3 100644 --- a/cmd/service/internal/sessions/sessions.go +++ b/cmd/service/internal/sessions/sessions.go @@ -29,17 +29,26 @@ func NewSessionManager() *SessionManager { } // Make sure map is initialized, add program to map if not already present +// Caller MUST hold sm.Mu Lock func (sm *SessionManager) EnsureProgram(name, category, project string) { - sm.Mu.Lock() - defer sm.Mu.Unlock() - if sm.Programs == nil { sm.Programs = make(map[string]*Tracked) } name = strings.ToLower(name) - if _, ok := sm.Programs[name]; !ok { + tracked, ok := sm.Programs[name] + + if !ok { // Program not in tracked list? sm.Programs[name] = &Tracked{Category: category, Project: project, PIDs: make(map[int]struct{})} + return + } + + if tracked.Category != category { // Category change? + tracked.Category = category + } + + if tracked.Project != project { // Project change? + tracked.Project = project } } diff --git a/cmd/service/service_windows.go b/cmd/service/service_windows.go index e337d41..c4f35dc 100644 --- a/cmd/service/service_windows.go +++ b/cmd/service/service_windows.go @@ -41,6 +41,7 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta status <- svc.Status{State: svc.StartPending} + s.logger.Logger.Println("DEBUG: Creating context") serviceCtx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -48,6 +49,7 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta s.eventCtrl.RunCtx = runCtx s.eventCtrl.Cancel = runCancel + s.logger.Logger.Println("DEBUG: Getting initial programs") programs, err := s.prRepo.GetAllPrograms(context.Background()) if err != nil { s.logger.Logger.Printf("ERROR: Failed to get programs: %s", err) @@ -65,12 +67,15 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta if program.Project.Valid { project = program.Project.String } + s.sessions.Mu.Lock() s.sessions.EnsureProgram(program.Name, category, project) + s.sessions.Mu.Unlock() toTrack = append(toTrack, program.Name) } - go s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) + s.logger.Logger.Println("DEBUG: Starting initial monitor") + s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } if s.eventCtrl.Config.WakaTime.Enabled { From 1d9ef884f502bf627c9270bc98756f0f1b06c170 Mon Sep 17 00:00:00 2001 From: jms-guy Date: Wed, 15 Oct 2025 10:54:44 -0400 Subject: [PATCH 4/5] fixed remove command bug, removed debug statements --- cmd/cli/commands.go | 4 ++++ cmd/cli/timekeep.go | 2 +- .../internal/events/event_controller.go | 22 ++----------------- cmd/service/internal/events/events_windows.go | 2 +- cmd/service/service_windows.go | 3 --- 5 files changed, 8 insertions(+), 25 deletions(-) diff --git a/cmd/cli/commands.go b/cmd/cli/commands.go index 8c04494..a18188f 100644 --- a/cmd/cli/commands.go +++ b/cmd/cli/commands.go @@ -89,6 +89,10 @@ func (s *CLIService) RemovePrograms(ctx context.Context, args []string, all bool return nil } + if len(args) < 1 { + return fmt.Errorf("missing argument") + } + for _, program := range args { err := s.PrRepo.RemoveProgram(ctx, strings.ToLower(program)) if err != nil { diff --git a/cmd/cli/timekeep.go b/cmd/cli/timekeep.go index b547b97..e218cbc 100644 --- a/cmd/cli/timekeep.go +++ b/cmd/cli/timekeep.go @@ -57,7 +57,7 @@ func (s *CLIService) removeProgramsCmd() *cobra.Command { Aliases: []string{"RM", "remove", "Remove", "REMOVE"}, Short: "Remove a program from tracking list", Long: "User may specify multiple programs to remove, as long as they're separated by a space. May provide the --all flag to remove all programs from tracking list", - Args: cobra.MinimumNArgs(1), + Args: cobra.RangeArgs(0, 1), RunE: func(cmd *cobra.Command, args []string) error { ctx := cmd.Context() diff --git a/cmd/service/internal/events/event_controller.go b/cmd/service/internal/events/event_controller.go index 1dbe090..42892f3 100644 --- a/cmd/service/internal/events/event_controller.go +++ b/cmd/service/internal/events/event_controller.go @@ -84,20 +84,13 @@ func (e *EventController) HandleConnection(serviceCtx context.Context, logger *l // Stops the currently running process monitoring script, and starts a new one with updated program list func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log.Logger, sm *sessions.SessionManager, pr repository.ProgramRepository, a repository.ActiveRepository, h repository.HistoryRepository) { - logger.Printf("DEBUG: Refresh: Incoming context: %v", ctx) - - logger.Println("DEBUG: Refresh: Stopping heartbeats") e.StopHeartbeats() - - logger.Println("DEBUG: Refresh: Stopping process monitor") e.StopProcessMonitor() if e.Cancel != nil { - logger.Println("DEBUG: Refresh: Cancelling old context") e.Cancel() } runCtx, runCancel := context.WithCancel(ctx) - logger.Printf("DEBUG: Refresh: Created new runCtx: %v", runCtx) e.RunCtx = runCtx e.Cancel = runCancel @@ -109,24 +102,19 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log e.Config = newConfig - logger.Println("DEBUG: Refresh: Getting programs") programs, err := pr.GetAllPrograms(context.Background()) if err != nil { logger.Printf("ERROR: Failed to get programs: %s", err) return } - logger.Println("DEBUG: Refresh: Updating sessions") if len(programs) > 0 { - toTrack := updateSessionsMapOnRefresh(logger, sm, programs) - logger.Printf("DEBUG: Refresh: updateSessionsMapOnRefresh returned %d programs to track", len(toTrack)) + toTrack := updateSessionsMapOnRefresh(sm, programs) - logger.Println("DEBUG: Refresh: Starting process monitor") go e.MonitorProcesses(e.RunCtx, logger, sm, pr, a, h, toTrack) } if e.Config.WakaTime.Enabled { - logger.Println("DEBUG: Refresh: Starting heartbeats") e.StartHeartbeats(e.RunCtx, logger, sm) } @@ -134,20 +122,16 @@ func (e *EventController) RefreshProcessMonitor(ctx context.Context, logger *log } // Takes list of programs from database, and updates session map by adding/removing/altering based on any changes from last database grab -func updateSessionsMapOnRefresh(logger *log.Logger, sm *sessions.SessionManager, programs []database.TrackedProgram) []string { +func updateSessionsMapOnRefresh(sm *sessions.SessionManager, programs []database.TrackedProgram) []string { desired := make(map[string]struct{}, len(programs)) toTrack := make([]string, 0, len(programs)) - logger.Printf("DEBUG: updateSessionsMapOnRefresh called with %d programs", len(programs)) - sm.Mu.Lock() currentKeys := make([]string, 0, len(sm.Programs)) for k := range sm.Programs { currentKeys = append(currentKeys, k) } - logger.Printf("DEBUG: Current session map has %d programs", len(sm.Programs)) - for _, p := range programs { name := p.Name cat := "" @@ -159,7 +143,6 @@ func updateSessionsMapOnRefresh(logger *log.Logger, sm *sessions.SessionManager, proj = p.Project.String } - logger.Printf("DEBUG: Processing program: %s", name) sm.EnsureProgram(name, cat, proj) desired[name] = struct{}{} toTrack = append(toTrack, name) @@ -178,6 +161,5 @@ func updateSessionsMapOnRefresh(logger *log.Logger, sm *sessions.SessionManager, } sm.Mu.Unlock() - logger.Printf("DEBUG: Returning %d programs to track", len(toTrack)) return toTrack } diff --git a/cmd/service/internal/events/events_windows.go b/cmd/service/internal/events/events_windows.go index 336ed4b..7d8b97b 100644 --- a/cmd/service/internal/events/events_windows.go +++ b/cmd/service/internal/events/events_windows.go @@ -30,7 +30,7 @@ func (e *EventController) startProcessMonitor(ctx context.Context, logger *log.L // Check if context is already cancelled select { case <-ctx.Done(): - logger.Println("INFO: Context already cancelled, not starting monitor") + logger.Println("WARNING: Context already cancelled, not starting monitor") return default: } diff --git a/cmd/service/service_windows.go b/cmd/service/service_windows.go index c4f35dc..20526d2 100644 --- a/cmd/service/service_windows.go +++ b/cmd/service/service_windows.go @@ -41,7 +41,6 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta status <- svc.Status{State: svc.StartPending} - s.logger.Logger.Println("DEBUG: Creating context") serviceCtx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -49,7 +48,6 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta s.eventCtrl.RunCtx = runCtx s.eventCtrl.Cancel = runCancel - s.logger.Logger.Println("DEBUG: Getting initial programs") programs, err := s.prRepo.GetAllPrograms(context.Background()) if err != nil { s.logger.Logger.Printf("ERROR: Failed to get programs: %s", err) @@ -74,7 +72,6 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta toTrack = append(toTrack, program.Name) } - s.logger.Logger.Println("DEBUG: Starting initial monitor") s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } From 834fcef62c7afe0ed05202b9cad3552d36fa45c2 Mon Sep 17 00:00:00 2001 From: jms-guy Date: Wed, 15 Oct 2025 12:36:41 -0400 Subject: [PATCH 5/5] updated readme, beginning linux debug --- .gitignore | 2 + README.md | 26 +++--- cmd/service/internal/events/events_linux.go | 2 + .../internal/events/events_wakatime.go | 2 +- cmd/service/internal/events/events_windows.go | 83 +++++++++++++++++++ cmd/service/internal/events/premonitor.ps1 | 1 - cmd/service/internal/logs/logging_linux.go | 2 +- cmd/service/service_linux.go | 7 ++ cmd/service/service_windows.go | 1 + docs/commands.md | 2 +- scripts/install.sh | 4 + 11 files changed, 118 insertions(+), 14 deletions(-) diff --git a/.gitignore b/.gitignore index 99c66bc..4078760 100644 --- a/.gitignore +++ b/.gitignore @@ -32,4 +32,6 @@ go.work.sum # .vscode/ testbuild.sh +testlinuxbuild.sh +timekeep-release changes.md \ No newline at end of file diff --git a/README.md b/README.md index 0eb3276..383926e 100644 --- a/README.md +++ b/README.md @@ -7,6 +7,8 @@ A process activity tracker, it runs as a background service recording start/stop events for select programs and aggregates active sessions, session history, and lifetime program usage. Now has [WakaTime](https://github.com/jms-guy/timekeep?tab=readme-ov-file#wakatime) integration. +**Linux version currently not working** + ## Table of Contents - [Features](#features) - [How It Works](#how-it-works) @@ -15,7 +17,6 @@ A process activity tracker, it runs as a background service recording start/stop - [WakaTime](#wakatime) - [File Locations](#file-locations) - [Current Limitations](#current-limitations) -- [To-Do](#to-do) - [Contributing & Issues](#contributing--issues) - [License](#license) @@ -30,8 +31,8 @@ A process activity tracker, it runs as a background service recording start/stop - WakaTime integration allows for tracking external program usage alongside your IDE/web-browsing stats ## How It Works -- Windows: embeds a PowerShell script to subscribe to WMI process start/stop events. -- Linux: polls `/proc`, resolves process identity via `/proc//exe` (readlink) -> fallback to `/proc//cmdline` -> last-resort `/proc//comm`, then matches by basename. +- Windows: Embeds a PowerShell script to subscribe to WMI process start/stop events. Runs a pre-monitoring script to find any tracked programs already running on service start +- Linux: Polls `/proc`, resolves process identity via `/proc//exe` (readlink) -> fallback to `/proc//cmdline` -> last-resort `/proc//comm`, then matches by basename. - Session model: A session begins when the first process for a tracked program starts. Additional processes (ex. multiple windows) are added to the active session. The session ends only when the last process terminates, giving an accurate picture of total time with that program. ## Usage @@ -122,6 +123,11 @@ sudo mkdir -p /var/run/timekeep sudo chown "$USER_NAME":"$GROUP_NAME" /var/run/timekeep sudo chmod 755 /var/run/timekeep +# Create and set permissions for log directory +sudo mkdir -p /var/log/timekeep +sudo chown "$USER_NAME":"$GROUP_NAME" /var/log/timekeep +sudo chmod 755 /var/log/timekeep + # Create systemd service sudo tee /etc/systemd/system/timekeep.service > /dev/null < 0 { + logger.Printf("INFO: PowerShell stderr (on Start() failure): %s", stderr.String()) + } + } + + go func() { + defer os.Remove(tempFile.Name()) + + err := cmd.Wait() + + select { + case <-ctx.Done(): + logger.Println("INFO: Powershell pre-monitor stopped due to context cancellation") + return + default: + } + + if err != nil { + logger.Printf("ERROR: PowerShell pre-monitor process exited with error: %s", err) + } else { + logger.Println("INFO: PowerShell pre-monitor process exited successfully.") + } + + if stderr.Len() > 0 { + logger.Printf("PowerShell stderr output: %s", stderr.String()) + } else { + logger.Println("INFO: No PowerShell stderr output.") + } + }() +} diff --git a/cmd/service/internal/events/premonitor.ps1 b/cmd/service/internal/events/premonitor.ps1 index c4186e1..f4c4add 100644 --- a/cmd/service/internal/events/premonitor.ps1 +++ b/cmd/service/internal/events/premonitor.ps1 @@ -41,7 +41,6 @@ try { } } catch { - # Surface errors to logs $err = @{ action = "ps_error" message = $_.Exception.Message diff --git a/cmd/service/internal/logs/logging_linux.go b/cmd/service/internal/logs/logging_linux.go index 2bee6ce..a8b8f33 100644 --- a/cmd/service/internal/logs/logging_linux.go +++ b/cmd/service/internal/logs/logging_linux.go @@ -6,6 +6,6 @@ import "path/filepath" // Get path for logging file func getLogPath() (string, error) { - logDir := "/var/log/timekeep/logs" + logDir := "/var/log/timekeep" return filepath.Join(logDir, "timekeep.log"), nil } diff --git a/cmd/service/service_linux.go b/cmd/service/service_linux.go index c0f655b..388166b 100644 --- a/cmd/service/service_linux.go +++ b/cmd/service/service_linux.go @@ -27,6 +27,9 @@ func RunService(name string, isDebug *bool) error { // Main daemon management function func (s *timekeepService) Manage() (string, error) { + logger := s.logger.Logger + + logger.Println("INFO: Starting Manage function") usage := "Usage: timekeep install | remove | start | stop | status" if len(os.Args) > 1 { @@ -58,6 +61,7 @@ func (s *timekeepService) Manage() (string, error) { if err != nil { return "ERROR: Failed to get programs", err } + logger.Printf("DEBUG: Have %d programs", len(programs)) if len(programs) > 0 { toTrack := []string{} for _, program := range programs { @@ -69,14 +73,17 @@ func (s *timekeepService) Manage() (string, error) { if program.Project.Valid { project = program.Project.String } + logger.Printf("DEBUG: Tracking %s", program.Name) s.sessions.EnsureProgram(program.Name, category, project) toTrack = append(toTrack, program.Name) } + logger.Printf("DEBUG: Entering main Monitor function") go s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } + logger.Printf("DEBUG: Starting heartbeats") if s.eventCtrl.Config.WakaTime.Enabled { s.eventCtrl.StartHeartbeats(runCtx, s.logger.Logger, s.sessions) } diff --git a/cmd/service/service_windows.go b/cmd/service/service_windows.go index 20526d2..dd4f64d 100644 --- a/cmd/service/service_windows.go +++ b/cmd/service/service_windows.go @@ -72,6 +72,7 @@ func (s *timekeepService) Execute(args []string, r <-chan svc.ChangeRequest, sta toTrack = append(toTrack, program.Name) } + s.eventCtrl.StartPreMonitor(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) s.eventCtrl.MonitorProcesses(runCtx, s.logger.Logger, s.sessions, s.prRepo, s.asRepo, s.hsRepo, toTrack) } diff --git a/docs/commands.md b/docs/commands.md index 12bb64d..c8af441 100644 --- a/docs/commands.md +++ b/docs/commands.md @@ -43,7 +43,7 @@ - `status` - Gets current state of Timekeep service - - `timekeep ping` + - `timekeep status` - `update` - Update a given program's category/project fields diff --git a/scripts/install.sh b/scripts/install.sh index fa592ae..39214e8 100755 --- a/scripts/install.sh +++ b/scripts/install.sh @@ -33,6 +33,10 @@ sudo mkdir -p /var/run/timekeep sudo chown "$USER_NAME":"$GROUP_NAME" /var/run/timekeep sudo chmod 755 /var/run/timekeep +sudo mkdir -p /var/log/timekeep +sudo chown "$USER_NAME":"$GROUP_NAME" /var/log/timekeep +sudo chmod 755 /var/log/timekeep + sudo tee /etc/systemd/system/timekeep.service > /dev/null <