From 30d91833eba7c7cab9636077ac77ca42ccb13a38 Mon Sep 17 00:00:00 2001 From: AdaAibaby Date: Thu, 17 Sep 2026 15:16:22 +0800 Subject: [PATCH 1/2] fix(python-sdk): log the local cause when a command stream is cancelled MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When a command output stream ends on the client side without an end event, the SDK left no trace of why. The server (envd) only records that the stream was cancelled, not the client-side reason, so a cancelled commands.run (consumer stopped iterating, request timeout, sibling task cancel, caller exit, explicit disconnect(), or an RPC error) was invisible from the SDK side — and note the process itself is NOT killed, it keeps running, so the result is silently uncollected. CommandHandle (sync + async) now takes the logger the sandbox was already constructed with (ConnectionConfig.logger) and records, at INFO, why the stream ended, tagged with the pid: - explicit disconnect() — command left running - consumer stopped iterating (break / cancel / caller exit): the sync handle catches GeneratorExit; the async handle logs in disconnect() and the error path of its reader task - stream error before the end event (RPC failure): the error type/message No-op when no logger is configured (the default), so nothing changes for callers that did not opt into logging. This is the client-side, first increment of e2b-dev/E2B#1877 (correlate SDK cancellations with envd logs); it does not yet depend on a shared request-id — logs correlate by sandbox id + pid + timestamp with the server-side change e2b-dev/runtime#3647. --- .../e2b/sandbox_async/commands/command.py | 2 ++ .../sandbox_async/commands/command_handle.py | 19 ++++++++++++ .../e2b/sandbox_async/commands/pty.py | 2 ++ .../e2b/sandbox_sync/commands/command.py | 2 ++ .../sandbox_sync/commands/command_handle.py | 29 +++++++++++++++++++ .../e2b/sandbox_sync/commands/pty.py | 2 ++ 6 files changed, 56 insertions(+) diff --git a/packages/python-sdk/e2b/sandbox_async/commands/command.py b/packages/python-sdk/e2b/sandbox_async/commands/command.py index 19d7e23649..1e484783d7 100644 --- a/packages/python-sdk/e2b/sandbox_async/commands/command.py +++ b/packages/python-sdk/e2b/sandbox_async/commands/command.py @@ -334,6 +334,7 @@ async def _start( pid, request_timeout ), check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: @@ -393,6 +394,7 @@ async def connect( pid, request_timeout ), check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: diff --git a/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py b/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py index 4168cfe63d..810c9279e6 100644 --- a/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py +++ b/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py @@ -1,6 +1,7 @@ import asyncio import codecs import inspect +import logging from typing import ( Optional, Callable, @@ -95,6 +96,7 @@ def __init__( Callable[[Optional[float]], Coroutine[Any, Any, None]] ] = None, check_health: Optional[Callable[[], Awaitable[Optional[bool]]]] = None, + logger: Optional[logging.Logger] = None, ): self._pid = pid self._handle_kill = handle_kill @@ -102,6 +104,7 @@ def __init__( self._handle_close_stdin = handle_close_stdin self._check_health = check_health self._events = events + self._logger = logger self._stdout_chunks: List[str] = [] self._stderr_chunks: List[str] = [] @@ -138,6 +141,18 @@ def _flush_decoders( events.append((None, err, None)) return events + def _log_stream_ended(self, reason: str) -> None: + """ + Record why the command's output stream ended on the client side. + + The server (envd) only sees that the stream was cancelled, not why; this + logs the local cause so the two can be correlated. No-op when no logger + was configured. See e2b-dev/E2B#1877. + """ + if self._logger is None: + return + self._logger.info("command stream ended (pid=%s): %s", self._pid, reason) + async def _iterate_events( self, ) -> AsyncGenerator[ @@ -209,6 +224,7 @@ async def disconnect(self) -> None: The command is not killed, but SDK stops receiving events from the command. You can reconnect to the command using `sandbox.commands.connect` method. """ + self._log_stream_ended("explicit disconnect() (command left running)") self._wait.cancel() await asyncio.wait([self._wait]) try: @@ -234,6 +250,9 @@ async def _handle_events(self): except StopAsyncIteration: pass except Exception as e: + self._log_stream_ended( + f"stream error before end event: {type(e).__name__}: {e}" + ) self._iteration_exception = await ahandle_rpc_exception_with_health( e, self._check_health ) diff --git a/packages/python-sdk/e2b/sandbox_async/commands/pty.py b/packages/python-sdk/e2b/sandbox_async/commands/pty.py index dda9d2e6f3..03f05fb86a 100644 --- a/packages/python-sdk/e2b/sandbox_async/commands/pty.py +++ b/packages/python-sdk/e2b/sandbox_async/commands/pty.py @@ -172,6 +172,7 @@ async def create( events=events, on_pty=on_data, check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: @@ -221,6 +222,7 @@ async def connect( events=events, on_pty=on_data, check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: diff --git a/packages/python-sdk/e2b/sandbox_sync/commands/command.py b/packages/python-sdk/e2b/sandbox_sync/commands/command.py index 0198c42c5a..80005dc602 100644 --- a/packages/python-sdk/e2b/sandbox_sync/commands/command.py +++ b/packages/python-sdk/e2b/sandbox_sync/commands/command.py @@ -330,6 +330,7 @@ def _start( pid, request_timeout ), check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: @@ -381,6 +382,7 @@ def connect( pid, request_timeout ), check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: diff --git a/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py b/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py index ea2b3fdad7..4d81cc87d3 100644 --- a/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py +++ b/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py @@ -1,4 +1,5 @@ import codecs +import logging from typing import Optional, Callable, Any, Generator, List, Union, Tuple @@ -42,6 +43,7 @@ def __init__( ] = None, handle_close_stdin: Optional[Callable[[Optional[float]], None]] = None, check_health: Optional[Callable[[], Optional[bool]]] = None, + logger: Optional[logging.Logger] = None, ): self._pid = pid self._handle_kill = handle_kill @@ -49,6 +51,7 @@ def __init__( self._handle_close_stdin = handle_close_stdin self._check_health = check_health self._events = events + self._logger = logger self._stdout_chunks: List[str] = [] self._stderr_chunks: List[str] = [] @@ -67,6 +70,18 @@ def __iter__(self): """ return self._handle_events() + def _log_stream_ended(self, reason: str) -> None: + """ + Record why the command's output stream ended on the client side. + + The server (envd) only sees that the stream was cancelled, not why; this + logs the local cause so the two can be correlated. No-op when no logger + was configured. See e2b-dev/E2B#1877. + """ + if self._logger is None: + return + self._logger.info("command stream ended (pid=%s): %s", self._pid, reason) + def _flush_decoders( self, ) -> List[Union[Tuple[Stdout, None, None], Tuple[None, Stderr, None]]]: @@ -140,11 +155,24 @@ def _handle_events( # characters instead of being silently dropped. if self._result is None: yield from self._flush_decoders() + except GeneratorExit: + # The consumer stopped iterating before an end event (e.g. it broke + # out of the loop, was cancelled by a timeout/sibling task, or the + # caller exited). Closing this generator closes the underlying event + # stream, which the server (envd) records as a client cancellation — + # note the process itself is NOT killed and keeps running. Log the + # local cause so it can be correlated with the server-side line; + # see e2b-dev/E2B#1877. + self._log_stream_ended("consumer stopped iterating (break/cancel/exit)") + raise except Exception as e: # The stream raised before an end event (e.g. disconnect or RPC # failure). Flush any bytes still buffered in the decoders so # incomplete trailing sequences surface as replacement characters # instead of being silently dropped, then surface the error. + self._log_stream_ended( + f"stream error before end event: {type(e).__name__}: {e}" + ) yield from self._flush_decoders() raise handle_rpc_exception_with_health(e, self._check_health) @@ -155,6 +183,7 @@ def disconnect(self) -> None: The command is not killed, but SDK stops receiving events from the command. You can reconnect to the command using `sandbox.commands.connect` method. """ + self._log_stream_ended("explicit disconnect() (command left running)") self._events.close() def wait( diff --git a/packages/python-sdk/e2b/sandbox_sync/commands/pty.py b/packages/python-sdk/e2b/sandbox_sync/commands/pty.py index 9465007759..b4893bf0f6 100644 --- a/packages/python-sdk/e2b/sandbox_sync/commands/pty.py +++ b/packages/python-sdk/e2b/sandbox_sync/commands/pty.py @@ -163,6 +163,7 @@ def create( handle_kill=lambda: self.kill(pid), events=events, check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: @@ -207,6 +208,7 @@ def connect( handle_kill=lambda: self.kill(pid), events=events, check_health=self._check_health, + logger=self._connection_config.logger, ) except Exception as e: try: From 628298c965ce2a513942134a60b036328f3cdd1e Mon Sep 17 00:00:00 2001 From: AdaAibaby Date: Thu, 17 Sep 2026 16:21:19 +0800 Subject: [PATCH 2/2] =?UTF-8?q?fix(sdk):=20address=20review=20=E2=80=94=20?= =?UTF-8?q?dedupe=20cancel=20log,=20add=20JS=20parity,=20tests,=20changese?= =?UTF-8?q?t?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Follow-up to the review on this PR: - T-62: `_log_stream_ended` now records at most once per handle (guarded by `_stream_end_logged`), so `disconnect()` and the generator-close / reader-task path can no longer emit two contradictory causes for the same command. - T-3a: the new `logger` parameter is keyword-only in both CommandHandle constructors. - T-1/T-2: JS parity — `commandHandle.ts` gets the equivalent stream-ended logging in `disconnect()` and the stream-error path, reading `connectionConfig.logger`, wired through all four construction sites (commands + pty). - Tests: `tests/test_command_handle.py` covers the log lines for sync and async — stream error, explicit disconnect (asserting a single line), and the no-logger no-op. - Adds a changeset (patch) for e2b and @e2b/python-sdk. --- .changeset/command-stream-cancel-logging.md | 6 ++ .../src/sandbox/commands/commandHandle.ts | 27 +++++- packages/js-sdk/src/sandbox/commands/index.ts | 11 ++- packages/js-sdk/src/sandbox/commands/pty.ts | 12 +-- .../sandbox_async/commands/command_handle.py | 9 +- .../sandbox_sync/commands/command_handle.py | 9 +- .../python-sdk/tests/test_command_handle.py | 96 +++++++++++++++++++ 7 files changed, 154 insertions(+), 16 deletions(-) create mode 100644 .changeset/command-stream-cancel-logging.md diff --git a/.changeset/command-stream-cancel-logging.md b/.changeset/command-stream-cancel-logging.md new file mode 100644 index 0000000000..5a861d94bc --- /dev/null +++ b/.changeset/command-stream-cancel-logging.md @@ -0,0 +1,6 @@ +--- +"e2b": patch +"@e2b/python-sdk": patch +--- + +Log the local cause when a command output stream is cancelled. `CommandHandle` (sync and async, in both the Python and JS SDKs) now records, via the logger the sandbox was constructed with, why the stream ended — explicit `disconnect()`, an early stop of iteration/cancellation, or a stream error before the end event — tagged with the command pid, at most once per handle. This is a no-op when no logger is configured, so behavior is unchanged for callers that did not opt into logging. It gives the client-side reason to correlate with the server-side "stream end" line (e2b-dev/E2B#1877, e2b-dev/runtime#3647). diff --git a/packages/js-sdk/src/sandbox/commands/commandHandle.ts b/packages/js-sdk/src/sandbox/commands/commandHandle.ts index 759d17fe51..f5a5a854c7 100644 --- a/packages/js-sdk/src/sandbox/commands/commandHandle.ts +++ b/packages/js-sdk/src/sandbox/commands/commandHandle.ts @@ -4,6 +4,7 @@ import { } from '../../envd/rpc' import { SandboxError } from '../../errors' import { ConnectResponse, StartResponse } from '../../envd/process/process_pb' +import { Logger } from '../../logs' import type { CommandRequestOpts } from '.' declare const __brand: unique symbol @@ -121,11 +122,31 @@ export class CommandHandle private readonly handleCloseStdin?: ( opts?: CommandRequestOpts ) => Promise, - private readonly checkHealth?: SandboxHealthCheck + private readonly checkHealth?: SandboxHealthCheck, + private readonly logger?: Logger ) { this._wait = this.handleEvents() } + private streamEndLogged = false + + /** + * Record why the command's output stream ended on the client side. + * + * The server (envd) only sees that the stream was cancelled, not why; this + * logs the local cause so the two can be correlated. No-op when no logger was + * configured. Records at most once per handle so the disconnect() and + * stream-error paths cannot emit two contradictory causes for the same + * command. See e2b-dev/E2B#1877. + */ + private logStreamEnded(reason: string) { + if (!this.logger?.info || this.streamEndLogged) { + return + } + this.streamEndLogged = true + this.logger.info(`command stream ended (pid=${this.pid}): ${reason}`) + } + /** * Command execution exit code. * `0` if the command finished successfully. @@ -193,6 +214,7 @@ export class CommandHandle * whose stream produces no further output. */ async disconnect() { + this.logStreamEnded('explicit disconnect() (command left running)') this.disconnected = true this.handleDisconnect() } @@ -328,6 +350,9 @@ export class CommandHandle // failure). Flush any bytes still buffered in the decoders so incomplete // trailing sequences surface as replacement characters instead of being // silently dropped, then re-raise so the error is still surfaced. + this.logStreamEnded( + `stream error before end event: ${e instanceof Error ? `${e.name}: ${e.message}` : String(e)}` + ) yield* this.flushDecoders() throw e } diff --git a/packages/js-sdk/src/sandbox/commands/index.ts b/packages/js-sdk/src/sandbox/commands/index.ts index 22c9a4028d..245e6c2d06 100644 --- a/packages/js-sdk/src/sandbox/commands/index.ts +++ b/packages/js-sdk/src/sandbox/commands/index.ts @@ -37,9 +37,8 @@ export { Pty } from './pty' /** * Options for sending a command request. */ -export interface CommandRequestOpts extends Partial< - Pick -> {} +export interface CommandRequestOpts + extends Partial> {} /** * Options for starting a new command. @@ -364,7 +363,8 @@ export class Commands { undefined, (data, stdinOpts) => this.sendStdin(pid, data, stdinOpts), (stdinOpts) => this.closeStdin(pid, stdinOpts), - this.checkHealth + this.checkHealth, + this.connectionConfig.logger ) } catch (err) { cleanup() @@ -479,7 +479,8 @@ export class Commands { undefined, (data, stdinOpts) => this.sendStdin(pid, data, stdinOpts), (stdinOpts) => this.closeStdin(pid, stdinOpts), - this.checkHealth + this.checkHealth, + this.connectionConfig.logger ) } catch (err) { cleanup() diff --git a/packages/js-sdk/src/sandbox/commands/pty.ts b/packages/js-sdk/src/sandbox/commands/pty.ts index 29928a92f3..960bac7b52 100644 --- a/packages/js-sdk/src/sandbox/commands/pty.ts +++ b/packages/js-sdk/src/sandbox/commands/pty.ts @@ -30,10 +30,8 @@ import { handleProcessStartEvent, } from '../../envd/api' -export interface PtyCreateOpts extends Pick< - ConnectionOpts, - 'requestTimeoutMs' | 'signal' -> { +export interface PtyCreateOpts + extends Pick { /** * Number of columns for the PTY. */ @@ -157,7 +155,8 @@ export class Pty { opts.onData, undefined, undefined, - this.checkHealth + this.checkHealth, + this.connectionConfig.logger ) } catch (err) { cleanup() @@ -214,7 +213,8 @@ export class Pty { opts?.onData, undefined, undefined, - this.checkHealth + this.checkHealth, + this.connectionConfig.logger ) } catch (err) { cleanup() diff --git a/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py b/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py index 810c9279e6..6b4dd06189 100644 --- a/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py +++ b/packages/python-sdk/e2b/sandbox_async/commands/command_handle.py @@ -96,6 +96,7 @@ def __init__( Callable[[Optional[float]], Coroutine[Any, Any, None]] ] = None, check_health: Optional[Callable[[], Awaitable[Optional[bool]]]] = None, + *, logger: Optional[logging.Logger] = None, ): self._pid = pid @@ -105,6 +106,7 @@ def __init__( self._check_health = check_health self._events = events self._logger = logger + self._stream_end_logged = False self._stdout_chunks: List[str] = [] self._stderr_chunks: List[str] = [] @@ -147,10 +149,13 @@ def _log_stream_ended(self, reason: str) -> None: The server (envd) only sees that the stream was cancelled, not why; this logs the local cause so the two can be correlated. No-op when no logger - was configured. See e2b-dev/E2B#1877. + was configured. Records at most once per handle so the disconnect() and + reader-task paths cannot emit two contradictory causes for the same + command. """ - if self._logger is None: + if self._logger is None or self._stream_end_logged: return + self._stream_end_logged = True self._logger.info("command stream ended (pid=%s): %s", self._pid, reason) async def _iterate_events( diff --git a/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py b/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py index 4d81cc87d3..700d31eb40 100644 --- a/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py +++ b/packages/python-sdk/e2b/sandbox_sync/commands/command_handle.py @@ -43,6 +43,7 @@ def __init__( ] = None, handle_close_stdin: Optional[Callable[[Optional[float]], None]] = None, check_health: Optional[Callable[[], Optional[bool]]] = None, + *, logger: Optional[logging.Logger] = None, ): self._pid = pid @@ -52,6 +53,7 @@ def __init__( self._check_health = check_health self._events = events self._logger = logger + self._stream_end_logged = False self._stdout_chunks: List[str] = [] self._stderr_chunks: List[str] = [] @@ -76,10 +78,13 @@ def _log_stream_ended(self, reason: str) -> None: The server (envd) only sees that the stream was cancelled, not why; this logs the local cause so the two can be correlated. No-op when no logger - was configured. See e2b-dev/E2B#1877. + was configured. Records at most once per handle so the disconnect() and + generator-close paths cannot emit two contradictory causes for the same + command. """ - if self._logger is None: + if self._logger is None or self._stream_end_logged: return + self._stream_end_logged = True self._logger.info("command stream ended (pid=%s): %s", self._pid, reason) def _flush_decoders( diff --git a/packages/python-sdk/tests/test_command_handle.py b/packages/python-sdk/tests/test_command_handle.py index 6a2f81c1ad..84683778dc 100644 --- a/packages/python-sdk/tests/test_command_handle.py +++ b/packages/python-sdk/tests/test_command_handle.py @@ -1,4 +1,5 @@ import asyncio +import logging from typing import Any, cast import pytest @@ -288,3 +289,98 @@ async def events(): # be flushed to the stdout callback as a replacement character. assert "".join(chunks) == "a�" assert isinstance(handle._iteration_exception, RuntimeError) + + +def _capturing_logger(name: str): + """A real logging.Logger whose INFO messages are captured into a list.""" + messages: list[str] = [] + + class _ListHandler(logging.Handler): + def emit(self, record: logging.LogRecord) -> None: + messages.append(record.getMessage()) + + logger = logging.getLogger(name) + logger.handlers = [_ListHandler()] + logger.setLevel(logging.INFO) + logger.propagate = False + return logger, messages + + +def test_sync_logs_stream_end_cause_on_stream_error(): + def events(): + yield _stdout_event(b"a") + raise RuntimeError("stream died") + + logger, messages = _capturing_logger("e2b.test.sync.err") + handle = CommandHandle( + pid=42, handle_kill=lambda: True, events=events(), logger=logger + ) + + with pytest.raises(RuntimeError): + handle.wait() + + assert len(messages) == 1 + assert "pid=42" in messages[0] + assert "stream error before end event" in messages[0] + assert "RuntimeError" in messages[0] + + +def test_sync_logs_disconnect_cause_once(): + # disconnect() records the cause; the subsequent GeneratorExit path must not + # add a second, contradictory line for the same command (T-62 idempotency). + def events(): + yield _stdout_event(b"a") + yield _end_event() + + logger, messages = _capturing_logger("e2b.test.sync.disc") + handle = CommandHandle( + pid=7, handle_kill=lambda: True, events=events(), logger=logger + ) + handle.disconnect() + + assert len(messages) == 1 + assert "pid=7" in messages[0] + assert "disconnect()" in messages[0] + + +def test_sync_no_log_without_logger(): + # No logger configured -> no logging attribute access, no error, no output. + def events(): + yield _end_event() + + handle = CommandHandle(pid=1, handle_kill=lambda: True, events=events()) + handle.disconnect() # must not raise + + +async def test_async_logs_stream_end_cause_on_stream_error(): + async def events(): + yield _stdout_event(b"a") + raise RuntimeError("stream died") + + logger, messages = _capturing_logger("e2b.test.async.err") + handle = AsyncCommandHandle( + pid=99, handle_kill=_kill, events=events(), logger=logger + ) + await handle._wait + + assert len(messages) == 1 + assert "pid=99" in messages[0] + assert "stream error before end event" in messages[0] + + +async def test_async_logs_disconnect_cause_once(): + events = _AsyncControllableEvents() + logger, messages = _capturing_logger("e2b.test.async.disc") + handle = AsyncCommandHandle( + pid=8, + handle_kill=_kill, + events=cast(Any, events), + logger=logger, + ) + await handle.disconnect() + + # Exactly one cause, even though disconnect() cancels the reader task whose + # own error path would otherwise log a second line (T-62 idempotency). + assert len(messages) == 1 + assert "pid=8" in messages[0] + assert "disconnect()" in messages[0]