From 9837473ca7ea6e26d253ac6926254eda12d707a1 Mon Sep 17 00:00:00 2001 From: Jeroen Schweitzer Date: Mon, 15 Jun 2026 09:56:53 +0200 Subject: [PATCH] feat(pty): FFI breadcrumbs around the syscalls that wedge (T-434) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The freeze hypothesis is a wedged FFI call — a reader isolate blocked forever in ReadFile, a waiter in WaitForSingleObject, Isolate.kill unable to interrupt either. To NAME the wedge after a power-cycle, each backend now drops a breadcrumb before/after every risky syscall. - pty_log.dart (new, Flutter-free, tested): PtyLog — an injectable, no-op-by- default breadcrumb hook for the MAIN isolate (wired to the kernel Logger, source 'conpty'/'pty' = an eager FileLogSink source) — and IsolateCrumbFile, which the SPAWNED reader/waiter isolates use to open their OWN append handle and flushSync per line, so a wedged isolate's last crumb survives even a frozen main isolate (the whole point). Bounded by a truncating size cap. - native_pty.dart + windows_pty.dart: crumbs around posix_spawn/read and CreatePseudoConsole/CreateProcessW/ReadFile/WaitForSingleObject; the reader/ waiter isolates carry a sendable crumb path + verbose flag. Per-syscall crumbs only at debug/trace; lifecycle crumbs always. - Wiring: startPtySession → PaneRegistry → buildDispatcher build the PtyLog from the kernel Logger + a crumb file under logDirectory(); verbose follows the log level. Default everywhere is PtyLog.none — zero behaviour change off the wire. Tested: PtyLog/IsolateCrumbFile units (cap-truncation, append, no-op) + an end-to-end real-PTY test asserting the reader isolate writes its own crumbs ('reader started' / 'read -> n=' / 'reader exiting'), which validates the identical Windows structure that can't run here. Coverage gate 95.10%. Co-Authored-By: Claude Opus 4.8 (1M context) --- CHANGELOG.md | 6 ++ lib/main.dart | 27 +++++++-- lib/src/panes/registry.dart | 17 +++++- lib/src/pty/native_pty.dart | 41 ++++++++++--- lib/src/pty/pty_log.dart | 111 +++++++++++++++++++++++++++++++++++ lib/src/pty/pty_session.dart | 4 ++ lib/src/pty/windows_pty.dart | 57 ++++++++++++++---- test/pty/pty_log_test.dart | 99 +++++++++++++++++++++++++++++++ test/pty/session_test.dart | 35 +++++++++++ 9 files changed, 373 insertions(+), 24 deletions(-) create mode 100644 lib/src/pty/pty_log.dart create mode 100644 test/pty/pty_log_test.dart diff --git a/CHANGELOG.md b/CHANGELOG.md index dc06408d..5170ed8a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -24,6 +24,12 @@ heading, and (b) bumping `pubspec.yaml` `version:` in the same commit. a freeze leaves on-disk evidence. `CLIDE_LOG` (dart-define / env) or the `app.log.level` setting sets verbosity (warn in release, info in debug). (T-432) +- **PTY FFI breadcrumbs.** Each PTY backend drops a breadcrumb before/after + every risky syscall (`CreatePseudoConsole`/`CreateProcessW`/`ReadFile`, + `posix_spawn`/`read`); the reader/waiter isolates fsync their OWN file handle + so a wedged isolate's last crumb survives a freeze that also froze the main + isolate — naming the wedge after the fact. Per-syscall crumbs at debug level. + (T-434) ## [2.5.0] — 2026-06-14 diff --git a/lib/main.dart b/lib/main.dart index 29976ff8..57ed9520 100644 --- a/lib/main.dart +++ b/lib/main.dart @@ -52,6 +52,7 @@ import 'package:clide/src/cli/argv_dispatch.dart'; import 'package:clide/src/ipc/envelope.dart'; import 'package:clide/src/ipc/mcp_server.dart'; import 'package:clide/src/ipc/paths.dart' show workspaceSocketPath, logDirectory; +import 'package:clide/src/pty/pty_log.dart'; import 'package:clide/src/ipc/server.dart'; import 'package:clide/src/panes/event_sink.dart'; import 'package:clide/src/panes/registry.dart'; @@ -131,6 +132,9 @@ Future main() async { // The filter-state cache, captured post-boot so `ui.filter` can read a // box's current value back — the observe-half of D-6 (T-270). FilterStateCache? kernelFilterStates; + // The kernel Logger, captured in the factory so a post-boot project switch + // can rebuild the dispatcher with PTY breadcrumbs wired (T-434). + Logger? kernelLog; // IPC socket server (T-99 / T-124, per D-70/71/72). One server per // workspace; restarted when the active project switches because the // socket path is workspace-derived. The local DaemonClient connects @@ -240,11 +244,23 @@ Future main() async { Toolchain tc, Directory workRoot, LayoutArrangement arrangement, - PanelRegistry panels, - ) { + PanelRegistry panels, { + Logger? log, + }) { final dispatcher = DaemonDispatcher(); final eventSink = _BusEventSink(events); - final paneRegistry = PaneRegistry(events: eventSink); + // FFI breadcrumbs (T-434): route PTY crumbs to the kernel Logger (source + // 'conpty', an eager FileLogSink source) and a sendable crumb file the + // reader/waiter isolates open themselves. Verbose (per-syscall) crumbs only + // when the log level is debug/trace. + final ptyLog = (log == null || kIsWeb) + ? PtyLog.none + : PtyLog( + onCrumb: (m) => log.trace('conpty', m), + crumbPath: '${logDirectory()}/clide-pty.crumbs.log', + verbose: log.minLevel.index <= LogLevel.debug.index, + ); + final paneRegistry = PaneRegistry(events: eventSink, ptyLog: ptyLog); // D-6 parity (T-219, D-83): make the tabs the user sees in the GUI // visible to `pane list` by snapshotting the kernel PanelRegistry + // LayoutArrangement at request time — no mirrored state to drift. @@ -361,8 +377,9 @@ Future main() async { daemonBus = events; kernelArrangement = arrangement; kernelPanels = panels; + kernelLog = log; final workRoot = startupWorkRoot; - final (dispatcher, teardown) = buildDispatcher(events, toolchain, workRoot, arrangement, panels); + final (dispatcher, teardown) = buildDispatcher(events, toolchain, workRoot, arrangement, panels, log: log); // Build the client at the workspace's socket path. The // server is started below (swapBackend) which the // client will then auto-connect to via its reconnect @@ -387,7 +404,7 @@ Future main() async { final arrangement = kernelArrangement; final panels = kernelPanels; if (bus == null || arrangement == null || panels == null) return; - final (dispatcher, teardown) = buildDispatcher(bus, toolchain, Directory(path), arrangement, panels); + final (dispatcher, teardown) = buildDispatcher(bus, toolchain, Directory(path), arrangement, panels, log: kernelLog); await swapBackend(dispatcher, teardown, Directory(path)); }, ); diff --git a/lib/src/panes/registry.dart b/lib/src/panes/registry.dart index ebca165d..c8f4a10e 100644 --- a/lib/src/panes/registry.dart +++ b/lib/src/panes/registry.dart @@ -12,14 +12,19 @@ import 'dart:io' show Platform; import 'dart:typed_data'; import '../ipc/envelope.dart'; +import '../pty/pty_log.dart'; import '../pty/pty_session.dart'; import 'event_sink.dart'; import 'pane.dart'; class PaneRegistry { - PaneRegistry({required this.events}); + PaneRegistry({required this.events, this.ptyLog = PtyLog.none}); final DaemonEventSink events; + + /// Breadcrumb hook handed to every PTY this registry spawns (T-434). Default + /// no-op; production wires it to the kernel Logger + a crumb file. + final PtyLog ptyLog; final Map _panes = {}; final Map _sessions = {}; final Map> _subs = {}; @@ -55,7 +60,15 @@ class PaneRegistry { ...?env, }; - final session = startPtySession(executable: executable, arguments: arguments, columns: cols, rows: rows, workingDirectory: cwd, environment: fullEnv); + final session = startPtySession( + executable: executable, + arguments: arguments, + columns: cols, + rows: rows, + workingDirectory: cwd, + environment: fullEnv, + log: ptyLog, + ); final pane = Pane(id: id, kind: kind, pid: session.pid, argv: argv, cwd: cwd, title: title); _panes[id] = pane; _sessions[id] = session; diff --git a/lib/src/pty/native_pty.dart b/lib/src/pty/native_pty.dart index 3043760e..e7cecd91 100644 --- a/lib/src/pty/native_pty.dart +++ b/lib/src/pty/native_pty.dart @@ -25,6 +25,7 @@ import 'dart:typed_data'; import 'package:ffi/ffi.dart'; import 'errors.dart'; +import 'pty_log.dart'; import 'pty_size.dart'; import '../ipc/errno_mapping.dart' show PosixErrno; import 'ffi/libc.dart' as libc; @@ -153,7 +154,12 @@ class NativePty implements PtySession { ReceivePort? _readerPort; Completer? _readerExited; - NativePty._(this._fd, this.pid); + /// Breadcrumb file path + verbosity threaded into the reader isolate (T-434). + /// Plain values so they survive `Isolate.spawn`. + final String? _crumbPath; + final bool _verbose; + + NativePty._(this._fd, this.pid, this._crumbPath, this._verbose); /// Byte stream of data produced by the child. @override @@ -177,7 +183,9 @@ class NativePty implements PtySession { required int rows, String? workingDirectory, Map environment = const {}, + PtyLog log = PtyLog.none, }) { + log.crumb('native: start exe=$executable'); // Resolve bare command names via PATH (posix_spawn requires an absolute // or relative path — posix_spawnp would search PATH for us but we want // resolution to be visible/debuggable from Dart). @@ -296,8 +304,10 @@ class NativePty implements PtySession { } // ---- Spawn ------------------------------------------------------- + log.crumb('native: posix_spawn enter'); final spawnRc = _posixSpawn(pidOut, exeN, fa, attr, argvN, envpN); final pid = pidOut.value; + log.crumb('native: posix_spawn -> rc=$spawnRc pid=$pid'); _faDestroy(fa); _spawnattrDestroy(attr); @@ -318,7 +328,7 @@ class NativePty implements PtySession { freeAllInputs(); - final pty = NativePty._(masterFd, pid); + final pty = NativePty._(masterFd, pid, log.crumbPath, log.verbose); pty._spawnReader(); return pty; } @@ -349,7 +359,7 @@ class NativePty implements PtySession { } }); try { - _readerIsolate = await Isolate.spawn(_readLoop, (rp.sendPort, _fd)); + _readerIsolate = await Isolate.spawn(_readLoop, (rp.sendPort, _fd, _crumbPath, _verbose)); } catch (e) { // Surface the spawn failure instead of leaving the PTY in a // half-alive state where output never flows but isClosed=false. @@ -363,8 +373,13 @@ class NativePty implements PtySession { } /// Isolate entry — polls then reads until EOF/error/fd-closed. - static void _readLoop((SendPort, int) msg) { - final (port, fd) = msg; + static void _readLoop((SendPort, int, String?, bool) msg) { + final (port, fd, crumbPath, verbose) = msg; + // The reader runs in a SPAWNED isolate with no Logger; it opens its own + // append handle so a wedge in read()/poll() leaves its last crumb on disk + // even if the main isolate is frozen too (T-434). + final crumbs = IsolateCrumbFile(crumbPath, 'pty.reader'); + crumbs.crumb('reader started fd=$fd'); final dl = ffi.DynamicLibrary.process(); final rd = dl.lookupFunction, ffi.IntPtr), int Function(int, ffi.Pointer, int)>('read'); final poll = dl.lookupFunction, ffi.Uint32, ffi.Int32), int Function(ffi.Pointer<_Pollfd>, int, int)>('poll'); @@ -374,24 +389,36 @@ class NativePty implements PtySession { pfd.ref.fd = fd; pfd.ref.events = libc.pollin; + var reason = 'eof'; try { while (true) { final ready = poll(pfd, 1, 100); - if (ready < 0) break; + if (ready < 0) { + reason = 'poll<0'; + break; + } if (ready == 0) continue; // Slave closed (POLLHUP / POLLERR / POLLNVAL) with no buffered // bytes left to read — caller loop exits and we send EOF. if (pfd.ref.revents & libc.pollAnyErr != 0 && pfd.ref.revents & libc.pollin == 0) { + reason = 'pollhup'; break; } + if (verbose) crumbs.crumb('read enter fd=$fd'); final n = rd(fd, buf.cast(), 65536); - if (n <= 0) break; + if (verbose) crumbs.crumb('read -> n=$n'); + if (n <= 0) { + reason = 'read<=0 ($n)'; + break; + } port.send(Uint8List.fromList(buf.asTypedList(n))); } } finally { calloc.free(pfd); malloc.free(buf); } + crumbs.crumb('reader exiting ($reason)'); + crumbs.close(); port.send(null); } diff --git a/lib/src/pty/pty_log.dart b/lib/src/pty/pty_log.dart new file mode 100644 index 00000000..2e50781c --- /dev/null +++ b/lib/src/pty/pty_log.dart @@ -0,0 +1,111 @@ +/// Breadcrumb logging for the PTY backends (T-434, under the T-425 epic). +/// +/// The Windows freeze hypothesis is a wedged FFI call — a reader isolate +/// blocked forever in `ReadFile`, a waiter stuck in `WaitForSingleObject`, +/// `Isolate.kill` unable to interrupt either (dart-lang/sdk#46680). To NAME +/// the wedge after a power-cycle, each backend drops a breadcrumb before and +/// after every risky syscall. There are two delivery paths because the +/// reader/waiter run in SPAWNED isolates that cannot see the main isolate's +/// [Logger] — only sendable values cross `Isolate.spawn`: +/// +/// - Main isolate → [PtyLog.crumb], a callback the kernel wires to its +/// Logger (source `pty`/`conpty`, an eager FileLogSink source, so each +/// crumb is fsynced). +/// - Spawned isolates → [IsolateCrumbFile], opened from a plain file path +/// (sendable) so the isolate writes with its OWN append handle and +/// flushSync per line. That is the whole point: a reader wedged in +/// `ReadFile` leaves its last "ReadFile enter" crumb on disk even though +/// the main isolate (and its Logger) may be frozen too. +/// +/// Default is fully no-op: callers that pass nothing ([PtyLog.none]) get +/// exactly today's behaviour and zero I/O. Everything swallows its own errors +/// — a logging failure must never perturb the PTY it is observing. +library; + +import 'dart:convert'; +import 'dart:io'; + +/// Main-isolate breadcrumb hook handed to a PTY backend. +class PtyLog { + const PtyLog({this.onCrumb, this.crumbPath, this.verbose = false}); + + /// Called on the main isolate for each lifecycle/syscall breadcrumb. The + /// kernel wires this to `(m) => logger.trace('pty', m)`. + final void Function(String message)? onCrumb; + + /// File path the SPAWNED reader/waiter isolates open for their own crumbs. + /// A String (not a closure/Logger) so it survives `Isolate.spawn`. Null + /// disables isolate crumbs. + final String? crumbPath; + + /// When true, the high-frequency per-syscall crumbs fire too (debug/trace + /// level). When false, only low-frequency lifecycle crumbs are written, so + /// production wiring stays cheap. + final bool verbose; + + /// The no-op default — zero I/O, today's behaviour. + static const none = PtyLog(); + + /// Emit a main-isolate breadcrumb. Never throws. + void crumb(String message) { + final cb = onCrumb; + if (cb == null) return; + try { + cb(message); + } catch (_) {} + } +} + +/// An append-only breadcrumb file for use INSIDE a spawned isolate, where no +/// [Logger] is reachable. Opens [path] once and flushSync per line so a wedge +/// leaves its last crumb on disk. Bounded: truncates back to empty once it +/// passes [capBytes] (we only ever need the tail before a wedge), so a chatty +/// session can't grow it without limit. Every operation swallows its own error. +class IsolateCrumbFile { + IsolateCrumbFile(String? path, this.source, {int capBytes = 256 * 1024}) : _capBytes = capBytes { + if (path == null) return; + try { + final raf = File(path).openSync(mode: FileMode.append); + _raf = raf; + _size = raf.lengthSync(); + } catch (_) { + _raf = null; // a disk problem must never perturb the reader/waiter + } + } + + final String source; + final int _capBytes; + RandomAccessFile? _raf; + int _size = 0; + + bool get enabled => _raf != null; + + /// Append one breadcrumb line, fsynced immediately. + void crumb(String message) { + final raf = _raf; + if (raf == null) return; + try { + if (_size >= _capBytes) { + // Reset to empty: truncate AND rewind. truncateSync alone leaves the + // write position at the old high-water mark, so the next write would + // land past the hole and the file would keep growing (sparse) instead + // of shrinking — rewind to 0 so we actually reclaim the space. + raf.truncateSync(0); + raf.setPositionSync(0); + _size = 0; + } + final bytes = utf8.encode('${DateTime.now().toUtc().toIso8601String()} [$source] $message\n'); + raf.writeFromSync(bytes); + raf.flushSync(); + _size += bytes.length; + } catch (_) {} + } + + void close() { + try { + _raf?.flushSync(); + _raf?.closeSync(); + } catch (_) {} + _raf = null; + } +} diff --git a/lib/src/pty/pty_session.dart b/lib/src/pty/pty_session.dart index 1bff349c..c5caf5c7 100644 --- a/lib/src/pty/pty_session.dart +++ b/lib/src/pty/pty_session.dart @@ -12,6 +12,7 @@ import 'dart:io' show Platform; import 'dart:typed_data'; import 'native_pty.dart'; +import 'pty_log.dart'; import 'windows_pty.dart'; abstract interface class PtySession { @@ -49,6 +50,7 @@ PtySession startPtySession({ required int rows, String? workingDirectory, Map environment = const {}, + PtyLog log = PtyLog.none, }) { if (Platform.isWindows) { return WindowsPty.start( @@ -58,6 +60,7 @@ PtySession startPtySession({ rows: rows, workingDirectory: workingDirectory, environment: environment, + log: log, ); } return NativePty.start( @@ -67,5 +70,6 @@ PtySession startPtySession({ rows: rows, workingDirectory: workingDirectory, environment: environment, + log: log, ); } diff --git a/lib/src/pty/windows_pty.dart b/lib/src/pty/windows_pty.dart index 20afd933..c0bee9e4 100644 --- a/lib/src/pty/windows_pty.dart +++ b/lib/src/pty/windows_pty.dart @@ -45,6 +45,7 @@ import 'dart:typed_data'; import 'package:ffi/ffi.dart'; import 'errors.dart'; +import 'pty_log.dart'; import 'pty_session.dart'; import 'pty_size.dart'; @@ -259,6 +260,11 @@ class WindowsPty implements PtySession { Completer? _readerExited; ReceivePort? _waiterPort; + /// Breadcrumb file path + verbosity threaded into the reader/waiter isolates + /// (T-434). Plain values so they survive `Isolate.spawn`. + String? _crumbPath; + bool _verbose = false; + @override Stream get output => _out.stream; @@ -277,7 +283,9 @@ class WindowsPty implements PtySession { required int rows, String? workingDirectory, Map environment = const {}, + PtyLog log = PtyLog.none, }) { + log.crumb('conpty: start exe=$executable'); executable = resolveExecutable(executable, environment); // ---- Pipes + pseudo console --------------------------------------- @@ -308,7 +316,9 @@ class WindowsPty implements PtySession { ..ref.x = clampPtyDimension(columns) ..ref.y = clampPtyDimension(rows); final hpcOut = calloc<_Handle>(); + log.crumb('conpty: CreatePseudoConsole enter'); final hr = _createPseudoConsole(size.ref, inRead, outWrite, 0, hpcOut); + log.crumb('conpty: CreatePseudoConsole -> hr=$hr'); calloc.free(size); if (hr != 0) { _closeHandle(inRead); @@ -375,6 +385,7 @@ class WindowsPty implements PtySession { ..ref.lpAttributeList = attrList; final pi = calloc<_ProcessInformation>(); + log.crumb('conpty: CreateProcessW enter'); final ok = _createProcessW( ffi.nullptr, cmdLine, @@ -388,6 +399,7 @@ class WindowsPty implements PtySession { pi, ); final spawnErr = ok == 0 ? _getLastError() : 0; + log.crumb('conpty: CreateProcessW -> ok=$ok err=$spawnErr'); _deleteAttrList(attrList); freeAttrs(); @@ -411,7 +423,10 @@ class WindowsPty implements PtySession { final childPid = pi.ref.dwProcessId; calloc.free(pi); - final pty = WindowsPty._(hpc, hProcess, hThread, inWrite, outRead, inRead, outWrite, childPid); + final pty = WindowsPty._(hpc, hProcess, hThread, inWrite, outRead, inRead, outWrite, childPid) + .._crumbPath = log.crumbPath + .._verbose = log.verbose; + log.crumb('conpty: spawned pid=$childPid'); pty._spawnReader(); pty._spawnWaiter(); return pty; @@ -439,7 +454,7 @@ class WindowsPty implements PtySession { } }); try { - _readerIsolate = await Isolate.spawn(_readLoop, (rp.sendPort, _outRead.address)); + _readerIsolate = await Isolate.spawn(_readLoop, (rp.sendPort, _outRead.address, _crumbPath, _verbose)); } catch (e) { _dead = true; if (!_out.isClosed) _out.addError(PtyException('reader-spawn', '$e')); @@ -450,8 +465,15 @@ class WindowsPty implements PtySession { } /// Isolate entry — blocking ReadFile until the ConPTY side closes. - static void _readLoop((SendPort, int) msg) { - final (port, handleAddr) = msg; + static void _readLoop((SendPort, int, String?, bool) msg) { + final (port, handleAddr, crumbPath, verbose) = msg; + // This isolate is the prime suspect for the freeze: ReadFile blocks + // forever if the ConPTY host never closes the pipe, and Isolate.kill + // can't interrupt the FFI (dart-lang/sdk#46680). It opens its OWN append + // handle so its last "ReadFile enter" crumb survives even a frozen main + // isolate — the breadcrumb that NAMES the wedge after a power-cycle (T-434). + final crumbs = IsolateCrumbFile(crumbPath, 'conpty.reader'); + crumbs.crumb('reader started handle=$handleAddr'); final handle = ffi.Pointer.fromAddress(handleAddr); final k32 = ffi.DynamicLibrary.open('kernel32.dll'); final readFile = k32 @@ -462,20 +484,31 @@ class WindowsPty implements PtySession { final buf = malloc(65536); final nRead = calloc(); + var reason = 'eof'; try { while (true) { // Blocks until data, broken pipe (ConPTY closed), or invalid // handle (close() already released it). + if (verbose) crumbs.crumb('ReadFile enter'); final ok = readFile(handle, buf, 65536, nRead, ffi.nullptr); - if (ok == 0) break; + if (verbose) crumbs.crumb('ReadFile -> ok=$ok n=${nRead.value}'); + if (ok == 0) { + reason = 'broken-pipe/invalid'; + break; + } final n = nRead.value; - if (n == 0) break; + if (n == 0) { + reason = 'n=0'; + break; + } port.send(Uint8List.fromList(buf.asTypedList(n))); } } finally { calloc.free(nRead); malloc.free(buf); } + crumbs.crumb('reader exiting ($reason)'); + crumbs.close(); port.send(null); } @@ -490,7 +523,7 @@ class WindowsPty implements PtySession { _waiterPort = null; _closeConsole(); }); - Isolate.spawn(_waitLoop, (wp.sendPort, _hProcess.address)).catchError((Object e) { + Isolate.spawn(_waitLoop, (wp.sendPort, _hProcess.address, _crumbPath)).catchError((Object e) { // Fall back to close()-driven teardown; the child just won't be // auto-reaped on self-exit. wp.close(); @@ -499,11 +532,15 @@ class WindowsPty implements PtySession { }); } - static void _waitLoop((SendPort, int) msg) { - final (port, handleAddr) = msg; + static void _waitLoop((SendPort, int, String?) msg) { + final (port, handleAddr, crumbPath) = msg; + final crumbs = IsolateCrumbFile(crumbPath, 'conpty.waiter'); + crumbs.crumb('waiter started; WaitForSingleObject(INFINITE) enter'); final k32 = ffi.DynamicLibrary.open('kernel32.dll'); final wait = k32.lookupFunction('WaitForSingleObject'); - wait(ffi.Pointer.fromAddress(handleAddr), _kInfinite); + final r = wait(ffi.Pointer.fromAddress(handleAddr), _kInfinite); + crumbs.crumb('WaitForSingleObject -> $r (child exited)'); + crumbs.close(); port.send(null); } diff --git a/test/pty/pty_log_test.dart b/test/pty/pty_log_test.dart new file mode 100644 index 00000000..6673bee6 --- /dev/null +++ b/test/pty/pty_log_test.dart @@ -0,0 +1,99 @@ +// Unit tests for the PTY breadcrumb plumbing (T-434). Pure callback + file I/O +// (no real PTY), so this is NOT tagged `pty` — it runs in the coverage pool. +import 'dart:io'; + +import 'package:clide/src/pty/pty_log.dart'; +import 'package:flutter_test/flutter_test.dart'; + +void main() { + group('PtyLog', () { + test('none is a no-op — crumb does nothing and never throws', () { + expect(() => PtyLog.none.crumb('x'), returnsNormally); + expect(PtyLog.none.onCrumb, isNull); + expect(PtyLog.none.crumbPath, isNull); + expect(PtyLog.none.verbose, isFalse); + }); + + test('crumb forwards messages to onCrumb', () { + final got = []; + final log = PtyLog(onCrumb: got.add); + log.crumb('a'); + log.crumb('b'); + expect(got, ['a', 'b']); + }); + + test('crumb swallows an exception thrown by onCrumb', () { + final log = PtyLog(onCrumb: (_) => throw StateError('boom')); + expect(() => log.crumb('x'), returnsNormally); + }); + }); + + group('IsolateCrumbFile', () { + late Directory dir; + setUp(() => dir = Directory.systemTemp.createTempSync('clide-crumb-')); + tearDown(() { + if (dir.existsSync()) dir.deleteSync(recursive: true); + }); + + String path() => '${dir.path}${Platform.pathSeparator}crumbs.log'; + + test('null path → disabled, crumb is a no-op', () { + final c = IsolateCrumbFile(null, 'pty.reader'); + expect(c.enabled, isFalse); + expect(() => c.crumb('x'), returnsNormally); + c.close(); + }); + + test('writes one tagged, timestamped line per crumb', () { + final c = IsolateCrumbFile(path(), 'pty.reader'); + expect(c.enabled, isTrue); + c.crumb('ReadFile enter'); + c.crumb('ReadFile -> ok=1 n=12'); + c.close(); + + final lines = File(path()).readAsLinesSync(); + expect(lines, hasLength(2)); + expect(lines[0], contains('[pty.reader] ReadFile enter')); + expect(lines[1], contains('[pty.reader] ReadFile -> ok=1 n=12')); + // ISO-8601 UTC timestamp prefix. + expect(lines[0], matches(RegExp(r'^\d{4}-\d{2}-\d{2}T'))); + }); + + test('appends across reopen (each isolate opens its own handle)', () { + IsolateCrumbFile(path(), 'conpty.reader') + ..crumb('reader started') + ..close(); + IsolateCrumbFile(path(), 'conpty.waiter') + ..crumb('waiter started') + ..close(); + + final lines = File(path()).readAsLinesSync(); + expect(lines, hasLength(2)); + expect(lines[0], contains('[conpty.reader] reader started')); + expect(lines[1], contains('[conpty.waiter] waiter started')); + }); + + test('truncates back to empty past the cap, keeping the tail bounded', () { + final c = IsolateCrumbFile(path(), 's', capBytes: 200); + for (var i = 0; i < 50; i++) { + c.crumb('breadcrumb line number $i with some padding'); + } + c.crumb('LAST'); + c.close(); + + final bytes = File(path()).lengthSync(); + // Bounded: cap + at most one over-cap line, never the full 50 lines. + expect(bytes, lessThan(400)); + // The most recent crumb survived the wrap. + expect(File(path()).readAsStringSync(), contains('LAST')); + }); + + test('close is idempotent and post-close crumbs are no-ops', () { + final c = IsolateCrumbFile(path(), 's')..crumb('one'); + c.close(); + c.close(); + c.crumb('after-close'); + expect(File(path()).readAsLinesSync(), hasLength(1)); + }); + }); +} diff --git a/test/pty/session_test.dart b/test/pty/session_test.dart index adf45752..7fdc4ad7 100644 --- a/test/pty/session_test.dart +++ b/test/pty/session_test.dart @@ -18,6 +18,7 @@ import 'dart:io'; import 'package:clide/src/pty/errors.dart'; import 'package:clide/src/pty/native_pty.dart'; +import 'package:clide/src/pty/pty_log.dart'; import 'package:test/test.dart'; import '../helpers/timeouts.dart'; @@ -41,6 +42,40 @@ void main() { expect(got, contains('hello-pty')); }); + test('emits FFI breadcrumbs to the main callback + the reader isolate crumb file (T-434)', tags: ['pty'], () async { + final dir = Directory.systemTemp.createTempSync('clide-pty-crumb-'); + addTearDown(() { + if (dir.existsSync()) dir.deleteSync(recursive: true); + }); + final crumbPath = '${dir.path}/pty.crumbs'; + final mainCrumbs = []; + + final s = NativePty.start( + executable: '/bin/sh', + arguments: ['-c', 'echo crumb-test'], + columns: 80, + rows: 24, + workingDirectory: '/', + environment: {...Platform.environment, 'TERM': 'xterm-256color'}, + log: PtyLog(onCrumb: mainCrumbs.add, crumbPath: crumbPath, verbose: true), + ); + addTearDown(s.close); + + // Drain to EOF so the reader isolate runs its full lifecycle (it writes + // its 'exiting' crumb + closes the file before sending the EOF we await). + await s.output.drain().timeout(ioTimeout, onTimeout: () {}); + + // Main-isolate crumbs captured the spawn syscall sequence. + expect(mainCrumbs.join('\n'), contains('posix_spawn')); + + // The SPAWNED reader isolate wrote its own crumbs to its own handle. + final crumbs = File(crumbPath).readAsStringSync(); + expect(crumbs, contains('[pty.reader] reader started')); + expect(crumbs, contains('[pty.reader] reader exiting')); + // verbose:true → per-read crumbs around the (potentially blocking) read. + expect(crumbs, contains('[pty.reader] read -> n=')); + }); + test('write sends keystrokes to child', tags: ['pty'], () async { final s = NativePty.start( executable: '/bin/sh',