diff --git a/internal/buildtools/install_refresh_marker_test.go b/internal/buildtools/install_refresh_marker_test.go new file mode 100644 index 000000000..da6e85a2b --- /dev/null +++ b/internal/buildtools/install_refresh_marker_test.go @@ -0,0 +1,222 @@ +package buildtools + +import ( + "encoding/json" + "os" + "os/exec" + "path/filepath" + "strings" + "testing" + "time" +) + +// BUG-3215. Between the stop and the restart nothing serves the port, and a +// pad CLI call in that window used to auto-start a server of its own (the +// caller's binary, cwd and default flags) that then held the port against the +// refresh. The script now claims the window with a marker the CLI's +// auto-start defers to, and checks WHO holds the port both before it spawns +// the restart and after the probe. + +// markerRun runs the script and returns its result plus the pid of the bash +// process that ran it: the pid the marker must name, because the CLI's +// liveness check probes it. +func markerRun(t *testing.T, e stubEnv, built, installed, commit string, extraEnv ...string) (runResult, int) { + t.Helper() + cmd := exec.Command("bash", scriptPath(t), built, installed, commit) + cmd.Env = append(e.env(), extraEnv...) + var out, errb strings.Builder + cmd.Stdout, cmd.Stderr = &out, &errb + if err := cmd.Start(); err != nil { + t.Fatalf("start script: %v", err) + } + pid := cmd.Process.Pid + err := cmd.Wait() + return runResult{stdout: out.String(), stderr: errb.String(), err: err}, pid +} + +func countServerStarts(t *testing.T, argvLog string) int { + t.Helper() + b, err := os.ReadFile(argvLog) + if err != nil { + if os.IsNotExist(err) { + return 0 + } + t.Fatalf("read argv log: %v", err) + } + n := 0 + for _, l := range strings.Split(strings.TrimSpace(string(b)), "\n") { + if strings.Contains(l, "server start") { + n++ + } + } + return n +} + +// The marker exists for the restart, names this script, this port and a +// short deadline, lives where the CLI will look (the DataDir rule, not the +// cwd), and is gone when the script exits. Run once with the default +// location and once with PAD_DATA_DIR and PAD_DB_PATH, because a marker the +// CLI resolves somewhere else is a marker nobody honours. +func TestInstallRefresh_HoldsTheRefreshMarkerForTheRestartWindow(t *testing.T) { + requireScriptDeps(t) + cases := []struct { + name string + // env returns extra environment and the marker path it implies. + env func(home string) ([]string, string) + }{ + {"default data dir", func(home string) ([]string, string) { + return nil, filepath.Join(home, ".pad", "refresh.lock") + }}, + {"PAD_DATA_DIR", func(home string) ([]string, string) { + d := filepath.Join(home, "elsewhere") + return []string{"PAD_DATA_DIR=" + d}, filepath.Join(d, "refresh.lock") + }}, + {"PAD_DB_PATH wins over PAD_DATA_DIR", func(home string) ([]string, string) { + d := filepath.Join(home, "dbdir") + return []string{"PAD_DATA_DIR=" + filepath.Join(home, "loser"), "PAD_DB_PATH=" + filepath.Join(d, "pad.db")}, + filepath.Join(d, "refresh.lock") + }}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + home, dir := t.TempDir(), t.TempDir() + name := uniqueName(t) + defer killStub(t, name) + port := freePort(t) + const commit = "abc1234" + + built := installStub(t, dir, name) + installed := filepath.Join(home, "bin", name) + markerLog := filepath.Join(home, "marker.log") + extra, markerPath := tc.env(home) + extra = append(extra, "STUB_MARKER_LOG="+markerLog, "STUB_MARKER_PATH="+markerPath) + e := stubEnv{version: "pad version dev (" + commit + " x)", healthy: "1", + argvLog: filepath.Join(home, "argv.log"), port: port, home: home} + + pre := exec.Command(built, "server", "start") + pre.Env = append(e.env(), extra...) + startPreServer(t, pre, "127.0.0.1", port) + + before := time.Now().Unix() + res, scriptPID := markerRun(t, e, built, installed, commit, extra...) + if res.err != nil { + t.Fatalf("refresh failed: %v\nstdout=%s\nstderr=%s", res.err, res.stdout, res.stderr) + } + + logged, err := os.ReadFile(markerLog) + if err != nil { + t.Fatalf("read marker log: %v", err) + } + lines := strings.Split(strings.TrimSpace(string(logged)), "\n") + if len(lines) != 2 { + t.Fatalf("want 2 server starts logged (the pre-server and the restart), got %d: %q", len(lines), lines) + } + // PREMISE: before the refresh there is no marker, so the one the + // restart sees was written by the refresh. + if lines[0] != "absent" { + t.Fatalf("premise: a marker existed before the refresh: %q", lines[0]) + } + var m struct { + PID int `json:"pid"` + Port int `json:"port"` + Deadline int64 `json:"deadline"` + } + if err := json.Unmarshal([]byte(lines[1]), &m); err != nil { + t.Fatalf("the restart did not find a readable marker at %s: %q (%v)", markerPath, lines[1], err) + } + if m.PID != scriptPID { + t.Errorf("marker pid = %d, want the script's pid %d", m.PID, scriptPID) + } + if m.Port != port { + t.Errorf("marker port = %d, want %d", m.Port, port) + } + // PAD_PROBE_TIMEOUT is 8 in these tests, so the deadline is + // now + 18s: short, and not already past. + if m.Deadline <= before || m.Deadline > before+19+5 { + t.Errorf("marker deadline %d is not a short one after %d", m.Deadline, before) + } + if _, err := os.Stat(markerPath); !os.IsNotExist(err) { + t.Errorf("the marker outlived the refresh (stat err=%v)", err) + } + }) + } +} + +// Day 79, in order: the refresh stops the server, and before it restarts it a +// pad CLI call auto-starts a stray on the port (a binary that predates the +// marker, or a start by hand). The restart cannot bind, so it is not spawned, +// and the holder is named. +func TestInstallRefresh_NamesAStrayThatTookThePortBeforeTheRestart(t *testing.T) { + requireScriptDeps(t) + home, dir := t.TempDir(), t.TempDir() + name := uniqueName(t) + defer killStub(t, name) + port := freePort(t) + const commit = "abc1234" + + built := installStub(t, dir, name) + installed := filepath.Join(home, "bin", name) + argvLog := filepath.Join(home, "argv.log") + e := stubEnv{version: "pad version dev (" + commit + " x)", healthy: "1", + argvLog: argvLog, port: port, home: home} + + // The pre-server hands its port to a stray when the refresh stops it. + pre := exec.Command(built, "server", "start") + pre.Env = append(e.env(), "STUB_STRAY_ON_TERM=1") + startPreServer(t, pre, "127.0.0.1", port) + + res := runScript(t, e, built, installed, commit) + if res.err == nil { + t.Fatalf("refresh reported success with a stray on the port; stdout=%s", res.stdout) + } + if !strings.Contains(res.stderr, "was taken after the old server stopped and before the restart") { + t.Errorf("the refusal does not say the port was taken in the window; stderr=%s", res.stderr) + } + if !strings.Contains(res.stderr, name+" server start") { + t.Errorf("the refusal does not name the holder's argv; stderr=%s", res.stderr) + } + // Only the pre-server ever started: no restart was spawned into a port + // it could not bind. + if got := countServerStarts(t, argvLog); got != 1 { + t.Errorf("server starts logged = %d, want 1 (the pre-server alone)", got) + } + if _, err := os.Stat(filepath.Join(home, ".pad", "refresh.lock")); !os.IsNotExist(err) { + t.Errorf("the marker outlived a refusal (stat err=%v)", err) + } +} + +// The probe answers for whoever holds the address. Here a stray beats the +// restart to the port after it is spawned, so the probe PASSES, and the only +// thing that can tell this from a good refresh is who is listening. Before +// this check the script printed success over the stray. +func TestInstallRefresh_RefusesSuccessWhenTheListenerIsNotTheRestart(t *testing.T) { + requireScriptDeps(t, "ss") + home, dir := t.TempDir(), t.TempDir() + name := uniqueName(t) + defer killStub(t, name) + port := freePort(t) + const commit = "abc1234" + + built := installStub(t, dir, name) + installed := filepath.Join(home, "bin", name) + e := stubEnv{version: "pad version dev (" + commit + " x)", healthy: "1", + argvLog: filepath.Join(home, "argv.log"), port: port, home: home} + + // No server running: the refresh starts one with defaults, and that + // start is beaten to the port. + res, _ := markerRun(t, e, built, installed, commit, "STUB_STRAY_ON_START=1") + if res.err == nil { + t.Fatalf("refresh reported success while a stray served the port; stdout=%s", res.stdout) + } + if strings.Contains(res.stdout, "server restarted and answering") { + t.Errorf("the script claimed the restart answered; stdout=%s", res.stdout) + } + if !strings.Contains(res.stderr, "not by this refresh's restart") { + t.Errorf("the refusal does not say the listener is not the restart; stderr=%s", res.stderr) + } + // PREMISE: the probe itself passed. Otherwise this is the ordinary + // "did not answer" failure and the ownership check was never reached. + if strings.Contains(res.stderr, "did not answer on") { + t.Fatalf("premise: the probe failed, so the stray was not answering; stderr=%s", res.stderr) + } +} diff --git a/internal/buildtools/install_refresh_test.go b/internal/buildtools/install_refresh_test.go index edbcf54c5..72a9f9c54 100644 --- a/internal/buildtools/install_refresh_test.go +++ b/internal/buildtools/install_refresh_test.go @@ -1538,9 +1538,19 @@ func TestPreServerFixtureAcceptsItsOwnStub(t *testing.T) { // check passes, because the untouched test runs fine wherever the // dependencies exist. func TestEveryScriptTestDeclaresItsDependencies(t *testing.T) { - src, err := os.ReadFile("install_refresh_test.go") - if err != nil { - t.Fatalf("read own source: %v", err) + // Every file of script tests, not only this one: a guard that reads one + // file exempts the next file anyone adds (BUG-3215 added one). + files, err := filepath.Glob("install_refresh*_test.go") + if err != nil || len(files) < 2 { + t.Fatalf("glob script test files: %v (found %v)", err, files) + } + var src []byte + for _, f := range files { + b, err := os.ReadFile(f) + if err != nil { + t.Fatalf("read %s: %v", f, err) + } + src = append(src, b...) } re := regexp.MustCompile(`func (TestInstallRefresh_\w+)\(t \*testing\.T\) \{\n(\t[^\n]*)`) matches := re.FindAllStringSubmatch(string(src), -1) diff --git a/internal/buildtools/testdata/stub/main.go b/internal/buildtools/testdata/stub/main.go index 1ba1107d2..28a902311 100644 --- a/internal/buildtools/testdata/stub/main.go +++ b/internal/buildtools/testdata/stub/main.go @@ -13,13 +13,31 @@ package main import ( "fmt" + "io" "net" "net/http" "os" + "os/exec" + "os/signal" + "strconv" "strings" + "syscall" + "time" ) func main() { + // STUB_STRAY_HOP is the middle process of the double fork in spawnStray: + // it starts the stray and exits at once, so the stray's parent is NOT the + // process that spawned it. The script accepts the restart's direct child + // as the restart itself, so a stray that stayed a direct child would be + // accepted and the test would measure nothing. + if os.Getenv("STUB_STRAY_HOP") == "1" { + cmd := exec.Command(os.Args[0], "server", "start") + cmd.Env = strayEnv() + cmd.SysProcAttr = &syscall.SysProcAttr{Setsid: true} + _ = cmd.Start() + return + } if len(os.Args) > 1 && os.Args[1] == "--version" { // The version can depend on WHERE this copy lives, which is what // makes the post-copy outcome check testable at all. The script has @@ -63,6 +81,27 @@ func main() { } } } + // STUB_MARKER_LOG records, at each server start, the refresh marker at + // STUB_MARKER_PATH as it reads right then, or "absent" (BUG-3215). The + // restart is spawned inside the window the marker covers, so its line is + // the marker as a CLI in that window would have found it. + if logPath := os.Getenv("STUB_MARKER_LOG"); logPath != "" { + line := "absent" + if b, err := os.ReadFile(os.Getenv("STUB_MARKER_PATH")); err == nil { + line = strings.TrimSpace(string(b)) + } + if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644); err == nil { + fmt.Fprintln(f, line) + f.Close() + } + } + // STUB_STRAY_ON_START=1: this start is beaten to the port by a stray + // (BUG-3215, the post-probe check). The stray binds first; this process + // then fails its own bind and exits, as the refresh's restart did on + // day 79. + if os.Getenv("STUB_STRAY_ON_START") == "1" { + spawnStray() + } // STUB_HEALTHY=0 exits immediately: what a restart that silently did // not happen looks like from outside. if os.Getenv("STUB_HEALTHY") != "1" { @@ -99,5 +138,66 @@ func main() { if os.Getenv("STUB_ANNOUNCE") == "1" { fmt.Printf("LISTENING %d\n", ln.Addr().(*net.TCPAddr).Port) } + // STUB_STRAY_ON_TERM=1: on SIGTERM, release the port and let a stray + // take it before exiting (BUG-3215, the pre-spawn check). That is the + // day-79 order: the refresh stops the server, and a CLI auto-start takes + // the port before the refresh restarts it. + if os.Getenv("STUB_STRAY_ON_TERM") == "1" { + term := make(chan os.Signal, 1) + signal.Notify(term, syscall.SIGTERM) + go func() { + <-term + _ = ln.Close() + spawnStray() + os.Exit(0) + }() + // Closing the listener makes Serve return; main must not return + // with it, or the process exits before the stray exists. + _ = http.Serve(ln, mux) + select {} + } _ = http.Serve(ln, mux) } + +// strayEnv is this process's environment without the knobs that would make +// the stray do anything but serve: no stray of its own, no log lines that a +// test counts as the refresh's restart. +func strayEnv() []string { + var env []string + for _, kv := range os.Environ() { + switch strings.SplitN(kv, "=", 2)[0] { + case "STUB_STRAY_ON_START", "STUB_STRAY_ON_TERM", "STUB_STRAY_HOP", + "STUB_ARGV_LOG", "STUB_CWD_LOG", "STUB_MARKER_LOG", "STUB_ANNOUNCE", "STUB_HEALTHY": + continue + } + env = append(env, kv) + } + return append(env, "STUB_HEALTHY=1") +} + +// spawnStray starts a detached server on STUB_PORT through a double fork and +// waits until it answers, so the caller's next step meets a port that is +// already taken. A stray that never answers fails the fixture loudly rather +// than letting the test pass on an empty port. +func spawnStray() { + hop := exec.Command(os.Args[0]) + hop.Env = append(strayEnv(), "STUB_STRAY_HOP=1") + if err := hop.Run(); err != nil { + fmt.Fprintln(os.Stderr, "stub: stray hop:", err) + os.Exit(3) + } + url := "http://" + net.JoinHostPort("127.0.0.1", os.Getenv("STUB_PORT")) + "/stub/pid" + client := &http.Client{Timeout: 500 * time.Millisecond} + for i := 0; i < 100; i++ { + if res, err := client.Get(url); err == nil { + body, _ := io.ReadAll(io.LimitReader(res.Body, 64)) + res.Body.Close() + if pid, err := strconv.Atoi(strings.TrimSpace(string(body))); err == nil && pid != os.Getpid() { + return + } + } + time.Sleep(50 * time.Millisecond) + } + fmt.Fprintln(os.Stderr, "stub: the stray never answered") + os.Exit(3) +} diff --git a/internal/cli/refresh_marker.go b/internal/cli/refresh_marker.go new file mode 100644 index 000000000..c0a12dad4 --- /dev/null +++ b/internal/cli/refresh_marker.go @@ -0,0 +1,130 @@ +package cli + +import ( + "encoding/json" + "fmt" + "os" + "path/filepath" + "time" + + "github.com/PerpetualSoftware/pad/internal/config" +) + +// RefreshMarkerName is the file scripts/install-refresh.sh writes, beside the +// PID file, for the window in which it has stopped the server and not yet seen +// its replacement answer (BUG-3215). +// +// That window used to belong to whichever process asked first. Any pad CLI +// call landing in it found no server and auto-started one with DEFAULT flags, +// running the CALLER's binary (a worktree build, or the old inode before the +// install's rename) from the caller's cwd. The refresh's own restart then +// could not bind, and the box was left serving the wrong argv and possibly the +// wrong commit. The marker hands the window back to the refresh: EnsureServer +// waits for it instead of spawning. +const RefreshMarkerName = "refresh.lock" + +// refreshMarker is the marker's content. The script writes it with printf, so +// the shape is kept flat and every member is a plain integer. +type refreshMarker struct { + // PID of the refresh script. A marker whose writer is gone describes + // nothing: crash-only, so no one else removes it. + PID int `json:"pid"` + // Port the refresh will restart the server on. A CLI pointed at another + // port (a seat's private server, an e2e server) is not in this window. + Port int `json:"port"` + // Deadline, unix seconds. A pid alone can be reused, so liveness is the + // pid AND the deadline; a marker past it is not honoured by a new call. + Deadline int64 `json:"deadline"` +} + +// RefreshMarkerPath is where the marker lives for this config: the DataDir +// the PID file is in. The script resolves the same directory by the same +// rule (PAD_DB_PATH's directory, else PAD_DATA_DIR, else ~/.pad); neither +// the cwd nor the linked workspace takes part, so every CLI on the box finds +// the one marker. +func RefreshMarkerPath(cfg *config.Config) string { + return filepath.Join(cfg.DataDir, RefreshMarkerName) +} + +// refreshState is what a read of the marker says about THIS config's server. +type refreshState int + +const ( + // refreshNone: no marker, an unreadable one, another port's, a dead + // writer's, or one past its deadline. Nothing to wait for. + refreshNone refreshState = iota + // refreshLive: a refresh of this port is in progress. + refreshLive + // refreshExpired: the marker's writer is alive but its deadline has + // passed. Only meaningful to a caller that was already waiting. + refreshExpired +) + +// Package-level so the tests can drive the clock and the pid probe. Neither +// is swapped outside tests. +var ( + refreshNow = time.Now + refreshOwnerGone = processIsGone +) + +func readRefreshMarker(cfg *config.Config) (refreshMarker, refreshState) { + data, err := os.ReadFile(RefreshMarkerPath(cfg)) + if err != nil { + return refreshMarker{}, refreshNone + } + var m refreshMarker + // An unparseable marker is read as absent, not as live: it cannot name a + // writer whose liveness bounds it, so honouring it could block auto-start + // for ever. The script writes it by rename, so a half-written file is + // never observed. + if err := json.Unmarshal(data, &m); err != nil || m.PID <= 0 || m.Port <= 0 { + return refreshMarker{}, refreshNone + } + if m.Port != cfg.Port { + return m, refreshNone + } + if refreshOwnerGone(m.PID) { + return m, refreshNone + } + if refreshNow().Unix() >= m.Deadline { + return m, refreshExpired + } + return m, refreshLive +} + +// refreshPoll is how often a waiting call re-reads the marker and the health +// probe. +var refreshPoll = 200 * time.Millisecond + +// awaitRefresh defers to a refresh in progress on this config's port. It +// returns nil when there is nothing to wait for, or when the server answered +// during the wait; the caller re-probes health and spawns only if it still +// has to. It returns an error, and the caller must NOT spawn, when the +// refresh's deadline passes while its writer is still alive: the refresh is +// still acting on the port, and an auto-start there is the defect. +func awaitRefresh(cfg *config.Config) error { + if _, st := readRefreshMarker(cfg); st != refreshLive { + // An expired marker found by a call that was not waiting is not + // honoured: pid AND deadline is the liveness rule. + return nil + } + for { + if isServerHealthy(cfg.Host, cfg.Port) { + return nil + } + time.Sleep(refreshPoll) + cur, st := readRefreshMarker(cfg) + switch st { + case refreshNone: + // Removed, or its writer died: the refresh is over, and if + // nothing answers now an auto-start is legitimate again. + return nil + case refreshExpired: + return fmt.Errorf( + "a server refresh (pid %d) is in progress on port %d and the server has not answered by its deadline; "+ + "not auto-starting over it. Check that refresh's output; if it is stuck, stop it (kill %d) and retry. "+ + "Marker: %s", + cur.PID, cur.Port, cur.PID, RefreshMarkerPath(cfg)) + } + } +} diff --git a/internal/cli/refresh_marker_test.go b/internal/cli/refresh_marker_test.go new file mode 100644 index 000000000..93f3ba113 --- /dev/null +++ b/internal/cli/refresh_marker_test.go @@ -0,0 +1,260 @@ +package cli + +import ( + "fmt" + "net" + "net/http" + "os" + "path/filepath" + "regexp" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/PerpetualSoftware/pad/internal/config" +) + +// BUG-3215. install-refresh.sh stops the server, installs, and restarts it with +// the argv it captured. Any pad CLI call in between found nothing answering +// and auto-started a server with default flags, which then held the port +// against the refresh's own restart. The refresh now writes a marker for that +// window and EnsureServer defers to it. +// +// Every test here counts SPAWNS, because the defect is a spawn: an end state of +// "a healthy server on the port" is produced identically by the refresh's +// restart and by the stray, so only the counter tells them apart. + +// refreshTestConfig returns a locally-managed config pointed at a port nothing +// listens on, and a spawn counter installed in place of the real spawn. +func refreshTestConfig(t *testing.T) (*config.Config, *int32) { + t.Helper() + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("reserve a port: %v", err) + } + port := l.Addr().(*net.TCPAddr).Port + _ = l.Close() + + cfg := &config.Config{ + Host: "127.0.0.1", + Port: port, + Mode: config.ModeLocal, + LoadedFromFile: true, + DataDir: t.TempDir(), + } + + var spawns int32 + origSpawn, origPoll := spawnServer, refreshPoll + spawnServer = func(*config.Config) error { + atomic.AddInt32(&spawns, 1) + return nil + } + refreshPoll = 20 * time.Millisecond + t.Cleanup(func() { spawnServer, refreshPoll = origSpawn, origPoll }) + return cfg, &spawns +} + +func writeMarker(t *testing.T, cfg *config.Config, pid, port int, deadline time.Time) { + t.Helper() + body := fmt.Sprintf(`{"pid": %d, "port": %d, "deadline": %d}`, pid, port, deadline.Unix()) + if err := os.WriteFile(RefreshMarkerPath(cfg), []byte(body), 0o644); err != nil { + t.Fatalf("write marker: %v", err) + } +} + +// serveHealthAt starts answering the health probe on the config's port. +func serveHealthAt(t *testing.T, cfg *config.Config) { + t.Helper() + l, err := net.Listen("tcp", fmt.Sprintf("127.0.0.1:%d", cfg.Port)) + if err != nil { + t.Fatalf("listen on %d: %v", cfg.Port, err) + } + srv := &http.Server{Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + _, _ = w.Write([]byte(`{"status":"ok"}`)) + })} + go func() { _ = srv.Serve(l) }() + t.Cleanup(func() { _ = srv.Close() }) +} + +// The control for everything below: with no marker, an unhealthy server is +// auto-started, exactly as before. Without this leg the counter could be +// broken and every "no spawn" assertion would pass. +func TestEnsureServer_SpawnsWithoutAMarker(t *testing.T) { + cfg, spawns := refreshTestConfig(t) + if err := EnsureServer(cfg); err != nil { + t.Fatalf("EnsureServer: %v", err) + } + if got := atomic.LoadInt32(spawns); got != 1 { + t.Fatalf("spawns = %d, want 1: the counter does not observe the ordinary auto-start", got) + } +} + +func TestEnsureServer_WaitsForALiveRefreshInsteadOfSpawning(t *testing.T) { + cfg, spawns := refreshTestConfig(t) + writeMarker(t, cfg, os.Getpid(), cfg.Port, time.Now().Add(30*time.Second)) + + // The refresh's restart comes up while the CLI is waiting. + up := time.AfterFunc(300*time.Millisecond, func() { serveHealthAt(t, cfg) }) + defer up.Stop() + + start := time.Now() + if err := EnsureServer(cfg); err != nil { + t.Fatalf("EnsureServer: %v", err) + } + if got := atomic.LoadInt32(spawns); got != 0 { + t.Fatalf("spawns = %d, want 0: the CLI auto-started a server over a refresh in progress", got) + } + // It waited for the restart, rather than returning early with nothing up. + if waited := time.Since(start); waited < 250*time.Millisecond { + t.Fatalf("returned after %v, before the restart was up", waited) + } + if !isServerHealthy(cfg.Host, cfg.Port) { + t.Fatal("returned nil with nothing answering") + } +} + +func TestEnsureServer_RefusesRatherThanSpawnsWhenALiveRefreshMissesItsDeadline(t *testing.T) { + cfg, spawns := refreshTestConfig(t) + writeMarker(t, cfg, os.Getpid(), cfg.Port, time.Now().Add(1500*time.Millisecond)) // the deadline is whole seconds + + err := EnsureServer(cfg) + if err == nil { + t.Fatal("EnsureServer returned nil with nothing answering and the refresh past its deadline") + } + if got := atomic.LoadInt32(spawns); got != 0 { + t.Fatalf("spawns = %d, want 0: a refresh that is still alive owns the port", got) + } + msg := err.Error() + for _, want := range []string{fmt.Sprintf("pid %d", os.Getpid()), fmt.Sprintf("kill %d", os.Getpid()), RefreshMarkerPath(cfg)} { + if !strings.Contains(msg, want) { + t.Errorf("error does not name %q: %s", want, msg) + } + } +} + +// A marker that is not live is not honoured. Each case must spawn, because a +// stale marker that blocked auto-start would turn a crashed refresh into a +// permanently unstartable CLI. +func TestEnsureServer_IgnoresAMarkerThatIsNotLive(t *testing.T) { + cases := []struct { + name string + setup func(t *testing.T, cfg *config.Config) + }{ + {"writer is dead", func(t *testing.T, cfg *config.Config) { + writeMarker(t, cfg, os.Getpid(), cfg.Port, time.Now().Add(30*time.Second)) + orig := refreshOwnerGone + refreshOwnerGone = func(int) bool { return true } + t.Cleanup(func() { refreshOwnerGone = orig }) + }}, + {"deadline already passed", func(t *testing.T, cfg *config.Config) { + writeMarker(t, cfg, os.Getpid(), cfg.Port, time.Now().Add(-time.Second)) + }}, + // A seat's private server, or an e2e server, on another port is not in + // the refresh's window. + {"another port", func(t *testing.T, cfg *config.Config) { + writeMarker(t, cfg, os.Getpid(), cfg.Port+1, time.Now().Add(30*time.Second)) + }}, + {"unparseable", func(t *testing.T, cfg *config.Config) { + if err := os.WriteFile(RefreshMarkerPath(cfg), []byte(`{"pid": `), 0o644); err != nil { + t.Fatal(err) + } + }}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + cfg, spawns := refreshTestConfig(t) + tc.setup(t, cfg) + if err := EnsureServer(cfg); err != nil { + t.Fatalf("EnsureServer: %v", err) + } + if got := atomic.LoadInt32(spawns); got != 1 { + t.Fatalf("spawns = %d, want 1: a marker that is not live blocked the auto-start", got) + } + }) + } +} + +// The refresh ended (its trap removed the marker) without anything answering: +// the auto-start is legitimate again, and the waiting call makes it. +func TestEnsureServer_SpawnsWhenTheMarkerIsRemovedMidWait(t *testing.T) { + cfg, spawns := refreshTestConfig(t) + writeMarker(t, cfg, os.Getpid(), cfg.Port, time.Now().Add(30*time.Second)) + rm := time.AfterFunc(200*time.Millisecond, func() { _ = os.Remove(RefreshMarkerPath(cfg)) }) + defer rm.Stop() + + if err := EnsureServer(cfg); err != nil { + t.Fatalf("EnsureServer: %v", err) + } + if got := atomic.LoadInt32(spawns); got != 1 { + t.Fatalf("spawns = %d, want 1", got) + } +} + +// The marker is found by the SAME DataDir rule the script uses, from any cwd: +// PAD_DB_PATH's directory, else PAD_DATA_DIR, else ~/.pad. A CLI started in +// another directory, or linked to another workspace, must find the one file. +func TestRefreshMarkerPath_FollowsTheDataDirRuleFromAnyCwd(t *testing.T) { + home := t.TempDir() + dataDir := t.TempDir() + dbDir := t.TempDir() + elsewhere := t.TempDir() + + t.Setenv("HOME", home) + t.Setenv("PAD_DATA_DIR", "") + t.Setenv("PAD_DB_PATH", "") + t.Chdir(elsewhere) + + load := func() string { + t.Helper() + cfg, err := config.Load() + if err != nil { + t.Fatalf("config.Load: %v", err) + } + return RefreshMarkerPath(cfg) + } + + if got, want := load(), filepath.Join(home, ".pad", RefreshMarkerName); got != want { + t.Errorf("default: %s, want %s", got, want) + } + t.Setenv("PAD_DATA_DIR", dataDir) + if got, want := load(), filepath.Join(dataDir, RefreshMarkerName); got != want { + t.Errorf("PAD_DATA_DIR: %s, want %s", got, want) + } + // PAD_DB_PATH wins over PAD_DATA_DIR, as config.Load applies it second. + t.Setenv("PAD_DB_PATH", filepath.Join(dbDir, "pad.db")) + if got, want := load(), filepath.Join(dbDir, RefreshMarkerName); got != want { + t.Errorf("PAD_DB_PATH: %s, want %s", got, want) + } +} + +// The marker is WRITTEN by bash and READ here, so the two sides share a format +// only if a test holds them to one. This reads the script's own printf format +// string, renders it the way printf does, and requires the reader to take the +// result as a live marker for this port. A renamed key or a changed shape on +// either side fails here instead of silently turning the marker off. +func TestReadRefreshMarker_ParsesTheScriptsOwnFormat(t *testing.T) { + src, err := os.ReadFile(filepath.Join("..", "..", "scripts", "install-refresh.sh")) + if err != nil { + t.Fatalf("read script: %v", err) + } + re := regexp.MustCompile(`printf '(\{"pid"[^']*)' "\$\$" "\$PORT"`) + m := re.FindAllSubmatch(src, -1) + if len(m) != 1 { + t.Fatalf("found %d marker printf lines in the script, want exactly 1", len(m)) + } + format := strings.ReplaceAll(string(m[0][1]), `\n`, "\n") + + cfg, _ := refreshTestConfig(t) + body := fmt.Sprintf(format, os.Getpid(), cfg.Port, time.Now().Add(30*time.Second).Unix()) + if err := os.WriteFile(RefreshMarkerPath(cfg), []byte(body), 0o644); err != nil { + t.Fatal(err) + } + got, st := readRefreshMarker(cfg) + if st != refreshLive { + t.Fatalf("the script's marker %q reads as state %d, want live", body, st) + } + if got.PID != os.Getpid() || got.Port != cfg.Port { + t.Fatalf("parsed %+v from %q", got, body) + } +} diff --git a/internal/cli/server.go b/internal/cli/server.go index e4b49beec..e5b23ff4d 100644 --- a/internal/cli/server.go +++ b/internal/cli/server.go @@ -24,6 +24,26 @@ func EnsureServer(cfg *config.Config) error { return nil } + // A refresh may have stopped the server on purpose and be about to + // restart it (BUG-3215). Its window is its own: wait for it rather than + // spawn a server with this caller's binary, flags and cwd over it. + if err := awaitRefresh(cfg); err != nil { + return err + } + if isServerHealthy(cfg.Host, cfg.Port) { + return nil + } + + return spawnServer(cfg) +} + +// spawnServer starts ` server start` in the background and waits +// for it to answer. A variable so the tests can count spawns: the defect +// BUG-3215 guards against is a spawn, and only a counter observes one that +// did not happen. +var spawnServer = startBackgroundServer + +func startBackgroundServer(cfg *config.Config) error { // Start server as background process exePath, err := os.Executable() if err != nil { diff --git a/scripts/install-refresh.sh b/scripts/install-refresh.sh index 80297c3eb..51e7712c3 100755 --- a/scripts/install-refresh.sh +++ b/scripts/install-refresh.sh @@ -70,6 +70,21 @@ flag_value() { return 1 } +# data_dir prints the directory the server and CLI keep their state in, by +# config.Load's rule: PAD_DB_PATH's directory, else PAD_DATA_DIR, else ~/.pad +# (PAD_DB_PATH is applied second there, so it wins). The refresh marker +# (BUG-3215) must be found by every CLI on the box, so it lives here and not +# anywhere the cwd or the linked workspace could change. +data_dir() { + if [ -n "${PAD_DB_PATH:-}" ]; then + dirname "$PAD_DB_PATH" + elif [ -n "${PAD_DATA_DIR:-}" ]; then + printf '%s' "$PAD_DATA_DIR" + else + printf '%s' "$HOME/.pad" + fi +} + # config_value prints a top-level key from the pad config file, or nothing. # # The file is FLAT TOML (internal/config/config.go: Host, Port, Mode, ... are @@ -82,9 +97,8 @@ flag_value() { # A stated boundary was the previous answer; it is a bad one when the cost of # closing it is a grep and the cost of leaving it is a permanent false alarm. config_value() { - local key="$1" path="$HOME/.pad/config.toml" - [ -n "${PAD_DATA_DIR:-}" ] && path="$PAD_DATA_DIR/config.toml" - [ -n "${PAD_DB_PATH:-}" ] && path="$(dirname "$PAD_DB_PATH")/config.toml" + local key="$1" path + path="$(data_dir)/config.toml" [ -r "$path" ] || return 1 # Strip an inline comment before taking the value: `port = 8080 # dev` # is valid TOML and the Go parser accepts it, so a regex that swallows @@ -464,7 +478,17 @@ fi mkdir -p "$(dirname "$INSTALLED")" STAGED="$(mktemp "$(dirname "$INSTALLED")/.$(basename "$INSTALLED").XXXXXX")" || die "could not stage the install next to $INSTALLED" -cleanup() { [ -n "${STAGED:-}" ] && rm -f "$STAGED"; } +# The marker is removed only while it is still OURS: a second refresh that +# started after this one owns the file now, and removing it would reopen the +# window it is holding. +cleanup() { + [ -n "${STAGED:-}" ] && rm -f "$STAGED" + if [ -n "${MARKER_WRITTEN:-}" ] && + [ "$(sed -n 's/.*"pid": *\([0-9]*\).*/\1/p' "$REFRESH_MARKER" 2>/dev/null)" = "$$" ]; then + rm -f "$REFRESH_MARKER" + fi + return 0 +} trap cleanup EXIT cp -f "$BUILT" "$STAGED" || die "cp failed" @@ -483,6 +507,70 @@ if [ -n "$EXPECT_COMMIT" ]; then fi fi +# PORT resolution, in the server's own precedence order. Resolved before the +# stop because the refresh marker names it (BUG-3215); the probe uses it too. +# +# Codex round 1: probing a fixed 7777 while faithfully restarting a server +# that was started with `--port 8080` fails a HEALTHY restart, and does it +# with this script's most confident message. The flag exists +# (cmd_server.go: `--port`, default 7777) so the case is reachable, and the +# whole point of this script is that the restart preserves the invocation — +# a probe that ignores half of that invocation is checking the wrong server. +configured_port="$(flag_value --port "${SERVER_ARGV[@]}" || true)" +# Each source is accepted only if it is NUMERIC, mirroring the application: +# config.go ignores a non-integer PAD_PORT and falls through to the next +# source. Without that, a mistyped or inherited PAD_PORT is probed +# literally and every refresh fails against a server that is running fine +# (codex round 7). +PORT="" +for candidate in "$configured_port" "${PAD_PORT:-}" "$(config_value port || true)"; do + if numeric "$candidate"; then + PORT="$candidate" + break + fi + if [ -n "$candidate" ]; then + note "ignoring non-numeric port value \"$candidate\" (as the server does)" + fi +done +PORT="${PORT:-7777}" + +# --- 2b. Claim the stop->restart window (BUG-3215) --------------------------- +# +# Between the stop below and the restart answering, nothing serves this port, +# and any pad CLI call in that window used to AUTO-START a server of its own: +# the caller's binary (a worktree build, or the old inode before the rename), +# from the caller's cwd, with default flags. It then held the port against +# this script's restart. Measured on day 79: the lead's `pad item comment` +# took the port during a bounce, 127.0.0.1:7777 went dark, and the script +# exited 1. +# +# The marker hands the window to this script. EnsureServer +# (internal/cli/refresh_marker.go) reads it and waits instead of spawning +# while it is LIVE: the pid below alive AND the deadline not passed, for the +# port it names. Written by rename, so a reader never sees half of it; removed +# by the EXIT trap, on success and on every refusal after this point. +# +# The deadline is short on purpose: the 5s TERM wait, a 5s margin for the +# install and the spawn, and one probe timeout (PAD_PROBE_TIMEOUT, 20s by +# default), so 30s by default. A healthy bounce is over in seconds and the +# waiting CLI returns the moment the server answers; the deadline only +# decides how long a CLI waits on a refresh that is failing, after which it +# errors naming this pid rather than spawning. +REFRESH_MARKER="$(data_dir)/refresh.lock" +MARKER_WRITTEN="" +probe_budget="$PROBE_TIMEOUT" +numeric "$probe_budget" || probe_budget=20 +mkdir -p "$(dirname "$REFRESH_MARKER")" || die "could not create $(dirname "$REFRESH_MARKER") for the refresh marker" +marker_tmp="$(mktemp "$REFRESH_MARKER.XXXXXX")" || die "could not stage the refresh marker next to $REFRESH_MARKER" +printf '{"pid": %d, "port": %d, "deadline": %d}\n' "$$" "$PORT" "$(($(date +%s) + 10 + probe_budget))" >"$marker_tmp" && + mv -f "$marker_tmp" "$REFRESH_MARKER" || + { + rm -f "$marker_tmp" + die "could not write the refresh marker $REFRESH_MARKER. + Nothing was stopped or installed." + } +MARKER_WRITTEN=1 + # --- 3. Stop ----------------------------------------------------------------- # # The TARGET only, by pid (BUG-3194). This used to be `pkill -x `, which @@ -619,11 +707,41 @@ if [ -n "$SERVER_CWD" ]; then cd "$SERVER_CWD" || die "could not enter $SERVER_CWD to restart the server there. The old server was signalled to stop and the new binary is installed; nothing was restarted. Check what is running on port $TARGET_PORT." fi +# describe_pid prints "pid N (argv)" for a report. Best effort: a pid that has +# gone by the time it is read is named alone. +describe_pid() { + local args + args="$(ps -o args= -p "$1" 2>/dev/null || true)" + if [ -n "$args" ]; then + printf 'pid %s (%s)' "$1" "$args" + else + printf 'pid %s' "$1" + fi +} + +# The old server is stopped, so anything holding the port NOW took it in the +# window (BUG-3215): a CLI auto-start from a binary that predates the marker, +# or a start by hand. The restart could not bind, so it is not spawned, and +# the holder is named instead of left for the probe to misread. +early=() +while read -r lp; do + case "$lp" in HIDDEN | '') ;; *) early+=("$lp") ;; esac +done < <(listener_pids "$PORT") +if [ "${#early[@]}" -gt 0 ]; then + held_by=() + for lp in "${early[@]}"; do held_by+=("$(describe_pid "$lp")"); done + die "port $PORT was taken after the old server stopped and before the restart, by: ${held_by[*]}. + The binary is installed; nothing was restarted, because the restart could not bind. + Most likely a pad CLI call auto-started a server in the window. Stop that process and re-run the refresh. + Restart argv would have been: ${restart[*]}" +fi + if [ -z "${PAD_NO_SETSID:-}" ] && command -v setsid >/dev/null 2>&1; then setsid nohup "${restart[@]}" >>"$HOME/.pad/server.log" 2>&1 >"$HOME/.pad/server.log" 2>&1 /dev/null || true # --- 6. Probe BOTH addresses before claiming anything ------------------------- @@ -634,31 +752,6 @@ disown 2>/dev/null || true # local CLI call and browser tab uses. configured_host="$(flag_value --host "${SERVER_ARGV[@]}" || true)" -# PORT resolution, in the server's own precedence order. -# -# Codex round 1: probing a fixed 7777 while faithfully restarting a server -# that was started with `--port 8080` fails a HEALTHY restart, and does it -# with this script's most confident message. The flag exists -# (cmd_server.go: `--port`, default 7777) so the case is reachable, and the -# whole point of this script is that the restart preserves the invocation — -# a probe that ignores half of that invocation is checking the wrong server. -configured_port="$(flag_value --port "${SERVER_ARGV[@]}" || true)" -# Each source is accepted only if it is NUMERIC, mirroring the application: -# config.go ignores a non-integer PAD_PORT and falls through to the next -# source. Without that, a mistyped or inherited PAD_PORT is probed -# literally and every refresh fails against a server that is running fine -# (codex round 7). -PORT="" -for candidate in "$configured_port" "${PAD_PORT:-}" "$(config_value port || true)"; do - if numeric "$candidate"; then - PORT="$candidate" - break - fi - if [ -n "$candidate" ]; then - note "ignoring non-numeric port value \"$candidate\" (as the server does)" - fi -done -PORT="${PORT:-7777}" # HOST likewise. When the argv carries no --host, fall back to PAD_HOST, # which config.go reads for exactly this purpose. @@ -754,6 +847,42 @@ if [ "${probe_any:-0}" = "1" ] && [ "$answered" -gt 0 ]; then probe_hosts=("localhost") fi +# WHO answered (BUG-3215). A health probe answers for whatever holds the +# address, so a server that took the port in the window passes it: on day 79 +# the stray bound the LAN address with default flags, and had it bound +# loopback this script would have printed success over the wrong server. The +# listener must be the restart this script spawned (or its direct child, +# should `setsid` have had to fork). Checked on the failure path too, where a +# named holder is the diagnosis a bare "did not answer" is not. +owner_ok() { + [ "$1" = "$RESTART_PID" ] && return 0 + [ "$(ps -o ppid= -p "$1" 2>/dev/null | tr -d ' ')" = "$RESTART_PID" ] +} +late=() +late_hidden="" +while read -r lp; do + case "$lp" in HIDDEN) late_hidden=1 ;; '') ;; *) late+=("$lp") ;; esac +done < <(listener_pids "$PORT") +foreign_late=() +for lp in "${late[@]}"; do + owner_ok "$lp" || foreign_late+=("$(describe_pid "$lp")") +done +if [ "${#foreign_late[@]}" -gt 0 ]; then + die "port $PORT is held by ${foreign_late[*]}, not by this refresh's restart (pid $RESTART_PID). + The binary is installed, but the server answering is not the one this refresh started. + Most likely a pad CLI call auto-started a server in the window. Stop that process and re-run the refresh. + Restart argv was: ${restart[*]}" +fi +if [ -n "$late_hidden" ]; then + die "a listener on port $PORT cannot be attributed to a process here, so this refresh cannot confirm the restart (pid $RESTART_PID) is what answers. + The binary is installed. Check what holds port $PORT." +fi +if [ "${#late[@]}" -eq 0 ] && [ ${#failed[@]} -eq 0 ]; then + # Neither ss nor lsof can see listeners here: the probe passed, but + # whose server answered is unverified, and the success line says so. + unattributed=1 +fi + if [ ${#failed[@]} -gt 0 ]; then die "server did not answer on: ${failed[*]} (port $PORT, waited ${PROBE_TIMEOUT}s each). The binary is installed; the server is not serving those addresses. @@ -761,3 +890,6 @@ if [ ${#failed[@]} -gt 0 ]; then fi note "server restarted and answering on: ${probe_hosts[*]} (port $PORT)" +if [ -n "${unattributed:-}" ]; then + note "listener ownership NOT verified: neither ss nor lsof can see listeners here, so the process answering was not confirmed to be the restart (pid $RESTART_PID)" +fi