Files
gosentry/src/runner/runner_test.go
T
mix 0c8442a8d1 perf: keep file I/O off Service.mu and untie StartOnly from the app context
Phase 7 of the whole-project review (findings 3.2 and 3.3).

Service.mu is the lock the Fyne main thread takes on every Jobs() and
Runtime() call, so anything blocking inside it makes a UI refresh wait on
the disk. Three things did:

- Every SaveJobs/SaveConfig was a marshal, fsync, and rename under mu.
  Writes are now prepared under the lock (Store.PrepareSaveJobs /
  PrepareSaveConfig snapshot the payload and target path) and run after
  it is released. deferSaveLocked takes saveMu while mu is still held, so
  writes still reach the file in the order their snapshots were taken and
  an older snapshot can never land on top of a newer one.
- executeRun ran runner.CleanupLogs under mu after every run. It needs
  only the values already snapshotted into runEnv, so it now runs after
  the unlock — including when the job is gone, since the run still wrote
  a log file that retention covers.
- adoptJobsLocked ran runner.SeedStats under mu, reached from
  UpdateSettings on the UI thread. Seeding moved out into
  applySeededStatsLocked; UpdateSettings now reads the new jobs file and
  seeds its statistics before taking the lock, and re-checks the
  "no jobs-file switch while running" guard once it has it.

SeedStats also opened every log file twice — once to find the job, again
to read the result. readLogSummary reads job_id, state, and duration in
one pass, so each log is opened once.

StartOnly runs were built with exec.CommandContext on the app's lifecycle
context. os/exec keeps a watcher goroutine alive until Wait returns or the
context is done, and StartOnly never calls Wait, so one goroutine leaked
per run and would then try to kill a process whose handle startJobOnly had
already released. The invocation now uses context.Background(), whose nil
Done channel means no watcher is started at all.

Regression tests: TestRunJobStartOnlyLeavesNoContextWatcher (fails with 5
leaked goroutines on the old code), TestConcurrentJobOperationsLeaveTheFileMatchingMemory,
and TestUpdateSettingsSeedsAdoptedJobsFromLogs. STANDARDS gains the
no-I/O-under-mu rule and the "a StartOnly process outlives GoSentry" entry.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-08-06 21:44:51 +03:00

484 lines
14 KiB
Go

package runner
import (
"context"
"os"
"path/filepath"
"runtime"
"strings"
"testing"
"time"
"gitea.mixdep.ru/mix/gosentry/src/domain"
)
func echoCommand(message string) string {
if runtime.GOOS == "windows" {
return "echo " + message
}
return "echo '" + strings.ReplaceAll(message, "'", "'\\''") + "'"
}
func TestRunJobLogFileAllHeaders(t *testing.T) {
logsDir := t.TempDir()
job := domain.Job{
ID: 99,
Name: "Log Header Test",
Command: echoCommand("header test output"),
}
record, err := RunJob(context.Background(), &job, "Schedule", logsDir, 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.LogFile == "" {
t.Fatal("expected log file to be written")
}
data, err := os.ReadFile(record.LogFile)
if err != nil {
t.Fatal(err)
}
content := string(data)
for _, want := range []string{
"job_id: 99",
"job_name: Log Header Test",
"trigger: Schedule",
"state: OK",
"detail: ",
"command: " + job.Command,
"arguments: <empty>",
"start_only: false",
"stdout:",
"stderr:",
} {
if !strings.Contains(content, want) {
t.Errorf("log file missing %q:\n%s", want, content)
}
}
// The time header must use the documented format.
for _, line := range strings.Split(content, "\n") {
if strings.HasPrefix(line, "time: ") {
ts := strings.TrimPrefix(line, "time: ")
if _, err := time.Parse("2006-01-02 15:04:05", ts); err != nil {
t.Errorf("time header %q does not match format 2006-01-02 15:04:05: %v", ts, err)
}
break
}
}
}
func TestRunJobRecordFields(t *testing.T) {
job := domain.Job{
ID: 55,
Name: "Record Fields Test",
Command: echoCommand("record field check"),
}
record, err := RunJob(context.Background(), &job, "Schedule", t.TempDir(), 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.JobID != job.ID {
t.Errorf("JobID: got %d, want %d", record.JobID, job.ID)
}
if record.JobName != job.Name {
t.Errorf("JobName: got %q, want %q", record.JobName, job.Name)
}
if record.Trigger != "Schedule" {
t.Errorf("Trigger: got %q, want 'Schedule'", record.Trigger)
}
if record.State != "OK" {
t.Errorf("State: got %q, want 'OK' (detail: %q)", record.State, record.Detail)
}
if record.LogFile == "" {
t.Error("LogFile should be a non-empty path")
}
if _, err := time.Parse("2006-01-02 15:04:05", record.Time); err != nil {
t.Errorf("Time format wrong, got %q: %v", record.Time, err)
}
if !strings.Contains(record.Output, "stdout:") {
t.Errorf("Output missing 'stdout:', got:\n%s", record.Output)
}
if !strings.Contains(record.Output, "stderr:") {
t.Errorf("Output missing 'stderr:', got:\n%s", record.Output)
}
}
func TestFormatOutput(t *testing.T) {
got := formatOutput("hello world", "some error")
want := "stdout:\nhello world\n\nstderr:\nsome error"
if got != want {
t.Errorf("formatOutput:\ngot: %q\nwant: %q", got, want)
}
}
func TestFormatOutputEmptyStreams(t *testing.T) {
got := formatOutput("", "")
if !strings.Contains(got, "stdout:\n<empty>") {
t.Errorf("empty stdout should show <empty>, got:\n%s", got)
}
if !strings.Contains(got, "stderr:\n<empty>") {
t.Errorf("empty stderr should show <empty>, got:\n%s", got)
}
}
func TestLogArguments(t *testing.T) {
cases := []struct{ input, want string }{
{"", "<empty>"},
{" ", "<empty>"},
{"--flag", "--flag"},
{"--flag\r\n--value", "--flag\n--value"},
{"--flag\n--value", "--flag\n--value"},
}
for _, tc := range cases {
if got := logArguments(tc.input); got != tc.want {
t.Errorf("logArguments(%q) = %q, want %q", tc.input, got, tc.want)
}
}
}
func TestSanitizeFileName(t *testing.T) {
cases := []struct{ input, want string }{
{"Hello Test", "Hello_Test"},
{"job-1_ok", "job-1_ok"},
{"!!!", "job"},
{"", "job"},
{"A/B:C", "A_B_C"},
}
for _, tc := range cases {
if got := sanitizeFileName(tc.input); got != tc.want {
t.Errorf("sanitizeFileName(%q) = %q, want %q", tc.input, got, tc.want)
}
}
}
func TestRunJobWritesLogFile(t *testing.T) {
logsDir := t.TempDir()
job := domain.Job{
ID: 42,
Name: "Hello Test",
Command: echoCommand("hello from test"),
}
record, err := RunJob(context.Background(), &job, "Manual", logsDir, 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.LogFile == "" {
t.Fatal("expected log file path")
}
if filepath.Dir(record.LogFile) != logsDir {
t.Fatalf("expected log in %q, got %q", logsDir, record.LogFile)
}
if !strings.Contains(filepath.Base(record.LogFile), "Hello_Test") {
t.Fatalf("expected job name in log filename, got %q", record.LogFile)
}
data, err := os.ReadFile(record.LogFile)
if err != nil {
t.Fatal(err)
}
content := string(data)
for _, want := range []string{"trigger: Manual", "job_name: Hello Test", "hello from test"} {
if !strings.Contains(content, want) {
t.Fatalf("expected log content to contain %q, got:\n%s", want, content)
}
}
}
func TestRunJobRunsQuotedWindowsExecutable(t *testing.T) {
if runtime.GOOS != "windows" {
t.Skip("Windows cmd.exe quoting only")
}
logsDir := t.TempDir()
job := domain.Job{
ID: 43,
Name: "Quoted Windows Command",
Command: `"C:\Windows\System32\cmd.exe" /C echo quoted command ok`,
}
record, err := RunJob(context.Background(), &job, "Manual", logsDir, 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected quoted command to run, got state %q detail %q output:\n%s", record.State, record.Detail, record.Output)
}
if !strings.Contains(record.Output, "quoted command ok") {
t.Fatalf("expected command output, got:\n%s", record.Output)
}
}
func TestRunJobRunsUnquotedWindowsProgramPathWithSpaces(t *testing.T) {
if runtime.GOOS != "windows" {
t.Skip("Windows cmd.exe quoting only")
}
logsDir := t.TempDir()
scriptDir := filepath.Join(t.TempDir(), "Program Files", "GoSentry Test")
if err := os.MkdirAll(scriptDir, 0o755); err != nil {
t.Fatal(err)
}
scriptPath := filepath.Join(scriptDir, "hello.cmd")
if err := os.WriteFile(scriptPath, []byte("@echo off\r\necho unquoted command ok\r\n"), 0o755); err != nil {
t.Fatal(err)
}
job := domain.Job{
ID: 44,
Name: "Unquoted Windows Command",
Command: scriptPath,
}
record, err := RunJob(context.Background(), &job, "Manual", logsDir, 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected unquoted command path to run, got state %q detail %q output:\n%s", record.State, record.Detail, record.Output)
}
if !strings.Contains(record.Output, "unquoted command ok") {
t.Fatalf("expected command output, got:\n%s", record.Output)
}
}
func TestRunJobRunsWindowsCommandWithSeparateArguments(t *testing.T) {
if runtime.GOOS != "windows" {
t.Skip("Windows command arguments only")
}
logsDir := t.TempDir()
job := domain.Job{
ID: 45,
Name: "Separate Arguments",
Command: `C:\Windows\System32\cmd.exe`,
Arguments: "/C\necho separate arguments ok",
}
record, err := RunJob(context.Background(), &job, "Manual", logsDir, 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected separate arguments to run, got state %q detail %q output:\n%s", record.State, record.Detail, record.Output)
}
if !strings.Contains(record.Output, "separate arguments ok") {
t.Fatalf("expected command output, got:\n%s", record.Output)
}
}
func TestRunJobFailsOnNonZeroExitCode(t *testing.T) {
command := `sh -c 'exit 1'`
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
}
job := domain.Job{
ID: 47,
Name: "Non-zero Exit Code",
Command: command,
}
if runtime.GOOS == "windows" {
job.Arguments = "/C\nexit /b 1"
}
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "Failed" {
t.Fatalf("expected non-zero exit code to fail, got state %q detail %q", record.State, record.Detail)
}
if !strings.Contains(record.Detail, "exit code 1") {
t.Fatalf("expected exit code detail, got %q", record.Detail)
}
}
func TestRunJobStartOnlyDoesNotWaitForExitCode(t *testing.T) {
command := "sh"
arguments := "-c\nexit 7"
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
arguments = "/C\nexit /b 7"
}
job := domain.Job{
ID: 48,
Name: "Start Only",
Command: command,
Arguments: arguments,
StartOnly: true,
}
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected start-only job to be OK after launch, got state %q detail %q", record.State, record.Detail)
}
if !strings.Contains(record.Detail, "not waiting for process exit") {
t.Fatalf("expected start-only detail, got %q", record.Detail)
}
if !strings.Contains(record.Output, "start_only:\ntrue") {
t.Fatalf("expected start-only output, got:\n%s", record.Output)
}
}
func TestRunJobStartOnlyReportsStartFailure(t *testing.T) {
job := domain.Job{
ID: 49,
Name: "Missing Start Only",
Command: "definitely-missing-gosentry-command",
Arguments: "--force-direct-start",
StartOnly: true,
}
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), 30*time.Second)
if err != nil {
t.Fatal(err)
}
if record.State != "Failed" {
t.Fatalf("expected missing start-only command to fail, got state %q detail %q", record.State, record.Detail)
}
if !strings.Contains(record.Output, "Process did not start") {
t.Fatalf("expected start failure output, got:\n%s", record.Output)
}
}
func TestRunJobTimesOut(t *testing.T) {
command := "sh"
arguments := "-c\nsleep 5"
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
// timeout waits ~5s; ping to localhost is a portable stall on hosts where
// timeout refuses to run without an interactive console.
arguments = "/C\nping -n 6 127.0.0.1 >NUL"
}
job := domain.Job{
ID: 50,
Name: "Timeout Test",
Command: command,
Arguments: arguments,
}
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), 100*time.Millisecond)
if err != nil {
t.Fatal(err)
}
if record.State != "Failed" {
t.Fatalf("expected timed-out job to fail, got state %q detail %q", record.State, record.Detail)
}
if !strings.Contains(record.Detail, "Timed out after 100ms") {
t.Fatalf("expected timeout detail with the effective timeout, got %q", record.Detail)
}
}
func TestRunJobZeroTimeoutMeansNoTimeout(t *testing.T) {
command := "sh"
arguments := "-c\nsleep 0.2"
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
arguments = "/C\nping -n 2 127.0.0.1 >NUL"
}
job := domain.Job{
ID: 52,
Name: "No Timeout Test",
Command: command,
Arguments: arguments,
}
// A non-positive timeout must not expire immediately (context.WithTimeout
// with a zero duration would); the job must run to completion.
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), 0)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected job with no timeout to complete OK, got state %q detail %q", record.State, record.Detail)
}
}
// A StartOnly run must not leave a watcher goroutine behind. exec.CommandContext
// keeps one alive until Wait returns or the context is done, and StartOnly never
// waits, so binding it to the caller's cancelable context would leak one
// goroutine per run for the lifetime of the app — and then, on shutdown, kill a
// process whose handle startJobOnly has already released.
func TestRunJobStartOnlyLeavesNoContextWatcher(t *testing.T) {
command := "sh"
arguments := "-c\nexit 0"
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
arguments = "/C\nexit /b 0"
}
job := domain.Job{
ID: 53,
Name: "Start Only Goroutines",
Command: command,
Arguments: arguments,
StartOnly: true,
}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
const runs = 5
before := settledGoroutines()
for i := 0; i < runs; i++ {
if _, err := RunJob(ctx, &job, "Manual", t.TempDir(), 30*time.Second); err != nil {
t.Fatal(err)
}
}
// Counted before cancel on purpose: a watcher would still be parked on
// ctx.Done() at this point, and cancelling first would release it.
if leaked := settledGoroutines() - before; leaked > 1 {
t.Errorf("%d goroutines left after %d StartOnly runs, want none tied to the run context", leaked, runs)
}
}
// settledGoroutines returns the goroutine count once it has stopped falling, so
// a goroutine that is still on its way out is not mistaken for a leak.
func settledGoroutines() int {
lowest := runtime.NumGoroutine()
for stable, i := 0, 0; stable < 3 && i < 100; i++ {
time.Sleep(10 * time.Millisecond)
if count := runtime.NumGoroutine(); count < lowest {
lowest, stable = count, 0
continue
}
stable++
}
return lowest
}
func TestRunJobStartOnlyIgnoresTimeout(t *testing.T) {
command := "sh"
arguments := "-c\nsleep 5"
if runtime.GOOS == "windows" {
command = `C:\Windows\System32\cmd.exe`
arguments = "/C\nping -n 6 127.0.0.1 >NUL"
}
job := domain.Job{
ID: 51,
Name: "Start Only Timeout",
Command: command,
Arguments: arguments,
StartOnly: true,
}
// A tiny run timeout must not affect StartOnly jobs: they never wait on the
// timed run context, so the launch succeeds regardless.
record, err := RunJob(context.Background(), &job, "Manual", t.TempDir(), time.Millisecond)
if err != nil {
t.Fatal(err)
}
if record.State != "OK" {
t.Fatalf("expected start-only job to be OK despite tiny timeout, got state %q detail %q", record.State, record.Detail)
}
if !strings.Contains(record.Detail, "not waiting for process exit") {
t.Fatalf("expected start-only detail, got %q", record.Detail)
}
}