fix: complete code review follow-ups for queue, stats, and docs

Replace overlap Pending flag with PendingRuns counter, match seed stats
by job_id, align average duration with TimedRunCount, and tidy docs.

Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
mixeme
2026-06-29 21:54:44 +03:00
parent e9fc9eaba0
commit 29d2ffed8f
13 changed files with 233 additions and 94 deletions
+13 -9
View File
@@ -57,8 +57,8 @@ func (s *Service) RunNow(id int) error {
// sequential mode a due job is left for a later tick while any other job is
// running. The overlap policy decides what happens when a job comes due again
// while its own previous run is still in flight: "skip" drops the new run,
// "queue" marks it Pending so executeRun re-runs it the moment the current run
// finishes. Either way NextDue is advanced past the fired occurrence so the same
// "queue" increments PendingRuns so executeRun drains missed occurrences after
// the current run finishes. Either way NextDue is advanced past the fired occurrence so the same
// moment is not re-evaluated on every tick.
func (s *Service) RunDue(now time.Time) {
s.mu.Lock()
@@ -78,7 +78,7 @@ func (s *Service) RunDue(now time.Time) {
// Apply the effective overlap policy and step past this
// occurrence.
if s.effectiveOverlapPolicy(job) == domain.OverlapPolicyQueue {
runtime.Pending = true
runtime.PendingRuns++
}
s.advanceNextDueLocked(job, runtime, now)
continue
@@ -152,8 +152,8 @@ func (s *Service) startRunLocked(job *domain.Job, runtime *domain.JobRuntime, tr
// executeRun runs the job off the lock, then records the result back through the
// Service under the lock and announces it. If the job was marked Pending while
// running (the "queue" overlap policy), and it is still enabled and the scheduler
// is not paused, the deferred run is started immediately. It runs on its own
// goroutine.
// is not paused, deferred runs are started one at a time until PendingRuns reaches
// zero. Each deferred run runs on its own goroutine.
func (s *Service) executeRun(ctx context.Context, jobCopy domain.Job, trigger string, env runEnv) {
record, logErr := s.runJob(ctx, &jobCopy, trigger, env.logsDir)
@@ -167,11 +167,11 @@ func (s *Service) executeRun(ctx context.Context, jobCopy domain.Job, trigger st
runtime.Output = record.Output
prependLog(runtime, record)
updateStats(runtime, record)
rerun := runtime.Pending && current.Enabled && !s.paused
runtime.Pending = false
rerun := runtime.PendingRuns > 0 && current.Enabled && !s.paused
if rerun {
runtime.PendingRuns--
// A scheduled occurrence fired while this run was active under the
// "queue" policy; start that deferred run now.
// "queue" policy; start one deferred run now.
saveErr = s.startRunLocked(current, runtime, "Schedule", time.Now())
rerunStarted = saveErr == nil
} else {
@@ -241,11 +241,15 @@ func updateStats(rt *domain.JobRuntime, r domain.RunRecord) {
if r.State == "Failed" {
rt.FailCount++
}
if r.DurationMS <= 0 {
return
}
rt.LastDurationMS = r.DurationMS
if r.DurationMS > rt.MaxDurationMS {
rt.MaxDurationMS = r.DurationMS
}
rt.AvgDurationMS = (rt.AvgDurationMS*int64(rt.RunCount-1) + r.DurationMS) / int64(rt.RunCount)
rt.TimedRunCount++
rt.AvgDurationMS = (rt.AvgDurationMS*int64(rt.TimedRunCount-1) + r.DurationMS) / int64(rt.TimedRunCount)
}
// runningOutput is the placeholder output shown while a job is running, before
+89 -21
View File
@@ -105,6 +105,24 @@ func TestUpdateStats(t *testing.T) {
}
}
func TestUpdateStatsSkipsZeroDuration(t *testing.T) {
rt := &domain.JobRuntime{}
updateStats(rt, domain.RunRecord{State: "OK", DurationMS: 200})
updateStats(rt, domain.RunRecord{State: "OK", DurationMS: 0})
if rt.RunCount != 2 {
t.Fatalf("RunCount = %d, want 2", rt.RunCount)
}
if rt.TimedRunCount != 1 {
t.Fatalf("TimedRunCount = %d, want 1", rt.TimedRunCount)
}
if rt.AvgDurationMS != 200 {
t.Errorf("AvgDurationMS = %d, want 200 (zero-duration run excluded)", rt.AvgDurationMS)
}
if rt.LastDurationMS != 200 {
t.Errorf("LastDurationMS = %d, want 200", rt.LastDurationMS)
}
}
// TestRunDueParallelStartsAllDueJobs verifies that in parallel mode every due job
// starts at once: both runs are in flight (blocked in the runner) before either
// is released.
@@ -214,10 +232,10 @@ func TestRunDueSkipDropsOverlap(t *testing.T) {
expectNoEntry(t, entered)
svc.mu.Lock()
pending := svc.runtimes[1].Pending
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if pending {
t.Error("skip policy must not mark the job Pending")
if pending != 0 {
t.Error("skip policy must not queue deferred runs")
}
close(release)
@@ -230,7 +248,7 @@ func TestRunDueSkipDropsOverlap(t *testing.T) {
}
// TestRunDueQueueRerunsAfterFinish verifies that under the "queue" overlap policy a
// job coming due again while running is marked Pending and re-run as soon as the
// job coming due again while running increments PendingRuns and re-runs after the
// in-flight run finishes.
func TestRunDueQueueRerunsAfterFinish(t *testing.T) {
svc := newQueueService(t, domain.ExecutionModeParallel, domain.OverlapPolicyQueue, []domain.Job{
@@ -254,17 +272,17 @@ func TestRunDueQueueRerunsAfterFinish(t *testing.T) {
t.Fatalf("started job = %d, want 1", id)
}
// Re-due the running job and tick: queue must mark it Pending without starting
// a second concurrent run.
// Re-due the running job and tick: queue must increment PendingRuns without
// starting a second concurrent run.
primeDue(t, svc, 1)
svc.RunDue(time.Now())
expectNoEntry(t, entered)
svc.mu.Lock()
pending := svc.runtimes[1].Pending
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if !pending {
t.Fatal("queue policy must mark the job Pending")
if pending != 1 {
t.Fatalf("queue policy must queue one deferred run, PendingRuns = %d", pending)
}
// Releasing the first run lets executeRun start the deferred run automatically.
@@ -279,10 +297,60 @@ func TestRunDueQueueRerunsAfterFinish(t *testing.T) {
t.Errorf("runner called %d time(s), want 2 (original + queued re-run)", got)
}
svc.mu.Lock()
pending = svc.runtimes[1].Pending
pending = svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if pending {
t.Error("Pending must be cleared after the re-run starts")
if pending != 0 {
t.Errorf("PendingRuns must be cleared after the re-run starts, got %d", pending)
}
}
// TestRunDueQueueDrainsMultipleOverlaps verifies that each missed occurrence
// under the queue policy eventually runs after the in-flight run finishes.
func TestRunDueQueueDrainsMultipleOverlaps(t *testing.T) {
svc := newQueueService(t, domain.ExecutionModeParallel, domain.OverlapPolicyQueue, []domain.Job{
{ID: 1, Name: "A", Schedule: "@every 1h", Command: "echo", Enabled: true},
})
release := make(chan struct{})
var calls int32
svc.runJob = func(_ context.Context, job *domain.Job, _ string, _ string) (domain.RunRecord, error) {
if atomic.LoadInt32(&calls) == 0 {
<-release
}
atomic.AddInt32(&calls, 1)
return domain.RunRecord{Time: "t", JobID: job.ID, JobName: job.Name, State: "Success"}, nil
}
done := completions(svc)
primeDue(t, svc, 1)
svc.RunDue(time.Now())
// Three extra due ticks while the first run is still in flight.
for range 3 {
primeDue(t, svc, 1)
svc.RunDue(time.Now())
}
svc.mu.Lock()
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if pending != 3 {
t.Fatalf("PendingRuns = %d, want 3 queued occurrences", pending)
}
close(release)
for range 4 {
waitRecord(t, done)
}
if got := atomic.LoadInt32(&calls); got != 4 {
t.Errorf("runner called %d time(s), want 4 (original + 3 queued)", got)
}
svc.mu.Lock()
pending = svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if pending != 0 {
t.Errorf("PendingRuns = %d after drain, want 0", pending)
}
}
@@ -318,10 +386,10 @@ func TestRunDuePerJobQueueOverridesGlobalSkip(t *testing.T) {
expectNoEntry(t, entered)
svc.mu.Lock()
pending := svc.runtimes[1].Pending
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if !pending {
t.Fatal("per-job queue policy must mark the job Pending despite global skip")
if pending != 1 {
t.Fatalf("per-job queue policy must queue a deferred run, PendingRuns = %d", pending)
}
// Releasing the first run lets executeRun start the deferred re-run.
@@ -368,10 +436,10 @@ func TestRunDuePerJobSkipOverridesGlobalQueue(t *testing.T) {
expectNoEntry(t, entered)
svc.mu.Lock()
pending := svc.runtimes[1].Pending
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if pending {
t.Error("per-job skip policy must not mark the job Pending despite global queue")
if pending != 0 {
t.Errorf("per-job skip policy must not queue deferred runs, PendingRuns = %d", pending)
}
close(release)
@@ -413,10 +481,10 @@ func TestRunDueEmptyOverlapInheritsGlobal(t *testing.T) {
expectNoEntry(t, entered)
svc.mu.Lock()
pending := svc.runtimes[1].Pending
pending := svc.runtimes[1].PendingRuns
svc.mu.Unlock()
if !pending {
t.Fatal("empty per-job policy must inherit the global queue and mark Pending")
if pending != 1 {
t.Fatalf("empty per-job policy must inherit global queue, PendingRuns = %d", pending)
}
close(release)
+6 -13
View File
@@ -18,16 +18,9 @@ import (
// to that state goes through a mutex so the GUI and the scheduler can no longer
// race on a shared *[]Job.
//
// State ownership and the locking contract were established in T3.1; the
// event/observer machinery in T3.2. T3.3 added the state-mutating intents
// (CreateJob, UpdateJob, DeleteJob, SetEnabled, RunNow, SetGlobalPause,
// UpdateSettings) in operations.go: the Service is the sole writer of job and
// runtime state, persisting through the store and announcing changes via events.
//
// T3.4 makes the Service drive scheduling too. It owns the timing loop through a
// scheduler.Scheduler that calls RunDue on every tick; the scheduler holds no
// job state and never touches the slice directly. The old shared *[]domain.Job
// between GUI and scheduler is gone — both go through the Service.
// Mutations live in operations.go; scheduling and run dispatch live in run.go;
// typed events live in events.go. The scheduler is a thin timing loop that calls
// RunDue on every tick and holds no job state of its own.
//
// Locking contract: mu is a plain, non-reentrant mutex. Exported methods take
// it; unexported helpers ending in "Locked" assume the caller already holds it.
@@ -107,6 +100,7 @@ func NewService(store *storage.Store, jobs []domain.Job) *Service {
runtime.LastDurationMS = seed.LastDurationMS
runtime.AvgDurationMS = seed.AvgDurationMS
runtime.MaxDurationMS = seed.MaxDurationMS
runtime.TimedRunCount = seed.TimedRunCount
}
return s
}
@@ -182,9 +176,8 @@ func (s *Service) Jobs() []domain.Job {
// Runtime returns the transient runtime state for a job ID, or nil if no job
// with that ID is loaded. The returned pointer is the live runtime; reads of it
// are only safe while no concurrent mutation is in flight. The scheduler now
// drives the Service rather than sharing state, so the remaining concurrent
// reader is the UI listener, which T4.1 marshals onto the main thread.
// are only safe while no concurrent mutation is in flight. The UI listener
// marshals reads onto the main thread via fyne.Do.
func (s *Service) Runtime(id int) *domain.JobRuntime {
s.mu.Lock()
defer s.mu.Unlock()
+10 -7
View File
@@ -19,18 +19,21 @@ type JobRuntime struct {
// the only form shown in the GUI.
NextDue time.Time
// Pending is set when a run was skipped due to the overlap policy being
// "queue". At most one deferred run is remembered; executeRun starts it when
// the current run ends.
Pending bool
// PendingRuns counts scheduled occurrences that fired while a run was still
// in flight under the "queue" overlap policy. executeRun drains the counter
// by starting one deferred run after each completion.
PendingRuns int
// Execution-time statistics accumulated since the last process start.
// Seeded from log files on startup by T2.5; zero until then.
RunCount int
FailCount int
// Seeded from log files on startup; zero until then.
RunCount int
FailCount int
LastDurationMS int64
AvgDurationMS int64
MaxDurationMS int64
// TimedRunCount is the number of runs that contributed to AvgDurationMS.
// StartOnly and legacy duration-less runs increment RunCount but not this.
TimedRunCount int
}
// NewRuntime builds the initial runtime state for a freshly loaded or created
+1 -1
View File
@@ -29,7 +29,7 @@ func RunJob(ctx context.Context, job *domain.Job, trigger string, logsDir string
var detail string
var durationMS int64
if job.StartOnly {
invocation := jobInvocation(context.Background(), *job)
invocation := jobInvocation(ctx, *job)
state, detail, output = startJobOnly(invocation, *job, started)
// StartOnly jobs don't wait for process exit, so no meaningful duration.
durationMS = 0
+46 -14
View File
@@ -20,19 +20,20 @@ type SeededStats struct {
LastDurationMS int64
AvgDurationMS int64
MaxDurationMS int64
TimedRunCount int
}
// SeedStats scans logsDir once and reconstructs per-job execution-time
// statistics from the log files written by previous runs, keyed by Job.ID.
//
// Log files are matched to a job by the sanitized job-name suffix of the file
// name (the same name writeRunLog uses), so no per-file header read is needed to
// associate a log with its job. For each job only the newest maxFiles matching
// logs are parsed, mirroring the retention policy that CleanupLogs enforces; a
// maxFiles of zero or less means "no bound". The duration and state are read
// from each log's header. Logs written before duration tracking existed carry no
// duration line: those are tolerated — they still count toward RunCount and
// FailCount but are left out of the duration aggregates (last/avg/max) so a
// Log files are matched primarily by the job_id header line writeRunLog writes.
// When that header is absent (legacy logs), files fall back to the sanitized
// job-name suffix in the filename. For each job only the newest maxFiles
// matching logs are parsed, mirroring the retention policy that CleanupLogs
// enforces; a maxFiles of zero or less means "no bound". The duration and state
// are read from each log's header. Logs written before duration tracking existed
// carry no duration line: those are tolerated — they still count toward RunCount
// and FailCount but are left out of the duration aggregates (last/avg/max) so a
// missing duration cannot masquerade as a zero-millisecond run.
//
// A missing or unreadable logs directory yields an empty map rather than an
@@ -44,9 +45,7 @@ func SeedStats(logsDir string, jobs []domain.Job, maxFiles int) map[int]SeededSt
return result
}
// Group log file names by the sanitized job-name portion of the file name.
// File names are "<timestamp>_<sanitizedName>.log"; the timestamp has no
// underscore, so everything after the first underscore is the name part.
byID := make(map[int][]string)
byName := make(map[string][]string)
for _, entry := range entries {
if entry.IsDir() {
@@ -56,17 +55,24 @@ func SeedStats(logsDir string, jobs []domain.Job, maxFiles int) map[int]SeededSt
if !strings.HasSuffix(strings.ToLower(name), ".log") {
continue
}
path := filepath.Join(logsDir, name)
if jobID, ok := readLogJobID(path); ok {
byID[jobID] = append(byID[jobID], name)
continue
}
base := name[:len(name)-len(".log")]
idx := strings.Index(base, "_")
if idx < 0 {
continue
}
jobPart := base[idx+1:]
byName[jobPart] = append(byName[jobPart], name)
byName[base[idx+1:]] = append(byName[base[idx+1:]], name)
}
for _, job := range jobs {
files := byName[sanitizeFileName(job.Name)]
files := byID[job.ID]
if len(files) == 0 {
files = byName[sanitizeFileName(job.Name)]
}
if len(files) == 0 {
continue
}
@@ -105,11 +111,37 @@ func aggregateLogStats(logsDir string, files []string) SeededStats {
}
}
if durationCount > 0 {
stats.TimedRunCount = durationCount
stats.AvgDurationMS = durationSum / int64(durationCount)
}
return stats
}
// readLogJobID reads the job_id field from a log file header.
func readLogJobID(path string) (int, bool) {
file, err := os.Open(path)
if err != nil {
return 0, false
}
defer file.Close()
scanner := bufio.NewScanner(file)
for scanner.Scan() {
line := scanner.Text()
if line == "" {
break
}
if rest, ok := strings.CutPrefix(line, "job_id: "); ok {
id, err := strconv.Atoi(strings.TrimSpace(rest))
if err != nil {
return 0, false
}
return id, true
}
}
return 0, false
}
// readLogHeader reads the "state" and "duration" fields from a log file's
// header (the lines before the first blank line). hasDuration reports whether a
// well-formed duration line was present, distinguishing a legacy duration-less
+47 -16
View File
@@ -3,6 +3,8 @@ package runner
import (
"os"
"path/filepath"
"strconv"
"strings"
"testing"
"gitea.mixdep.ru/mix/gosentry/src/domain"
@@ -10,15 +12,21 @@ import (
// writeTestLog writes a minimal log file in the format writeRunLog produces.
// Pass durationMS < 0 to omit the duration line (legacy log simulation).
func writeTestLog(t *testing.T, dir, filename, state string, durationMS int64) {
// When jobID > 0 a job_id header line is included.
func writeTestLog(t *testing.T, dir, filename, state string, durationMS int64, jobID int) {
t.Helper()
var content string
if durationMS >= 0 {
content = "state: " + state + "\nduration: " + itoa(durationMS) + "\n\n"
} else {
content = "state: " + state + "\n\n"
var content strings.Builder
if jobID > 0 {
content.WriteString("job_id: ")
content.WriteString(strconv.Itoa(jobID))
content.WriteString("\n")
}
if err := os.WriteFile(filepath.Join(dir, filename), []byte(content), 0o644); err != nil {
if durationMS >= 0 {
content.WriteString("state: " + state + "\nduration: " + itoa(durationMS) + "\n\n")
} else {
content.WriteString("state: " + state + "\n\n")
}
if err := os.WriteFile(filepath.Join(dir, filename), []byte(content.String()), 0o644); err != nil {
t.Fatal(err)
}
}
@@ -47,9 +55,9 @@ func TestSeedStatsBasic(t *testing.T) {
job := domain.Job{ID: 1, Name: "Build"}
name := sanitizeFileName(job.Name)
writeTestLog(t, dir, "20260601-100000_"+name+".log", "OK", 200)
writeTestLog(t, dir, "20260601-110000_"+name+".log", "Failed", 400)
writeTestLog(t, dir, "20260601-120000_"+name+".log", "OK", 600)
writeTestLog(t, dir, "20260601-100000_"+name+".log", "OK", 200, job.ID)
writeTestLog(t, dir, "20260601-110000_"+name+".log", "Failed", 400, job.ID)
writeTestLog(t, dir, "20260601-120000_"+name+".log", "OK", 600, job.ID)
result := SeedStats(dir, []domain.Job{job}, 0)
s, ok := result[job.ID]
@@ -83,9 +91,9 @@ func TestSeedStatsDurationLessLegacyLog(t *testing.T) {
name := sanitizeFileName(job.Name)
// Legacy log (no duration line).
writeTestLog(t, dir, "20260601-080000_"+name+".log", "OK", -1)
writeTestLog(t, dir, "20260601-080000_"+name+".log", "OK", -1, job.ID)
// Modern log with duration.
writeTestLog(t, dir, "20260601-090000_"+name+".log", "OK", 300)
writeTestLog(t, dir, "20260601-090000_"+name+".log", "OK", 300, job.ID)
result := SeedStats(dir, []domain.Job{job}, 0)
s := result[job.ID]
@@ -113,9 +121,9 @@ func TestSeedStatsMaxFilesHonoured(t *testing.T) {
name := sanitizeFileName(job.Name)
// Write 3 logs; only the 2 newest should be counted (maxFiles=2).
writeTestLog(t, dir, "20260601-060000_"+name+".log", "OK", 100)
writeTestLog(t, dir, "20260601-070000_"+name+".log", "OK", 200)
writeTestLog(t, dir, "20260601-080000_"+name+".log", "Failed", 300)
writeTestLog(t, dir, "20260601-060000_"+name+".log", "OK", 100, job.ID)
writeTestLog(t, dir, "20260601-070000_"+name+".log", "OK", 200, job.ID)
writeTestLog(t, dir, "20260601-080000_"+name+".log", "Failed", 300, job.ID)
result := SeedStats(dir, []domain.Job{job}, 2)
s := result[job.ID]
@@ -140,10 +148,33 @@ func TestSeedStatsMissingDir(t *testing.T) {
// any known job are silently ignored.
func TestSeedStatsUnknownJobProducesNoEntry(t *testing.T) {
dir := t.TempDir()
writeTestLog(t, dir, "20260601-100000_UnknownJob.log", "OK", 100)
writeTestLog(t, dir, "20260601-100000_UnknownJob.log", "OK", 100, 0)
result := SeedStats(dir, []domain.Job{{ID: 1, Name: "KnownJob"}}, 0)
if _, ok := result[1]; ok {
t.Error("expected no entry for a job with no matching log files")
}
}
// TestSeedStatsMatchesByJobID verifies that logs are associated by job_id even
// when sanitized job names would collide.
func TestSeedStatsMatchesByJobID(t *testing.T) {
dir := t.TempDir()
jobA := domain.Job{ID: 1, Name: "foo@bar"}
jobB := domain.Job{ID: 2, Name: "foo bar"}
colliding := sanitizeFileName(jobA.Name)
if colliding != sanitizeFileName(jobB.Name) {
t.Fatalf("test setup: expected colliding sanitized names, got %q and %q", sanitizeFileName(jobA.Name), sanitizeFileName(jobB.Name))
}
writeTestLog(t, dir, "20260601-100000_"+colliding+".log", "OK", 100, jobA.ID)
writeTestLog(t, dir, "20260601-110000_"+colliding+".log", "Failed", 200, jobB.ID)
result := SeedStats(dir, []domain.Job{jobA, jobB}, 0)
if result[jobA.ID].RunCount != 1 || result[jobA.ID].LastDurationMS != 100 {
t.Errorf("job A stats = %+v, want one OK run at 100 ms", result[jobA.ID])
}
if result[jobB.ID].RunCount != 1 || result[jobB.ID].FailCount != 1 || result[jobB.ID].LastDurationMS != 200 {
t.Errorf("job B stats = %+v, want one Failed run at 200 ms", result[jobB.ID])
}
}
+1 -1
View File
@@ -17,7 +17,7 @@ const appID = "ru.mixeme.gosentry.desktop"
// instance arbitration, Fyne app + window construction, tray wiring, and the
// startup-timing record — and delegates all view construction to newMainView in
// mainwindow.go. Keeping lifecycle here and the view there is the run.go /
// mainwindow.go split introduced in T4.1.
// mainwindow.go split keeps lifecycle separate from view construction.
func Run(startInTray bool) {
started := time.Now()
instanceListener, primary := acquireSingleInstance(!startInTray)