| 1 | // Per-plugin startup latency tracking for MCP servers. Reasonix uses these |
| 2 | // samples to decide whether a chronically slow plugin should be demoted from |
| 3 | // "eager" to background loading for the rest of a session — see Recommend. |
| 4 | // |
| 5 | // Storage is one tiny JSON file per plugin under <cacheDir>/mcp/, written |
| 6 | // atomically (tmpfile + Rename) so a crash mid-write can't corrupt history. |
| 7 | // All errors are best-effort: missing/unreadable files yield "no demote", |
| 8 | // write failures get logged via slog and dropped — startup must not fail |
| 9 | // because telemetry can't persist. |
| 10 | package plugin |
| 11 | |
| 12 | import ( |
| 13 | "encoding/json" |
| 14 | "fmt" |
| 15 | "hash/fnv" |
| 16 | "log/slog" |
| 17 | "os" |
| 18 | "path/filepath" |
| 19 | "sort" |
| 20 | "time" |
| 21 | |
| 22 | "reasonix/internal/config" |
| 23 | fileencoding "reasonix/internal/fileutil/encoding" |
| 24 | ) |
| 25 | |
| 26 | const ( |
| 27 | // statsVersion is the on-disk format version. Bump when StartupStats changes |
| 28 | // shape incompatibly; older files are then ignored on load (treated as |
| 29 | // missing) so a new build doesn't crash on a stale schema. |
| 30 | statsVersion = 1 |
| 31 | // maxSamples bounds the rolling window. 20 is enough to absorb a few flukes |
| 32 | // while still letting recent regressions dominate p99 / consecutive-fail |
| 33 | // checks. Older samples drop off the front. |
| 34 | maxSamples = 20 |
| 35 | // defaultDemoteAfter is the consecutive-over-budget threshold used when the |
| 36 | // caller passes <= 0. Three in a row is "user has felt it three startups", |
| 37 | // which matches what the plan calls out as the demote signal. |
| 38 | defaultDemoteAfter = 3 |
| 39 | ) |
| 40 | |
| 41 | // StartupStats is the on-disk record of recent startup durations for one |
| 42 | // plugin. SamplesMs is oldest→newest (newest appended at the tail); LastSeen |
| 43 | // is the wall-clock time the most recent sample was recorded so a future |
| 44 | // "stale data" pruning step can act on it without re-parsing each sample. |
| 45 | type StartupStats struct { |
| 46 | Version int `json:"version"` |
| 47 | SamplesMs []int64 `json:"samples_ms"` |
| 48 | LastSeen time.Time `json:"last_seen"` |
| 49 | // Name is the raw (pre-slug) server name that owns these samples. The |
| 50 | // filename slug is lossy — "foo.bar" and "foo-bar" share one file — so |
| 51 | // readers verify ownership before trusting samples, or a slow server's |
| 52 | // history could demote an unrelated healthy one. Empty on files written |
| 53 | // by older versions; those are adopted by the first writer (additive |
| 54 | // field, no version bump, so downgraded builds still read the file). |
| 55 | Name string `json:"name,omitempty"` |
| 56 | } |
| 57 | |
| 58 | // Recommendation is the result of inspecting a plugin's recent startup |
| 59 | // history. Demote is the actionable bit boot.go consumes (true → switch this |
| 60 | // plugin to background startup for this session). P99 and Reason are |
| 61 | // descriptive only — Reason is meant to be surfaced to the user as a Notice so a |
| 62 | // sudden demotion isn't silent. |
| 63 | type Recommendation struct { |
| 64 | Demote bool |
| 65 | P99 time.Duration |
| 66 | Reason string |
| 67 | } |
| 68 | |
| 69 | // RecordStartup appends one sample (the wall-clock duration of a plugin's |
| 70 | // blocking handshake phase) to that plugin's stats file. The file is created |
| 71 | // on first call; existing samples are kept in a rolling window of maxSamples, |
| 72 | // dropping the oldest when full. |
| 73 | // |
| 74 | // Best-effort: any I/O or marshal failure is logged with slog.Warn and |
| 75 | // returned, but callers are expected to ignore the error — telemetry must |
| 76 | // never block real work. Writes go through a tmpfile + Rename so a partial |
| 77 | // write can't leave the stats file truncated or unparseable. |
| 78 | func RecordStartup(name string, dur time.Duration) error { |
| 79 | path := statsPath(name) |
| 80 | if path == "" { |
| 81 | // No cache dir resolvable on this host — silently skip. This is the |
| 82 | // same fallback every other persistence helper in the project takes |
| 83 | // (ArchiveDir/SessionDir return "" and writers no-op). |
| 84 | return nil |
| 85 | } |
| 86 | |
| 87 | stats := loadStatsForOwner(name) // missing/corrupt/foreign → fresh zero value |
| 88 | if stats.Version != statsVersion { |
| 89 | // Version mismatch: start over rather than try to migrate. The window |
| 90 | // is small enough that "lose 20 samples" is cheap, and it keeps the |
| 91 | // migration path trivial as the format evolves. |
| 92 | stats = StartupStats{Version: statsVersion} |
| 93 | } |
| 94 | stats.Name = name |
| 95 | |
| 96 | ms := dur.Milliseconds() |
| 97 | if ms < 0 { |
| 98 | ms = 0 |
| 99 | } |
| 100 | stats.SamplesMs = append(stats.SamplesMs, ms) |
| 101 | if len(stats.SamplesMs) > maxSamples { |
| 102 | // Trim from the front: oldest samples leave first. |
| 103 | stats.SamplesMs = stats.SamplesMs[len(stats.SamplesMs)-maxSamples:] |
| 104 | } |
| 105 | stats.LastSeen = time.Now() |
| 106 | |
| 107 | if err := writeStatsAtomic(path, stats); err != nil { |
| 108 | slog.Warn("plugin: record startup stats failed", "server", name, "err", err) |
| 109 | return err |
| 110 | } |
| 111 | return nil |
| 112 | } |
| 113 | |
| 114 | // Recommend inspects the recent samples for name and decides whether the |
| 115 | // plugin should be demoted to "lazy" this session. The rule is simple: demote |
| 116 | // when the last demoteAfter samples all hit or exceed the blocking startup |
| 117 | // budget. Missing/empty stats → no demote (a fresh plugin gets the benefit of |
| 118 | // the doubt and one normal startup attempt). |
| 119 | // |
| 120 | // budget == 0 disables the check (returns no-demote). demoteAfter <= 0 falls |
| 121 | // back to defaultDemoteAfter so callers can pass the config value verbatim |
| 122 | // without sanitising it. |
| 123 | func Recommend(name string, budget time.Duration, demoteAfter int) Recommendation { |
| 124 | if budget <= 0 { |
| 125 | return Recommendation{} |
| 126 | } |
| 127 | if demoteAfter <= 0 { |
| 128 | demoteAfter = defaultDemoteAfter |
| 129 | } |
| 130 | |
| 131 | path := statsPath(name) |
| 132 | if path == "" { |
| 133 | return Recommendation{} |
| 134 | } |
| 135 | stats := loadStatsForOwner(name) |
| 136 | if stats.Version != statsVersion || len(stats.SamplesMs) == 0 { |
| 137 | // Either no history yet or a format we can't read — give the plugin a |
| 138 | // chance. The cost of one slow start is small compared to wrongly |
| 139 | // demoting a healthy plugin off stale data. |
| 140 | return Recommendation{} |
| 141 | } |
| 142 | |
| 143 | rec := Recommendation{P99: p99(stats.SamplesMs)} |
| 144 | if len(stats.SamplesMs) < demoteAfter { |
| 145 | return rec |
| 146 | } |
| 147 | |
| 148 | threshold := budget.Milliseconds() |
| 149 | tail := stats.SamplesMs[len(stats.SamplesMs)-demoteAfter:] |
| 150 | for _, ms := range tail { |
| 151 | if ms < threshold { |
| 152 | return rec |
| 153 | } |
| 154 | } |
| 155 | rec.Demote = true |
| 156 | rec.Reason = fmt.Sprintf( |
| 157 | "plugin %q has been slow %d startups in a row (last %dms, budget %dms); demoting to background startup this session", |
| 158 | name, demoteAfter, tail[len(tail)-1], budget.Milliseconds(), |
| 159 | ) |
| 160 | return rec |
| 161 | } |
| 162 | |
| 163 | // statsPath returns the canonical path for one plugin's stats file: |
| 164 | // <config.CacheDir()>/mcp/<slug>-<hash>.stats.json. The slug alone is lossy — |
| 165 | // "foo.bar" and "foo-bar" collapse to one slug — and two colliding servers |
| 166 | // sharing a file would alternately reset each other's window, so neither |
| 167 | // could ever accumulate enough consecutive samples to demote. Hashing the raw |
| 168 | // name into the filename gives every server its own history. The slug portion |
| 169 | // is bounded so the whole component stays under the 255-byte filesystem limit |
| 170 | // even for very long server names — the hash carries the uniqueness, so |
| 171 | // truncating the slug is safe. Returns "" when no cache dir is resolvable, |
| 172 | // which all callers treat as "skip telemetry". |
| 173 | func statsPath(name string) string { |
| 174 | base := config.CacheDir() |
| 175 | if base == "" { |
| 176 | return "" |
| 177 | } |
| 178 | h := fnv.New32a() |
| 179 | _, _ = h.Write([]byte(name)) |
| 180 | // 255-byte component budget: slug + "-" + 8 hex digits + ".stats.json". |
| 181 | stem := slug(name) |
| 182 | if maxStem := 255 - len("-00000000.stats.json"); len(stem) > maxStem { |
| 183 | stem = stem[:maxStem] |
| 184 | } |
| 185 | return filepath.Join(base, "mcp", fmt.Sprintf("%s-%08x.stats.json", stem, h.Sum32())) |
| 186 | } |
| 187 | |
| 188 | // legacyStatsPath is the pre-hash location, shared by every server whose name |
| 189 | // collapses to the same slug. Read-only for migration: a named legacy file is |
| 190 | // adopted by its owner; a nameless one (pre-Name builds) has no provable owner |
| 191 | // and is never trusted for demotion or adopted into a new window. |
| 192 | func legacyStatsPath(name string) string { |
| 193 | base := config.CacheDir() |
| 194 | if base == "" { |
| 195 | return "" |
| 196 | } |
| 197 | return filepath.Join(base, "mcp", slug(name)+".stats.json") |
| 198 | } |
| 199 | |
| 200 | // loadStats reads and decodes a stats file. Any failure (missing file, |
| 201 | // permission denied, malformed JSON) returns a zero StartupStats so callers |
| 202 | // can treat absence and corruption identically. The slog.Warn fires only on |
| 203 | // non-NotExist read errors and on JSON errors — those are surprising enough |
| 204 | // to be worth a trace, but they still must not stop the caller. |
| 205 | func loadStats(path string) StartupStats { |
| 206 | var s StartupStats |
| 207 | b, err := fileencoding.ReadFileUTF8(path) |
| 208 | if err != nil { |
| 209 | if !os.IsNotExist(err) { |
| 210 | slog.Warn("plugin: read startup stats failed", "path", path, "err", err) |
| 211 | } |
| 212 | return s |
| 213 | } |
| 214 | if err := json.Unmarshal(b, &s); err != nil { |
| 215 | slog.Warn("plugin: parse startup stats failed", "path", path, "err", err) |
| 216 | return StartupStats{} |
| 217 | } |
| 218 | return s |
| 219 | } |
| 220 | |
| 221 | // loadStatsForOwner reads name's history from its hashed path, falling back to |
| 222 | // the shared legacy (pre-hash) file for a one-time migration. Legacy files are |
| 223 | // trusted only when their recorded Name matches: a nameless legacy file |
| 224 | // (written before ownership tracking) is shared by every server whose name |
| 225 | // collapses to the same slug, so its samples cannot be attributed and must not |
| 226 | // seed anyone's window or demote anyone. |
| 227 | func loadStatsForOwner(name string) StartupStats { |
| 228 | if s := loadStats(statsPath(name)); s.Version != 0 || len(s.SamplesMs) > 0 { |
| 229 | if s.Name == "" || s.Name == name { |
| 230 | return s |
| 231 | } |
| 232 | return StartupStats{} |
| 233 | } |
| 234 | legacy := legacyStatsPath(name) |
| 235 | if legacy == "" { |
| 236 | return StartupStats{} |
| 237 | } |
| 238 | if s := loadStats(legacy); s.Name == name { |
| 239 | return s |
| 240 | } |
| 241 | return StartupStats{} |
| 242 | } |
| 243 | |
| 244 | // writeStatsAtomic serialises s and writes it via tmpfile + os.Rename so that |
| 245 | // concurrent readers see either the old content or the new one, never a |
| 246 | // half-written file. Mirrors desktop/sessions.go:40-64. |
| 247 | func writeStatsAtomic(path string, s StartupStats) error { |
| 248 | dir := filepath.Dir(path) |
| 249 | if err := os.MkdirAll(dir, 0o755); err != nil { |
| 250 | return err |
| 251 | } |
| 252 | b, err := json.Marshal(s) |
| 253 | if err != nil { |
| 254 | return err |
| 255 | } |
| 256 | tmp, err := os.CreateTemp(dir, ".stats.*.tmp") |
| 257 | if err != nil { |
| 258 | return err |
| 259 | } |
| 260 | tmpPath := tmp.Name() |
| 261 | if _, err := tmp.Write(b); err != nil { |
| 262 | tmp.Close() |
| 263 | os.Remove(tmpPath) |
| 264 | return err |
| 265 | } |
| 266 | if err := tmp.Close(); err != nil { |
| 267 | os.Remove(tmpPath) |
| 268 | return err |
| 269 | } |
| 270 | return os.Rename(tmpPath, path) |
| 271 | } |
| 272 | |
| 273 | // p99 returns the 99th-percentile sample as a Duration. With small windows |
| 274 | // (n ≤ 20) "p99" collapses to "the slowest sample we have"; the value is |
| 275 | // purely informational, surfaced in Recommendation for UI/notice text. |
| 276 | func p99(samples []int64) time.Duration { |
| 277 | if len(samples) == 0 { |
| 278 | return 0 |
| 279 | } |
| 280 | sorted := append([]int64(nil), samples...) |
| 281 | sort.Slice(sorted, func(i, j int) bool { return sorted[i] < sorted[j] }) |
| 282 | // Use ceil(0.99 * n) - 1 so that for n=1..100 we always pick the last |
| 283 | // element; for larger n it's the index at the 99% boundary. |
| 284 | idx := int(float64(len(sorted))*0.99+0.9999999) - 1 |
| 285 | if idx < 0 { |
| 286 | idx = 0 |
| 287 | } |
| 288 | if idx >= len(sorted) { |
| 289 | idx = len(sorted) - 1 |
| 290 | } |
| 291 | return time.Duration(sorted[idx]) * time.Millisecond |
| 292 | } |
| 293 |