| 1 | package cli |
| 2 | |
| 3 | import ( |
| 4 | "fmt" |
| 5 | "io" |
| 6 | "log/slog" |
| 7 | "os" |
| 8 | "path/filepath" |
| 9 | "runtime" |
| 10 | "strings" |
| 11 | "sync" |
| 12 | "sync/atomic" |
| 13 | "time" |
| 14 | |
| 15 | tea "charm.land/bubbletea/v2" |
| 16 | ) |
| 17 | |
| 18 | const ( |
| 19 | tuiDiagnosticLogLimit = 4 << 20 |
| 20 | tuiDiagnosticLogRetention = 7 * 24 * time.Hour |
| 21 | tuiWatchdogInterval = time.Second |
| 22 | tuiWatchdogStall = 10 * time.Second |
| 23 | tuiWatchdogCancelGrace = 2 * time.Second |
| 24 | ) |
| 25 | |
| 26 | // watchdogKillFallbackDelay bounds how long a watchdog kill waits after |
| 27 | // requesting a graceful shutdown before the hard kill fires. The final |
| 28 | // snapshot may legitimately spend five seconds waiting for a compatibility |
| 29 | // file lock before writing a recovery branch, so this grace must exceed that |
| 30 | // bounded recovery path rather than turning a successful save into Kill. |
| 31 | const watchdogKillFallbackDelay = 12 * time.Second |
| 32 | |
| 33 | // Watchdog lifecycle phases. Only booting (no first Update) and running |
| 34 | // (active turn / shell with no event-loop heartbeat) can escalate to kill. |
| 35 | // Idle never terminates the process — that was the #7809 false-kill path. |
| 36 | type tuiWatchdogPhase int |
| 37 | |
| 38 | const ( |
| 39 | watchdogBooting tuiWatchdogPhase = iota |
| 40 | watchdogIdle |
| 41 | watchdogRunning |
| 42 | watchdogClosed |
| 43 | ) |
| 44 | |
| 45 | func (p tuiWatchdogPhase) String() string { |
| 46 | switch p { |
| 47 | case watchdogBooting: |
| 48 | return "booting" |
| 49 | case watchdogIdle: |
| 50 | return "idle" |
| 51 | case watchdogRunning: |
| 52 | return "running" |
| 53 | case watchdogClosed: |
| 54 | return "closed" |
| 55 | default: |
| 56 | return fmt.Sprintf("phase(%d)", int(p)) |
| 57 | } |
| 58 | } |
| 59 | |
| 60 | // watchdogEscalation is the dump/cancel/grace/hard-kill bookkeeping for the |
| 61 | // generation currently stalling; grouping it keeps the guarded scalar count |
| 62 | // flat and the lifecycle explicit. |
| 63 | type watchdogEscalation struct { |
| 64 | // generation is the one inside dump/cancel/grace (0 = none); a heartbeat |
| 65 | // clears it so a later stall can re-enter escalation for hard-kill only. |
| 66 | generation uint64 |
| 67 | // cancelIssued is sticky for the Turn: Cancel() runs at most once per |
| 68 | // generation even if the grace window is aborted and the turn stalls again. |
| 69 | cancelIssued uint64 |
| 70 | cancelDeadline time.Time // zero until escalated for current generation |
| 71 | hardKillIssued bool |
| 72 | hardKilledGen uint64 |
| 73 | } |
| 74 | |
| 75 | // tuiDiagnostics owns diagnostics for the interactive terminal UI. Logs and |
| 76 | // plugin stderr use a private file; typed notices remain user-facing if it |
| 77 | // cannot be created. The watchdog uses booting/idle/running/closed: idle never |
| 78 | // kills, while running stalls escalate through dump, cancel, grace, and kill. |
| 79 | type tuiDiagnostics struct { |
| 80 | previous *slog.Logger |
| 81 | logger *slog.Logger |
| 82 | writer io.Writer |
| 83 | file *os.File |
| 84 | path string |
| 85 | close sync.Once |
| 86 | |
| 87 | stopWatch chan struct{} |
| 88 | watchOnce sync.Once |
| 89 | watchWG sync.WaitGroup |
| 90 | |
| 91 | mu sync.Mutex |
| 92 | |
| 93 | phase tuiWatchdogPhase |
| 94 | generation uint64 // increments on each idle→running transition |
| 95 | lastHeartbeat time.Time |
| 96 | lastHeartbeatSource string |
| 97 | // escalation groups the per-generation kill-escalation state by lifetime. |
| 98 | escalation watchdogEscalation |
| 99 | |
| 100 | // cancelFn is the non-blocking controller cancel for the active generation. |
| 101 | // Cleared on idle/closed. Invoked under mu after a generation check. |
| 102 | cancelFn func() |
| 103 | // statusFn optionally returns Controller RuntimeStatus text for dumps. |
| 104 | statusFn func() string |
| 105 | |
| 106 | // tickLastSeen is the previous onTick time: consecutive ~1s ticks at least |
| 107 | // a stall apart mean suspend/starvation, not a wedged loop, so the |
| 108 | // first such tick refreshes instead of escalating (#9233). |
| 109 | tickLastSeen time.Time |
| 110 | |
| 111 | // Injectable seams for deterministic tests (nil = production defaults). |
| 112 | nowFn func() time.Time |
| 113 | newTicker func(d time.Duration) watchdogTicker |
| 114 | afterFunc func(delay time.Duration, fn func()) |
| 115 | dumpFn func(reason string) |
| 116 | killFn func() |
| 117 | logFn func(format string, args ...any) |
| 118 | shutdownFn func(*tuiShutdownCompletion) |
| 119 | |
| 120 | // Test observation counters (safe under mu). |
| 121 | cancelCalls atomic.Int32 |
| 122 | killCalls atomic.Int32 |
| 123 | dumpCalls atomic.Int32 |
| 124 | } |
| 125 | |
| 126 | // watchdogTicker is the subset of time.Ticker used by the watch loop. |
| 127 | type watchdogTicker interface { |
| 128 | C() <-chan time.Time |
| 129 | Stop() |
| 130 | } |
| 131 | |
| 132 | type realTicker struct{ *time.Ticker } |
| 133 | |
| 134 | func (t realTicker) C() <-chan time.Time { return t.Ticker.C } |
| 135 | |
| 136 | func startTUIDiagnostics(reasonixHome string) *tuiDiagnostics { |
| 137 | d := &tuiDiagnostics{ |
| 138 | previous: slog.Default(), |
| 139 | writer: io.Discard, |
| 140 | stopWatch: make(chan struct{}), |
| 141 | phase: watchdogBooting, |
| 142 | } |
| 143 | if logDir := tuiDiagnosticLogDir(reasonixHome); logDir != "" { |
| 144 | if err := os.MkdirAll(logDir, 0o700); err == nil { |
| 145 | pruneTUIDiagnosticLogs(logDir, time.Now()) |
| 146 | if file, err := os.CreateTemp(logDir, "cli-tui-*.log"); err == nil { |
| 147 | d.file = file |
| 148 | d.path = file.Name() |
| 149 | d.writer = &boundedDiagnosticWriter{dst: file, remaining: tuiDiagnosticLogLimit} |
| 150 | } |
| 151 | } |
| 152 | } |
| 153 | d.logger = slog.New(slog.NewTextHandler(d.writer, &slog.HandlerOptions{Level: slog.LevelInfo})) |
| 154 | slog.SetDefault(d.logger) |
| 155 | d.lastHeartbeat = d.now() |
| 156 | d.lastHeartbeatSource = "diagnostics_started" |
| 157 | d.Milestone("diagnostics_started") |
| 158 | return d |
| 159 | } |
| 160 | |
| 161 | // Milestone records a startup/runtime phase and flushes the log immediately so a |
| 162 | // subsequent hang still leaves a non-zero diagnostic file. Milestones do not |
| 163 | // count as active event-loop heartbeats. |
| 164 | func (d *tuiDiagnostics) Milestone(name string) { |
| 165 | if d == nil { |
| 166 | return |
| 167 | } |
| 168 | msg := fmt.Sprintf("milestone=%s t=%s", strings.TrimSpace(name), d.now().UTC().Format(time.RFC3339Nano)) |
| 169 | _, _ = fmt.Fprintln(d.Writer(), msg) |
| 170 | d.Sync() |
| 171 | } |
| 172 | |
| 173 | // Sync flushes the diagnostic file to disk when possible. |
| 174 | func (d *tuiDiagnostics) Sync() { |
| 175 | if d == nil || d.file == nil { |
| 176 | return |
| 177 | } |
| 178 | _ = d.file.Sync() |
| 179 | } |
| 180 | |
| 181 | // Path returns the diagnostic log path (empty when falling back to Discard). |
| 182 | func (d *tuiDiagnostics) Path() string { |
| 183 | if d == nil { |
| 184 | return "" |
| 185 | } |
| 186 | return d.path |
| 187 | } |
| 188 | |
| 189 | func (d *tuiDiagnostics) Writer() io.Writer { |
| 190 | if d == nil || d.writer == nil { |
| 191 | return io.Discard |
| 192 | } |
| 193 | return d.writer |
| 194 | } |
| 195 | |
| 196 | // NoteBooted transitions booting → idle after the first valid chatTUI.Update. |
| 197 | // Subsequent calls are no-ops until the watchdog is closed. |
| 198 | func (d *tuiDiagnostics) NoteBooted() { |
| 199 | if d == nil { |
| 200 | return |
| 201 | } |
| 202 | d.mu.Lock() |
| 203 | defer d.mu.Unlock() |
| 204 | if d.phase != watchdogBooting { |
| 205 | return |
| 206 | } |
| 207 | d.phase = watchdogIdle |
| 208 | d.lastHeartbeat = d.now() |
| 209 | d.lastHeartbeatSource = "booted" |
| 210 | d.logfLocked("watchdog_state phase=%s gen=%d source=booted", d.phase, d.generation) |
| 211 | } |
| 212 | |
| 213 | // NoteRunning transitions idle/booting → running for a new Turn/shell generation. |
| 214 | // cancel must be non-blocking (context cancel / queue a cancel); it is invoked |
| 215 | // under the watchdog lifecycle lock after checking the active generation. |
| 216 | func (d *tuiDiagnostics) NoteRunning(cancel func()) { |
| 217 | if d == nil { |
| 218 | return |
| 219 | } |
| 220 | d.mu.Lock() |
| 221 | defer d.mu.Unlock() |
| 222 | if d.phase == watchdogClosed { |
| 223 | return |
| 224 | } |
| 225 | d.generation++ |
| 226 | d.phase = watchdogRunning |
| 227 | d.lastHeartbeat = d.now() |
| 228 | d.lastHeartbeatSource = "enter_running" |
| 229 | d.cancelFn = cancel |
| 230 | d.escalation.cancelDeadline = time.Time{} |
| 231 | d.logfLocked("watchdog_state phase=%s gen=%d source=enter_running", d.phase, d.generation) |
| 232 | } |
| 233 | |
| 234 | // NoteIdle transitions running → idle after TurnDone, shell completion, or |
| 235 | // synchronous cancel. Clears the active cancel hook and cancels any pending |
| 236 | // hard-kill for the previous generation. |
| 237 | func (d *tuiDiagnostics) NoteIdle() { |
| 238 | if d == nil { |
| 239 | return |
| 240 | } |
| 241 | d.mu.Lock() |
| 242 | defer d.mu.Unlock() |
| 243 | if d.phase == watchdogClosed || d.phase == watchdogIdle { |
| 244 | return |
| 245 | } |
| 246 | prev := d.phase |
| 247 | d.phase = watchdogIdle |
| 248 | d.cancelFn = nil |
| 249 | d.escalation.cancelDeadline = time.Time{} |
| 250 | d.lastHeartbeat = d.now() |
| 251 | d.lastHeartbeatSource = "enter_idle" |
| 252 | d.logfLocked("watchdog_state phase=%s gen=%d prev=%s source=enter_idle", d.phase, d.generation, prev) |
| 253 | } |
| 254 | |
| 255 | // NoteActiveHeartbeat records event-loop progress that proves a running turn |
| 256 | // is still being serviced. Only elapsedTick, agent/shell/controller work |
| 257 | // events, and explicitly marked work progress should call this. Keyboard, |
| 258 | // mouse, and focus activity must not refresh the active heartbeat. |
| 259 | func (d *tuiDiagnostics) NoteActiveHeartbeat(source string) { |
| 260 | if d == nil { |
| 261 | return |
| 262 | } |
| 263 | d.mu.Lock() |
| 264 | defer d.mu.Unlock() |
| 265 | if d.phase != watchdogRunning { |
| 266 | return |
| 267 | } |
| 268 | d.lastHeartbeat = d.now() |
| 269 | if source == "" { |
| 270 | source = "active" |
| 271 | } |
| 272 | d.lastHeartbeatSource = source |
| 273 | // Fresh heartbeat aborts the in-flight grace window for this gen so a later |
| 274 | // stall may re-enter dump/grace/hard-kill. Cancel stays sticky via |
| 275 | // cancelIssuedGeneration (at most one Cancel per Turn). |
| 276 | if d.escalation.generation == d.generation && d.generation != 0 && !d.escalation.cancelDeadline.IsZero() { |
| 277 | d.escalation.cancelDeadline = time.Time{} |
| 278 | d.escalation.generation = 0 |
| 279 | d.logfLocked("watchdog_escalation_aborted phase=%s gen=%d source=%s reason=heartbeat cancel_issued=%v", |
| 280 | d.phase, d.generation, d.lastHeartbeatSource, d.escalation.cancelIssued == d.generation) |
| 281 | } |
| 282 | } |
| 283 | |
| 284 | // SetStatusProvider installs an optional Controller RuntimeStatus snapshot for |
| 285 | // structured stall dumps. Safe to call at any time. |
| 286 | func (d *tuiDiagnostics) SetStatusProvider(fn func() string) { |
| 287 | if d == nil { |
| 288 | return |
| 289 | } |
| 290 | d.mu.Lock() |
| 291 | d.statusFn = fn |
| 292 | d.mu.Unlock() |
| 293 | } |
| 294 | |
| 295 | // StartWatchdog arms the lifecycle watchdog. p may be nil in tests that inject killFn. |
| 296 | // The booting timer starts here (not at diagnostics construction) so slow config / |
| 297 | // controller setup before terminal takeover cannot trip a false boot stall. |
| 298 | func (d *tuiDiagnostics) StartWatchdog(p *tea.Program) { |
| 299 | if d == nil { |
| 300 | return |
| 301 | } |
| 302 | d.watchOnce.Do(func() { |
| 303 | if d.killFn == nil && p != nil { |
| 304 | d.killFn = p.Kill |
| 305 | } |
| 306 | if d.shutdownFn == nil && p != nil { |
| 307 | d.shutdownFn = func(completion *tuiShutdownCompletion) { |
| 308 | p.Send(tuiShutdownMsg{completion: completion}) |
| 309 | } |
| 310 | } |
| 311 | d.mu.Lock() |
| 312 | armedAt := d.now() |
| 313 | d.tickLastSeen = armedAt |
| 314 | if d.phase == watchdogBooting { |
| 315 | d.lastHeartbeat = armedAt |
| 316 | d.lastHeartbeatSource = "watchdog_armed" |
| 317 | } |
| 318 | d.mu.Unlock() |
| 319 | d.watchWG.Go(func() { |
| 320 | d.watch() |
| 321 | }) |
| 322 | }) |
| 323 | } |
| 324 | |
| 325 | func (d *tuiDiagnostics) watch() { |
| 326 | newTicker := d.newTicker |
| 327 | if newTicker == nil { |
| 328 | newTicker = func(interval time.Duration) watchdogTicker { |
| 329 | return realTicker{time.NewTicker(interval)} |
| 330 | } |
| 331 | } |
| 332 | ticker := newTicker(tuiWatchdogInterval) |
| 333 | defer ticker.Stop() |
| 334 | for { |
| 335 | select { |
| 336 | case <-d.stopWatch: |
| 337 | return |
| 338 | case now := <-ticker.C(): |
| 339 | d.onTick(now) |
| 340 | } |
| 341 | } |
| 342 | } |
| 343 | |
| 344 | // logHeartbeatLocked records the per-tick heartbeat line in a stable format. |
| 345 | func (d *tuiDiagnostics) logHeartbeatLocked(now time.Time, phase tuiWatchdogPhase, gen uint64, age time.Duration, source string, escalated, hardKilled bool) { |
| 346 | d.logfLocked("heartbeat t=%s phase=%s gen=%d last_progress_age=%s last_source=%s cancel_requested=%v hard_kill_phase=%v", |
| 347 | now.UTC().Format(time.RFC3339Nano), phase, gen, age.Round(time.Millisecond), source, escalated, hardKilled) |
| 348 | } |
| 349 | |
| 350 | // absorbClockJumpLocked treats a >=stall gap between consecutive ~1s ticks as |
| 351 | // suspend/resume or scheduler starvation: the loop is alive on this tick, so |
| 352 | // the stale age must not dump/cancel/kill a healthy turn (#9233). |
| 353 | func (d *tuiDiagnostics) absorbClockJumpLocked(now time.Time) { |
| 354 | gap := now.Sub(d.tickLastSeen) |
| 355 | if d.tickLastSeen.IsZero() || gap < tuiWatchdogStall { |
| 356 | d.tickLastSeen = now |
| 357 | return |
| 358 | } |
| 359 | if d.phase == watchdogRunning { |
| 360 | d.escalation.generation = 0 |
| 361 | d.escalation.cancelDeadline = time.Time{} |
| 362 | } |
| 363 | d.lastHeartbeat = now |
| 364 | d.lastHeartbeatSource = "clock_jump" |
| 365 | d.logfLocked("watchdog_clock_jump gap=%s phase=%s gen=%d", gap.Round(time.Millisecond), d.phase, d.generation) |
| 366 | d.tickLastSeen = now |
| 367 | } |
| 368 | |
| 369 | // onTick is the pure escalation step. Tests drive it directly with a fake clock |
| 370 | // so no real sleeps are required. |
| 371 | func (d *tuiDiagnostics) onTick(now time.Time) { |
| 372 | if d == nil { |
| 373 | return |
| 374 | } |
| 375 | |
| 376 | d.mu.Lock() |
| 377 | phase := d.phase |
| 378 | if phase == watchdogClosed { |
| 379 | d.mu.Unlock() |
| 380 | return |
| 381 | } |
| 382 | d.absorbClockJumpLocked(now) |
| 383 | gen := d.generation |
| 384 | last := d.lastHeartbeat |
| 385 | if last.IsZero() { |
| 386 | last = now |
| 387 | } |
| 388 | age := now.Sub(last) |
| 389 | source := d.lastHeartbeatSource |
| 390 | cancelDeadline := d.escalation.cancelDeadline |
| 391 | escalatedGen := d.escalation.generation |
| 392 | hardKillIssued := d.escalation.hardKillIssued |
| 393 | hardKilledGen := d.escalation.hardKilledGen |
| 394 | statusFn := d.statusFn |
| 395 | cancelFn := d.cancelFn |
| 396 | d.logHeartbeatLocked(now, phase, gen, age, source, |
| 397 | escalatedGen == gen && gen != 0 && !cancelDeadline.IsZero(), |
| 398 | hardKillIssued && hardKilledGen == gen) |
| 399 | d.Sync() |
| 400 | |
| 401 | // Idle: never dump/cancel/kill. Heartbeat log above is the only activity. |
| 402 | if phase == watchdogIdle { |
| 403 | d.mu.Unlock() |
| 404 | return |
| 405 | } |
| 406 | |
| 407 | // Grace window follow-up: same generation still running after cancel. |
| 408 | // Wait until the deadline; only then hard-kill if there is still no heartbeat. |
| 409 | if phase == watchdogRunning && escalatedGen == gen && gen != 0 && !cancelDeadline.IsZero() { |
| 410 | if now.Before(cancelDeadline) { |
| 411 | d.mu.Unlock() |
| 412 | return |
| 413 | } |
| 414 | // Deadline reached. Re-check heartbeat under the same lock before kill. |
| 415 | if now.Sub(d.lastHeartbeat) >= tuiWatchdogStall && !(d.escalation.hardKillIssued && d.escalation.hardKilledGen == gen) { |
| 416 | d.escalation.hardKillIssued = true |
| 417 | d.escalation.hardKilledGen = gen |
| 418 | d.escalation.cancelDeadline = time.Time{} |
| 419 | diag := d.formatDiagLocked(now, "watchdog_hard_kill") |
| 420 | d.mu.Unlock() |
| 421 | d.killCalls.Add(1) |
| 422 | d.doDump("watchdog_hard_kill") |
| 423 | d.writeLine(diag) |
| 424 | d.Sync() |
| 425 | d.doKill() |
| 426 | return |
| 427 | } |
| 428 | // Heartbeat recovered (or phase raced) before hard-kill — clear grace. |
| 429 | d.escalation.cancelDeadline = time.Time{} |
| 430 | d.mu.Unlock() |
| 431 | return |
| 432 | } |
| 433 | |
| 434 | if age < tuiWatchdogStall { |
| 435 | d.mu.Unlock() |
| 436 | return |
| 437 | } |
| 438 | |
| 439 | // Already hard-killed this generation — stay quiet. |
| 440 | if hardKillIssued && hardKilledGen == gen { |
| 441 | d.mu.Unlock() |
| 442 | return |
| 443 | } |
| 444 | |
| 445 | // Already escalated (dump+cancel) for this generation; waiting on grace. |
| 446 | // gen==0 is booting (no generation yet); use a dedicated escalated flag path. |
| 447 | if phase == watchdogRunning && escalatedGen == gen && gen != 0 { |
| 448 | d.mu.Unlock() |
| 449 | return |
| 450 | } |
| 451 | if phase == watchdogBooting && hardKillIssued { |
| 452 | d.mu.Unlock() |
| 453 | return |
| 454 | } |
| 455 | |
| 456 | // First escalation for this stall (or re-entry after a grace abort). |
| 457 | diag := d.formatDiagLocked(now, "watchdog_stall") |
| 458 | if phase == watchdogRunning { |
| 459 | d.escalation.generation = gen |
| 460 | d.escalation.cancelDeadline = now.Add(tuiWatchdogCancelGrace) |
| 461 | // Cancel at most once per generation; re-stalls after recovery still |
| 462 | // get dump + grace + hard-kill, but not a second Cancel(). |
| 463 | issueCancel := cancelFn != nil && d.escalation.cancelIssued != gen |
| 464 | if issueCancel { |
| 465 | d.escalation.cancelIssued = gen |
| 466 | } |
| 467 | // Snapshot cancel under lock; invoke after the dump outside this critical |
| 468 | // section, with a second generation check immediately before the call. |
| 469 | d.mu.Unlock() |
| 470 | d.dumpCalls.Add(1) |
| 471 | d.doDump("watchdog_stall") |
| 472 | d.writeLine(diag) |
| 473 | if statusFn != nil { |
| 474 | if st := statusFn(); st != "" { |
| 475 | d.writeLine("controller_status " + st) |
| 476 | } |
| 477 | } |
| 478 | d.Sync() |
| 479 | if issueCancel { |
| 480 | d.cancelCurrentGeneration(gen, cancelFn) |
| 481 | } |
| 482 | return |
| 483 | } |
| 484 | |
| 485 | // Booting stall: dump + hard-kill (no controller turn to cancel). |
| 486 | d.escalation.hardKillIssued = true |
| 487 | d.escalation.hardKilledGen = gen |
| 488 | d.mu.Unlock() |
| 489 | d.dumpCalls.Add(1) |
| 490 | d.killCalls.Add(1) |
| 491 | d.doDump("watchdog_boot_stall") |
| 492 | d.writeLine(diag) |
| 493 | d.Sync() |
| 494 | d.doKill() |
| 495 | } |
| 496 | |
| 497 | func (d *tuiDiagnostics) cancelCurrentGeneration(gen uint64, cancelFn func()) { |
| 498 | if d == nil || cancelFn == nil { |
| 499 | return |
| 500 | } |
| 501 | d.mu.Lock() |
| 502 | defer d.mu.Unlock() |
| 503 | if d.phase != watchdogRunning || d.generation != gen || d.escalation.cancelIssued != gen { |
| 504 | return |
| 505 | } |
| 506 | d.cancelCalls.Add(1) |
| 507 | cancelFn() |
| 508 | } |
| 509 | |
| 510 | func (d *tuiDiagnostics) formatDiagLocked(now time.Time, reason string) string { |
| 511 | age := now.Sub(d.lastHeartbeat) |
| 512 | if d.lastHeartbeat.IsZero() { |
| 513 | age = 0 |
| 514 | } |
| 515 | return fmt.Sprintf( |
| 516 | "watchdog_diag reason=%s phase=%s gen=%d last_heartbeat_age=%s last_event=%s cancel_requested=%v hard_kill_phase=%v", |
| 517 | reason, |
| 518 | d.phase, |
| 519 | d.generation, |
| 520 | age.Round(time.Millisecond), |
| 521 | d.lastHeartbeatSource, |
| 522 | d.escalation.generation == d.generation && d.generation != 0 && !d.escalation.cancelDeadline.IsZero(), |
| 523 | d.escalation.hardKillIssued && d.escalation.hardKilledGen == d.generation, |
| 524 | ) |
| 525 | } |
| 526 | |
| 527 | func (d *tuiDiagnostics) doDump(reason string) { |
| 528 | if d == nil { |
| 529 | return |
| 530 | } |
| 531 | if d.dumpFn != nil { |
| 532 | d.dumpFn(reason) |
| 533 | return |
| 534 | } |
| 535 | d.dumpGoroutines(reason) |
| 536 | } |
| 537 | |
| 538 | func (d *tuiDiagnostics) doKill() { |
| 539 | if d == nil { |
| 540 | return |
| 541 | } |
| 542 | if d.shutdownFn != nil { |
| 543 | // Graceful first — the SIGHUP path snapshots and quits cleanly; a |
| 544 | // wedged loop can block Program.Send, so register the fallback before |
| 545 | // making the graceful request (#9233). |
| 546 | kill := d.killFn |
| 547 | afterFunc := d.afterFunc |
| 548 | if afterFunc == nil { |
| 549 | afterFunc = func(delay time.Duration, fn func()) { |
| 550 | time.AfterFunc(delay, fn) |
| 551 | } |
| 552 | } |
| 553 | completion := newTUIShutdownCompletion() |
| 554 | afterFunc(watchdogKillFallbackDelay, func() { |
| 555 | if completion.claimFallback() && kill != nil { |
| 556 | kill() |
| 557 | } |
| 558 | }) |
| 559 | d.shutdownFn(completion) |
| 560 | return |
| 561 | } |
| 562 | if d.killFn != nil { |
| 563 | d.killFn() |
| 564 | } |
| 565 | } |
| 566 | |
| 567 | func (d *tuiDiagnostics) dumpGoroutines(reason string) { |
| 568 | if d == nil { |
| 569 | return |
| 570 | } |
| 571 | buf := make([]byte, 1<<20) |
| 572 | for { |
| 573 | n := runtime.Stack(buf, true) |
| 574 | if n < len(buf) { |
| 575 | buf = buf[:n] |
| 576 | break |
| 577 | } |
| 578 | buf = make([]byte, len(buf)*2) |
| 579 | } |
| 580 | _, _ = fmt.Fprintf(d.Writer(), "goroutine_dump reason=%s bytes=%d\n%s\n", reason, len(buf), buf) |
| 581 | } |
| 582 | |
| 583 | func (d *tuiDiagnostics) writeLine(line string) { |
| 584 | if d == nil { |
| 585 | return |
| 586 | } |
| 587 | _, _ = fmt.Fprintln(d.Writer(), line) |
| 588 | } |
| 589 | |
| 590 | func (d *tuiDiagnostics) now() time.Time { |
| 591 | if d != nil && d.nowFn != nil { |
| 592 | return d.nowFn() |
| 593 | } |
| 594 | return time.Now() |
| 595 | } |
| 596 | |
| 597 | func (d *tuiDiagnostics) logfLocked(format string, args ...any) { |
| 598 | if d.logFn != nil { |
| 599 | d.logFn(format, args...) |
| 600 | return |
| 601 | } |
| 602 | _, _ = fmt.Fprintf(d.Writer(), format+"\n", args...) |
| 603 | } |
| 604 | |
| 605 | // phaseForTest returns the current phase under lock (test helper). |
| 606 | func (d *tuiDiagnostics) phaseForTest() tuiWatchdogPhase { |
| 607 | d.mu.Lock() |
| 608 | defer d.mu.Unlock() |
| 609 | return d.phase |
| 610 | } |
| 611 | |
| 612 | // generationForTest returns the current generation under lock (test helper). |
| 613 | func (d *tuiDiagnostics) generationForTest() uint64 { |
| 614 | d.mu.Lock() |
| 615 | defer d.mu.Unlock() |
| 616 | return d.generation |
| 617 | } |
| 618 | |
| 619 | func (d *tuiDiagnostics) Close() { |
| 620 | if d == nil { |
| 621 | return |
| 622 | } |
| 623 | d.close.Do(func() { |
| 624 | d.mu.Lock() |
| 625 | d.phase = watchdogClosed |
| 626 | d.cancelFn = nil |
| 627 | d.escalation.cancelDeadline = time.Time{} |
| 628 | d.logfLocked("watchdog_state phase=%s gen=%d source=closed", d.phase, d.generation) |
| 629 | d.mu.Unlock() |
| 630 | |
| 631 | select { |
| 632 | case <-d.stopWatch: |
| 633 | default: |
| 634 | close(d.stopWatch) |
| 635 | } |
| 636 | // Wait for the watchdog to fully exit before closing the log. A timed |
| 637 | // wait left a window where runtime.Stack / Sync / Kill could still write |
| 638 | // the file after Close returned. |
| 639 | d.watchWG.Wait() |
| 640 | // Do not overwrite a logger deliberately installed by another owner |
| 641 | // after the TUI started. |
| 642 | if slog.Default() == d.logger && d.previous != nil { |
| 643 | slog.SetDefault(d.previous) |
| 644 | } |
| 645 | if d.file != nil { |
| 646 | _ = d.file.Sync() |
| 647 | _ = d.file.Close() |
| 648 | } |
| 649 | }) |
| 650 | } |
| 651 | |
| 652 | func tuiDiagnosticLogDir(reasonixHome string) string { |
| 653 | if strings.TrimSpace(reasonixHome) == "" { |
| 654 | return "" |
| 655 | } |
| 656 | return filepath.Join(reasonixHome, "logs") |
| 657 | } |
| 658 | |
| 659 | func pruneTUIDiagnosticLogs(logDir string, now time.Time) { |
| 660 | entries, err := os.ReadDir(logDir) |
| 661 | if err != nil { |
| 662 | return |
| 663 | } |
| 664 | cutoff := now.Add(-tuiDiagnosticLogRetention) |
| 665 | for _, entry := range entries { |
| 666 | if entry.IsDir() || !strings.HasPrefix(entry.Name(), "cli-tui-") || !strings.HasSuffix(entry.Name(), ".log") { |
| 667 | continue |
| 668 | } |
| 669 | info, err := entry.Info() |
| 670 | if err != nil || !info.ModTime().Before(cutoff) { |
| 671 | continue |
| 672 | } |
| 673 | _ = os.Remove(filepath.Join(logDir, entry.Name())) |
| 674 | } |
| 675 | } |
| 676 | |
| 677 | type boundedDiagnosticWriter struct { |
| 678 | mu sync.Mutex |
| 679 | dst io.Writer |
| 680 | remaining int64 |
| 681 | truncated bool |
| 682 | } |
| 683 | |
| 684 | func (w *boundedDiagnosticWriter) Write(p []byte) (int, error) { |
| 685 | w.mu.Lock() |
| 686 | defer w.mu.Unlock() |
| 687 | |
| 688 | total := len(p) |
| 689 | if total == 0 || w.dst == nil || w.remaining <= 0 { |
| 690 | return total, nil |
| 691 | } |
| 692 | n := total |
| 693 | if int64(n) > w.remaining { |
| 694 | n = int(w.remaining) |
| 695 | } |
| 696 | written, err := w.dst.Write(p[:n]) |
| 697 | if written > 0 { |
| 698 | w.remaining -= int64(written) |
| 699 | } |
| 700 | if err != nil || written != n { |
| 701 | w.remaining = 0 |
| 702 | return total, nil |
| 703 | } |
| 704 | if n < total && !w.truncated { |
| 705 | w.truncated = true |
| 706 | _, _ = io.WriteString(w.dst, "\nreasonix: CLI TUI diagnostic log limit reached; further diagnostics omitted\n") |
| 707 | w.remaining = 0 |
| 708 | } |
| 709 | return total, nil |
| 710 | } |
| 711 |