diff --git a/cmd/mcpproxy/main.go b/cmd/mcpproxy/main.go index 05ad24ea..17759f2e 100644 --- a/cmd/mcpproxy/main.go +++ b/cmd/mcpproxy/main.go @@ -714,6 +714,15 @@ func loadConfig(cmd *cobra.Command) (*config.Config, error) { // Load configuration - use LoadFromFile if config file specified, otherwise use Load if configFile != "" { + // A named config that has never been written is a FIRST RUN, not an + // error: the relocated tray instance of GH #936 spawns its core with + // --data-dir --config /mcp_config.json against a root + // nothing has used before. The implicit path has always created its + // default here; the explicit one used to exit with "no such file or + // directory" instead, which made that whole flow unusable. + if _, ensureErr := config.EnsureConfigFile(configFile, dataDir); ensureErr != nil { + return nil, ensureErr + } cfg, err = config.LoadFromFile(configFile) } else { cfg, err = config.Load() diff --git a/docs/tray-debug.md b/docs/tray-debug.md index fc1b2788..497b9d47 100644 --- a/docs/tray-debug.md +++ b/docs/tray-debug.md @@ -6,10 +6,61 @@ This guide explains how to control the mcpproxy tray during development and auto | Variable | Scope | Default | Purpose | |----------|-------|---------|---------| +| `MCPPROXY_HOME` | macOS tray | `~/.mcpproxy` | Relocates the whole instance root: socket, config, database, autostart sidecar, lifecycle journal. | +| `MCPPROXY_SOCKET_PATH` | macOS tray | `/mcpproxy.sock` | Points the tray at one specific core's socket, wherever the root is. | | `MCPPROXY_TRAY_SKIP_CORE` | Tray | unset | Prevents the tray from launching the core binary. | | `MCPPROXY_CORE_URL` | Tray | `http://localhost:8080` | Overrides the core API endpoint the tray connects to. | | `MCPPROXY_DISABLE_OAUTH` | Core | unset | Disables OAuth popups and tray-driven login prompts. | +## Running a Second (Dev/QA) macOS Tray Instance + +The native macOS tray resolves its paths through `homeDirectoryForCurrentUser`, which **ignores `$HOME`**. Without an override, a tray built from a branch and run out of a scratch bundle still reads and writes the real `~/.mcpproxy` — which means QA runs cannot go in parallel (they contend for one socket) and the autostart sidecar overwrites the user's real login-item state on every launch. + +`MCPPROXY_HOME` moves the whole instance in one step. It is unset in normal use, and with it unset every path resolves exactly where it always did. + +```bash +# Keep the root SHORT: sockaddr_un caps the socket path at 103 bytes, and a +# deep scratch directory silently fails to bind. The tray logs a warning if +# the resolved path is over the limit. +export MCPPROXY_HOME=/tmp/mcpproxy-qa +/path/to/dev/mcpproxy.app/Contents/MacOS/MCPProxy +``` + +With it set: + +| File | Default | With `MCPPROXY_HOME=/tmp/mcpproxy-qa` | +|------|---------|----------------------------------------| +| Core socket | `~/.mcpproxy/mcpproxy.sock` | `/tmp/mcpproxy-qa/mcpproxy.sock` | +| Config opened by **Open Config File** | `~/.mcpproxy/mcp_config.json` | `/tmp/mcpproxy-qa/mcp_config.json` | +| Autostart sidecar | `~/.mcpproxy/tray-autostart.json` | `/tmp/mcpproxy-qa/tray-autostart.json` | +| Lifecycle journal | `~/.mcpproxy/tray-lifecycle.jsonl` | `/tmp/mcpproxy-qa/tray-lifecycle.jsonl` | +| Spawned core | `mcpproxy serve` | `mcpproxy serve --data-dir /tmp/mcpproxy-qa --config /tmp/mcpproxy-qa/mcp_config.json` | + +Notes and limits: + +- A brand-new root needs nothing prepared. The core creates the config file named by `--config` when it does not exist yet (printing `INFO: Created default configuration file at …`), so `export MCPPROXY_HOME=/tmp/mcpproxy-qa` and launching the tray is the whole setup. An existing file is never touched. +- The core also reads its autostart sidecar out of the data directory it was given, so a QA instance reports its own login-item state rather than the real install's. +- `MCPPROXY_SOCKET_PATH` still wins over the root. Use it to attach to a core somebody else started; use `MCPPROXY_HOME` to own a whole instance. +- **Not** relocated: `~/Library/Logs/mcpproxy` (the core's log directory, which follows the core's own rules) and the app's preferences domain — `cfprefsd` honours neither `$HOME` nor this variable, so give a dev bundle a distinct bundle id if you need separate defaults. +- The first-run dialog is a `UserDefaults` flag, so it lives in the preferences domain rather than the instance root; a fresh bundle id will show it again. Its "Launch at login" checkbox is pre-checked, so clicking through it in a dev instance registers a real login item. + +## Attributing a Tray or Core Exit + +Every start and stop is recorded in `/tray-lifecycle.jsonl`, one JSON object per line, and mirrored to the macOS unified log at Notice level (`log show --predicate 'subsystem == "com.smartmcpproxy.mcpproxy"'`) — Notice because the Info and Debug tiers are purged within hours, which is precisely why an earlier silent exit could not be attributed. + +```bash +tail -5 ~/.mcpproxy/tray-lifecycle.jsonl | python3 -m json.tool --json-lines +``` + +Recorded events: `appLaunched`, `appTerminating`, `signalReceived`, `coreLaunched`, `coreTerminated`, `coreExited`, `updateCheck`. Each carries a free-text reason, the uptime of the tray process, and a pid. + +The rules worth knowing when reading one: + +- Every shutdown records **who asked**. A shutdown nobody claimed is written as `unattributed (no initiator claimed this shutdown)` rather than as something plausible. +- `SIGTERM`, `SIGINT` and `SIGHUP` are caught, recorded, and then routed through the normal quit path — handled off the main thread, so a wedged main thread cannot swallow them. If the app has not gone five seconds later, the signal's default action is restored and re-raised: catching a termination signal delays the exit, it never prevents it. `SIGKILL` and a jetsam kill cannot be caught by anyone. +- Which is why the **next** launch reports an unaccounted-for previous run: if the previous run recorded no `appTerminating` at all, the new `appLaunched` record says so and names the last thing the dead run did. That marker is the signature of a SIGKILL-class death (jetsam, `pkill`, power loss) or a crash outside the app's handlers. It is not the *last* record that decides this — an ordinary clean exit writes `appTerminating` first and then `coreTerminated` for the core it tears down. +- The journal is trimmed to its newest 500 records at launch. + ## Use Cases ### Debugging the Core and Tray Separately diff --git a/internal/config/ensure_config_file_test.go b/internal/config/ensure_config_file_test.go new file mode 100644 index 00000000..84bef421 --- /dev/null +++ b/internal/config/ensure_config_file_test.go @@ -0,0 +1,108 @@ +package config + +import ( + "os" + "path/filepath" + "testing" +) + +// A relocated tray instance (GH #936) spawns its core with BOTH flags: +// +// mcpproxy serve --data-dir --config /mcp_config.json +// +// against a root that has never been used before, so the named config does not +// exist yet. LoadFromFile is deliberately strict about a missing explicit path +// — it is also the hot-reload entry point, where "the file vanished" must never +// mean "reset to defaults" — so the serve entry point seeds the file first. +// Without that seeding the documented flow was dead on arrival: the core exited +// immediately with "failed to load config file …: no such file or directory". +func TestAFreshInstanceRootIsSeededAndThenLoads(t *testing.T) { + root := t.TempDir() + path := filepath.Join(root, ConfigFileName) + + created, err := EnsureConfigFile(path, root) + if err != nil { + t.Fatalf("EnsureConfigFile: %v", err) + } + if !created { + t.Fatal("a config that did not exist must be reported as created") + } + if _, err := os.Stat(path); err != nil { + t.Fatalf("config file was not created at %s: %v", path, err) + } + + cfg, err := LoadFromFile(path) + if err != nil { + t.Fatalf("the seeded config must load: %v", err) + } + if cfg.DataDir != root { + t.Fatalf("seeded config should own the instance root, got DataDir=%q want %q", + cfg.DataDir, root) + } +} + +// The seeding must be a no-op for an existing install: this runs on every +// `serve` with an explicit --config, and overwriting there would erase every +// server the user has. +func TestEnsureConfigFileNeverTouchesAnExistingFile(t *testing.T) { + root := t.TempDir() + path := filepath.Join(root, ConfigFileName) + original := []byte(`{"listen":"127.0.0.1:9999","mcpServers":[]}`) + if err := os.WriteFile(path, original, 0o600); err != nil { + t.Fatalf("write: %v", err) + } + + created, err := EnsureConfigFile(path, root) + if err != nil { + t.Fatalf("EnsureConfigFile: %v", err) + } + if created { + t.Fatal("an existing config must not be reported as created") + } + + after, err := os.ReadFile(path) + if err != nil { + t.Fatalf("read back: %v", err) + } + if string(after) != string(original) { + t.Fatalf("existing config was rewritten:\n got %s\nwant %s", after, original) + } +} + +// Nothing to do without an explicit path — the implicit path already creates +// its own default inside the data directory (see Load). +func TestEnsureConfigFileIgnoresAnEmptyPath(t *testing.T) { + created, err := EnsureConfigFile("", t.TempDir()) + if err != nil { + t.Fatalf("EnsureConfigFile: %v", err) + } + if created { + t.Fatal("an empty path creates nothing") + } +} + +// The counterweight to the seeding: LoadFromFile itself stays strict. It is +// also the hot-reload path (internal/runtime/lifecycle.go, +// internal/runtime/configsvc), where a config file that has gone missing must +// fail the reload and keep the running config — never silently become a fresh +// default that drops every server the user had. +func TestLoadFromFileStillRefusesAMissingExplicitPath(t *testing.T) { + missing := filepath.Join(t.TempDir(), "nope", ConfigFileName) + if _, err := LoadFromFile(missing); err == nil { + t.Fatal("LoadFromFile must not invent a config for a path that is not there") + } +} + +// The parent may not exist yet either: MCPPROXY_HOME can name a directory that +// has never been created. +func TestEnsureConfigFileCreatesTheInstanceRootItself(t *testing.T) { + root := filepath.Join(t.TempDir(), "mcpproxy-qa") + path := filepath.Join(root, ConfigFileName) + + if _, err := EnsureConfigFile(path, root); err != nil { + t.Fatalf("EnsureConfigFile: %v", err) + } + if _, err := LoadFromFile(path); err != nil { + t.Fatalf("the seeded config must load: %v", err) + } +} diff --git a/internal/config/loader.go b/internal/config/loader.go index fdcf533e..d51c048a 100644 --- a/internal/config/loader.go +++ b/internal/config/loader.go @@ -486,6 +486,54 @@ func CreateSampleConfig(path string) error { return SaveConfig(cfg, path) } +// EnsureConfigFile seeds a default configuration at an explicitly named path +// that does not exist yet, and reports whether it created one. +// +// It exists for the first run of an instance whose config path is named on the +// command line rather than discovered — the relocated tray instance of GH #936 +// spawns its core with BOTH `--data-dir ` and `--config +// /mcp_config.json`, and on a fresh root that file has never been +// written. LoadFromFile refuses a missing explicit path, so without this the +// core exited on the spot with "no such file or directory" and the instance +// could never come up. +// +// Why here and not inside LoadFromFile: LoadFromFile is also the HOT-RELOAD +// entry point (internal/runtime/lifecycle.go, internal/runtime/configsvc). A +// config file that disappears under a running proxy must fail the reload and +// leave the live config alone; creating a default there would replace every +// server the user has with nothing. Seeding is a startup decision, so it is +// made at startup, once. +// +// dataDir is the directory the caller will run out of (the `--data-dir` flag +// when one was given); the seeded file records it, exactly as the implicit path +// records its own. An empty dataDir leaves the field unset, so the loader's +// usual default applies. +func EnsureConfigFile(path, dataDir string) (created bool, err error) { + if path == "" { + return false, nil + } + if _, statErr := os.Stat(path); statErr == nil { + return false, nil + } else if !os.IsNotExist(statErr) { + return false, fmt.Errorf("failed to inspect config file %s: %w", path, statErr) + } + + if dir := filepath.Dir(path); dir != "" { + if err := os.MkdirAll(dir, 0700); err != nil { + return false, fmt.Errorf("failed to create config directory %s: %w", dir, err) + } + } + + seed := &Config{DataDir: dataDir} + if err := createDefaultConfigFile(path, seed); err != nil { + return false, fmt.Errorf("failed to create default config file %s: %w", path, err) + } + // Same notice the implicit path prints, for the same reason: a typo in + // --config would otherwise create a blank instance in silence. + fmt.Fprintf(os.Stderr, "INFO: Created default configuration file at %s\n", path) + return true, nil +} + // Helper function to get current time (useful for testing) var now = time.Now diff --git a/internal/httpapi/server.go b/internal/httpapi/server.go index b4ce9645..77ee7c43 100644 --- a/internal/httpapi/server.go +++ b/internal/httpapi/server.go @@ -988,8 +988,15 @@ func (s *Server) writeSuccess(w http.ResponseWriter, data interface{}) { func (s *Server) handleGetStatus(w http.ResponseWriter, _ *http.Request) { // Get routing mode from config routingMode := config.RoutingModeRetrieveTools - if cfg, err := s.controller.GetConfig(); err == nil && cfg != nil && cfg.RoutingMode != "" { - routingMode = cfg.RoutingMode + // …and the data directory, which is where the tray's autostart sidecar + // lives. It is not always ~/.mcpproxy — MCPPROXY_HOME relocates the whole + // instance root, tray and core together (GH #936). + autostartDataDir := "" + if cfg, err := s.controller.GetConfig(); err == nil && cfg != nil { + if cfg.RoutingMode != "" { + routingMode = cfg.RoutingMode + } + autostartDataDir = cfg.DataDir } response := map[string]interface{}{ @@ -1035,7 +1042,7 @@ func (s *Server) handleGetStatus(w http.ResponseWriter, _ *http.Request) { // — this endpoint is read-only). autostart_enabled reads the tray-owned // sidecar with its 1h TTL; nil on Linux / tray not running / malformed. response["launch_source"] = string(telemetry.DetectLaunchSourceOnce()) - response["autostart_enabled"] = telemetry.DefaultAutostartReader().Read() + response["autostart_enabled"] = telemetry.AutostartReaderForDataDir(autostartDataDir).Read() s.writeSuccess(w, response) } diff --git a/internal/telemetry/autostart.go b/internal/telemetry/autostart.go index f0e89670..941092f5 100644 --- a/internal/telemetry/autostart.go +++ b/internal/telemetry/autostart.go @@ -53,6 +53,21 @@ type AutostartReader struct { // (by design), so the returned reader will simply always yield nil — the // heartbeat's AutostartEnabled field stays JSON-null, matching data-model.md. func DefaultAutostartReader() *AutostartReader { + return AutostartReaderForDataDir("") +} + +// AutostartReaderForDataDir returns the reader for the instance rooted at +// dataDir, falling back to ~/.mcpproxy when dataDir is empty. +// +// The tray writes its sidecar into the SAME root it hands the core as +// --data-dir, and MCPPROXY_HOME relocates that root (GH #936). A reader that +// always looked in ~/.mcpproxy therefore reported the real install's login-item +// state for a QA instance that has nothing to do with it, while the sidecar the +// QA tray actually wrote was never read by anything. +func AutostartReaderForDataDir(dataDir string) *AutostartReader { + if dataDir != "" { + return &AutostartReader{Path: filepath.Join(dataDir, autostartSidecarName)} + } home, err := os.UserHomeDir() if err != nil || home == "" { // Fall back to a non-existent path — Read will return nil. diff --git a/internal/telemetry/autostart_datadir_test.go b/internal/telemetry/autostart_datadir_test.go new file mode 100644 index 00000000..a9a5ea3a --- /dev/null +++ b/internal/telemetry/autostart_datadir_test.go @@ -0,0 +1,62 @@ +package telemetry + +import ( + "os" + "path/filepath" + "runtime" + "testing" +) + +// The tray writes its autostart sidecar under the instance root, which +// MCPPROXY_HOME relocates (GH #936). A core told `--data-dir ` therefore +// has to read /tray-autostart.json — reading ~/.mcpproxy instead makes a +// QA instance report the real install's login-item state as its own, and leaves +// the sidecar the tray actually wrote as dead data. +func TestAutostartReaderForDataDirReadsTheInstanceRootSidecar(t *testing.T) { + if runtime.GOOS == "linux" { + t.Skip("no tray sidecar on Linux by design; Read() always yields nil") + } + root := t.TempDir() + writeSidecar(t, filepath.Join(root, autostartSidecarName), `{"enabled":true}`) + + got := AutostartReaderForDataDir(root).Read() + if got == nil { + t.Fatal("reader ignored the data directory and found no sidecar") + } + if !*got { + t.Fatalf("sidecar says enabled:true, reader says %v", *got) + } +} + +// …and the relocated reader must not fall back to the production sidecar when +// the instance root has none: "this instance has no sidecar" is `unknown`, not +// "whatever the real install says". +func TestAutostartReaderForDataDirDoesNotFallBackToTheRealHome(t *testing.T) { + root := t.TempDir() + r := AutostartReaderForDataDir(root) + if want := filepath.Join(root, autostartSidecarName); r.Path != want { + t.Fatalf("reader path = %q, want %q", r.Path, want) + } + if got := r.Read(); got != nil { + t.Fatalf("no sidecar in the instance root must read as unknown, got %v", *got) + } +} + +// An empty data directory keeps the historical behaviour: ~/.mcpproxy. +func TestAutostartReaderForDataDirFallsBackToHomeWhenUnset(t *testing.T) { + home, err := os.UserHomeDir() + if err != nil { + t.Skip("no home directory") + } + r := AutostartReaderForDataDir("") + if want := filepath.Join(home, ".mcpproxy", autostartSidecarName); r.Path != want { + t.Fatalf("reader path = %q, want %q", r.Path, want) + } +} + +func writeSidecar(t *testing.T, path, body string) { + t.Helper() + if err := os.WriteFile(path, []byte(body), 0o600); err != nil { + t.Fatalf("write sidecar: %v", err) + } +} diff --git a/internal/telemetry/telemetry.go b/internal/telemetry/telemetry.go index 64232ea9..1964e706 100644 --- a/internal/telemetry/telemetry.go +++ b/internal/telemetry/telemetry.go @@ -864,8 +864,15 @@ func (s *Service) buildHeartbeat() HeartbeatPayload { payload.AutostartEnabled = s.autostartReader.Read() } else { // Lazy-init the default reader on first heartbeat. The reader is - // safe to reuse across heartbeats (1h TTL cache inside). - s.autostartReader = DefaultAutostartReader() + // safe to reuse across heartbeats (1h TTL cache inside). It reads the + // sidecar inside THIS instance's data directory: the tray writes it + // into the same root it hands the core, and MCPPROXY_HOME moves both + // (GH #936). + dataDir := "" + if s.config != nil { + dataDir = s.config.DataDir + } + s.autostartReader = AutostartReaderForDataDir(dataDir) payload.AutostartEnabled = s.autostartReader.Read() } diff --git a/native/macos/MCPProxy/MCPProxy/Core/CoreProcessManager.swift b/native/macos/MCPProxy/MCPProxy/Core/CoreProcessManager.swift index 355557ac..5ef65639 100644 --- a/native/macos/MCPProxy/MCPProxy/Core/CoreProcessManager.swift +++ b/native/macos/MCPProxy/MCPProxy/Core/CoreProcessManager.swift @@ -101,6 +101,10 @@ actor CoreProcessManager { /// Socket path for the core process. private let socketPath: String + /// The bbolt database whose lock answers "is a core alive here?" when the + /// socket has stopped answering (GH #933). Derived from `socketPath`. + private let dataDirectoryLockPath: String + /// How often the periodic refresh tick runs. Injectable so tests can drive /// the tick — and the liveness probe on it — without waiting 30 seconds. private let refreshInterval: TimeInterval @@ -218,9 +222,14 @@ actor CoreProcessManager { self.unresponsiveCoreTimeout = unresponsiveCoreTimeout self.socketWaitTimeout = socketWaitTimeout - // Compute socket path: ~/.mcpproxy/mcpproxy.sock - let home = FileManager.default.homeDirectoryForCurrentUser.path - self.socketPath = socketPath ?? "\(home)/.mcpproxy/mcpproxy.sock" + // `~/.mcpproxy/mcpproxy.sock`, or wherever this instance has been + // relocated to (GH #936). + let resolvedSocket = socketPath ?? InstancePaths.socketPath + self.socketPath = resolvedSocket + // The database of the core that owns THAT socket — see + // `DataDirectoryLock.path(forSocket:)` for why it is derived from the + // socket rather than from this instance's own root. + self.dataDirectoryLockPath = DataDirectoryLock.path(forSocket: resolvedSocket) } // MARK: - Public API @@ -420,8 +429,16 @@ actor CoreProcessManager { } /// A socket FILE exists and not one connection has ever been accepted on - /// it. The only reading of that which is consistent with everything we - /// have seen is: the process that created it is gone. + /// it. Consistent with a dead core's leftovers — and equally consistent + /// with a live core whose listen backlog was already full when the + /// episode began, which is why this is never the whole answer. + /// + /// The data-directory lock is what separates the two (GH #933), and it + /// is deliberately NOT folded in here: a lock is a fact about RIGHT NOW, + /// not accumulated evidence. Latching it turned "a core is busy" into a + /// verdict that outlived the core, so a saturated core that then died + /// left the tray parked forever. See `reportUnresponsiveCore`, which + /// asks the kernel afresh at every deadline. var onlyEverRefused: Bool { refusals > 0 && !somethingAccepted } } @@ -742,6 +759,7 @@ actor CoreProcessManager { guard proc.isRunning else { return } NSLog("[MCPProxy] Terminating PID %d (%@)", proc.processIdentifier, reason) + AppLifecycle.shared.recordCoreTerminated(pid: proc.processIdentifier, reason: reason) kill(proc.processIdentifier, SIGTERM) let deadline = Date().addingTimeInterval(5.0) @@ -789,6 +807,32 @@ actor CoreProcessManager { // might cancel it, or we would cancel ourselves mid-launch. unresponsiveDeadlineTask = nil + // Before concluding "stale", ask the one question the socket cannot + // answer: is a live process holding this core's data directory RIGHT + // NOW? A saturated core refuses every probe exactly as a dead core's + // leftover file does, and only the lock tells them apart (GH #933). + // + // Asked fresh at every deadline, and never remembered between them. + // "Something held it once" is not a reason to keep waiting: the kernel + // drops `flock` the instant the holder dies, so a saturated core that + // is subsequently SIGKILLed (jetsam, `kill -9`) leaves its socket file + // behind and nothing else. A remembered verdict re-armed the deadline + // on that dead core forever, and `.waitingForCore` offers neither Stop + // nor Retry — quitting the app was the only way out. + if socketEvidence.onlyEverRefused, + case .heldByALiveProcess = DataDirectoryLock.probe(path: dataDirectoryLockPath) { + // Keep waiting rather than launching or erroring: the attach watch + // is still running underneath, so the core is picked up the moment + // it drains its backlog — which is what the tray failed to do when + // this was reproduced live, staying wedged on an error for 75 + // seconds while the core answered /ready normally. + NSLog("[MCPProxy] %@ refuses every probe, but a live process holds %@ — " + + "a busy core, not a stale socket. Waiting again (%@)", + socketPath, dataDirectoryLockPath, reason) + armUnresponsiveCoreDeadline(reason: reason) + return + } + if socketEvidence.onlyEverRefused, await escalateToLaunchOverAStaleSocket(reason: reason) { return } @@ -1065,7 +1109,11 @@ actor CoreProcessManager { let proc = Process() proc.executableURL = URL(fileURLWithPath: binaryPath) - proc.arguments = ["serve"] + // `["serve"]` unless this instance has been relocated, in which case the + // core is told the same root the tray resolved — a core writing the real + // ~/.mcpproxy while the tray watches a scratch socket is the accident + // GH #936 is about. + proc.arguments = InstancePaths.coreArguments // Let core use its own config API key (or auto-generate one). // We fetch the key from core via socket after it starts. @@ -1127,6 +1175,13 @@ actor CoreProcessManager { coresLaunched += 1 process = proc + // On the record before anything can go wrong with it: "which tray + // started this core, and when" is the first question a dropped MCP + // session raises (#862). + AppLifecycle.shared.recordCoreLaunched( + pid: proc.processIdentifier, + reason: "tray launched core (\(binaryPath))" + ) } /// Append a line to the stderr buffer (called from background task). @@ -1715,6 +1770,16 @@ actor CoreProcessManager { let stderr = stderrBuffer + // Recorded whatever we decide to do about it, and recorded here rather + // than only in the retry branches: an exit that leads to no retry (the + // user stopped it, a clean shutdown) is exactly the one that otherwise + // leaves no trace at all (#862). + AppLifecycle.shared.recordCoreExited( + pid: process?.processIdentifier ?? 0, + status: status, + reason: "core process exited" + ) + // If stopped by user, don't retry — this is intentional let isStopped = await MainActor.run { appState.isStopped } if isStopped { diff --git a/native/macos/MCPProxy/MCPProxy/Core/DataDirectoryLock.swift b/native/macos/MCPProxy/MCPProxy/Core/DataDirectoryLock.swift new file mode 100644 index 00000000..70447430 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxy/Core/DataDirectoryLock.swift @@ -0,0 +1,83 @@ +// DataDirectoryLock.swift +// MCPProxy +// +// "Is a core alive?", asked WITHOUT going through the socket (GH #933). +// +// Every other liveness signal the tray has is a socket probe, and a socket probe +// cannot distinguish the two situations that matter most: +// +// * a file a dead core left behind, which refuses every connection, and +// * a LIVE core whose listen backlog is full, which also refuses every +// connection (on macOS a full backlog is ECONNREFUSED, not EAGAIN). +// +// Accumulated evidence closes most of the gap — a core that accepted even once +// during the episode is never launched over — but not the case where the core +// was already saturated when the episode began. It accepts nothing, so +// `onlyEverRefused` stays true, and after the deadline the tray escalated to a +// launch over a healthy core. Reproduced live: four doomed cores in 39 seconds, +// each dying on the lock this file asks about, ending in a retry-exhaustion +// error about a core that was answering `/ready` normally the whole time. +// +// The lock is the missing signal, and it is a good one for one specific reason: +// the kernel releases `flock` when the holding process dies. There is no such +// thing as a stale flock, so "somebody holds it" cannot be faked by a dead core +// the way a leftover socket FILE can. The core takes it (bbolt, via +// `internal/storage/bbolt.go`) before it creates its listener, so it is held for +// strictly longer than the socket exists. + +import Foundation + +/// What the data directory's database says about a core owning it. +enum DataDirectoryLock: Equatable { + + /// A live process holds the exclusive lock. Something IS running here. + case heldByALiveProcess + + /// The file is there and nobody holds it — the process that did is gone. + case free + + /// No file, or the probe could not run. Says nothing either way, and must + /// be treated as such: this is the answer for a socket that is not inside a + /// data directory at all. + case unknown(String) + + /// The database beside a core's socket. + /// + /// Derived from the socket rather than from the instance root because the + /// question is about THAT core: a tray pointed at another instance's socket + /// (`MCPPROXY_SOCKET_PATH`) must ask about that instance's data directory, + /// not its own. When the socket is not in a data directory the probe simply + /// answers `.unknown` and nothing changes. + static func path(forSocket socketPath: String) -> String { + URL(fileURLWithPath: socketPath) + .deletingLastPathComponent() + .appendingPathComponent(InstancePaths.databaseFileName) + .path + } + + /// Ask whether a live process holds the database. + /// + /// A SHARED, non-blocking lock, released immediately. Shared for a reason: + /// bbolt's is exclusive, so a shared request still fails against a live core + /// — while two trays probing at the same moment both succeed instead of each + /// reporting the other as a running core. Non-blocking so the probe cannot + /// become the thing that stalls a launch, and released at once so it cannot + /// delay a core that is starting up. + static func probe(path: String) -> DataDirectoryLock { + let descriptor = open(path, O_RDONLY) + guard descriptor >= 0 else { + return .unknown("cannot open \(path) (errno \(errno))") + } + defer { close(descriptor) } + + if flock(descriptor, LOCK_SH | LOCK_NB) == 0 { + flock(descriptor, LOCK_UN) + return .free + } + let code = errno + // EWOULDBLOCK is EAGAIN on Darwin, and it is the only errno that means + // "somebody else holds it". Anything else is our problem, not evidence. + if code == EWOULDBLOCK { return .heldByALiveProcess } + return .unknown("flock failed on \(path) (errno \(code))") + } +} diff --git a/native/macos/MCPProxy/MCPProxy/Core/InstancePaths.swift b/native/macos/MCPProxy/MCPProxy/Core/InstancePaths.swift new file mode 100644 index 00000000..e870b5d1 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxy/Core/InstancePaths.swift @@ -0,0 +1,163 @@ +// InstancePaths.swift +// MCPProxy +// +// Every path a tray instance owns, resolved in one place (GH #936). +// +// Why this file exists rather than a `homeDirectoryForCurrentUser` per call +// site: that API IGNORES `$HOME`, so a tray built from a branch and run out of a +// scratch bundle still read and wrote the real `~/.mcpproxy`. Two things went +// wrong repeatedly during live QA. The socket is a machine-wide exclusive +// resource, so two QA runs could not proceed in parallel — one silently attached +// to the other's core and produced garbage results. And +// `AutostartSidecarService.refresh()` wrote the scratch bundle's login-item +// state (always `false`, because a copied bundle is not a registered login item) +// straight over the user's real `{"enabled":true}`. +// +// The override is dev/QA-only IN SPIRIT, not by enforcement: it is an +// environment variable, unset in normal use, and with it unset every path below +// resolves exactly where it always did. `MCPPROXY_SOCKET_PATH` (GH #926) was the +// first half of this and still outranks the root — it points at one specific +// core, which is not always the core that owns the root. +// +// Deliberately NOT relocated: `~/Library/Logs/mcpproxy` (the core's own log +// directory, which follows the core's rules, not the tray's) and the app's +// preferences domain (`cfprefsd` honours neither `$HOME` nor this variable — +// use a distinct bundle id for a dev instance). + +import Foundation + +/// Resolves the files a tray instance reads and writes. +/// +/// Every rule takes `environment` and `home` as parameters so it is testable +/// without mutating the process's real environment; the no-argument +/// conveniences below are what production calls. +enum InstancePaths { + + // MARK: - Names + + /// Relocates the whole instance root — everything that would otherwise live + /// in `~/.mcpproxy`. + static let rootEnvVar = "MCPPROXY_HOME" + + /// Points at one core's socket, wherever the root is (GH #926). + static let socketPathEnvVar = "MCPPROXY_SOCKET_PATH" + + static let defaultRootName = ".mcpproxy" + static let socketFileName = "mcpproxy.sock" + static let sidecarFileName = "tray-autostart.json" + static let configFileName = "mcp_config.json" + + /// The bbolt database the core takes an exclusive `flock` on before it + /// creates its listener (`internal/storage/bbolt.go`). Named here because + /// the liveness check in `CoreProcessManager` asks whether a live process + /// holds it — see `DataDirectoryLock` (GH #933). + static let databaseFileName = "config.db" + + /// Usable bytes of `sockaddr_un.sun_path` (104 including the terminator). + static let socketPathByteLimit = 103 + + // MARK: - Rules + + /// The instance root: the override, or `~/.mcpproxy`. + static func root(environment: [String: String], home: URL) -> URL { + guard let override = nonBlank(environment[rootEnvVar]) else { + return home.appendingPathComponent(defaultRootName, isDirectory: true) + } + return URL(fileURLWithPath: (override as NSString).expandingTildeInPath, + isDirectory: true).standardizedFileURL + } + + /// Whether this instance has been relocated. Production reads it to decide + /// what to tell the core it spawns, and to log the fact once at launch — + /// a relocated instance that looks ordinary in the log is how a QA run + /// convinces itself it tested the real thing. + static func isOverridden(environment: [String: String]) -> Bool { + nonBlank(environment[rootEnvVar]) != nil + } + + /// The core's socket. `MCPPROXY_SOCKET_PATH` first, then the root. + static func socketPath(environment: [String: String], home: URL) -> String { + if let explicit = nonBlank(environment[socketPathEnvVar]) { return explicit } + return root(environment: environment, home: home) + .appendingPathComponent(socketFileName, isDirectory: false).path + } + + static func autostartSidecarURL(environment: [String: String], home: URL) -> URL { + root(environment: environment, home: home) + .appendingPathComponent(sidecarFileName, isDirectory: false) + } + + static func configFileURL(environment: [String: String], home: URL) -> URL { + root(environment: environment, home: home) + .appendingPathComponent(configFileName, isDirectory: false) + } + + static func dataLockURL(environment: [String: String], home: URL) -> URL { + root(environment: environment, home: home) + .appendingPathComponent(databaseFileName, isDirectory: false) + } + + /// Arguments for a core this tray spawns. + /// + /// Both flags or neither: `--data-dir` alone still loads the default + /// config file (see `cmd/mcpproxy/cli_config.go`), and a core reading the + /// real config while writing a scratch data directory is a subtler version + /// of the accident this override exists to prevent. + static func coreArguments(environment: [String: String], home: URL) -> [String] { + guard isOverridden(environment: environment) else { return ["serve"] } + let root = root(environment: environment, home: home) + return [ + "serve", + "--data-dir", root.path, + "--config", configFileURL(environment: environment, home: home).path + ] + } + + /// Why this socket path cannot work, or nil when it can. + /// + /// The failure it catches is silent: `bind(2)` copies into a 104-byte + /// `sun_path`, so a socket under a deep scratch directory is never created + /// and the tray simply never finds a core. Reported rather than clamped — + /// there is no shorter path that is still the path the core was told. + static func socketPathProblem(_ path: String) -> String? { + let bytes = path.utf8.count + guard bytes > socketPathByteLimit else { return nil } + return "socket path is \(bytes) bytes, over the \(socketPathByteLimit)-byte " + + "sockaddr_un limit — it cannot be bound. Use a shorter \(rootEnvVar) " + + "(e.g. /tmp/mcpproxy-qa)." + } + + private static func nonBlank(_ value: String?) -> String? { + guard let value else { return nil } + let trimmed = value.trimmingCharacters(in: .whitespacesAndNewlines) + return trimmed.isEmpty ? nil : trimmed + } + + // MARK: - Production conveniences + + private static var processEnvironment: [String: String] { + ProcessInfo.processInfo.environment + } + + /// `homeDirectoryForCurrentUser`, kept in ONE place. It ignores `$HOME`; + /// `rootEnvVar` is the supported way around that. + private static var currentHome: URL { + FileManager.default.homeDirectoryForCurrentUser + } + + static var root: URL { root(environment: processEnvironment, home: currentHome) } + static var isOverridden: Bool { isOverridden(environment: processEnvironment) } + static var socketPath: String { socketPath(environment: processEnvironment, home: currentHome) } + static var autostartSidecarURL: URL { + autostartSidecarURL(environment: processEnvironment, home: currentHome) + } + static var configFileURL: URL { + configFileURL(environment: processEnvironment, home: currentHome) + } + static var dataLockURL: URL { + dataLockURL(environment: processEnvironment, home: currentHome) + } + static var coreArguments: [String] { + coreArguments(environment: processEnvironment, home: currentHome) + } +} diff --git a/native/macos/MCPProxy/MCPProxy/MCPProxyApp.swift b/native/macos/MCPProxy/MCPProxy/MCPProxyApp.swift index 0c151cb9..9bbaeca2 100644 --- a/native/macos/MCPProxy/MCPProxy/MCPProxyApp.swift +++ b/native/macos/MCPProxy/MCPProxy/MCPProxyApp.swift @@ -145,6 +145,28 @@ final class AppController: NSObject, NSApplicationDelegate, NSWindowDelegate, NS // Switch to accessory (menu bar only) now that launch is complete NSApp.setActivationPolicy(.accessory) + // Lifecycle bookkeeping FIRST, so a launch that fails later is still on + // the record — and so an unaccounted-for previous exit is reported now, + // while somebody is reading the log, rather than never (#862). + Self.logInstanceRoot() + AppLifecycle.shared.recordLaunch() + AppLifecycle.shared.installSignalHandlers { + // A caught signal goes through the normal quit path so the core is + // shut down properly. The hop to main is made HERE, not by the + // signal machinery: reaching this decision must not depend on a + // main thread that may never answer, and if it does not answer the + // escalation inside AppLifecycle restores the signal's default + // action so the process still goes. + DispatchQueue.main.async { NSApplication.shared.terminate(nil) } + } + // Logout, restart and shutdown reach applicationWillTerminate exactly + // like a Quit does, so the difference has to be claimed here. + NSWorkspace.shared.notificationCenter.addObserver( + forName: NSWorkspace.willPowerOffNotification, object: nil, queue: .main + ) { _ in + AppLifecycle.shared.note("macOS is logging out, restarting or shutting down") + } + // Monitor Cmd+/Cmd-/Cmd+0 globally for text size adjustment. // Store the monitor reference to prevent potential deallocation. // Match both "+" (Cmd+Shift+=) and "=" (Cmd+=) for zoom in, @@ -341,7 +363,16 @@ final class AppController: NSObject, NSApplicationDelegate, NSWindowDelegate, NS } func applicationWillTerminate(_ notification: Notification) { + // Written BEFORE the core is torn down: whatever happens next, the + // journal already carries a reason for this exit. The previous + // behaviour — terminate the core and say nothing — is what made the + // original incident unattributable (#862). + AppLifecycle.shared.recordTermination() if let process = coreManager?.managedProcess { + AppLifecycle.shared.recordCoreTerminated( + pid: process.processIdentifier, + reason: "tray is terminating" + ) process.terminate() } } @@ -680,8 +711,28 @@ final class AppController: NSObject, NSApplicationDelegate, NSWindowDelegate, NS /// CoreProcessManager initializer has always taken an injectable /// socketPath "so a test (or a second app)" can use it; this is the /// second-app case. Unset in normal use, so behavior is unchanged. + /// + /// Nil now means "whatever the instance root says", not "the real + /// ~/.mcpproxy": `MCPPROXY_HOME` moves the socket along with everything + /// else (GH #936), and `InstancePaths` is where the two are reconciled. static var socketPathOverride: String? { - ProcessInfo.processInfo.environment["MCPPROXY_SOCKET_PATH"] + ProcessInfo.processInfo.environment[InstancePaths.socketPathEnvVar] + } + + /// Announce a relocated instance once, at launch, and say so loudly if the + /// socket it implies cannot be bound. + /// + /// Both lines are diagnostics for a human running a second instance on + /// purpose. The length check in particular: over 103 bytes the bind fails + /// silently and the tray simply never finds a core, which costs an hour to + /// work out from the outside. + static func logInstanceRoot() { + guard InstancePaths.isOverridden else { return } + NSLog("[MCPProxy] Instance root overridden by %@: %@ (socket %@)", + InstancePaths.rootEnvVar, InstancePaths.root.path, InstancePaths.socketPath) + if let problem = InstancePaths.socketPathProblem(InstancePaths.socketPath) { + NSLog("[MCPProxy] %@", problem) + } } private func resolveBundledCoreBinary() -> String? { @@ -1282,8 +1333,7 @@ final class AppController: NSObject, NSApplicationDelegate, NSWindowDelegate, NS } @objc private func openConfigFile() { - let home = FileManager.default.homeDirectoryForCurrentUser - NSWorkspace.shared.open(home.appendingPathComponent(".mcpproxy/mcp_config.json")) + NSWorkspace.shared.open(InstancePaths.configFileURL) } @objc private func openLogsDirectory() { @@ -1320,6 +1370,10 @@ final class AppController: NSObject, NSApplicationDelegate, NSWindowDelegate, NS } @objc private func quitApp() { + // Claimed before anything else runs: the core teardown below would + // otherwise get there first and record its own mechanical description + // of what it is doing instead of the fact that the user asked (#862). + AppLifecycle.shared.note("user chose Quit in the tray menu") Task { await coreManager?.shutdown() try? await Task.sleep(nanoseconds: 200_000_000) diff --git a/native/macos/MCPProxy/MCPProxy/Menu/Glance/GlanceSection.swift b/native/macos/MCPProxy/MCPProxy/Menu/Glance/GlanceSection.swift index 3b33cf33..1342a0a9 100644 --- a/native/macos/MCPProxy/MCPProxy/Menu/Glance/GlanceSection.swift +++ b/native/macos/MCPProxy/MCPProxy/Menu/Glance/GlanceSection.swift @@ -108,6 +108,15 @@ final class GlanceSection { private var activityRows: [ActivityRow] = [] private var clientRows: [NSMenuItem] = [] + /// The "+N more" row under a truncated Clients list, or nil when every + /// client has a row of its own. + /// + /// Owned like the rows are, because N moves without the row COUNT moving: + /// a twelfth client beyond a cap of five changes nothing structural, and a + /// row left saying "+6 more" under a header that has already counted twelve + /// is the very disagreement this row exists to end (GH #934). + private var clientOverflowItem: NSMenuItem? + /// Snapshot of the structure the current items were built from, so an /// in-place update can detect that a full rebuild is required instead. private var hasBuilt = false @@ -145,6 +154,7 @@ final class GlanceSection { summaryItem = nil activityRows = [] clientRows = [] + clientOverflowItem = nil histogramItem = nil hasBuilt = true builtVisible = isVisible(for: state) @@ -188,16 +198,21 @@ final class GlanceSection { items.append(.separator()) items.append(disabledItem(titled: "Clients")) - let clients = GlancePresence.clients(from: state.glanceSessions, now: now) - if clients.isEmpty { + let presence = Self.clientList(for: state, now: now) + if presence.rows.isEmpty { items.append(disabledItem(titled: Self.noClientsTitle)) } else { - for client in clients { + for client in presence.rows { let row = actionableItem() apply(client, to: row, now: now) clientRows.append(row) items.append(row) } + if presence.hidden > 0 { + let overflow = disabledItem(titled: Self.overflowTitle(presence.hidden)) + clientOverflowItem = overflow + items.append(overflow) + } } items.append(.separator()) @@ -231,9 +246,14 @@ final class GlanceSection { guard builtVisible else { return true } let runs = GlanceSelection.activityRows(from: state.glanceActivity) - let clients = GlancePresence.clients(from: state.glanceSessions, now: now) + let presence = Self.clientList(for: state, now: now) + let clients = presence.rows guard runs.count == activityRows.count, clients.count == clientRows.count else { return false } + // Gaining or losing the "+N more" row is gaining or losing a row, which + // resizes an open menu exactly as an extra client does — structural, so + // it waits for close (FR-023). A change to N alone is not. + guard (presence.hidden > 0) == (clientOverflowItem != nil) else { return false } // Preflight, before a single write: a row that gains or loses its // reason gains or loses a LINE, which resizes the menu just as surely as @@ -259,9 +279,34 @@ final class GlanceSection { apply(run, to: &activityRows[index], now: now) } for (row, client) in zip(clientRows, clients) { apply(client, to: row, now: now) } + if let clientOverflowItem { + let title = Self.overflowTitle(presence.hidden) + if clientOverflowItem.title != title { clientOverflowItem.title = title } + } return true } + /// The Clients section's rows and how many clients they leave out. + /// + /// Both numbers come from ONE deduplicated set, and the header's own + /// segment (`AppState.glanceClientSummary`) counts over the same rule — so + /// "8 active · 3 idle" above five rows is always accompanied by the row + /// that accounts for the difference. + private static func clientList( + for state: AppState, now: Date + ) -> (rows: [ClientPresenceRow], hidden: Int) { + let all = GlancePresence.clients(from: state.glanceSessions, now: now, limit: Int.max) + let shown = Array(all.prefix(GlancePresence.rowLimit)) + return (shown, all.count - shown.count) + } + + private static func overflowTitle(_ hidden: Int) -> String { "+\(hidden) more" } + + /// The overflow row's current text, for tests that pin it after an in-place + /// update — the item itself is private, and reaching into the menu to find + /// it by title would assert nothing about which row was rewritten. + var clientOverflowTitleForTesting: String? { clientOverflowItem?.title } + // MARK: Row rendering /// Identity of the run a row is showing: `GlanceRun.identity`, which is the @@ -385,18 +430,47 @@ final class GlanceSection { if #available(macOS 14.4, *) { item.subtitle = text } } - /// First clause of an error message — everything up to the first newline, - /// period or colon — so a multi-sentence backend error still fits one row. - /// The full message stays in the tooltip. + /// First clause of an error message — everything up to the first clause + /// BOUNDARY — so a multi-sentence backend error still fits one row. The full + /// message stays in the tooltip. + /// + /// A period or colon is a boundary only when whitespace (or the end of the + /// message) follows it (GH #934). Splitting on a bare `.` or `:` cut inside + /// the two things mcpproxy errors are most likely to contain: a `server:tool` + /// identifier and a host:port. `invalid arguments for + /// memory:create_entities: at '/entities': …` rendered as "invalid arguments + /// for memory", which reads as though the server named `memory` were at + /// fault — and that is the common shape of these messages, not an edge case. static func firstClause(of message: String?) -> String? { guard let message else { return nil } let trimmed = message.trimmingCharacters(in: .whitespacesAndNewlines) guard !trimmed.isEmpty else { return nil } - let head = trimmed.components(separatedBy: CharacterSet(charactersIn: ".:\n")).first ?? trimmed + let head = clauseBoundary(in: trimmed).map { trimmed[trimmed.startIndex..<$0] } + ?? Substring(trimmed) let clause = head.trimmingCharacters(in: .whitespaces) return clause.isEmpty ? trimmed : clause } + /// Index of the first character that ends the leading clause, or nil when + /// the whole message is one clause. `text` must already be trimmed, so a + /// trailing separator is genuinely final rather than the start of "…. ". + private static func clauseBoundary(in text: String) -> String.Index? { + var index = text.startIndex + while index < text.endIndex { + let character = text[index] + if character.isNewline { return index } + if character == "." || character == ":" { + let next = text.index(after: index) + // Nothing after it, or space after it: a separator. Anything + // else and it is part of a token — `memory:create_entities`, + // `127.0.0.1`, `a.txt` — which is the whole point of this rule. + if next == text.endIndex || text[next].isWhitespace { return index } + } + index = text.index(after: index) + } + return nil + } + // MARK: Status iconography /// Tint for an activity record's outcome. @@ -619,7 +693,10 @@ final class GlanceSection { /// headline over a section that had rows in it. private func summaryTitle(for state: AppState, now: Date = Date()) -> String { var parts: [String] = [] - if let calls = state.callsThisHour { + // `glanceCallsThisHour`, not the raw polled `callsThisHour`: the rows + // below arrive over SSE and the poll is 30 seconds apart, so the raw + // count sat under rows it had never heard of (GH #934). + if let calls = state.glanceCallsThisHour(now: now) { parts.append(calls == 1 ? "1 call this hour" : "\(calls) calls this hour") } if let clients = state.glanceClientSummary(now: now) { parts.append(clients) } diff --git a/native/macos/MCPProxy/MCPProxy/Services/AppLifecycle.swift b/native/macos/MCPProxy/MCPProxy/Services/AppLifecycle.swift new file mode 100644 index 00000000..c0203623 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxy/Services/AppLifecycle.swift @@ -0,0 +1,280 @@ +// AppLifecycle.swift +// MCPProxy +// +// The tray's shutdown-reason bookkeeping (GH #862). +// +// `LifecycleJournal` is the storage; this is the policy on top of it — what +// counts as a reason, who is allowed to claim one, and what happens when nobody +// does. The rule the issue asks for is one line long: *every* ending names who +// asked for it, and an ending nobody claimed says so explicitly rather than +// looking like an ordinary quit. +// +// Reasons are CLAIMED IN ADVANCE, by whoever initiates the stop (`note(_:)`), +// because by the time `applicationWillTerminate` runs the initiator is long out +// of the call stack: AppKit tells us the app is going, never why. A quit chosen +// from the tray menu, a `SIGTERM` from a script, and a logout all arrive at the +// same delegate method, and telling them apart afterwards is impossible. +// +// Deliberately NOT an actor: the signal source's handler and +// `applicationWillTerminate` are both synchronous contexts with no opportunity +// to await — the process may be gone microseconds later. The state is a string +// and a date behind a lock instead. + +import AppKit +import Foundation + +/// Records why the tray and its core start and stop. +final class AppLifecycle: @unchecked Sendable { + + /// The instance production uses. Tests build their own with an injected + /// journal; this one writes to the instance root — except under XCTest, see + /// `defaultJournalURL`. + static let shared = AppLifecycle(journal: LifecycleJournal(url: defaultJournalURL)) + + /// `/tray-lifecycle.jsonl`, or a scratch file when running + /// under XCTest. + /// + /// The test suite drives the REAL `CoreProcessManager` and the real app + /// delegate, and both record lifecycle events — so without this the suite + /// appends to the developer's own `~/.mcpproxy/tray-lifecycle.jsonl` and + /// pollutes the journal of a live install with events from cores that were + /// never theirs. A diagnostic that corrupts the thing it diagnoses is worse + /// than no diagnostic. + static var defaultJournalURL: URL { + let name = "tray-lifecycle.jsonl" + guard ProcessInfo.processInfo.environment["XCTestConfigurationFilePath"] == nil, + NSClassFromString("XCTestCase") == nil else { + return URL(fileURLWithPath: NSTemporaryDirectory(), isDirectory: true) + .appendingPathComponent("mcpproxy-tests-\(name)") + } + return InstancePaths.root.appendingPathComponent(name) + } + + private let journal: LifecycleJournal + private let startedAt: Date + private let lock = NSLock() + private var claimedReason: String? + private var signalSources: [DispatchSourceSignal] = [] + + init(journal: LifecycleJournal = LifecycleJournal(), startedAt: Date = Date()) { + self.journal = journal + self.startedAt = startedAt + } + + /// Seconds since this tray process came up. Part of every record: a run + /// that died at 25 hours and one that died at 25 seconds are different + /// incidents with the same log line otherwise. + var uptime: TimeInterval { Date().timeIntervalSince(startedAt) } + + // MARK: - Launch + + /// Record this launch, and report on the previous one. + /// + /// Order matters: the previous ending is read BEFORE this run's record is + /// appended, or the launch we are recording becomes the ending we are + /// judging. + /// + /// Returns the unclean-exit marker when the previous run recorded no + /// shutdown reason, so the caller can surface it; nil otherwise. + @discardableResult + func recordLaunch(source: String = AppLifecycle.launchSource()) -> String? { + let previous = journal.previousRunEnding() + let marker = LifecycleJournal.uncleanExitSummary(for: previous) + if let marker { + journal.append(event(.appLaunched, "launched by \(source); PREVIOUS RUN: \(marker)")) + } else { + journal.append(event(.appLaunched, "launched by \(source)")) + } + journal.trim() + return marker + } + + /// How this app was started, as far as it can tell. The DMG installer and + /// the core-spawn path already set `MCPPROXY_LAUNCHED_BY`; a login item is + /// re-parented to launchd (ppid 1), and anything else is a user opening it. + static func launchSource() -> String { + if let declared = ProcessInfo.processInfo.environment["MCPPROXY_LAUNCHED_BY"], + !declared.isEmpty { + return declared + } + return getppid() == 1 ? "launchd (login item or relaunch)" : "user" + } + + // MARK: - Shutdown + + /// Claim the reason for the shutdown that is about to happen. + /// + /// First claim wins: the outermost initiator is the honest answer. A user + /// choosing Quit causes the app to tear its core down, and the core's + /// teardown must not overwrite "user quit" with "shutdown". + func note(_ reason: String) { + lock.lock() + defer { lock.unlock() } + if claimedReason == nil { claimedReason = reason } + } + + /// Record that the app is going, with whatever reason was claimed. + /// + /// An unclaimed termination is recorded as unattributed rather than as + /// something plausible. Guessing here would be worse than silence: the next + /// incident would read a confident reason that nobody actually gave. + func recordTermination() { + lock.lock() + let reason = claimedReason + lock.unlock() + journal.append(event(.appTerminating, + reason ?? "unattributed (no initiator claimed this shutdown)")) + } + + /// A catchable signal arrived. Recorded as its own event AND claimed as the + /// shutdown reason, since the termination that follows is its consequence. + func recordSignal(_ name: String) { + journal.append(event(.signalReceived, name)) + note("signal \(name)") + } + + // MARK: - Core process + + func recordCoreLaunched(pid: Int32, reason: String) { + journal.append(LifecycleEvent(kind: .coreLaunched, reason: reason, at: Date(), + uptimeSeconds: uptime, pid: pid)) + } + + func recordCoreTerminated(pid: Int32, reason: String) { + journal.append(LifecycleEvent(kind: .coreTerminated, reason: reason, at: Date(), + uptimeSeconds: uptime, pid: pid)) + } + + func recordCoreExited(pid: Int32, status: Int32, reason: String) { + journal.append(LifecycleEvent(kind: .coreExited, + reason: "\(reason) (exit status \(status))", + at: Date(), uptimeSeconds: uptime, pid: pid)) + } + + /// One line per periodic update check (issue #862, ask 3). The original + /// investigation could neither confirm nor exclude the updater because it + /// logged nothing at all about its hourly work. + func recordUpdateCheck(_ detail: String) { + journal.append(event(.updateCheck, detail)) + } + + // MARK: - Signals + + /// The signals this app catches, with the names the journal records. + static let caughtSignals: [(number: Int32, name: String)] = [ + (SIGTERM, "SIGTERM"), (SIGINT, "SIGINT"), (SIGHUP, "SIGHUP") + ] + + /// Where a caught signal is reasoned about. Deliberately NOT `.main`. + /// + /// Catching a signal suppresses its default action, so a handler that can + /// only run on the main thread is a promise the app cannot keep: with the + /// main thread wedged (a deadlock, a hung synchronous call) `pkill -TERM`, + /// `launchctl kill TERM` and a launchd stop would all become no-ops, where + /// before any of this existed they simply killed the process. Diagnostics + /// must not make the thing they diagnose harder to stop. + private static let signalQueue = DispatchQueue( + label: "com.smartmcpproxy.mcpproxy.signals" + ) + + /// How long the polite path gets before the signal does what it came to do. + /// The same order as the core teardown the tray-menu Quit performs. + static let signalEscalationDelay: TimeInterval = 5.0 + + /// Catch the signals that CAN be caught, so a `pkill` or a launchd stop is + /// attributable instead of silent. + /// + /// SIGKILL and a jetsam kill are deliberately absent — they cannot be + /// caught, which is exactly why the unclean-exit marker at the next launch + /// exists. + func installSignalHandlers( + onTerminate: @escaping @Sendable () -> Void, + escalateAfter: TimeInterval = AppLifecycle.signalEscalationDelay, + escalate: @escaping @Sendable (Int32) -> Void = AppLifecycle.restoreDefaultActionAndReraise + ) { + for (number, name) in Self.caughtSignals { + Self.suppressDefaultAction(number) + let source = DispatchSource.makeSignalSource(signal: number, queue: Self.signalQueue) + source.setEventHandler { [weak self] in + self?.respondToSignal(name, number: number, onTerminate: onTerminate, + escalateAfter: escalateAfter, escalate: escalate) + } + source.resume() + lock.lock() + signalSources.append(source) + lock.unlock() + } + } + + /// Undo `installSignalHandlers`. Only tests need it — the app installs once + /// and lives with it — but a test that left TERM/INT/HUP rewired would take + /// the rest of the suite with it. + func uninstallSignalHandlers() { + lock.lock() + let sources = signalSources + signalSources = [] + lock.unlock() + for source in sources { source.cancel() } + for (number, _) in Self.caughtSignals { signal(number, SIG_DFL) } + } + + /// What a caught signal does: record it, ask for a graceful stop, and stop + /// asking nicely if the app is still here afterwards. + /// + /// Separated from the source plumbing so the policy is reachable from a + /// test — a real signal delivered to a test process is not. + func respondToSignal( + _ name: String, + number: Int32, + onTerminate: @escaping @Sendable () -> Void, + escalateAfter: TimeInterval, + escalate: @escaping @Sendable (Int32) -> Void + ) { + recordSignal(name) + // Called here, on the signal queue. Whatever needs the main thread — + // `NSApplication.terminate` does — hops there itself, so that a main + // thread which never answers delays the shutdown instead of cancelling + // it. + onTerminate() + // The fallback only ever runs in a process that is still alive: a + // successful termination takes this timer with it. + Self.signalQueue.asyncAfter(deadline: .now() + escalateAfter) { + NSLog("[MCPProxy] %@ did not stop the app within %.0fs — " + + "restoring its default action", name, escalateAfter) + escalate(number) + } + } + + /// Stop the signal from killing us by default, WITHOUT ignoring it. + /// + /// `SIG_IGN` would have been shorter and is wrong twice over. An ignored + /// disposition survives `execve`, and Go's runtime deliberately preserves an + /// inherited `SIG_IGN` for SIGHUP and SIGINT (`runtime.initsig`) — so every + /// core this tray spawns would spend its life unable to be stopped by + /// `kill -INT` or `kill -HUP`. A real (empty) handler is reset to the + /// default across `execve`, so children inherit nothing. `EVFILT_SIGNAL`, + /// which is what `DispatchSourceSignal` is built on, records the signal + /// whatever the disposition — it only needs the default action gone. + private static func suppressDefaultAction(_ number: Int32) { + var action = sigaction() + action.__sigaction_u.__sa_handler = { _ in } + sigemptyset(&action.sa_mask) + action.sa_flags = Int32(SA_RESTART) + sigaction(number, &action, nil) + } + + /// Put the signal back the way the system found it and send it again. + /// + /// This is the production `escalate`. It is what makes catching a + /// termination signal safe: the worst case is now a five-second delay, not + /// a process that only `SIGKILL` can stop. + static func restoreDefaultActionAndReraise(_ number: Int32) { + signal(number, SIG_DFL) + kill(getpid(), number) + } + + private func event(_ kind: LifecycleEvent.Kind, _ reason: String) -> LifecycleEvent { + LifecycleEvent(kind: kind, reason: reason, at: Date(), uptimeSeconds: uptime, + pid: ProcessInfo.processInfo.processIdentifier) + } +} diff --git a/native/macos/MCPProxy/MCPProxy/Services/AutostartSidecarService.swift b/native/macos/MCPProxy/MCPProxy/Services/AutostartSidecarService.swift index 3733a887..1b005c01 100644 --- a/native/macos/MCPProxy/MCPProxy/Services/AutostartSidecarService.swift +++ b/native/macos/MCPProxy/MCPProxy/Services/AutostartSidecarService.swift @@ -22,13 +22,14 @@ import Foundation /// crashing the app over telemetry plumbing. enum AutostartSidecarService { - /// Returns `~/.mcpproxy/tray-autostart.json`. - private static var sidecarURL: URL { - let home = FileManager.default.homeDirectoryForCurrentUser - return home - .appendingPathComponent(".mcpproxy", isDirectory: true) - .appendingPathComponent("tray-autostart.json", isDirectory: false) - } + /// Returns `~/.mcpproxy/tray-autostart.json` — or the same file under the + /// instance root when one has been set (GH #936). + /// + /// This is the write that made a dev instance dangerous: `refresh()` reads + /// the RUNNING bundle's login-item state, and a copied bundle is never a + /// registered login item, so a QA run wrote `{"enabled":false}` over the + /// user's real `{"enabled":true}` on every launch. + private static var sidecarURL: URL { InstancePaths.autostartSidecarURL } /// Sidecar JSON schema. Matches `autostartSidecar` in /// `internal/telemetry/autostart.go`. diff --git a/native/macos/MCPProxy/MCPProxy/Services/LifecycleJournal.swift b/native/macos/MCPProxy/MCPProxy/Services/LifecycleJournal.swift new file mode 100644 index 00000000..e8264442 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxy/Services/LifecycleJournal.swift @@ -0,0 +1,227 @@ +// LifecycleJournal.swift +// MCPProxy +// +// A persistent record of who started and stopped what (GH #862). +// +// The gap it fills: when the app and its core disappeared mid-session, nothing +// on disk said why. Graceful paths log — but only to the running process's log, +// and only while it is running; a SIGKILL-class death (jetsam, `pkill`, a crash +// outside our handlers) leaves the log simply STOPPING, which reads exactly like +// a clean quit once the process is gone. macOS purges the Info/Debug tier of the +// unified log within hours, so by the time anyone looks there is nothing left to +// read either. +// +// Two things follow from that, and they are the whole design: +// +// * Every ending records a REASON, at the moment it happens. A shutdown that +// logs nothing is indistinguishable from a kill. +// * A run that recorded no ending is detectable at the NEXT launch. That is +// the only way a silent death is ever attributable, because the process that +// could have described it is gone. +// +// The file is JSON lines rather than a JSON document precisely because it is +// written by a process that may be killed mid-write: a truncated tail costs the +// last record, not the file. Everything here is best-effort — diagnostics must +// never be why the app fails to start. + +import Foundation +import os + +/// One lifecycle transition. +struct LifecycleEvent: Codable, Equatable { + + enum Kind: String, Codable { + /// The tray process came up. + case appLaunched + /// The tray process is going down, for a reason it can name. + case appTerminating + /// A core process was spawned by this tray. + case coreLaunched + /// A core this tray owned was asked to stop, with the reason it was. + case coreTerminated + /// A core exited on its own — crash, `pkill`, its own shutdown. + case coreExited + /// A catchable signal arrived. On its own this is NOT an ending: the + /// termination record that should follow it is. + case signalReceived + /// A periodic update check ran. Cheap, and it makes the updater + /// trivially includable or excludable in any future incident. + case updateCheck + } + + let kind: Kind + /// Who asked, and why. Free text, because that is what a human reads. + let reason: String + let at: Date + /// How long this tray process had been up when the event happened. + let uptimeSeconds: TimeInterval? + let pid: Int32 +} + +/// How the previous run of the app ended. +enum PreviousRunEnding: Equatable { + /// No journal, or nothing readable in it. + case noPreviousRun + /// The run recorded why it was going. + case clean(LifecycleEvent) + /// The run stopped without recording anything. `last` is the final thing it + /// did record — the only lead an incident has. + case unclean(last: LifecycleEvent?) +} + +/// Append-only lifecycle record, one JSON object per line. +/// +/// Not an actor and not `@MainActor`: it is called from a signal-source handler +/// and from `applicationWillTerminate`, neither of which can await anything, and +/// the writes are serialised by an internal lock instead. +final class LifecycleJournal { + + private let url: URL + private let maxRecords: Int + private let lock = NSLock() + + /// Notice level, deliberately: `os_log` Info and Debug are purged from the + /// unified log within hours, which is exactly why the original incident had + /// no spawn/exit context left by the time it was investigated. + private static let log = Logger(subsystem: "com.smartmcpproxy.mcpproxy", + category: "lifecycle") + + init(url: URL = InstancePaths.root.appendingPathComponent("tray-lifecycle.jsonl"), + maxRecords: Int = 500) { + self.url = url + self.maxRecords = maxRecords + } + + /// Record an event: to the journal, and to the unified log at a level that + /// survives. + func append(_ event: LifecycleEvent) { + Self.log.notice(""" + lifecycle \(event.kind.rawValue, privacy: .public): \ + \(event.reason, privacy: .public) \ + [pid \(event.pid, privacy: .public), \ + uptime \(Self.duration(event.uptimeSeconds), privacy: .public)] + """) + NSLog("[MCPProxy] lifecycle %@: %@ (uptime %@)", + event.kind.rawValue, event.reason, Self.duration(event.uptimeSeconds)) + + guard let line = try? Self.encoder.encode(event) else { return } + var data = line + data.append(0x0A) + + lock.lock() + defer { lock.unlock() } + try? FileManager.default.createDirectory(at: url.deletingLastPathComponent(), + withIntermediateDirectories: true) + if let handle = try? FileHandle(forWritingTo: url) { + defer { try? handle.close() } + handle.seekToEndOfFile() + handle.write(data) + return + } + try? data.write(to: url, options: .atomic) + } + + /// Every readable record, oldest first. Unparsable lines are skipped: a + /// record torn in half by a kill must not cost the ones around it. + func events() -> [LifecycleEvent] { + lock.lock() + let raw = try? Data(contentsOf: url) + lock.unlock() + guard let raw, let text = String(data: raw, encoding: .utf8) else { return [] } + return text.split(separator: "\n").compactMap { line in + guard let data = line.data(using: .utf8) else { return nil } + return try? Self.decoder.decode(LifecycleEvent.self, from: data) + } + } + + /// Keep only the newest `maxRecords`. Called once at launch, so an + /// always-on tray does not grow a journal nobody will ever read the middle + /// of — an incident is read backwards from the end. + func trim() { + let kept = events().suffix(maxRecords) + guard kept.count < events().count else { return } + let lines = kept.compactMap { try? Self.encoder.encode($0) } + var data = Data() + for line in lines { + data.append(line) + data.append(0x0A) + } + lock.lock() + defer { lock.unlock() } + try? data.write(to: url, options: .atomic) + } + + /// How the previous run ended. MUST be consulted before this run appends + /// its own launch record, or it reads that record as the previous ending. + /// + /// The question is "did the previous run record a reason", not "is the last + /// line a shutdown line" — and those differ in the ordinary case. The app + /// writes its own ending FIRST, so that a reason is on disk whatever happens + /// next, and only then tears its core down, which appends a `coreTerminated` + /// record after it. Judging by the final record alone reported every logout, + /// every launchd stop and every caught signal as a SIGKILL-class crash at + /// the next launch: a confidently false claim in the one diagnostic this + /// file exists to provide. + /// + /// Scoped to the last run, not the whole file: an ending recorded before the + /// most recent `appLaunched` belongs to an earlier run and cannot vouch for + /// this one. A journal trimmed past its last launch record falls back to the + /// whole tail, which is the same reading as before. + func previousRunEnding() -> PreviousRunEnding { + let events = events() + guard let last = events.last else { return .noPreviousRun } + let lastRun = events.lastIndex { $0.kind == .appLaunched } + .map { Array(events[$0...]) } ?? events + if let ending = lastRun.last(where: { $0.kind == .appTerminating }) { + return .clean(ending) + } + return .unclean(last: last) + } + + /// The line to log at launch when the previous run never said goodbye, or + /// nil when it did. + /// + /// It names the three facts an incident needs and nothing else: how long + /// the run lasted, what it was doing last, and when that was. Anything a + /// reader has to reconstruct is a fact the journal failed to keep. + static func uncleanExitSummary(for ending: PreviousRunEnding) -> String? { + guard case .unclean(let last) = ending else { return nil } + guard let last else { + return "previous run ended without recording a shutdown reason " + + "(no events survived) — likely SIGKILL-class termination " + + "(jetsam, pkill, power loss)" + } + let stamp = ISO8601DateFormatter().string(from: last.at) + return "previous run ended without recording a shutdown reason — " + + "last event \(last.kind.rawValue) \"\(last.reason)\" at \(stamp) " + + "after \(duration(last.uptimeSeconds)) of uptime; a graceful stop always " + + "records one, so this was SIGKILL-class (jetsam, pkill, power loss) " + + "or a crash outside the app's handlers" + } + + /// Uptime as something a human reads at a glance. + static func duration(_ seconds: TimeInterval?) -> String { + guard let seconds, seconds >= 0 else { return "unknown" } + let total = Int(seconds.rounded()) + let hours = total / 3600 + let minutes = (total % 3600) / 60 + if hours > 0 { return "\(hours)h\(minutes)m" } + if minutes > 0 { return "\(minutes)m\(total % 60)s" } + return "\(total)s" + } + + private static let encoder: JSONEncoder = { + let encoder = JSONEncoder() + encoder.dateEncodingStrategy = .iso8601 + // One line per record, always: a pretty-printed record would span + // several and the line-per-record recovery rule would be a lie. + encoder.outputFormatting = [] + return encoder + }() + + private static let decoder: JSONDecoder = { + let decoder = JSONDecoder() + decoder.dateDecodingStrategy = .iso8601 + return decoder + }() +} diff --git a/native/macos/MCPProxy/MCPProxy/Services/UpdateService.swift b/native/macos/MCPProxy/MCPProxy/Services/UpdateService.swift index c679739b..5f3afa2b 100644 --- a/native/macos/MCPProxy/MCPProxy/Services/UpdateService.swift +++ b/native/macos/MCPProxy/MCPProxy/Services/UpdateService.swift @@ -143,6 +143,12 @@ final class UpdateService: ObservableObject { private func checkWithGitHub() { guard !isChecking else { return } isChecking = true + // One line per check, on the record (#862 ask 3). The updater could + // neither be confirmed nor excluded during the original investigation + // because its hourly work logged nothing whatsoever. + AppLifecycle.shared.recordUpdateCheck( + "checking GitHub releases (running \(currentVersion.isEmpty ? "unknown" : currentVersion))" + ) Task { defer { DispatchQueue.main.async { self.isChecking = false } } diff --git a/native/macos/MCPProxy/MCPProxy/State/AppState.swift b/native/macos/MCPProxy/MCPProxy/State/AppState.swift index f49ca028..71067ad0 100644 --- a/native/macos/MCPProxy/MCPProxy/State/AppState.swift +++ b/native/macos/MCPProxy/MCPProxy/State/AppState.swift @@ -122,9 +122,44 @@ final class AppState: ObservableObject { /// an empty array means "loaded, and the proxy was idle". @Published var usageTimeline: [UsageBucket]? - /// Calls recorded in the CURRENT UTC hour. `nil` means "not loaded yet". + /// Calls recorded in the CURRENT UTC hour, as of the last usage poll. `nil` + /// means "not loaded yet". + /// + /// This is the POLLED number. What the header renders is + /// `glanceCallsThisHour(now:)`, which adds the calls that have arrived over + /// SSE since — see there for why the raw value cannot be shown. @Published var callsThisHour: Int? + /// The UTC hour `callsThisHour` is a total FOR. + /// + /// Without it the polled number outlives its hour: at 09:00:00, with the + /// last poll up to 30 seconds old, the header went on reporting 08:00's + /// total as "this hour" — and did so while the live half of the same sum + /// was already being filtered by hour, so the two halves disagreed about + /// which hour they were describing. + private var callsThisHourBucket: Date? + + /// When each live SSE call that the usage timeline will eventually count + /// arrived, for as long as the poll has not answered for it. + /// + /// Not `@Published`: every write here happens inside `prependGlanceActivity` + /// or `updateUsage`, both of which publish something the menu already + /// rebuilds on, so publishing this too would only double the churn. + private var liveCallsSinceUsagePoll: [Date] = [] + + /// The instant the most recent completed usage poll was ISSUED — the line + /// between "the core has already counted this call" and "it has not". + /// + /// A poll is an `await` across the network, and SSE rows land on the same + /// actor while it is in flight, so the two interleave. Clearing the live + /// list wholesale on any completed poll therefore dropped calls the poll + /// could not have seen (header falls from 13 back to 12 under a visible + /// thirteenth row), and re-admitting calls it already counted double-counted + /// them (header climbs to 14). Both are settled by one boundary: a live call + /// counts only while its timestamp is strictly after the poll that is + /// currently answering for the hour. + private var usagePollBoundary: Date = .distantPast + /// Last usage-refresh failure, surfaced as a muted row in the histogram /// submenu. `nil` means "no failure recorded"; the next successful refresh /// clears it. Without this the submenu could not tell "still loading" from @@ -369,6 +404,48 @@ final class AppState: ObservableObject { return 0 } + /// Whether a live SSE row will show up in the usage timeline's call count + /// once the poll catches up. + /// + /// The core's aggregate counts records of type `tool_call` and nothing else + /// — a blocked policy decision never executed, and an internal (built-in) + /// call is not an upstream one (`UsageAggregate.Apply`, + /// internal/runtime/usage_aggregate.go). Counting anything wider here would + /// swap one disagreement for the opposite one: the header would overshoot + /// the rows and then jump BACK at the next poll. + static func countsTowardUsageTimeline(_ entry: ActivityEntry) -> Bool { + entry.type == "tool_call" && !(entry.toolName ?? "").isEmpty + } + + /// The header's call count: the polled hour total plus the calls that have + /// arrived over SSE since that poll and fall in the same hour. + /// + /// The rows in the glance block come from SSE and are on screen within + /// milliseconds; the count came from a poll up to 30 seconds old, so the + /// header routinely sat one or more calls below the rows beneath it (GH + /// #934). Both now move on the same event. + /// + /// Still `nil` before the first usage response. A live call must not invent + /// "1 call this hour" for a proxy that has served hundreds — until the poll + /// answers there is no total to add to, and the header omits the segment. + /// + /// Once the hour rolls over, the polled total is dropped rather than + /// carried: it is a total for the hour that just ended, and reporting it as + /// this hour's is the same kind of untruth the live increment exists to + /// remove. What is left is the calls seen since — 0 on a quiet proxy, which + /// is exactly right, and corrected within one poll if it is not. + @MainActor + func glanceCallsThisHour(now: Date = Date()) -> Int? { + guard let callsThisHour else { return nil } + let hour = AppState.floorToHour(now) + let live = liveCallsSinceUsagePoll.filter { AppState.floorToHour($0) == hour }.count + // Dropped only when the total is KNOWN to be for another hour. A total + // with no recorded bucket has no provenance to distrust — production + // always writes the two together in `updateUsage`. + if let bucket = callsThisHourBucket, bucket != hour { return live } + return callsThisHour + live + } + /// Store the 24h timeline and derive the current-hour headline count. /// /// Ignored unless the core is `.connected`, like the other two glance @@ -379,12 +456,30 @@ final class AppState: ObservableObject { /// write feeds the debounced `objectWillChange → rebuildMenu()` sink in /// MCPProxyApp — an unguarded write here would rebuild the menu every 30s on /// a completely idle proxy. `UsageBucket` is `Equatable`, so the guard is free. + /// + /// `polledAt` is when the request that produced this timeline was ISSUED, + /// not when its answer arrived — the two differ by a round trip during + /// which SSE rows keep landing, and the difference is the whole reason the + /// parameter exists. It defaults to `now` for the callers (tests, mostly) + /// that have no separate notion of the two. @MainActor - func updateUsage(timeline: [UsageBucket], now: Date = Date()) { + func updateUsage(timeline: [UsageBucket], now: Date = Date(), polledAt: Date? = nil) { guard coreState == .connected else { return } if usageTimeline != timeline { usageTimeline = timeline } let calls = AppState.callsInCurrentHour(timeline, now: now) if callsThisHour != calls { callsThisHour = calls } + // Which hour that total is FOR. Not @Published: it only ever changes + // alongside `callsThisHour`, which already drives the rebuild. + callsThisHourBucket = AppState.floorToHour(now) + // This poll answered for everything that had already happened when it + // was issued, so those live increments are dropped rather than added to + // it — that is what keeps the two from accumulating (GH #934). What it + // could NOT have seen is kept: a call that arrived while the request was + // in flight is still ours to count, and dropping it made the header fall + // back below the row already on screen for up to 30 seconds. + let boundary = polledAt ?? now + usagePollBoundary = boundary + liveCallsSinceUsagePoll.removeAll { $0 <= boundary } if usageError != nil { usageError = nil } clearGlanceFailure(.usage) } @@ -420,10 +515,14 @@ final class AppState: ObservableObject { @MainActor func refreshUsage(from source: GlanceDataSource) async { let generation = connectionGeneration + // Stamped BEFORE the await. Everything the core had counted by now is + // in the answer; anything that arrives over SSE while this request is in + // flight is not, and the two are told apart by this instant alone. + let issuedAt = Date() do { let usage = try await source.usageAggregate(window: "24h", top: 1) guard isCurrentConnection(generation) else { return } - updateUsage(timeline: usage.timeline) + updateUsage(timeline: usage.timeline, polledAt: issuedAt) } catch { guard isCurrentConnection(generation) else { return } recordUsageFailure(AppState.usageFailureMessage(for: error)) @@ -698,6 +797,18 @@ final class AppState: ObservableObject { @MainActor func prependGlanceActivity(_ entry: ActivityEntry, generation: Int) { guard isCurrentConnection(generation) else { return } + // Before the row it belongs to, so the two are published together: the + // header must never be a number the rows underneath it contradict. + // + // Only calls the last poll cannot already have counted. An SSE event for + // a call that happened before that poll was issued is a LATE row, not a + // new call — the aggregate has it, and adding it again pushed the header + // one above the rows until the next poll corrected it. + if AppState.countsTowardUsageTimeline(entry), + let stamp = GlanceFormatting.parseTimestamp(entry.timestamp), + stamp > usagePollBoundary { + liveCallsSinceUsagePoll.append(stamp) + } // Unconfirmed until a poll carries it back: this is the only row the // merge is allowed to keep against a page that omits it. unconfirmedLiveKeys.insert(GlanceSelection.recordKey(for: entry)) @@ -745,6 +856,9 @@ final class AppState: ObservableObject { if !glanceSessions.isEmpty { glanceSessions = [] } if usageTimeline != nil { usageTimeline = nil } if callsThisHour != nil { callsThisHour = nil } + callsThisHourBucket = nil + if !liveCallsSinceUsagePoll.isEmpty { liveCallsSinceUsagePoll = [] } + usagePollBoundary = .distantPast if usageError != nil { usageError = nil } if !unconfirmedLiveKeys.isEmpty { unconfirmedLiveKeys = [] } if !glanceFailureStreak.isEmpty { glanceFailureStreak = [:] } diff --git a/native/macos/MCPProxy/MCPProxyTests/AppLifecycleTests.swift b/native/macos/MCPProxy/MCPProxyTests/AppLifecycleTests.swift new file mode 100644 index 00000000..ca138186 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/AppLifecycleTests.swift @@ -0,0 +1,281 @@ +import XCTest +@testable import MCPProxy + +/// Who gets to say why the app stopped (GH #862). +/// +/// `applicationWillTerminate` is told that the app is going and never why: a +/// quit from the tray menu, a `SIGTERM` from a script and a logout all arrive +/// there identically. So the reason is claimed by whoever starts the stop, and +/// these tests pin the two rules that makes workable — first claim wins, and an +/// unclaimed shutdown says so rather than inventing something plausible. +final class AppLifecycleTests: XCTestCase { + + private var directory: URL! + private var journal: LifecycleJournal! + + override func setUpWithError() throws { + directory = URL(fileURLWithPath: NSTemporaryDirectory(), isDirectory: true) + .appendingPathComponent("applifecycle-\(UUID().uuidString)", isDirectory: true) + try FileManager.default.createDirectory(at: directory, withIntermediateDirectories: true) + journal = LifecycleJournal(url: directory.appendingPathComponent("tray-lifecycle.jsonl")) + } + + override func tearDownWithError() throws { + try? FileManager.default.removeItem(at: directory) + // Signal dispositions are process-wide. Anything a test installed has + // to come back off, or the rest of the suite runs under it. + for number in [SIGTERM, SIGINT, SIGHUP] { signal(number, SIG_DFL) } + } + + /// The suite drives the real `CoreProcessManager` and the real app + /// delegate, both of which record lifecycle events through + /// `AppLifecycle.shared`. If that wrote to the instance root, running the + /// tests would append cores that never existed to the journal of the + /// developer's own live install. + func testTheSharedJournalNeverWritesToTheRealInstanceRootUnderTests() { + let path = AppLifecycle.defaultJournalURL.path + XCTAssertFalse(path.hasPrefix(InstancePaths.root.path), + "under XCTest the journal must live in a scratch file, got \(path)") + AppLifecycle.shared.recordUpdateCheck("smoke") + XCTAssertFalse( + FileManager.default.fileExists( + atPath: InstancePaths.root.appendingPathComponent("tray-lifecycle.jsonl").path + ), + "…and writing through the shared instance must not create one there either" + ) + } + + func testAClaimedReasonIsWhatTheShutdownRecords() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.note("user chose Quit in the tray menu") + lifecycle.recordTermination() + + XCTAssertEqual(journal.events().last?.kind, .appTerminating) + XCTAssertEqual(journal.events().last?.reason, "user chose Quit in the tray menu") + } + + /// The outermost initiator is the honest answer. Quitting tears the core + /// down, and the teardown must not overwrite "the user asked" with its own + /// mechanical description of what it is doing. + func testTheFirstClaimWins() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.note("user chose Quit in the tray menu") + lifecycle.note("core shutdown") + lifecycle.recordTermination() + XCTAssertEqual(journal.events().last?.reason, "user chose Quit in the tray menu") + } + + /// A shutdown nobody claimed is recorded as exactly that. Guessing would be + /// worse than silence: the next incident would read a confident reason that + /// nobody gave. + func testAnUnclaimedShutdownIsRecordedAsUnattributed() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.recordTermination() + XCTAssertEqual(journal.events().last?.reason, + "unattributed (no initiator claimed this shutdown)") + } + + /// A signal is both an event in its own right and the reason for the + /// termination that follows it. + func testASignalIsRecordedAndBecomesTheShutdownReason() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.recordSignal("SIGTERM") + lifecycle.recordTermination() + + let kinds = journal.events().map(\.kind) + XCTAssertEqual(kinds, [.signalReceived, .appTerminating]) + XCTAssertEqual(journal.events().last?.reason, "signal SIGTERM") + } + + /// Every record carries the uptime, because a run that died at 25 hours and + /// one that died at 25 seconds are different incidents. + func testEveryRecordCarriesUptimeAndPid() { + let lifecycle = AppLifecycle(journal: journal, + startedAt: Date().addingTimeInterval(-3600)) + lifecycle.recordTermination() + + guard let record = journal.events().last else { return XCTFail("nothing recorded") } + XCTAssertEqual(record.pid, ProcessInfo.processInfo.processIdentifier) + guard let uptime = record.uptimeSeconds else { return XCTFail("no uptime recorded") } + XCTAssertEqual(uptime, 3600, accuracy: 30) + } + + // MARK: - Launch + + /// The launch record is what the NEXT launch judges, so it must be written + /// after the previous ending is read — otherwise every run looks clean. + func testLaunchReportsAnUncleanPreviousRunAndThenRecordsItself() { + journal.append(LifecycleEvent(kind: .appLaunched, reason: "launched by user", + at: Date().addingTimeInterval(-90_000), + uptimeSeconds: 0, pid: 1)) + journal.append(LifecycleEvent(kind: .coreLaunched, reason: "autostart", + at: Date().addingTimeInterval(-89_000), + uptimeSeconds: 1000, pid: 2)) + + let marker = AppLifecycle(journal: journal).recordLaunch(source: "test") + XCTAssertNotNil(marker, "the previous run recorded no shutdown reason") + XCTAssertEqual(journal.events().last?.kind, .appLaunched) + XCTAssertTrue(journal.events().last?.reason.contains("PREVIOUS RUN") == true, + "the marker travels with the launch record, not just to the console") + } + + func testACleanPreviousRunIsNotFlagged() { + journal.append(LifecycleEvent(kind: .appLaunched, reason: "launched by user", + at: Date(), uptimeSeconds: 0, pid: 1)) + journal.append(LifecycleEvent(kind: .appTerminating, reason: "user quit", + at: Date(), uptimeSeconds: 10, pid: 1)) + + XCTAssertNil(AppLifecycle(journal: journal).recordLaunch(source: "test")) + XCTAssertEqual(journal.events().last?.reason, "launched by test") + } + + /// The ORDER production actually writes in. `applicationWillTerminate` + /// records the app's ending first — so a reason exists whatever happens + /// next — and only then tears the core down, which appends a + /// `coreTerminated` record after it. That run said goodbye; a classifier + /// that only looks at the very last record calls every logout, every + /// launchd stop and every caught SIGTERM a SIGKILL-class crash at the next + /// launch, which is a confidently false claim in the one diagnostic #862 + /// asked for. + func testACleanShutdownIsStillCleanWhenACoreRecordFollowsIt() { + journal.append(LifecycleEvent(kind: .appLaunched, reason: "launched by user", + at: Date().addingTimeInterval(-3600), + uptimeSeconds: 0, pid: 1)) + journal.append(LifecycleEvent(kind: .appTerminating, + reason: "macOS is logging out, restarting or shutting down", + at: Date().addingTimeInterval(-10), + uptimeSeconds: 3590, pid: 1)) + journal.append(LifecycleEvent(kind: .coreTerminated, reason: "tray is terminating", + at: Date().addingTimeInterval(-9), + uptimeSeconds: 3591, pid: 2)) + + XCTAssertNil(AppLifecycle(journal: journal).recordLaunch(source: "test"), + "the run recorded why it was going; the core teardown that " + + "followed does not un-record it") + } + + /// …and the previous run's goodbye is not borrowed by the run after it. A + /// clean quit, then a relaunch that was killed, is still an unclean run. + func testAnEarlierRunsGoodbyeDoesNotCleanTheRunAfterIt() { + journal.append(LifecycleEvent(kind: .appLaunched, reason: "launched by user", + at: Date().addingTimeInterval(-7200), + uptimeSeconds: 0, pid: 1)) + journal.append(LifecycleEvent(kind: .appTerminating, reason: "user quit", + at: Date().addingTimeInterval(-7000), + uptimeSeconds: 200, pid: 1)) + journal.append(LifecycleEvent(kind: .appLaunched, reason: "launched by launchd", + at: Date().addingTimeInterval(-6000), + uptimeSeconds: 0, pid: 2)) + journal.append(LifecycleEvent(kind: .coreLaunched, reason: "tray launched core", + at: Date().addingTimeInterval(-5900), + uptimeSeconds: 100, pid: 3)) + + XCTAssertNotNil(AppLifecycle(journal: journal).recordLaunch(source: "test"), + "the second run never recorded an ending of its own") + } + + // MARK: - Signals + + /// The tray must not leave TERM/INT/HUP set to `SIG_IGN`. + /// + /// Two separate costs, both paid by processes that had nothing to do with + /// the diagnostic. An ignored disposition SURVIVES `execve`, and Go's + /// runtime deliberately preserves an inherited `SIG_IGN` for SIGHUP and + /// SIGINT (`runtime.initsig`) — so every core this tray spawns would go on + /// ignoring `kill -INT` and `kill -HUP` for its whole life. And in this + /// process, an ignored signal whose only handler is a dispatch source is a + /// signal that does nothing at all if that source never runs. + /// + /// A no-op `sigaction` handler suppresses the default action just as well, + /// is what `EVFILT_SIGNAL` needs (kqueue records the signal whatever the + /// disposition), and is RESET to the default across `execve` — so children + /// inherit nothing. + func testCaughtSignalsAreNotLeftIgnoredForChildrenToInherit() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.installSignalHandlers(onTerminate: {}) + defer { lifecycle.uninstallSignalHandlers() } + + for number in [SIGTERM, SIGINT, SIGHUP] { + XCTAssertNotEqual(Self.handlerBits(number), Self.ignoreBits, + "signal \(number) is left ignored; a spawned core inherits that") + XCTAssertNotEqual(Self.handlerBits(number), Self.defaultBits, + "signal \(number) still has its default action; the app would " + + "die before the source ever ran") + } + } + + /// Delivery must not depend on the main thread. The handler used to run on + /// `.main` only, so a wedged main thread turned `pkill -TERM`, `launchctl + /// kill TERM` and a launchd stop into no-ops — the signal was ignored and + /// nothing was left to act on it, where before this diagnostic existed they + /// simply killed the process. + /// + /// The main thread is the one blocking on the semaphore here, which is + /// exactly the wedge being described. + func testASignalIsActedOnEvenWhileTheMainThreadIsBlocked() throws { + let lifecycle = AppLifecycle(journal: journal) + let handled = DispatchSemaphore(value: 0) + lifecycle.installSignalHandlers(onTerminate: { handled.signal() }, + escalateAfter: 60, + escalate: { _ in }) + defer { lifecycle.uninstallSignalHandlers() } + + kill(getpid(), SIGHUP) + XCTAssertEqual(handled.wait(timeout: .now() + 3), .success, + "the signal never reached a handler that could act on it") + } + + /// …and if the graceful stop does not happen, the signal still ends the + /// process. Ignoring a termination request and then failing to terminate is + /// strictly worse than never having caught it: `SIGKILL` becomes the only + /// thing that works, which is precisely the unattributable death this whole + /// file exists to prevent. + func testASignalThatDoesNotStopTheAppFallsBackToItsDefaultAction() { + let lifecycle = AppLifecycle(journal: journal) + let escalated = expectation(description: "the default action is restored and re-raised") + var escalatedSignal: Int32 = 0 + + lifecycle.respondToSignal("SIGTERM", number: SIGTERM, + onTerminate: { /* wedged: nothing stops the app */ }, + escalateAfter: 0.05, + escalate: { number in + escalatedSignal = number + escalated.fulfill() + }) + + wait(for: [escalated], timeout: 3) + XCTAssertEqual(escalatedSignal, SIGTERM) + XCTAssertEqual(journal.events().first?.kind, .signalReceived, + "the signal is on the record before anything is done about it") + } + + /// Core transitions are attributable too: "who started this core" and "who + /// killed it" are the questions a dropped MCP session raises. + func testCoreTransitionsCarryTheirReason() { + let lifecycle = AppLifecycle(journal: journal) + lifecycle.recordCoreLaunched(pid: 4242, reason: "tray autostart") + lifecycle.recordCoreTerminated(pid: 4242, reason: "retry requested") + lifecycle.recordCoreExited(pid: 4242, status: 9, reason: "core exited unexpectedly") + + let events = journal.events() + XCTAssertEqual(events.map(\.kind), [.coreLaunched, .coreTerminated, .coreExited]) + XCTAssertEqual(events[0].pid, 4242) + XCTAssertEqual(events[1].reason, "retry requested") + XCTAssertTrue(events[2].reason.contains("exit status 9"), + "the status is the difference between a crash and a clean stop") + } + + // MARK: - Signal-disposition helpers + + /// The installed handler as a bit pattern, so it can be compared with the + /// two sentinels. `SIG_IGN` and `SIG_DFL` are function-pointer sentinels + /// (1 and 0), not real functions, so there is nothing else to compare. + private static func handlerBits(_ number: Int32) -> UInt { + var action = sigaction() + guard sigaction(number, nil, &action) == 0 else { return .max } + return unsafeBitCast(action.__sigaction_u.__sa_handler, to: UInt.self) + } + + private static var ignoreBits: UInt { unsafeBitCast(SIG_IGN, to: UInt.self) } + private static var defaultBits: UInt { unsafeBitCast(SIG_DFL, to: UInt.self) } +} diff --git a/native/macos/MCPProxy/MCPProxyTests/ConnectFormWindowLifecycleTests.swift b/native/macos/MCPProxy/MCPProxyTests/ConnectFormWindowLifecycleTests.swift index f6be9100..665b387e 100644 --- a/native/macos/MCPProxy/MCPProxyTests/ConnectFormWindowLifecycleTests.swift +++ b/native/macos/MCPProxy/MCPProxyTests/ConnectFormWindowLifecycleTests.swift @@ -97,7 +97,13 @@ final class ConnectFormWindowLifecycleTests: XCTestCase { let sheet = makeWindow() host.makeKeyAndOrderFront(nil) host.beginSheet(sheet) { _ in } - RunLoop.current.run(until: Date().addingTimeInterval(0.2)) + // Attachment is asynchronous, so wait for it rather than for a fixed + // slice of wall clock: a loaded runner that needed 0.3 s used to turn + // this test into a silent skip. + let attached = Date().addingTimeInterval(2) + while sheet.sheetParent == nil, Date() < attached { + RunLoop.current.run(mode: .default, before: Date().addingTimeInterval(0.02)) + } try XCTSkipIf(sheet.sheetParent == nil, "AppKit did not attach the sheet in this environment") lifecycle.adopt(sheet, model: ConnectClientModel(source: FakeConnectSource(), sleeper: { _ in })) @@ -109,12 +115,15 @@ final class ConnectFormWindowLifecycleTests: XCTestCase { host.close() } - /// Counts what the poll asked the clock for, so "it stopped" is a measured - /// fact rather than an inference. + /// Counts what the poll asked the clock for, and records the moment the + /// loop returned, so "it stopped" is a measured fact rather than an + /// inference. @MainActor final class PollCounter { private(set) var ticks = 0 + private(set) var loopReturned = false func tick() { ticks += 1 } + func markReturned() { loopReturned = true } } /// The leak that mattered is a poll that keeps running, so this drives the @@ -133,6 +142,14 @@ final class ConnectFormWindowLifecycleTests: XCTestCase { /// Note the sleeper mirrors the production one, which returns IMMEDIATELY /// once cancelled (`try? await Task.sleep`): a loop that did not check /// `Task.isCancelled` would not slow down here, it would spin. + /// + /// What "stopped" is measured as, and why it is not a wall-clock guess: the + /// cancellation can land while an iteration is already in flight — suspended + /// in the source call, past that iteration's cancellation check — and that + /// iteration still unwinds through the sleeper once. Counting from the + /// pre-cancellation total therefore proves nothing on a loaded runner. So + /// this waits for the loop to RETURN, allows that single settling tick as a + /// hard ceiling, and then samples the counter twice to show it is frozen. func testTheReachabilityPollRunsAndThenProvablyStops() async { let source = FakeConnectSource() source.clientsResults = [.failure(APIClientError.notReady)] @@ -142,12 +159,17 @@ final class ConnectFormWindowLifecycleTests: XCTestCase { try? await Task.sleep(nanoseconds: 5_000_000) }) - let poll = Task { await model.loadList() } + let poll = Task { + await model.loadList() + counter.markReturned() + } defer { poll.cancel() } // It is polling: wait for real iterations rather than assuming any. - for _ in 0..<200 where counter.ticks < 3 { + var waits = 0 + while counter.ticks < 3, waits < 200 { try? await Task.sleep(nanoseconds: 5_000_000) + waits += 1 } XCTAssertGreaterThanOrEqual(counter.ticks, 3, "precondition: the form is polling an unreachable core") @@ -156,10 +178,27 @@ final class ConnectFormWindowLifecycleTests: XCTestCase { poll.cancel() let atCancellation = counter.ticks - // Well past several poll intervals at this cadence. + // A cancelled loop returns; a runaway one never does, so this waits on + // the event rather than on the clock and a slow runner only makes the + // test slower, never red. + waits = 0 + while !counter.loopReturned, waits < 400 { + try? await Task.sleep(nanoseconds: 5_000_000) + waits += 1 + } + XCTAssertTrue(counter.loopReturned, + "cancellation must END loadList, not merely slow it down") + XCTAssertLessThanOrEqual(counter.ticks, atCancellation + 1, + "only the one already-in-flight iteration may settle; " + + "a second means the loop went round again after cancellation") + + // And it stays stopped. 200 ms is 40 of this sleeper's own delays, and + // an uncancellable loop does not add a tick per delay here — it spins, + // because the production sleeper returns immediately once cancelled. + let settled = counter.ticks try? await Task.sleep(nanoseconds: 200_000_000) - XCTAssertEqual(counter.ticks, atCancellation, + XCTAssertEqual(counter.ticks, settled, "the poll must STOP, not merely slow down, once its task is cancelled") } diff --git a/native/macos/MCPProxy/MCPProxyTests/DataDirectoryLockTests.swift b/native/macos/MCPProxy/MCPProxyTests/DataDirectoryLockTests.swift new file mode 100644 index 00000000..6b1c8d9e --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/DataDirectoryLockTests.swift @@ -0,0 +1,94 @@ +import XCTest +@testable import MCPProxy + +/// The one liveness signal that does not go through the socket (GH #933). +/// +/// A core with a saturated listen backlog refuses every probe, exactly like a +/// socket file a dead core left behind — sample by sample the two are +/// indistinguishable, which is what let the tray launch over a healthy core. +/// The core takes bbolt's exclusive `flock` on its data directory BEFORE it +/// creates its listener, and the kernel releases that lock when the process +/// dies. So "is somebody holding the lock" answers the question the socket +/// cannot, and answers it without a false positive: no dead process can hold it. +final class DataDirectoryLockTests: XCTestCase { + + private var directory: URL! + private var database: URL! + private var heldDescriptor: Int32 = -1 + + override func setUpWithError() throws { + directory = URL(fileURLWithPath: NSTemporaryDirectory(), isDirectory: true) + .appendingPathComponent("datalock-\(UUID().uuidString)", isDirectory: true) + try FileManager.default.createDirectory(at: directory, withIntermediateDirectories: true) + database = directory.appendingPathComponent("config.db") + } + + override func tearDownWithError() throws { + if heldDescriptor >= 0 { + flock(heldDescriptor, LOCK_UN) + close(heldDescriptor) + heldDescriptor = -1 + } + try? FileManager.default.removeItem(at: directory) + } + + /// No database, nothing to conclude. A tray pointed at a socket outside any + /// data directory must get "I cannot tell", never "nothing is running". + func testAMissingDatabaseIsUnknownNotFree() { + guard case .unknown = DataDirectoryLock.probe(path: database.path) else { + return XCTFail("a missing file cannot prove anything, got " + + "\(DataDirectoryLock.probe(path: database.path))") + } + } + + /// The stale-socket case: the file is there and nobody holds it, because + /// the process that did is gone. This is the reading that permits a launch. + func testAnUnlockedDatabaseReadsAsFree() throws { + FileManager.default.createFile(atPath: database.path, contents: Data()) + XCTAssertEqual(DataDirectoryLock.probe(path: database.path), .free) + } + + /// The case this exists for: something alive holds the lock. `flock` locks + /// belong to the open file DESCRIPTION, so a second `open` of the same file + /// conflicts even from inside this process — which is what makes the live + /// case testable at all. + func testADatabaseHeldByALiveProcessIsDetected() throws { + FileManager.default.createFile(atPath: database.path, contents: Data()) + heldDescriptor = open(database.path, O_RDONLY) + XCTAssertGreaterThanOrEqual(heldDescriptor, 0) + XCTAssertEqual(flock(heldDescriptor, LOCK_EX | LOCK_NB), 0, + "precondition: this test now holds the lock a core would hold") + + XCTAssertEqual(DataDirectoryLock.probe(path: database.path), .heldByALiveProcess) + } + + /// And the probe itself must not become the thing that blocks a core: it + /// takes a SHARED lock, non-blocking, and gives it straight back. Two + /// probes at once therefore both read "free" rather than each reporting the + /// other as a live core. + func testTheProbeDoesNotLockOutAnotherProbe() throws { + FileManager.default.createFile(atPath: database.path, contents: Data()) + XCTAssertEqual(DataDirectoryLock.probe(path: database.path), .free) + XCTAssertEqual(DataDirectoryLock.probe(path: database.path), .free) + + // The lock really was released: an exclusive taker still gets it. + let descriptor = open(database.path, O_RDONLY) + defer { close(descriptor) } + XCTAssertEqual(flock(descriptor, LOCK_EX | LOCK_NB), 0, + "the probe must leave no lock behind") + flock(descriptor, LOCK_UN) + } + + /// Where the tray looks: beside the socket it is probing. The core's socket + /// and its database live in the same directory, so the lock that answers + /// for THIS socket is the one next to it — not the one under the default + /// instance root, which belongs to a different core entirely. + func testTheLockIsLookedForBesideTheSocketBeingProbed() { + XCTAssertEqual(DataDirectoryLock.path(forSocket: "/tmp/qa933/mcpproxy.sock"), + "/tmp/qa933/config.db") + XCTAssertEqual( + DataDirectoryLock.path(forSocket: "/Users/x/.mcpproxy/mcpproxy.sock"), + "/Users/x/.mcpproxy/config.db" + ) + } +} diff --git a/native/macos/MCPProxy/MCPProxyTests/GlanceHeaderConsistencyTests.swift b/native/macos/MCPProxy/MCPProxyTests/GlanceHeaderConsistencyTests.swift new file mode 100644 index 00000000..67a69f3e --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/GlanceHeaderConsistencyTests.swift @@ -0,0 +1,290 @@ +import XCTest +import AppKit +@testable import MCPProxy + +/// The header must never contradict the rows under it (GH #934). +/// +/// Two independent ways it could, both observed in live QA: +/// +/// 1. The Clients header counts every client the proxy has seen while the list +/// shows at most five, so "11 clients" sat above five rows with nothing to +/// say the list was cut. +/// 2. The call count comes from the 30-second usage poll while the rows arrive +/// over SSE, so a call that already has a row is not in the number above it +/// for up to half a minute — "12 calls this hour" above a five-second-old +/// thirteenth call. +/// +/// Both are cosmetic and both cost trust in the one block whose entire job is to +/// be glanced at, so they are pinned here rather than left to a screenshot. +@MainActor +final class GlanceHeaderConsistencyTests: XCTestCase { + + static let now = GlanceFormatting.parseTimestamp("2027-01-15T08:00:00Z")! + + private static let clickStub = ClickTarget() + + final class ClickTarget: NSObject { + @objc func openGlanceRow(_ sender: NSMenuItem) {} + } + + private static func makeSection() -> GlanceSection { + GlanceSection(target: clickStub, action: #selector(ClickTarget.openGlanceRow(_:))) + } + + // MARK: - The list says how much of itself it is showing + + /// Eleven clients, five rows: the block must admit the other six exist. + /// Without the overflow row the header ("8 active · 3 idle") is simply a + /// bigger number than the list, with nothing to explain the difference. + func testTruncatedClientListDeclaresHowManyItLeftOut() { + let state = Self.stateWithClients(11) + let items = Self.makeSection().items(for: state, now: Self.now) + let titles = items.map { $0.isSeparatorItem ? "—" : $0.title } + + XCTAssertEqual(titles.filter { $0.hasPrefix("client-") }.count, 5, + "precondition: the list itself is still capped at five rows") + guard let overflow = items.first(where: { $0.title == "+6 more" }) else { + return XCTFail("a truncated client list must carry a '+N more' row, got \(titles)") + } + XCTAssertFalse(overflow.isEnabled, "the overflow row is a muted admission, not an action") + XCTAssertNil(overflow.action) + } + + /// …and says nothing when there is nothing to admit. An always-present + /// "+0 more" would be its own kind of noise. + func testAFullyVisibleClientListHasNoOverflowRow() { + let state = Self.stateWithClients(5) + let titles = Self.makeSection().items(for: state, now: Self.now).map(\.title) + XCTAssertFalse(titles.contains { $0.hasSuffix(" more") }, + "five clients fit in five rows, got \(titles)") + } + + /// The overflow count is live: a twelfth client appearing must not leave + /// "+6 more" on screen under a header that now counts twelve. + func testTheOverflowCountIsRewrittenInPlace() { + let state = Self.stateWithClients(11) + let section = Self.makeSection() + _ = section.items(for: state, now: Self.now) + + state.glanceSessions = Self.sessions(12) + XCTAssertTrue(section.updateInPlace(for: state, now: Self.now), + "one more client beyond the cap changes no row COUNT, so it is in-place") + XCTAssertEqual(section.clientOverflowTitleForTesting, "+7 more") + } + + /// Crossing the cap changes the number of rows, which resizes a menu the + /// user may have open — so it waits for close like every other structural + /// change (FR-023). + func testGainingAnOverflowRowIsStructural() { + let state = Self.stateWithClients(5) + let section = Self.makeSection() + _ = section.items(for: state, now: Self.now) + + state.glanceSessions = Self.sessions(6) + XCTAssertFalse(section.updateInPlace(for: state, now: Self.now), + "the block just gained a row; that is a rebuild, not a rewrite") + } + + // MARK: - The call count counts the rows it sits above + + /// A live SSE call lands in the rows immediately. The header must move with + /// it instead of waiting for the next usage poll. + func testALiveCallIsCountedInTheHeaderBeforeTheNextPoll() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now, + polledAt: Self.now.addingTimeInterval(-1)) + XCTAssertEqual(Self.makeSection().items(for: state, now: Self.now).first?.title, + "12 calls this hour · 1 active", + "precondition: the polled count is what the header shows") + + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: "2027-01-15T08:00:00Z", session: "sess-a"), + generation: state.connectionGeneration + ) + + XCTAssertEqual(Self.makeSection().items(for: state, now: Self.now).first?.title, + "13 calls this hour · 1 active", + "the row is on screen, so the number above it has to include it") + } + + /// The live increment is not a second source of truth: the next poll's + /// answer replaces it outright, so the two can never accumulate. + func testTheNextPollSupersedesTheLiveIncrement() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now, + polledAt: Self.now.addingTimeInterval(-1)) + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: "2027-01-15T08:00:00Z", session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13) + + // The poll that has now seen the same call: issued after it happened. + state.updateUsage(timeline: [Self.bucket(calls: 13)], now: Self.now, polledAt: Self.now) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13, + "the poll's count already includes the live call; adding it twice " + + "is the drift this fix exists to remove") + } + + /// A poll is an `await` across the network, and SSE rows land on the same + /// actor while it is in flight. A response that snapshotted the core BEFORE + /// a live call happened cannot answer for that call, so it must not delete + /// it: the header dropping from 13 back to 12 under a visible thirteenth row + /// — and staying there for up to 30 seconds — is the same inconsistency + /// #934 is about, arriving from the other direction. + func testAPollAlreadyInFlightDoesNotEraseACallItCouldNotHaveSeen() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now, + polledAt: Self.now.addingTimeInterval(-60)) + + // The next poll is issued… + let issuedAt = Self.now + // …a call arrives five seconds later, while it is still in flight… + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: "2027-01-15T08:00:05Z", session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13) + + // …and the response, which counted 12, lands after it. + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now, polledAt: issuedAt) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13, + "that poll answered for 08:00:00; the call at 08:00:05 is still ours") + } + + /// The mirror image. The aggregate counted a call, the response was + /// processed, and the SSE event for that same call is delivered a few + /// milliseconds later. Adding it on top of a total that already contains it + /// makes the header overshoot the rows until the next poll. + func testACallTheLastPollAlreadyCountedIsNotAddedAgainWhenItsEventArrivesLate() { + let state = Self.connectedState() + let calledAt = "2027-01-15T08:00:05Z" + // Issued after the call happened, so its 13 includes it. + state.updateUsage(timeline: [Self.bucket(calls: 13)], now: Self.now, + polledAt: GlanceFormatting.parseTimestamp("2027-01-15T08:00:10Z")!) + + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: calledAt, session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13, + "the row is late, the call is not: the poll already counted it") + } + + /// Only what the usage timeline itself counts. A blocked call never + /// executed — the core's aggregate excludes it (`UsageAggregate.Apply`) — + /// so counting it here would make the header disagree with the poll that + /// follows it, in the other direction. + func testABlockedCallIsNotAddedToTheCallCount() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now) + state.prependGlanceActivity(Self.blockedEntry(), generation: state.connectionGeneration) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 12) + } + + /// A live call from the hour that just ended belongs to that hour's bucket, + /// not to this one — and neither does the POLLED total it was added to. + /// "12 calls this hour" for an hour in which nothing has happened yet is the + /// same lie as the one the live increment fixes, told by the other half of + /// the sum. + func testNeitherHalfOfTheCountSurvivesAnHourRollover() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now) + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: "2027-01-15T08:00:30Z", session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now), 13, + "precondition: both halves count inside the polled hour") + + // …an hour later, with no poll in between. + let nextHour = Self.now.addingTimeInterval(3600) + XCTAssertEqual(state.glanceCallsThisHour(now: nextHour), 0, + "the poll answered for 07:00–08:00; nothing has answered for 08:00–09:00") + } + + /// The base is stale only until it is stale in the same direction as the + /// live calls: a call that arrives in the NEW hour is this hour's whole + /// count, and the previous hour's polled total must not be added to it. + func testAfterAnHourRolloverOnlyTheNewHoursLiveCallsCount() { + let state = Self.connectedState() + state.updateUsage(timeline: [Self.bucket(calls: 12)], now: Self.now) + state.prependGlanceActivity( + GlanceFixtures.entry(id: "next-hour", server: "github", tool: "create_issue", + timestamp: "2027-01-15T09:00:10Z", session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertEqual(state.glanceCallsThisHour(now: Self.now.addingTimeInterval(3600)), 1) + } + + /// Nothing to add to. Until the first usage response the header has no call + /// segment at all, and one live call must not invent "1 call this hour" + /// over a proxy that has served hundreds. + func testLiveCallsDoNotFabricateACountBeforeTheFirstPoll() { + let state = Self.connectedState() + state.callsThisHour = nil + state.prependGlanceActivity( + GlanceFixtures.entry(id: "live", server: "github", tool: "create_issue", + timestamp: "2027-01-15T08:00:00Z", session: "sess-a"), + generation: state.connectionGeneration + ) + XCTAssertNil(state.glanceCallsThisHour(now: Self.now)) + } + + // MARK: - Fixtures + + private static func connectedState() -> AppState { + let state = AppState() + state.coreState = .connected + state.glanceSessions = [ + GlanceFixtures.session(id: "sess-a", name: "Claude Code", calls: 8, + lastActivity: "2027-01-15T07:59:00Z") + ] + return state + } + + private static func stateWithClients(_ count: Int) -> AppState { + let state = AppState() + state.coreState = .connected + state.glanceSessions = sessions(count) + return state + } + + /// `count` distinct clients, each a minute apart so the order is total. + private static func sessions(_ count: Int) -> [APIClient.MCPSession] { + (0.. UsageBucket { + UsageBucket(start: AppState.floorToHour(now), calls: calls, errors: 0, totalRespBytes: 0) + } + + private static func blockedEntry() -> ActivityEntry { + let json: [String: Any] = [ + "id": "blocked-1", + "type": ActivityEntry.policyDecisionType, + "status": "blocked", + "timestamp": "2027-01-15T08:00:00Z", + "request_id": "req-blocked-1", + "server_name": "github", + "tool_name": "create_issue" + ] + let data = try! JSONSerialization.data(withJSONObject: json) + // swiftlint:disable:next force_try + return try! JSONDecoder().decode(ActivityEntry.self, from: data) + } +} diff --git a/native/macos/MCPProxy/MCPProxyTests/GlanceSectionTests.swift b/native/macos/MCPProxy/MCPProxyTests/GlanceSectionTests.swift index 18068ec4..efe2e542 100644 --- a/native/macos/MCPProxy/MCPProxyTests/GlanceSectionTests.swift +++ b/native/macos/MCPProxy/MCPProxyTests/GlanceSectionTests.swift @@ -119,12 +119,33 @@ final class GlanceSectionTests: XCTestCase { func testFirstClauseKeepsOnlyTheLeadingClause() { XCTAssertEqual(GlanceSection.firstClause(of: "auth failed: token expired"), "auth failed") - XCTAssertEqual(GlanceSection.firstClause(of: "dial tcp 127.0.0.1"), "dial tcp 127") XCTAssertEqual(GlanceSection.firstClause(of: " boom "), "boom") + XCTAssertEqual(GlanceSection.firstClause(of: "timed out.\nretrying"), "timed out") + XCTAssertEqual(GlanceSection.firstClause(of: "not found."), "not found") XCTAssertNil(GlanceSection.firstClause(of: " ")) XCTAssertNil(GlanceSection.firstClause(of: nil)) } + /// A separator only ends a clause when something separates because of it + /// (GH #934). mcpproxy names tools `server:tool` and hosts `127.0.0.1`, and + /// cutting at a bare `:` or `.` lands inside both — the observed rendering + /// of `invalid arguments for memory:create_entities: …` was "invalid + /// arguments for memory", which reads as an accusation against the server. + func testFirstClauseDoesNotCutInsideAnIdentifier() { + XCTAssertEqual( + GlanceSection.firstClause( + of: "invalid arguments for memory:create_entities: at '/entities': " + + "got string, want array" + ), + "invalid arguments for memory:create_entities" + ) + XCTAssertEqual(GlanceSection.firstClause(of: "dial tcp 127.0.0.1"), "dial tcp 127.0.0.1") + XCTAssertEqual(GlanceSection.firstClause(of: "dial tcp 127.0.0.1:8080: refused"), + "dial tcp 127.0.0.1:8080") + XCTAssertEqual(GlanceSection.firstClause(of: "read file a.txt failed: EACCES"), + "read file a.txt failed") + } + // MARK: - Grouped rows (spec 090 US1) /// A burst of one tool is one row, and the rest of the page still gets rows. diff --git a/native/macos/MCPProxy/MCPProxyTests/InstancePathsTests.swift b/native/macos/MCPProxy/MCPProxyTests/InstancePathsTests.swift new file mode 100644 index 00000000..0de75f59 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/InstancePathsTests.swift @@ -0,0 +1,144 @@ +import XCTest +@testable import MCPProxy + +/// Where a tray instance keeps its state, and how a dev/QA instance is pointed +/// somewhere else (GH #936). +/// +/// The tray resolves everything under `homeDirectoryForCurrentUser`, which +/// IGNORES `$HOME` — so a build run out of a scratch bundle still read and wrote +/// the real `~/.mcpproxy`, and the autostart sidecar silently overwrote the +/// user's login-item state with the scratch bundle's. There is no way to test +/// "does not touch real user state" by running the app, so the resolution rules +/// are pinned here instead: every one of them takes its environment and home as +/// parameters precisely so a test can supply them. +final class InstancePathsTests: XCTestCase { + + private let home = URL(fileURLWithPath: "/Users/tester", isDirectory: true) + + // MARK: - Default (no override): behaviour is exactly what it always was + + func testWithoutTheOverrideEverythingResolvesUnderTheRealHome() { + let env: [String: String] = [:] + XCTAssertEqual(InstancePaths.root(environment: env, home: home).path, + "/Users/tester/.mcpproxy") + XCTAssertEqual(InstancePaths.socketPath(environment: env, home: home), + "/Users/tester/.mcpproxy/mcpproxy.sock") + XCTAssertEqual(InstancePaths.autostartSidecarURL(environment: env, home: home).path, + "/Users/tester/.mcpproxy/tray-autostart.json") + XCTAssertEqual(InstancePaths.configFileURL(environment: env, home: home).path, + "/Users/tester/.mcpproxy/mcp_config.json") + XCTAssertEqual(InstancePaths.dataLockURL(environment: env, home: home).path, + "/Users/tester/.mcpproxy/config.db") + XCTAssertFalse(InstancePaths.isOverridden(environment: env)) + } + + /// An empty or whitespace-only value is not an override. A launcher that + /// exports the variable unset must not silently relocate the instance to + /// the filesystem root. + func testABlankOverrideIsNoOverride() { + for blank in ["", " ", "\n"] { + let env = [InstancePaths.rootEnvVar: blank] + XCTAssertEqual(InstancePaths.root(environment: env, home: home).path, + "/Users/tester/.mcpproxy", + "\(blank.debugDescription) must not be treated as a root") + XCTAssertFalse(InstancePaths.isOverridden(environment: env)) + } + } + + // MARK: - The override moves everything at once + + func testTheRootOverrideRelocatesEveryInstanceFile() { + let env = [InstancePaths.rootEnvVar: "/tmp/qa936"] + XCTAssertEqual(InstancePaths.root(environment: env, home: home).path, "/tmp/qa936") + XCTAssertEqual(InstancePaths.socketPath(environment: env, home: home), + "/tmp/qa936/mcpproxy.sock") + XCTAssertEqual(InstancePaths.autostartSidecarURL(environment: env, home: home).path, + "/tmp/qa936/tray-autostart.json", + "the sidecar is the file that silently overwrote real user state") + XCTAssertEqual(InstancePaths.configFileURL(environment: env, home: home).path, + "/tmp/qa936/mcp_config.json") + XCTAssertEqual(InstancePaths.dataLockURL(environment: env, home: home).path, + "/tmp/qa936/config.db") + XCTAssertTrue(InstancePaths.isOverridden(environment: env)) + } + + /// A relative or `~`-prefixed value is resolved, not passed through: a + /// socket path the tray and the core disagree about is worse than none. + func testTheOverrideIsExpandedAndStandardised() { + let env = [InstancePaths.rootEnvVar: "~/scratch/qa"] + XCTAssertEqual(InstancePaths.root(environment: env, home: home).path, + "\(NSHomeDirectory())/scratch/qa", + "tilde expansion goes through the same rule everything else does") + + let trailing = [InstancePaths.rootEnvVar: "/tmp/qa936/"] + XCTAssertEqual(InstancePaths.root(environment: trailing, home: home).path, "/tmp/qa936") + } + + // MARK: - The socket override still wins + + /// `MCPPROXY_SOCKET_PATH` shipped first and points at ONE core, which is + /// not always the core that owns the root (attaching to a core somebody + /// else started is the whole point of it). It therefore outranks the root. + func testAnExplicitSocketPathOutranksTheRoot() { + let env = [ + InstancePaths.rootEnvVar: "/tmp/qa936", + InstancePaths.socketPathEnvVar: "/tmp/other/mcpproxy.sock" + ] + XCTAssertEqual(InstancePaths.socketPath(environment: env, home: home), + "/tmp/other/mcpproxy.sock") + XCTAssertEqual(InstancePaths.autostartSidecarURL(environment: env, home: home).path, + "/tmp/qa936/tray-autostart.json", + "…and moves nothing else") + } + + // MARK: - The one failure mode that is silent + + /// `sockaddr_un.sun_path` is 104 bytes. Over that the bind simply fails and + /// a QA run spends an hour wondering why the tray never sees its core, so + /// the tray says so instead. + func testAnOverlongSocketPathIsReported() { + let deep = "/tmp/" + String(repeating: "a", count: 120) + let env = [InstancePaths.rootEnvVar: deep] + let path = InstancePaths.socketPath(environment: env, home: home) + guard let warning = InstancePaths.socketPathProblem(path) else { + return XCTFail("a \(path.utf8.count)-byte socket path cannot be bound and must warn") + } + XCTAssertTrue(warning.contains("\(path.utf8.count)"), "the warning names the length: \(warning)") + + XCTAssertNil(InstancePaths.socketPathProblem("/tmp/qa936/mcpproxy.sock"), + "a path that fits is not a problem") + XCTAssertNil( + InstancePaths.socketPathProblem( + InstancePaths.socketPath(environment: [:], home: home) + ), + "and the default never warns" + ) + } + + /// The boundary itself: 103 bytes of `sun_path` plus the NUL fit, 104 do not. + func testTheSocketPathLimitIsTheSunPathBoundary() { + let fits = "/tmp/" + String(repeating: "a", count: 103 - 5) + XCTAssertEqual(fits.utf8.count, 103) + XCTAssertNil(InstancePaths.socketPathProblem(fits)) + XCTAssertNotNil(InstancePaths.socketPathProblem(fits + "a")) + } + + // MARK: - What the spawned core is told + + /// A tray with an overridden root must hand the core the same root, or the + /// tray watches `/tmp/qa936/mcpproxy.sock` while the core it just launched + /// writes to the real `~/.mcpproxy` — the accidental mutation this issue + /// was opened about. + func testTheSpawnedCoreIsPointedAtTheSameRoot() { + let env = [InstancePaths.rootEnvVar: "/tmp/qa936"] + XCTAssertEqual( + InstancePaths.coreArguments(environment: env, home: home), + ["serve", "--data-dir", "/tmp/qa936", "--config", "/tmp/qa936/mcp_config.json"] + ) + } + + /// …and an ordinary launch is byte-for-byte the command it always was. + func testWithoutTheOverrideTheCoreIsLaunchedExactlyAsBefore() { + XCTAssertEqual(InstancePaths.coreArguments(environment: [:], home: home), ["serve"]) + } +} diff --git a/native/macos/MCPProxy/MCPProxyTests/LifecycleJournalTests.swift b/native/macos/MCPProxy/MCPProxyTests/LifecycleJournalTests.swift new file mode 100644 index 00000000..0f26b3e6 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/LifecycleJournalTests.swift @@ -0,0 +1,215 @@ +import XCTest +@testable import MCPProxy + +/// The tray's persistent record of who started and stopped what (GH #862). +/// +/// The issue it answers: an app that exits leaves NOTHING behind saying why, so +/// a silent SIGKILL-class death (jetsam, a `pkill`, a crash outside our +/// handlers) is indistinguishable from a clean quit once the process is gone — +/// and macOS purges the Info tier of the unified log long before anyone looks. +/// The journal is the only artefact that outlives the process, so its two +/// promises are pinned here: a shutdown always records a reason, and a run that +/// ended without one is detectable at the NEXT launch. +final class LifecycleJournalTests: XCTestCase { + + private var directory: URL! + private var journalURL: URL! + + override func setUpWithError() throws { + directory = URL(fileURLWithPath: NSTemporaryDirectory(), isDirectory: true) + .appendingPathComponent("lifecycle-\(UUID().uuidString)", isDirectory: true) + try FileManager.default.createDirectory(at: directory, withIntermediateDirectories: true) + journalURL = directory.appendingPathComponent("tray-lifecycle.jsonl") + } + + override func tearDownWithError() throws { + try? FileManager.default.removeItem(at: directory) + } + + // MARK: - Round trip + + func testEventsAreAppendedAndReadBackInOrder() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.coreLaunched, "autostart")) + journal.append(Self.event(.appTerminating, "user quit")) + + let events = journal.events() + XCTAssertEqual(events.map(\.kind), [.appLaunched, .coreLaunched, .appTerminating]) + XCTAssertEqual(events.map(\.reason), ["launch", "autostart", "user quit"]) + } + + /// One record per line, so a truncated tail (a kill mid-write) costs the + /// last line and not the file. + func testAGarbledLineIsSkippedRatherThanLosingTheJournal() throws { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + let handle = try FileHandle(forWritingTo: journalURL) + handle.seekToEndOfFile() + handle.write(Data("{\"kind\":\"appTermin".utf8)) + try handle.close() + + XCTAssertEqual(journal.events().map(\.kind), [.appLaunched], + "a half-written record must not take the readable ones with it") + } + + /// A journal that grows without bound is a journal somebody deletes. It is + /// trimmed at launch, keeping the newest records — the ones an incident is + /// read backwards from. + func testTheJournalIsTrimmedToItsNewestRecords() { + let journal = LifecycleJournal(url: journalURL, maxRecords: 10) + for index in 0..<25 { + journal.append(Self.event(.coreLaunched, "run-\(index)")) + } + journal.trim() + + let events = journal.events() + XCTAssertEqual(events.count, 10) + XCTAssertEqual(events.first?.reason, "run-15") + XCTAssertEqual(events.last?.reason, "run-24") + } + + // MARK: - Was the previous run accounted for? + + func testAFirstEverLaunchHasNoPreviousRun() { + XCTAssertEqual(LifecycleJournal(url: journalURL).previousRunEnding(), .noPreviousRun) + } + + func testARunThatRecordedItsShutdownIsClean() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.appTerminating, "user quit from the tray menu")) + + guard case .clean(let last) = journal.previousRunEnding() else { + return XCTFail("a recorded shutdown is a clean ending, got \(journal.previousRunEnding())") + } + XCTAssertEqual(last.reason, "user quit from the tray menu") + } + + /// The case the whole issue is about: the process vanished between two + /// ordinary records. The next launch must be able to say so, and to name + /// the last thing that happened before the silence. + func testARunThatJustStoppedIsReportedUnclean() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.coreLaunched, "autostart", uptime: 90)) + + guard case .unclean(let last) = journal.previousRunEnding() else { + return XCTFail("a run with no shutdown record ended unclean, " + + "got \(journal.previousRunEnding())") + } + XCTAssertEqual(last?.kind, .coreLaunched) + XCTAssertEqual(last?.reason, "autostart", + "the last thing recorded is the only lead an incident has") + } + + /// The shutdown record is not always the LAST record. The app writes its own + /// ending first and then tears the core down, so a perfectly clean logout + /// finishes with `coreTerminated`. Judging "clean" by the final line alone + /// turned every one of those into a reported SIGKILL at the next launch. + func testATerminationFollowedByItsCoreTeardownIsStillClean() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.appTerminating, "macOS is logging out")) + journal.append(Self.event(.coreTerminated, "tray is terminating")) + + guard case .clean(let last) = journal.previousRunEnding() else { + return XCTFail("the run named its reason; the core record after it is bookkeeping, " + + "got \(journal.previousRunEnding())") + } + XCTAssertEqual(last.reason, "macOS is logging out", + "the ending reported is the app's own, not the core's") + } + + /// Scoped to the run being judged: an ending recorded before the last launch + /// belongs to an earlier run and cannot vouch for this one. + func testAnEndingFromBeforeTheLastLaunchDoesNotCountAsThisRunsEnding() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "first launch")) + journal.append(Self.event(.appTerminating, "user quit")) + journal.append(Self.event(.appLaunched, "second launch")) + journal.append(Self.event(.coreLaunched, "autostart")) + + guard case .unclean(let last) = journal.previousRunEnding() else { + return XCTFail("the second run recorded no ending, got \(journal.previousRunEnding())") + } + XCTAssertEqual(last?.kind, .coreLaunched) + } + + /// A signal we caught and logged is an accounted-for ending too — the point + /// is attribution, not tidiness. `signalReceived` on its own is not it: + /// the terminating record follows, and only that says the app is going. + func testASignalFollowedByATerminationRecordIsClean() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.signalReceived, "SIGTERM")) + journal.append(Self.event(.appTerminating, "signal SIGTERM")) + + guard case .clean = journal.previousRunEnding() else { + return XCTFail("a signal that was caught, logged and acted on is attributable") + } + } + + /// A signal record with nothing after it is the opposite: something asked + /// the app to go and the app never finished going. + func testASignalWithNoTerminationRecordIsUnclean() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.signalReceived, "SIGKILL is not catchable; SIGTERM is")) + + guard case .unclean(let last) = journal.previousRunEnding() else { + return XCTFail("a run that logged a signal and then stopped is still unaccounted for") + } + XCTAssertEqual(last?.kind, .signalReceived) + } + + // MARK: - What the next launch says about it + + /// The unclean marker is a log line a human reads a year later, so it + /// carries the three facts an incident needs: how long the run lasted, when + /// it stopped, and what it was doing. + func testTheUncleanMarkerNamesUptimeAndTheLastEvent() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.coreLaunched, "autostart", uptime: 90_061)) + + let summary = LifecycleJournal.uncleanExitSummary(for: journal.previousRunEnding()) + guard let summary else { + return XCTFail("an unclean previous run must produce a marker") + } + XCTAssertTrue(summary.contains("coreLaunched"), summary) + XCTAssertTrue(summary.contains("autostart"), summary) + XCTAssertTrue(summary.contains("25h"), "uptime is stated in a readable form: \(summary)") + } + + func testACleanPreviousRunProducesNoMarker() { + let journal = LifecycleJournal(url: journalURL) + journal.append(Self.event(.appLaunched, "launch")) + journal.append(Self.event(.appTerminating, "user quit")) + XCTAssertNil(LifecycleJournal.uncleanExitSummary(for: journal.previousRunEnding())) + XCTAssertNil(LifecycleJournal.uncleanExitSummary(for: .noPreviousRun)) + } + + // MARK: - Writing where it cannot write + + /// Best-effort, like the autostart sidecar: diagnostics must never be the + /// reason the app fails to start. + func testAnUnwritableJournalIsSurvived() { + let journal = LifecycleJournal( + url: URL(fileURLWithPath: "/dev/null/nope/tray-lifecycle.jsonl") + ) + journal.append(Self.event(.appLaunched, "launch")) + XCTAssertEqual(journal.events(), []) + XCTAssertEqual(journal.previousRunEnding(), .noPreviousRun) + } + + // MARK: - Fixtures + + private static func event( + _ kind: LifecycleEvent.Kind, + _ reason: String, + uptime: TimeInterval? = nil + ) -> LifecycleEvent { + LifecycleEvent(kind: kind, reason: reason, at: Date(), uptimeSeconds: uptime, pid: 42) + } +} diff --git a/native/macos/MCPProxy/MCPProxyTests/MenuOpenNetworkTests.swift b/native/macos/MCPProxy/MCPProxyTests/MenuOpenNetworkTests.swift index bb0bdbfa..a887faba 100644 --- a/native/macos/MCPProxy/MCPProxyTests/MenuOpenNetworkTests.swift +++ b/native/macos/MCPProxy/MCPProxyTests/MenuOpenNetworkTests.swift @@ -69,7 +69,13 @@ final class MenuOpenNetworkTests: XCTestCase { // give the run loop long enough for one to land. Without this the test // could only catch a synchronous regression, and there is no synchronous // way to fetch — every route is async. - let deadline = Date().addingTimeInterval(0.3) + // + // This window is the only thing between an async regression and a + // vacuous pass, so it errs long: a runner slow enough to schedule that + // Task in more than a second would otherwise report green. It costs the + // full second only when there is nothing to find — the loop leaves the + // moment a request appears. + let deadline = Date().addingTimeInterval(1.0) while Date() < deadline, source.totalCallCount == requestsBefore, GlanceStubURLProtocol.requestedURLs.isEmpty { RunLoop.main.run(mode: .default, before: Date().addingTimeInterval(0.02)) diff --git a/native/macos/MCPProxy/MCPProxyTests/SaturatedCoreEscalationTests.swift b/native/macos/MCPProxy/MCPProxyTests/SaturatedCoreEscalationTests.swift new file mode 100644 index 00000000..264829b3 --- /dev/null +++ b/native/macos/MCPProxy/MCPProxyTests/SaturatedCoreEscalationTests.swift @@ -0,0 +1,205 @@ +import XCTest +@testable import MCPProxy + +/// A live core whose listen backlog is saturated must not be launched over +/// (GH #933). +/// +/// `onlyEverRefused` — refusals with nothing ever accepted during the episode — +/// was taken as proof that a socket file is stale. It is sound for a crashed +/// core and wrong for a live one that was already saturated when the episode +/// began: it refuses every probe too, never records an acceptance, and after the +/// 60-second deadline the tray escalated to a launch. The escalation's own +/// confirmation window and the launch preflight see only refusals as well, so +/// nothing vetoed it. Reproduced live on real processes (`SIGSTOP` a core, +/// fill the backlog past `kern.ipc.somaxconn`): the tray launched four doomed +/// cores in 39 seconds, each dying on bbolt's lock, and ended on a +/// retry-exhaustion error about a core that was alive and healthy. +/// +/// `CoreLivenessTests.testACoreThatAcceptedEarlierInTheWindowIsNeverEscalatedOver` +/// covers the easier half — a core that accepted once and then stopped. The +/// uncovered case, and the one here, is a core that refuses from the very first +/// probe. +final class SaturatedCoreEscalationTests: XCTestCase { + + private var manager: CoreProcessManager? + private var directory: URL! + private var heldDescriptor: Int32 = -1 + + override func setUpWithError() throws { + // /tmp, not NSTemporaryDirectory(): the socket bound below has to fit + // in sun_path's 104 bytes, and /var/folders/… already spends half of it. + directory = URL(fileURLWithPath: "/tmp/mcpproxy-sat-\(UUID().uuidString.prefix(8))", + isDirectory: true) + try FileManager.default.createDirectory(at: directory, withIntermediateDirectories: true) + } + + override func tearDown() async throws { + if let manager { await manager.shutdown() } + manager = nil + if heldDescriptor >= 0 { + flock(heldDescriptor, LOCK_UN) + close(heldDescriptor) + heldDescriptor = -1 + } + try? FileManager.default.removeItem(at: directory) + try await super.tearDown() + } + + /// The regression itself. Every probe refuses from the start, so the socket + /// evidence says "stale" — but a live process holds the data directory, and + /// that is a fact no dead core can fake (the kernel drops `flock` when a + /// process dies). The tray must keep waiting instead of spawning. + func testASaturatedButLiveCoreIsNeverLaunchedOver() async throws { + let fakeCore = try FakeCoreBinary(behaviour: "sleep 30") + let restoreEnv = fakeCore.install() + defer { restoreEnv() } + + let socketPath = try refusingSocket() + holdTheDataDirectoryLock() + + let appState = await MainActor.run { AppState() } + let manager = makeManager(appState: appState, socketPath: socketPath) + self.manager = manager + + await manager.start(maySpawn: true) + + // Well past the deadline and its confirmation window, and past several + // attach-watch probes. + try await Task.sleep(nanoseconds: 3_000_000_000) + + let launched = await manager.coresLaunched + XCTAssertEqual(launched, 0, + "a live process holds the data directory: that core is there, " + + "whatever its listen queue is doing") + XCTAssertEqual(fakeCore.launchCount(), 0) + XCTAssertNil(manager.managedProcess) + + // …and the tray stays in the state whose attach watch will pick the + // core up the moment it drains, rather than dead-ending on an error + // about a process that is perfectly healthy. + let state = await MainActor.run { appState.coreState } + XCTAssertEqual(state, .waitingForCore) + } + + /// The other half of the same rule: a socket file with NO live holder is + /// still escalated over, exactly as before. Without this the fix would have + /// traded a rare bad launch for a permanent deadlock on every stale socket — + /// nothing else in the system removes that file. + func testAGenuinelyStaleSocketIsStillLaunchedOver() async throws { + let fakeCore = try FakeCoreBinary(behaviour: "sleep 30") + let restoreEnv = fakeCore.install() + defer { restoreEnv() } + + let socketPath = try refusingSocket() + // A database exists beside it — a real data directory — but nobody + // holds it, because the core that did is gone. + FileManager.default.createFile( + atPath: directory.appendingPathComponent("config.db").path, contents: Data() + ) + + let appState = await MainActor.run { AppState() } + let manager = makeManager(appState: appState, socketPath: socketPath) + self.manager = manager + + await manager.start(maySpawn: true) + try await Task.sleep(nanoseconds: 3_000_000_000) + + let launched = await manager.coresLaunched + XCTAssertGreaterThan(launched, 0, + "an unheld data directory beside a refusing socket is a dead " + + "core's leftovers; refusing to launch would deadlock startup") + } + + /// The saturated core then dies — SIGKILL, jetsam, `kill -9` — leaving its + /// socket file behind. The lock is gone the instant the process is (the + /// kernel drops `flock`), so the very next deadline must see a stale socket + /// and escalate. + /// + /// The regression this pins: the "a live process holds it" verdict was + /// latched for the lifetime of the episode and the lock was only ever + /// re-probed while the evidence still LOOKED stale — which that same verdict + /// made impossible. Every subsequent deadline re-armed itself on a fact that + /// stopped being true minutes ago, and `.waitingForCore` offers neither Stop + /// nor Retry, so quitting the app was the only way out. Before this change + /// the same sequence recovered at the first deadline. + func testACoreThatDiesAfterTheFirstDeadlineIsEventuallyEscalatedOver() async throws { + let fakeCore = try FakeCoreBinary(behaviour: "sleep 30") + let restoreEnv = fakeCore.install() + defer { restoreEnv() } + + let socketPath = try refusingSocket() + holdTheDataDirectoryLock() + + let appState = await MainActor.run { AppState() } + let manager = makeManager(appState: appState, socketPath: socketPath) + self.manager = manager + + await manager.start(maySpawn: true) + + // Past the first deadline: the lock is held, so nothing is launched. + try await Task.sleep(nanoseconds: 1_200_000_000) + var launched = await manager.coresLaunched + XCTAssertEqual(launched, 0, "precondition: a held lock still parks the tray") + + // The core dies. Its socket file survives it; its lock cannot. + releaseTheDataDirectoryLock() + + try await Task.sleep(nanoseconds: 3_000_000_000) + launched = await manager.coresLaunched + XCTAssertGreaterThan(launched, 0, + "nothing holds the data directory any more — that socket is a " + + "dead core's leftovers and the tray has to get past it on its own") + } + + // MARK: - Fixtures + + private func makeManager(appState: AppState, socketPath: String) -> CoreProcessManager { + CoreProcessManager( + appState: appState, + notificationService: NotificationService(deliveryEnabled: false), + reconnectionPolicy: ReconnectionPolicy( + baseDelay: 0.05, maxDelay: 0.1, maxAttempts: 3, jitterFactor: 0.0 + ), + socketPath: socketPath, + refreshInterval: 60, + probeTimeout: 0.3, + unresponsiveCoreTimeout: 0.5, + socketWaitTimeout: 1.0 + ) + } + + /// A socket file that refuses every connection — what a saturated backlog + /// and a dead core's leftovers look like from the outside, identically. + private func refusingSocket() throws -> String { + let stub = UnixSocketHTTPStub.healthyCore( + at: directory.appendingPathComponent("mcpproxy.sock").path + ) + try stub.start() + stub.stop(unlinkSocket: false) + let path = stub.path + guard SocketTransport.probeSocket(path: path) == .refused else { + throw XCTSkip("precondition: the socket must refuse every probe") + } + return path + } + + /// Hold the lock a running core holds: bbolt takes it on the data directory + /// before it ever creates a listener. `flock` is per open file description, + /// so this conflicts with the probe even from inside this process. + private func holdTheDataDirectoryLock() { + let path = directory.appendingPathComponent("config.db").path + FileManager.default.createFile(atPath: path, contents: Data()) + heldDescriptor = open(path, O_RDONLY) + XCTAssertGreaterThanOrEqual(heldDescriptor, 0) + XCTAssertEqual(flock(heldDescriptor, LOCK_EX | LOCK_NB), 0, + "precondition: this test holds the lock a live core would hold") + } + + /// What the kernel does when the holding process dies. + private func releaseTheDataDirectoryLock() { + guard heldDescriptor >= 0 else { return } + flock(heldDescriptor, LOCK_UN) + close(heldDescriptor) + heldDescriptor = -1 + } +}