diff --git a/crates/apps/spaced/host/cli/src/main.rs b/crates/apps/spaced/host/cli/src/main.rs index 7362548f16..044533798e 100644 --- a/crates/apps/spaced/host/cli/src/main.rs +++ b/crates/apps/spaced/host/cli/src/main.rs @@ -288,7 +288,7 @@ async fn run() -> anyhow::Result<()> { } Commands::Connect { process_id } => { let mut stream = client - .connect_process_stream_with_cursor(process_id, None, None) + .connect_process_stream_with_cursor(process_id, None, None, false) .await?; while let Some(event) = stream.message().await? { print_process_event(event).await?; diff --git a/crates/libs/api/src/routes/public_docs.rs b/crates/libs/api/src/routes/public_docs.rs index eb7a4941d9..167f642dcc 100644 --- a/crates/libs/api/src/routes/public_docs.rs +++ b/crates/libs/api/src/routes/public_docs.rs @@ -71,7 +71,7 @@ fn public_openapi_value() -> Value { let data_plane_events_item = json!({ "get": { "summary": "Stream process output or file-watch events over SSE", - "description": "Streams output from process or file-watch sessions.\n\n### Connect\n\n- Use the session token, not your management API token. Send it in `Authorization: Bearer ...` or `Sec-WebSocket-Protocol`; query-string tokens are rejected.\n- Every frame after `attached` has an increasing SSE `id`.\n\n### Reconnect\n\n- Send the last received `id` as `Last-Event-ID`. The stream resumes live; missed output is not replayed.\n- The first identified frame is `resync_required`, with reason `cursor_replay_unavailable` and id `Last-Event-ID + 1`.\n- Keep output already received. If the process exited while disconnected, reconnecting still reports `process_exited`.\n- For file watches, re-list the watched path after `resync_required` before using new events.", + "description": "Streams output from process or file-watch sessions.\n\n### Connect\n\n- Use the session token, not your management API token. Send it in `Authorization: Bearer ...` or `Sec-WebSocket-Protocol`; query-string tokens are rejected.\n- SSE `id`s increase. Every file-watch frame after `attached` has one. On a process stream only `stdout`, `stderr` and `resync_required` frames do; other frames carry none, so the last `id` received stays the one to resume from.\n- Echo the `id` exactly as received: process stream ids are not consecutive. They stay below 2^53, so a JavaScript `Number` holds them exactly.\n\n### Reconnect\n\n- Send the last received `id` as `Last-Event-ID`. An `id` is only valid for the session whose stream sent it.\n- A process stream resumes with the output after that frame while the sandbox retains it, a bounded amount per process. Without `Last-Event-ID` it starts from the beginning of the output, which can repeat output already received.\n- When the output to resume from is no longer retained, the stream sends `resync_required` with reason `cursor_out_of_window`, then continues with the oldest output still retained (with live output on sandboxes from older templates). When `Last-Event-ID` is past the process's output, it sends the same frame and replays the output from its start. Keep output already received.\n- An `id` that does not resume exactly (one from an earlier SPACE version, one altered in transit, or one sent after the stream replayed the output from its start behind `cursor_out_of_window` or continued with live output) replays the retained output behind `resync_required` with reason `cursor_replay_unavailable`.\n- Every `id` a resumed process stream sends is above `Last-Event-ID`.\n- Process stream ids carry the output position for a process's first 2^33 - 1 output chunks (about 8.6 billion; some 99 days at 1,000 separate writes a second). After that, each resume replays the output still retained behind `resync_required`.\n- If the process exited while disconnected, reconnecting still reports `process_exited`.\n- A file-watch stream resumes live: its first identified frame is `resync_required`, with reason `cursor_replay_unavailable` and id `Last-Event-ID + 1`. Re-list the watched path before using new events.", "responses": { "200": { "description": "Server-sent event stream using DataPlaneServerFrame JSON payloads" }, "401": { "description": "Invalid or expired data-plane token" }, diff --git a/crates/libs/api/src/routes/public_docs/schema_contract.rs b/crates/libs/api/src/routes/public_docs/schema_contract.rs index 5f61b6ead0..01b92e95b1 100644 --- a/crates/libs/api/src/routes/public_docs/schema_contract.rs +++ b/crates/libs/api/src/routes/public_docs/schema_contract.rs @@ -88,7 +88,7 @@ fn openapi_identifier(value: &str) -> String { pub(super) fn insert_command_event_stream_schema(spec: &mut Value) { let response = json!({ - "description": "### Read the stream\n\n- Each SSE event carries one `DataPlaneServerFrame` JSON object. Ignore comment heartbeats.\n- Decode stdout and stderr's `data_base64` using standard base64.\n- Success requires `process_exited` with exit code zero and no error or missing output. HTTP 200 or a closed stream alone is not success.\n\n### Example output\n\nExcerpt, not a complete stream:\n\n```text\nid: 2\nevent: stdout\ndata: {\"type\":\"stdout\",\"seq\":0,\"data_base64\":\"SGVsbG8gZnJvbSBTUEFDRQo=\"}\n\nid: 3\nevent: process_exited\ndata: {\"type\":\"process_exited\",\"process_id\":\"proc_00000000-0000-0000-0000-000000000000\",\"exit_code\":0,\"status\":\"exited\"}\n\n```", + "description": "### Read the stream\n\n- Each SSE event carries one `DataPlaneServerFrame` JSON object. Ignore comment heartbeats.\n- Decode stdout and stderr's `data_base64` using standard base64.\n- Success requires `process_exited` with exit code zero and no error or missing output. HTTP 200 or a closed stream alone is not success.\n\n### Example output\n\nExcerpt, not a complete stream:\n\n```text\nid: 4503599627632640\nevent: stdout\ndata: {\"type\":\"stdout\",\"seq\":1,\"data_base64\":\"SGVsbG8gZnJvbSBTUEFDRQo=\"}\n\nevent: process_exited\ndata: {\"type\":\"process_exited\",\"process_id\":\"proc_00000000-0000-0000-0000-000000000000\",\"exit_code\":0,\"status\":\"exited\"}\n\n```", "content": { "text/event-stream": { "schema": { "type": "string" }, @@ -117,7 +117,7 @@ pub(super) fn insert_command_event_stream_schema(spec: &mut Value) { "name": "Last-Event-ID", "in": "header", "required": false, - "description": "SSE `id` of the last frame received.\n\n- Resumes the live stream; missed output is not replayed.\n- The first identified frame is `resync_required` (`cursor_replay_unavailable`), with id `Last-Event-ID + 1`.\n- Values above the `int64` maximum return 400.", + "description": "SSE `id` of the last frame received.\n\n- Echo the `id` exactly as received, on the same session's stream.\n- A process stream resumes with the output after that frame while it is retained; otherwise `resync_required` precedes the output it continues with: `cursor_out_of_window` when the output is evicted or the `id` is past it, `cursor_replay_unavailable` when the `id` does not resume exactly.\n- A file-watch stream resumes live; its first identified frame is `resync_required` (`cursor_replay_unavailable`), with id `Last-Event-ID + 1`.\n- Values above the `int64` maximum, and process stream values too high to number a later frame above, return 400.", "schema": { "type": "integer", "format": "int64", diff --git a/crates/libs/common/core/src/lib.rs b/crates/libs/common/core/src/lib.rs index bc81f4777f..eb8a59b2b3 100644 --- a/crates/libs/common/core/src/lib.rs +++ b/crates/libs/common/core/src/lib.rs @@ -160,6 +160,29 @@ pub mod spaced { /// as opposed to the sandbox or its runtime being unknown to a hop. pub const GUEST_PATH_NOT_FOUND: &str = "guest-path-not-found"; + /// [`ERROR_REASON_METADATA_KEY`] value of an OUT_OF_RANGE that ends a + /// process output stream whose cursor is past the output the process has + /// written, as opposed to a message too large for a hop to decode. + pub const PROCESS_OUTPUT_CURSOR_AHEAD: &str = "process-output-cursor-ahead"; + + /// [`ERROR_REASON_METADATA_KEY`] value of a RESOURCE_EXHAUSTED that ends a + /// process output stream whose cursor is before the oldest output the + /// guest still retains, as opposed to a hop's refusal or a transport reset + /// with the same code. [`PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY`] says + /// where the retained output starts. + pub const PROCESS_OUTPUT_LAGGED: &str = "process-output-lagged"; + + /// Metadata key, on a [`PROCESS_OUTPUT_LAGGED`] status, of the cursor of + /// the oldest output the guest still retains, in decimal. Absent when the + /// guest no longer holds the process's output at all. + pub const PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY: &str = + "space-process-output-first-sequence"; + + /// Message of the guest's [`PROCESS_OUTPUT_LAGGED`] status. Guests older + /// than that reason send it untagged, so it identifies their lag status. + pub const PROCESS_OUTPUT_LAGGED_MESSAGE: &str = + "process output stream fell behind retained output buffer"; + /// [`ERROR_REASON_METADATA_KEY`] value of a request refused before any of /// its work started: an admission limit, or a guest or registry shutting /// down. This request did nothing, so the caller may retry it, after the diff --git a/crates/libs/data/plane/server/Cargo.toml b/crates/libs/data/plane/server/Cargo.toml index 54cdd3ceb9..52f7a6435b 100644 --- a/crates/libs/data/plane/server/Cargo.toml +++ b/crates/libs/data/plane/server/Cargo.toml @@ -64,6 +64,7 @@ pplx-space-public-api = { workspace = true, features = ["serde"] } pplx-space-sbx-mgr-client = { workspace = true } [dev-dependencies] +pplx-space-metrics = { workspace = true, features = ["test-capture"] } tokio = { workspace = true, features = ["test-util"] } pplx-space-test-env = { workspace = true } aws-lc-rs = { workspace = true } diff --git a/crates/libs/data/plane/server/src/ecw_connect/tests.rs b/crates/libs/data/plane/server/src/ecw_connect/tests.rs index 888afdcabb..540f683052 100644 --- a/crates/libs/data/plane/server/src/ecw_connect/tests.rs +++ b/crates/libs/data/plane/server/src/ecw_connect/tests.rs @@ -43,7 +43,9 @@ fn process_events_encode_connect_wire_shape() { process_id: "proc-1".to_string(), pid: None, event: Some(spaced_process_event::Event::Connected( - SpacedProcessConnected {}, + SpacedProcessConnected { + output_cursor: None, + }, )), }, true, diff --git a/crates/libs/data/plane/server/src/ecw_process.rs b/crates/libs/data/plane/server/src/ecw_process.rs index 7b6d0cbbe2..46fb18dd18 100644 --- a/crates/libs/data/plane/server/src/ecw_process.rs +++ b/crates/libs/data/plane/server/src/ecw_process.rs @@ -406,6 +406,7 @@ pub(super) async fn process_connect( process_id, timeout, output_cursor: None, + resume_from_oldest_retained: false, }), }; let route_state = state.clone(); diff --git a/crates/libs/data/plane/server/src/ecw_process/stream.rs b/crates/libs/data/plane/server/src/ecw_process/stream.rs index a6c228fecc..54cbec9159 100644 --- a/crates/libs/data/plane/server/src/ecw_process/stream.rs +++ b/crates/libs/data/plane/server/src/ecw_process/stream.rs @@ -449,6 +449,7 @@ pub(super) fn build_process_start_resume_request( .as_ref() .and_then(|operation| operation.timeout), output_cursor: Some(output_cursor), + resume_from_oldest_retained: false, }), } } diff --git a/crates/libs/data/plane/server/src/ecw_process/tests.rs b/crates/libs/data/plane/server/src/ecw_process/tests.rs index e335e9e72a..9c73fd2e2f 100644 --- a/crates/libs/data/plane/server/src/ecw_process/tests.rs +++ b/crates/libs/data/plane/server/src/ecw_process/tests.rs @@ -73,7 +73,9 @@ fn connected_process_event(process_id: &ProcessId) -> SpacedProcessEvent { process_id: process_id.to_string(), pid: Some(123), event: Some(spaced_ops::process_event::Event::Connected( - spaced_ops::ProcessConnected {}, + spaced_ops::ProcessConnected { + output_cursor: None, + }, )), } } diff --git a/crates/libs/data/plane/server/src/native/auth.rs b/crates/libs/data/plane/server/src/native/auth.rs index b39119ab76..1969f23a28 100644 --- a/crates/libs/data/plane/server/src/native/auth.rs +++ b/crates/libs/data/plane/server/src/native/auth.rs @@ -96,9 +96,10 @@ pub(crate) fn reject_query_tokens(query: Option<&str>) -> Result<(), AttachError } /// Largest `Last-Event-ID` a client may resume from. It is the OpenAPI -/// parameter's `int64` maximum, and it leaves room for the `last + 1` id the -/// resume contract promises, so the stream can never saturate onto an id the -/// client already acknowledged. +/// parameter's `int64` maximum, and it leaves room for the `last + 1` id a +/// file-watch resume sends, so that stream can never saturate onto an id the +/// client already acknowledged. Process streams bound their ids by their own +/// layout (see `ProcessEventId`) and refuse a higher id themselves. pub(crate) const MAX_LAST_EVENT_ID: u64 = i64::MAX as u64; pub(crate) fn last_event_id(headers: &HeaderMap) -> Result, &'static str> { diff --git a/crates/libs/data/plane/server/src/native/sse.rs b/crates/libs/data/plane/server/src/native/sse.rs index 73affd9fc9..8aade207f5 100644 --- a/crates/libs/data/plane/server/src/native/sse.rs +++ b/crates/libs/data/plane/server/src/native/sse.rs @@ -94,6 +94,21 @@ pub(crate) async fn session_events( }; let stream_state = match attached.kind { SessionKind::Process => { + // Only a forged id leaves no later id to number the stream with. + let Some(replay) = ProcessReplayState::load(last_event_id) else { + pplx_space_metrics::data_plane::attach( + session_id.kind().as_str(), + "invalid_last_event_id", + ); + return data_plane_http_error( + StatusCode::BAD_REQUEST, + DataPlaneHttpErrorCode::InvalidRequest, + "last-event-id is past every event id this stream can send", + false, + ResponseOrigin::Client, + ResponseKind::Validation, + ); + }; let start_permit = match state.native_sessions.try_acquire(session_id, attached.kind) { Ok(permit) => permit, Err(()) => { @@ -146,7 +161,7 @@ pub(crate) async fn session_events( state, session_id, attached, - last_event_id, + replay, input, stream_permit, start_permit, @@ -255,11 +270,28 @@ pub(crate) struct ProcessSseState { attached: AttachedSession, client: WorkerApiClient>, stream: tonic::Streaming, - event_seq: u64, + event_id: ProcessEventId, + /// The guest output journal position the client has received output up + /// to, or `None` once the stream follows the live tail from an unknown one. backend_output_cursor: Option, + /// The `seq` of the last output frame sent. + output_seq: u64, process_id: Option, process_bound: bool, binding: Option, + /// This response has sent `process_started`; a reopened backend stream + /// reports the start again, and the client already has it. + started_sent: bool, + /// `resync_required(cursor_out_of_window)` was sent and no output has + /// followed it, so another gap before any output is the same one. + gap_reported: bool, + /// The stream moved to the oldest output the guest retains after an + /// eviction, and no output has followed. Falling behind again before any + /// does is a race the stream keeps losing, so it follows the live tail. + at_oldest_retained: bool, + /// Backend reopens after an output window miss since the last output or + /// exit, capped at [`PROCESS_OUTPUT_WINDOW_REOPENS_WITHOUT_PROGRESS`]. + window_reopens_without_progress: u32, revocation_tick: tokio::time::Interval, pending: VecDeque, finished: bool, @@ -268,21 +300,22 @@ pub(crate) struct ProcessSseState { _stream_permit: AttachedStreamPermit, } -pub(crate) struct ProcessReplayState { - pub(crate) event_seq: u64, - pub(crate) backend_output_cursor: Option, - pub(crate) pending: VecDeque, +struct ProcessReplayState { + event_id: ProcessEventId, + backend_output_cursor: u64, + /// Sent with `event_id` before any live event. Counted only once the + /// stream opens, so a refused attach does not count a frame never sent. + resync: Option, } /// What a `Last-Event-ID` resume produces before any live event: the next SSE /// id and the `resync_required(cursor_replay_unavailable)` frame that carries /// it. `None` when the client did not send a cursor. /// -/// This is the public reconnection contract for both process and file-watch -/// sessions: the data plane resumes the *live* stream at `last + 1` and does -/// not replay what was missed, because it does not map SSE ids onto the guest -/// output journal. Keep this the single place that decides so the docs, the -/// conformance smoke, and both session kinds cannot drift. +/// This is the reconnection contract for file-watch sessions: the data plane +/// resumes the *live* stream at `last + 1` and does not replay what was +/// missed. Keep this the single place that decides so the docs and the +/// conformance smoke cannot drift. /// /// `last + 1` cannot overflow: the request boundary rejects cursors above /// [`auth::MAX_LAST_EVENT_ID`] (`i64::MAX`) with a 400, so a resumed stream @@ -299,57 +332,228 @@ pub(crate) fn resume_resync_frame( )) } -impl ProcessReplayState { - pub(crate) fn load(session_id: DataPlaneSessionId, last_event_id: Option) -> Self { - let Some((event_seq, frame)) = - resume_resync_frame(session_id.kind().as_str(), last_event_id) - else { - return Self { - event_seq: 0, - backend_output_cursor: None, - pending: VecDeque::new(), - }; +/// A process stream's SSE id, which a resume decodes to recover the guest +/// output position to continue from, so any replica can serve it. +/// +/// On the wire, bit 52 tags the id: no frame counter an earlier data plane +/// issued reaches it, and every id stays below 2^53, so a client that parses +/// it into a double still holds it exactly. The low +/// [`PROCESS_EVENT_ID_GUARD_BITS`] bits are zero, so an id that a data plane +/// without this encoding counted on from by `+1` fails to decode rather than +/// decoding to the wrong position, unless it counted a multiple of 2^16 +/// frames. Above them come a frame counter and a position field, whose top +/// bit marks a block of ids without a position. Those blocks sort above every +/// position, so a stream that loses its position keeps its ids increasing. +#[derive(Clone, Copy, Debug, Eq, PartialEq)] +pub(crate) enum ProcessEventId { + /// The client has received the guest's output up to `position`. + Position { position: u64, frame: u64 }, + /// The id carries no position; a resume from it cannot be exact. + Unknown { block: u64, frame: u64 }, +} + +const PROCESS_EVENT_ID_TAG_BIT: u32 = 52; +const PROCESS_EVENT_ID_TAG: u64 = 1 << PROCESS_EVENT_ID_TAG_BIT; +const PROCESS_EVENT_ID_GUARD_BITS: u32 = 16; +/// Identified frames at one position: output moves it, and so does every gap +/// that keeps it, so a position has at most two ids, the unsent +/// [`ProcessEventId::START`] and the `resync_required` that starts a replay +/// for an id without a position (see [`process_frame_has_event_id`]). The +/// rest of the 36 bits below the tag go to positions: ids carry one for a +/// process's first 2^33 - 1 outputs. +const PROCESS_EVENT_ID_FRAME_BITS: u32 = 2; +const PROCESS_EVENT_ID_FIELD_SHIFT: u32 = PROCESS_EVENT_ID_GUARD_BITS + PROCESS_EVENT_ID_FRAME_BITS; +const PROCESS_EVENT_ID_FIELD_BITS: u32 = PROCESS_EVENT_ID_TAG_BIT - PROCESS_EVENT_ID_FIELD_SHIFT; +const PROCESS_EVENT_ID_FIELD_MASK: u64 = (1 << PROCESS_EVENT_ID_FIELD_BITS) - 1; +const PROCESS_EVENT_ID_MAX_FRAME: u64 = (1 << PROCESS_EVENT_ID_FRAME_BITS) - 1; +const PROCESS_EVENT_ID_UNKNOWN: u64 = 1 << (PROCESS_EVENT_ID_FIELD_BITS - 1); +const PROCESS_EVENT_ID_MAX_POSITION: u64 = PROCESS_EVENT_ID_UNKNOWN - 1; +/// The highest block a resumed stream starts in: half the blocks, so every +/// stream has at least 2^(field + frame - 2) = 2^34 ids left to send. +const PROCESS_EVENT_ID_MAX_RESUME_BLOCK: u64 = 1 << (PROCESS_EVENT_ID_FIELD_BITS - 2); + +const _: () = { + // The field holds the no-position marker and at least two resume blocks, + // and an id, whose bits all lie at or below the tag, is below 2^53. + assert!(PROCESS_EVENT_ID_FIELD_BITS > 2); + assert!(PROCESS_EVENT_ID_TAG_BIT < 53); + // A stream that starts in the highest resume block has blocks left. They + // are finite: one that sent 2^34 ids without a position would wrap. + assert!(PROCESS_EVENT_ID_MAX_RESUME_BLOCK < PROCESS_EVENT_ID_MAX_POSITION); +}; + +impl ProcessEventId { + /// Precedes the first frame of a stream that starts at the beginning of + /// the guest's output. Never sent. + pub(crate) const START: Self = Self::Position { + position: 0, + frame: 0, + }; + + /// Precedes the first frame of a stream that replays the output from its + /// start for a client whose `Last-Event-ID` carries no position, so that + /// every id it sends is above that one. Never sent. A tagged id gets a + /// fresh block without a position: positions from the start would sort + /// below it. `None` for an id at or above 2^53, or in a block from + /// [`PROCESS_EVENT_ID_MAX_RESUME_BLOCK`] on, which only a forged one is, so + /// a stream never runs out of blocks. + fn first_after(last_event_id: u64) -> Option { + if last_event_id < PROCESS_EVENT_ID_TAG { + return Some(Self::START); + } + if last_event_id >> PROCESS_EVENT_ID_TAG_BIT != 1 { + return None; + } + let first_unknown = Self::Unknown { block: 0, frame: 0 }.encode(); + let block = if last_event_id < first_unknown { + 0 + } else { + let field = + (last_event_id >> PROCESS_EVENT_ID_FIELD_SHIFT) & PROCESS_EVENT_ID_FIELD_MASK; + (field & !PROCESS_EVENT_ID_UNKNOWN) + 1 }; + (block <= PROCESS_EVENT_ID_MAX_RESUME_BLOCK).then_some(Self::Unknown { block, frame: 0 }) + } - let mut pending = VecDeque::new(); - pending.push_back(sse_event_from_frame(&frame, Some(event_seq))); + pub(crate) fn encode(self) -> u64 { + let (field, frame) = match self { + Self::Position { position, frame } => { + debug_assert!(position <= PROCESS_EVENT_ID_MAX_POSITION, "{self:?}"); + (position, frame) + } + Self::Unknown { block, frame } => { + debug_assert!(block <= PROCESS_EVENT_ID_MAX_POSITION, "{self:?}"); + (PROCESS_EVENT_ID_UNKNOWN | block, frame) + } + }; + debug_assert!(frame <= PROCESS_EVENT_ID_MAX_FRAME, "{self:?}"); + PROCESS_EVENT_ID_TAG + | field << PROCESS_EVENT_ID_FIELD_SHIFT + | frame << PROCESS_EVENT_ID_GUARD_BITS + } - Self { - event_seq, - backend_output_cursor: None, - pending, + /// `None` for an id this encoding did not produce. + fn decode(id: u64) -> Option { + if id >> PROCESS_EVENT_ID_TAG_BIT != 1 || id & ((1 << PROCESS_EVENT_ID_GUARD_BITS) - 1) != 0 + { + return None; + } + let frame = (id >> PROCESS_EVENT_ID_GUARD_BITS) & PROCESS_EVENT_ID_MAX_FRAME; + let field = (id >> PROCESS_EVENT_ID_FIELD_SHIFT) & PROCESS_EVENT_ID_FIELD_MASK; + Some(if field & PROCESS_EVENT_ID_UNKNOWN == 0 { + Self::Position { + position: field, + frame, + } + } else { + Self::Unknown { + block: field & !PROCESS_EVENT_ID_UNKNOWN, + frame, + } + }) + } + + /// The id of the next frame, once the client has received output up to + /// `position`. Greater than this one while the blocks without a position + /// last: a stream has at least 2^34 ids after the block it starts in. + fn next(self, position: Option) -> Self { + match self { + Self::Position { + position: last, + frame, + } => match position { + Some(position) if position == last && frame < PROCESS_EVENT_ID_MAX_FRAME => { + Self::Position { + position, + frame: frame + 1, + } + } + Some(position) if position > last && position <= PROCESS_EVENT_ID_MAX_POSITION => { + Self::Position { position, frame: 0 } + } + // The position is unknown, beyond the field, behind this one, + // or out of frames: no later id of this stream carries one, and + // a resume from them replays behind `resync_required`. + _ => Self::Unknown { block: 0, frame: 0 }, + }, + Self::Unknown { block, frame } if frame < PROCESS_EVENT_ID_MAX_FRAME => Self::Unknown { + block, + frame: frame + 1, + }, + // A resumed stream starts at most at block + // `PROCESS_EVENT_ID_MAX_RESUME_BLOCK` (`first_after`), and would + // need 2^34 frames to exhaust the rest; past them this wraps. + Self::Unknown { block, .. } => Self::Unknown { + block: block + 1, + frame: 0, + }, } } } +impl ProcessReplayState { + /// Where a process stream starts in the guest's output journal: a fresh + /// attach replays the retained output from the start, and a resume + /// continues from the position its `Last-Event-ID` carries. A resume from + /// an id without one also replays from the start, behind + /// `resync_required(cursor_replay_unavailable)`, as output the client + /// already has may repeat. Every id the stream sends is above + /// `Last-Event-ID`; `None` when no id can be (see + /// [`ProcessEventId::first_after`]). + fn load(last_event_id: Option) -> Option { + let Some(last_event_id) = last_event_id else { + return Some(Self { + event_id: ProcessEventId::START, + backend_output_cursor: 0, + resync: None, + }); + }; + if let Some(event_id @ ProcessEventId::Position { position, .. }) = + ProcessEventId::decode(last_event_id) + { + return Some(Self { + event_id, + backend_output_cursor: position, + resync: None, + }); + } + Some(Self { + event_id: ProcessEventId::first_after(last_event_id)?.next(Some(0)), + backend_output_cursor: 0, + resync: Some(DataPlaneResyncReason::CursorReplayUnavailable), + }) + } +} + impl ProcessSseState { async fn new( state: DataPlaneState, session_id: DataPlaneSessionId, mut attached: AttachedSession, - last_event_id: Option, + replay: ProcessReplayState, input: ProcessInput, stream_permit: AttachedStreamPermit, start_permit: Option, ) -> Result { - let replay = ProcessReplayState::load(session_id, last_event_id); let (client, stream) = open_native_process_stream( &state, session_id, &mut attached, - replay.backend_output_cursor, + Some(replay.backend_output_cursor), input, ) .await?; let mut pending = VecDeque::new(); pending.push_back(sse_event_from_frame(&attached_frame(&attached), None)); - pending.extend(replay.pending); + if let Some(reason) = replay.resync { + pending.push_back(sse_event_from_frame( + &resync_required_frame(session_id.kind().as_str(), reason), + Some(replay.event_id.encode()), + )); + } let process_id = attached.backend_process_id.clone(); let process_bound = process_id.is_some(); let revocation_tick = revocation_check_interval(&state); - let backend_output_cursor = replay - .backend_output_cursor - .or_else(|| attached.backend_process_id.is_none().then_some(0)); let shutdown_token = state.stream_shutdown_token.child_token(); Ok(Self { @@ -358,11 +562,16 @@ impl ProcessSseState { attached, client, stream, - event_seq: replay.event_seq, - backend_output_cursor, + event_id: replay.event_id, + backend_output_cursor: Some(replay.backend_output_cursor), + output_seq: replay.backend_output_cursor, process_id, process_bound, binding: None, + started_sent: false, + gap_reported: false, + at_oldest_retained: false, + window_reopens_without_progress: 0, revocation_tick, pending, finished: false, @@ -372,10 +581,48 @@ impl ProcessSseState { }) } + /// Counts the client's output from the start of the guest's again, after + /// the position it resumed from turned out not to be in it. The ids sent + /// after this carry no position: they must stay above the ones already + /// sent, which positions from the start would sort below. + fn restart_from_output_start(&mut self, cause: &'static str) { + self.continue_after_gap(Some(0), cause); + } + + /// Continues the client's output at `position` of the guest's, or at the + /// live tail when `None`, behind `resync_required(cursor_out_of_window)`: + /// the output between what the client has and `position` is not sent. + fn continue_after_gap(&mut self, position: Option, cause: &'static str) { + tracing::info!( + cause, + from = ?self.backend_output_cursor, + to = ?position, + "process event stream continues after an output gap" + ); + self.backend_output_cursor = position; + if let Some(position) = position { + self.output_seq = position; + } + if !self.gap_reported { + self.gap_reported = true; + self.push_frame(resync_required_frame( + self.session_id.kind().as_str(), + DataPlaneResyncReason::CursorOutOfWindow, + )); + } + } + fn push_frame(&mut self, frame: DataPlaneServerFrame) { - self.event_seq = self.event_seq.saturating_add(1); - self.pending - .push_back(sse_event_from_frame(&frame, Some(self.event_seq))); + match frame { + DataPlaneServerFrame::ProcessStarted { .. } if self.started_sent => return, + DataPlaneServerFrame::ProcessStarted { .. } => self.started_sent = true, + _ => {} + } + let id = process_frame_has_event_id(&frame).then(|| { + self.event_id = self.event_id.next(self.backend_output_cursor); + self.event_id.encode() + }); + self.pending.push_back(sse_event_from_frame(&frame, id)); } fn finish(&mut self, result: &'static str) { @@ -399,6 +646,151 @@ impl ProcessSseState { retryable: true, }); } + + /// Continues at `start`, where the guest reports a backend stream starts: + /// past the client's position when the output there was evicted. The guest + /// chose it under the lock that makes the stream its primary reader, so + /// unless another reader holds that place, the output there stays until + /// the stream reads it. + fn continue_at_reported_start(&mut self, start: u64) { + if self + .backend_output_cursor + .is_some_and(|cursor| start > cursor) + { + self.continue_after_gap(Some(start), "output_evicted"); + self.at_oldest_retained = true; + } + } + + /// Reopens the backend stream after the guest refused its cursor as + /// outside the retained output, behind one + /// `resync_required(cursor_out_of_window)` for the gap: from the start of + /// the output when the cursor was past its end, and from the oldest output + /// the guest still retains when it reports it. The stream follows the live + /// tail instead when the guest does not report it, or when the stream + /// already moved there and fell behind again before any output. After + /// [`PROCESS_OUTPUT_WINDOW_REOPENS_WITHOUT_PROGRESS`] reopens, a cursor + /// past the output, or a live tail that falls behind, ends the stream. + async fn reopen_after_window_miss(&mut self, status: tonic::Status, miss: OutputWindowMiss) { + let Some(process_id) = self.process_id.clone() else { + self.finish_with_error(StreamBridgeError::BackendStatus(status)); + return; + }; + let out_of_reopens = + self.window_reopens_without_progress >= PROCESS_OUTPUT_WINDOW_REOPENS_WITHOUT_PROGRESS; + match (miss, self.backend_output_cursor) { + // Only a position the client resumed from can be past the output. + (OutputWindowMiss::CursorAhead, Some(cursor)) if cursor > 0 && !out_of_reopens => { + self.restart_from_output_start("cursor_ahead"); + } + ( + OutputWindowMiss::Evicted { + first_retained: Some(first), + }, + Some(cursor), + ) if first > cursor && !self.at_oldest_retained => { + self.continue_after_gap(Some(first), "output_evicted"); + self.at_oldest_retained = true; + } + (OutputWindowMiss::Evicted { .. }, Some(_)) => { + self.continue_after_gap(None, "output_evicted"); + } + (OutputWindowMiss::Evicted { .. }, None) if !out_of_reopens => { + self.continue_after_gap(None, "output_evicted"); + } + _ => { + self.finish_with_error(StreamBridgeError::BackendStatus(status)); + return; + } + } + self.window_reopens_without_progress += 1; + match connect_process_stream( + &mut self.client, + &self.attached.sandbox_id, + &process_id, + self.backend_output_cursor, + self.attached.space_api_route_token.as_ref(), + ) + .await + { + Ok(stream) => self.stream = stream, + // The route token may have expired since the stream opened. + Err(StreamBridgeError::BackendStatus(status)) if is_backend_reconnectable(&status) => { + self.reconnect_backend(status).await; + } + Err(error) => self.finish_with_error(error), + } + } + + /// Re-resolves the route after the backend stream failed with `status` + /// and reopens it at the output position the client has reached. + async fn reconnect_backend(&mut self, status: tonic::Status) { + let Some(current_process_id) = self.process_id.clone() else { + self.finish_with_error(StreamBridgeError::BackendStatus(status)); + return; + }; + let current_generation = self.attached.route_generation; + let (refreshed, refresh_dimension) = + match refresh_native_stream_route(&self.state, &self.attached, &status).await { + Ok(refreshed) => refreshed, + Err(error) => { + self.finish_with_error(error); + return; + } + }; + let reason = + reconnect_reason_for_route_change(current_generation, refreshed.route_generation); + record_backend_channel_reset(self.session_id.kind().as_str(), &reason); + self.push_frame(DataPlaneServerFrame::BackendReconnecting { + reason: reason.clone(), + route_generation: current_generation, + }); + if let Err(error) = + record_session_reconnect(&self.state, self.session_id, reason, current_generation).await + { + self.finish_with_error(error); + return; + } + let reopened = async { + let channel = self + .state + .backend_channels + .channel(&refreshed.backend_endpoint, self.session_id) + .await?; + let mut client = WorkerApiClient::new(wrap_grpc_client_channel(channel)); + let stream = connect_process_stream( + &mut client, + &refreshed.sandbox_id, + ¤t_process_id, + self.backend_output_cursor, + refreshed.space_api_route_token.as_ref(), + ) + .await?; + Ok((client, stream)) + } + .await; + match finish_native_stream_refresh(refresh_dimension, reopened) { + Ok((client, stream)) => { + self.client = client; + self.stream = stream; + self.push_frame(DataPlaneServerFrame::BackendReconnected { + route_generation: refreshed.route_generation, + current_node_id: refreshed.current_node_id.to_string(), + }); + // From a known position the reopened stream continues where + // this one stopped; only one that follows the live tail can + // skip output. + if self.backend_output_cursor.is_none() { + self.push_frame(resync_required_frame( + self.session_id.kind().as_str(), + DataPlaneResyncReason::ProcessStreamReconnected, + )); + } + self.attached = refreshed; + } + Err(error) => self.finish_with_error(error), + } + } } impl Drop for ProcessSseState { @@ -496,6 +888,16 @@ async fn next_process_sse_frame(state: &mut ProcessSseState) -> Option { }; state.process_id = Some(event_process_id.clone()); if !state.process_bound { + if matches!( + event.event, + Some(spaced_process_event::Event::Started(_)) + ) && state.backend_output_cursor != Some(0) + { + // This attach started the process, so its + // output begins here: the position the + // client resumed from was another's. + state.restart_from_output_start("foreign_last_event_id"); + } state.process_bound = true; state.binding = Some(PendingProcessBinding::spawn( &state.state, @@ -505,7 +907,13 @@ async fn next_process_sse_frame(state: &mut ProcessSseState) -> Option { )); } } - let mut output_seq = state.backend_output_cursor.unwrap_or_default(); + let reported_start = match &event.event { + Some(spaced_process_event::Event::Connected(connected)) => { + connected.output_cursor + } + _ => None, + }; + let mut output_seq = state.output_seq; let batch = process_event_frames(event, &mut output_seq); if batch .frames @@ -520,12 +928,18 @@ async fn next_process_sse_frame(state: &mut ProcessSseState) -> Option { for frame in batch.frames { let exited = matches!(frame, DataPlaneServerFrame::ProcessExited { .. }); - let advances_backend_cursor = - process_frame_advances_backend_cursor(&frame); - state.push_frame(frame); - if advances_backend_cursor { - state.backend_output_cursor = Some(output_seq); + if process_frame_advances_backend_cursor(&frame) { + state.output_seq = output_seq; + if let Some(cursor) = state.backend_output_cursor.as_mut() { + *cursor = output_seq; + } + } + if process_frame_advances_backend_cursor(&frame) || exited { + state.gap_reported = false; + state.at_oldest_retained = false; + state.window_reopens_without_progress = 0; } + state.push_frame(frame); if exited { state.push_frame(DataPlaneServerFrame::Closed { reason: StreamCloseReason::BackendClosed, @@ -533,92 +947,28 @@ async fn next_process_sse_frame(state: &mut ProcessSseState) -> Option { state.finish("backend_closed"); } } + if let Some(start) = reported_start { + state.continue_at_reported_start(start); + } if let Some(event) = state.pending.pop_front() { return Some(event); } } - Err(status) - if status.code() == tonic::Code::Unavailable - || is_refreshable_route_identity_rejection(&status) => - { - let Some(current_process_id) = state.process_id.clone() else { + Err(status) => { + if let Some(miss) = output_window_miss(&status) { + state.reopen_after_window_miss(status, miss).await; + } else if is_backend_reconnectable(&status) { + state.reconnect_backend(status).await; + } else { state.finish_with_error(StreamBridgeError::BackendStatus(status)); - return state.pending.pop_front(); - }; - let current_generation = state.attached.route_generation; - let (refreshed, refresh_dimension) = - match refresh_native_stream_route( - &state.state, - &state.attached, - &status, - ) - .await - { - Ok(refreshed) => refreshed, - Err(error) => { - state.finish_with_error(error); - return state.pending.pop_front(); - } - }; - let reason = reconnect_reason_for_route_change( - current_generation, - refreshed.route_generation, - ); - record_backend_channel_reset(state.session_id.kind().as_str(), &reason); - state.push_frame(DataPlaneServerFrame::BackendReconnecting { - reason: reason.clone(), - route_generation: current_generation, - }); - if let Err(error) = record_session_reconnect( - &state.state, - state.session_id, - reason, - current_generation, - ) - .await - { - state.finish_with_error(error); - return state.pending.pop_front(); } - let reopened = async { - let channel = state - .state - .backend_channels - .channel(&refreshed.backend_endpoint, state.session_id).await?; - let mut client = - WorkerApiClient::new(wrap_grpc_client_channel(channel)); - let stream = connect_process_stream( - &mut client, - &refreshed.sandbox_id, - ¤t_process_id, - state.backend_output_cursor, - refreshed.space_api_route_token.as_ref(), - ) - .await?; - Ok((client, stream)) + // A reopen after a gap already reported sends nothing. + if let Some(event) = state.pending.pop_front() { + return Some(event); } - .await; - match finish_native_stream_refresh(refresh_dimension, reopened) { - Ok((client, stream)) => { - state.client = client; - state.stream = stream; - state.push_frame(DataPlaneServerFrame::BackendReconnected { - route_generation: refreshed.route_generation, - current_node_id: refreshed.current_node_id.to_string(), - }); - state.push_frame(resync_required_frame( - state.session_id.kind().as_str(), - DataPlaneResyncReason::ProcessStreamReconnected, - )); - state.attached = refreshed; - } - Err(error) => state.finish_with_error(error), + if state.finished { + return None; } - return state.pending.pop_front(); - } - Err(status) => { - state.finish_with_error(StreamBridgeError::BackendStatus(status)); - return state.pending.pop_front(); } } } @@ -626,6 +976,82 @@ async fn next_process_sse_frame(state: &mut ProcessSseState) -> Option { } } +/// Whether a process stream frame carries an SSE id: only one that moves the +/// client's position does. That is output, and `resync_required`, which +/// acknowledges a gap. After evicted output the stream keeps its position, at +/// the oldest output retained, so a resume from that id continues past the +/// gap without reporting it again. After a restart from the start of the +/// output (a cursor past it, a foreign id) or a move to the live tail, the +/// ids carry no position, and a resume from them replays behind +/// `resync_required`. Every other frame (`process_started`, `process_exited`, +/// a backend reconnect's, `error`, `closed`) leaves the client's last id +/// unchanged, so resumes and reconnects against an idle process spend no +/// frames of the [`ProcessEventId`] at its position. +fn process_frame_has_event_id(frame: &DataPlaneServerFrame) -> bool { + process_frame_advances_backend_cursor(frame) + || matches!(frame, DataPlaneServerFrame::ResyncRequired { .. }) +} + +/// Backend reopens after an output window miss, without output or an exit +/// in between, after which a cursor past the output, or a live tail that +/// falls behind, ends the stream with an error; evicted output still +/// continues at the live tail. A cursor past the output restarts at the +/// start, which a guest may in turn report as evicted, so two in a row are +/// expected. +const PROCESS_OUTPUT_WINDOW_REOPENS_WITHOUT_PROGRESS: u32 = 3; + +/// Why the guest ended a process stream because its cursor is outside the +/// output it retains. +#[derive(Clone, Copy, Debug, Eq, PartialEq)] +enum OutputWindowMiss { + /// The cursor is past the output the process has written. + CursorAhead, + /// The output at the cursor was evicted. `first_retained` is the cursor + /// of the oldest output the guest still retains, when it reports one. + Evicted { first_retained: Option }, +} + +/// The window miss a backend stream status reports: an OUT_OF_RANGE or a +/// RESOURCE_EXHAUSTED the guest tagged as one, or, from a guest older than +/// those tags, a RESOURCE_EXHAUSTED with its lag message. Other statuses with +/// these codes (a hop's refusal of an oversized chunk, an HTTP/2 reset) are +/// not misses. +fn output_window_miss(status: &tonic::Status) -> Option { + use pplx_space_common_core::spaced; + let metadata = status.metadata(); + let reason = metadata + .get(spaced::ERROR_REASON_METADATA_KEY) + .and_then(|value| value.to_str().ok()); + match (status.code(), reason) { + (tonic::Code::OutOfRange, Some(spaced::PROCESS_OUTPUT_CURSOR_AHEAD)) => { + Some(OutputWindowMiss::CursorAhead) + } + (tonic::Code::ResourceExhausted, Some(spaced::PROCESS_OUTPUT_LAGGED)) => { + Some(OutputWindowMiss::Evicted { + first_retained: metadata + .get(spaced::PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY) + .and_then(|value| value.to_str().ok()) + .and_then(|value| value.parse().ok()), + }) + } + (tonic::Code::ResourceExhausted, None) + if status.message() == spaced::PROCESS_OUTPUT_LAGGED_MESSAGE => + { + Some(OutputWindowMiss::Evicted { + first_retained: None, + }) + } + _ => None, + } +} + +/// Whether a backend stream that failed with `status` may be reopened after +/// re-resolving its route: the backend is unavailable, or it rejected the +/// route's identity as one a refresh replaces. +fn is_backend_reconnectable(status: &tonic::Status) -> bool { + status.code() == tonic::Code::Unavailable || is_refreshable_route_identity_rejection(status) +} + pub(crate) struct FileWatchSseState { state: DataPlaneState, session_id: DataPlaneSessionId, @@ -881,3 +1307,6 @@ async fn next_file_watch_sse_frame(state: &mut FileWatchSseState) -> Option [u64; 3] { + [ + PROCESS_EVENT_ID_TAG - 1, + ProcessEventId::Position { + position: PROCESS_EVENT_ID_MAX_POSITION, + frame: PROCESS_EVENT_ID_MAX_FRAME, + } + .encode(), + ProcessEventId::Unknown { block: 0, frame: 0 }.encode() - 1, + ] +} + +/// A fresh attach replays the guest journal from its start, and a resume +/// continues from the output position its id carries. An id without one, +/// including every id an earlier data plane issued, also replays from the +/// start, behind `resync_required`. +#[test] +fn process_sse_resume_starts_at_the_journal_position_its_id_carries() { + let fresh = ProcessReplayState::load(None).unwrap(); + assert_eq!(fresh.event_id, ProcessEventId::START); + assert_eq!(fresh.backend_output_cursor, 0); + assert_eq!(fresh.resync, None); + + for carried in [ + ProcessEventId::Position { + position: 3, + frame: 2, + }, + ProcessEventId::Position { + position: PROCESS_EVENT_ID_MAX_POSITION, + frame: PROCESS_EVENT_ID_MAX_FRAME, + }, + ] { + let resumed = ProcessReplayState::load(Some(carried.encode())).unwrap(); + assert_eq!(resumed.event_id, carried); + let ProcessEventId::Position { position, .. } = carried else { + unreachable!() + }; + assert_eq!(resumed.backend_output_cursor, position); + assert_eq!(resumed.resync, None); + } + + // Earlier data planes count frames from 1, and one that counted on from a + // tagged id fails its guard. Whatever the id, every id the replay sends + // is above it. + let last_accepted_block = ProcessEventId::Unknown { + block: PROCESS_EVENT_ID_MAX_RESUME_BLOCK - 1, + frame: PROCESS_EVENT_ID_MAX_FRAME, + } + .encode(); + for last_event_id in [ + 0, + 41, + layout_edges()[0], + layout_edges()[1] + 1, + layout_edges()[2], + ProcessEventId::Position { + position: 3, + frame: 2, + } + .encode() + + 1, + ProcessEventId::Unknown { block: 4, frame: 1 }.encode(), + ProcessEventId::Unknown { block: 4, frame: 1 }.encode() + 1, + last_accepted_block, + last_accepted_block + (1 << PROCESS_EVENT_ID_GUARD_BITS) - 1, + ] { + let replay = ProcessReplayState::load(Some(last_event_id)).unwrap(); + assert_eq!(replay.backend_output_cursor, 0, "{last_event_id}"); + assert_eq!( + replay.resync, + Some(DataPlaneResyncReason::CursorReplayUnavailable), + "{last_event_id}" + ); + assert!(replay.event_id.encode() > last_event_id, "{last_event_id}"); + let mut id = replay.event_id; + for position in [Some(0), Some(1), None, Some(2)] { + id = id.next(position); + assert!(id.encode() > last_event_id, "{last_event_id}"); + } + } + + // An id this close to the end, or past it, leaves a stream too few ids + // to send. + for forged in [ + ProcessEventId::Unknown { + block: PROCESS_EVENT_ID_MAX_RESUME_BLOCK, + frame: 0, + } + .encode(), + (1 << 53) - 1, + 1 << 53, + 1 << 62, + MAX_LAST_EVENT_ID, + ] { + assert!(ProcessReplayState::load(Some(forged)).is_none(), "{forged}"); + } +} + +/// Process SSE ids increase on every frame, each decodes to the position the +/// client has received output up to, and once a stream loses that position no +/// later id of it carries one, however many frames follow. +#[test] +fn process_event_ids_increase_and_carry_the_output_position() { + let mut previous = ProcessEventId::START; + let mut lost = false; + let positions = [Some(0), Some(0), Some(1), Some(2)] + .into_iter() + .chain(std::iter::repeat_n( + Some(2), + PROCESS_EVENT_ID_MAX_FRAME as usize + 1, + )) + .chain([Some(3), None, Some(4)]) + .chain(std::iter::repeat_n( + None, + PROCESS_EVENT_ID_MAX_FRAME as usize + 1, + )); + for position in positions { + let id = previous.next(position); + assert!(id.encode() > previous.encode(), "{id:?} after {previous:?}"); + assert!(id.encode() < 1 << 53); + assert_eq!(ProcessEventId::decode(id.encode()), Some(id)); + lost |= !matches!(id, ProcessEventId::Position { .. }); + match id { + ProcessEventId::Position { + position: carried, .. + } => { + assert!(!lost, "{id:?} after the position was lost"); + assert_eq!(Some(carried), position); + } + ProcessEventId::Unknown { .. } => assert!(lost), + } + previous = id; + } + assert!(lost, "running out of frames at one position loses it"); + + for (from, position) in [ + // A position the field cannot hold, and one behind the last. + ( + ProcessEventId::START, + Some(PROCESS_EVENT_ID_MAX_POSITION + 1), + ), + ( + ProcessEventId::Position { + position: 5, + frame: 0, + }, + Some(4), + ), + // The highest position, out of frames. + ( + ProcessEventId::Position { + position: PROCESS_EVENT_ID_MAX_POSITION, + frame: PROCESS_EVENT_ID_MAX_FRAME, + }, + Some(PROCESS_EVENT_ID_MAX_POSITION), + ), + ] { + let id = from.next(position); + assert!(matches!(id, ProcessEventId::Unknown { .. }), "{id:?}"); + assert!(id.encode() > from.encode()); + } + + // Each edge sits where the layout puts it: the first tagged id is the + // start, and the block without a position follows the highest position. + assert_eq!(layout_edges()[0] + 1, ProcessEventId::START.encode()); + assert_eq!( + ProcessEventId::decode(layout_edges()[2] + 1), + Some(ProcessEventId::Unknown { block: 0, frame: 0 }) + ); + assert!(layout_edges()[1] < layout_edges()[2]); + let highest = ProcessEventId::Unknown { + block: PROCESS_EVENT_ID_MAX_POSITION, + frame: PROCESS_EVENT_ID_MAX_FRAME, + }; + assert_eq!( + highest.encode(), + (1 << 53) - (1 << PROCESS_EVENT_ID_GUARD_BITS) + ); + assert_eq!(ProcessEventId::decode(highest.encode()), Some(highest)); + + // An id off by less than the guard, as `+1` counting leaves it, carries + // no position; neither does one off the layout. + let id = ProcessEventId::Position { + position: 7, + frame: 3, + } + .encode(); + for mangled in [ + id + 1, + id - 1, + id + 96, + id - 512, + id + (1 << PROCESS_EVENT_ID_GUARD_BITS) - 1, + id | 1 << 53, + id & !PROCESS_EVENT_ID_TAG, + ] { + assert_eq!(ProcessEventId::decode(mangled), None, "{mangled}"); + } + + // A double, as a JavaScript `Number`, holds every id exactly and prints it + // back unchanged. + for id in [ + ProcessEventId::START.encode(), + id, + layout_edges()[1], + highest.encode(), + ] { + assert_eq!((id as f64).to_string(), id.to_string()); + } +} + +/// Ids carry the output position for a process's first 2^33 - 1 outputs, as +/// the API docs publish, and none after; the id the docs show for the first +/// output decodes to it. +#[test] +fn process_event_ids_carry_positions_up_to_the_published_limit() { + let last = (1 << 33) - 1; + let id = ProcessEventId::START.next(Some(last)); + assert_eq!( + id, + ProcessEventId::Position { + position: last, + frame: 0 + } + ); + assert_eq!(ProcessEventId::decode(id.encode()), Some(id)); + assert!(matches!( + id.next(Some(last + 1)), + ProcessEventId::Unknown { .. } + )); + + assert_eq!( + ProcessEventId::decode(4_503_599_627_632_640), + Some(ProcessEventId::Position { + position: 1, + frame: 0 + }) + ); +} diff --git a/crates/libs/data/plane/server/src/native/streams.rs b/crates/libs/data/plane/server/src/native/streams.rs index 4788e28fb1..357f693835 100644 --- a/crates/libs/data/plane/server/src/native/streams.rs +++ b/crates/libs/data/plane/server/src/native/streams.rs @@ -314,6 +314,9 @@ pub(crate) async fn connect_process_stream( process_id: process_id.to_string(), timeout: None, output_cursor, + // A cursor whose output was evicted starts at the oldest + // output retained, which `ProcessConnected` reports. + resume_from_oldest_retained: true, }), }, route_token, diff --git a/crates/libs/data/plane/server/src/native/tests.rs b/crates/libs/data/plane/server/src/native/tests.rs index 8d832cf1b1..b506bd0ea9 100644 --- a/crates/libs/data/plane/server/src/native/tests.rs +++ b/crates/libs/data/plane/server/src/native/tests.rs @@ -1,5 +1,8 @@ use super::*; use axum::extract::ws::Message; +use pplx_space_common_svc::space_api_route::{ + RouteIdentityRemediation, set_route_identity_rejection_metadata, +}; use std::sync::Arc; use std::sync::atomic::{AtomicBool, Ordering}; @@ -411,225 +414,39 @@ async fn full_guest_storage_is_named_and_not_retryable() { assert_eq!(body["error"]["retryable"], false); } -/// How a fake cluster API answers `BindDataPlaneSessionProcess`. +/// How a fake cluster API answers `BindDataPlaneSessionProcess` once the test +/// adds a `release` permit. #[derive(Clone, Copy)] enum FakeBind { Succeeds, NotFound, } -/// How the fake worker answers a connect to the session's process. -#[derive(Clone, Copy)] -enum FakeProcess { - Running, - /// The guest has no such process. - Missing, - /// The node has no such sandbox. - SandboxMissing, - Unreachable, -} - -/// The process session a fake cluster API serves. -struct FakeSession { - /// The session's stored `CreateProcessRequest`. - adapter_state: &'static str, - /// Whether each route lookup, in order, reports the process as bound to - /// the session; the last answer repeats. - bound: &'static [bool], - /// Whether the worker reports the process's exit after its first event. - exits: bool, - bind: FakeBind, - process: FakeProcess, -} - -/// A fake cluster API and worker for one native process session. Each bind -/// waits for a `release` permit before answering, so a test can hold the -/// binding open while it watches what the client receives. Every call, and -/// the `stdin` flag of every start, is recorded. -struct BindingFake { - endpoint: String, - release: Arc, - bind_started: Arc, - bound_process_ids: Arc>>, - calls: Arc>>, - started_stdin: Arc>>, -} - -impl BindingFake { - fn called(&self, method: &str) -> bool { - self.calls - .lock() - .unwrap() - .iter() - .any(|path| path.ends_with(method)) - } -} - +/// A process fake whose start reports the process (and its exit, if +/// `exits`) and stays open, and whose binds wait for a `release` permit, so +/// a test can hold the binding open while it watches what the client +/// receives. async fn spawn_binding_fake( session_id: DataPlaneSessionId, exits: bool, bind: FakeBind, -) -> BindingFake { - spawn_session_fake( +) -> ProcessFake { + spawn_process_fake( session_id, - FakeSession { - adapter_state: r#"{"command":["true"]}"#, - bound: &[false], - exits, - bind, - process: FakeProcess::Running, - }, + FakeRoute::unbound(), + Some(bind), + Arc::new(move |_, open| { + assert_eq!(open, FakeOpen::Start); + let mut replies = vec![started()]; + if exits { + replies.push(exited()); + } + replies + }), ) .await } -async fn spawn_session_fake(session_id: DataPlaneSessionId, session: FakeSession) -> BindingFake { - use prost::Message as _; - let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.unwrap(); - let endpoint = format!("http://{}", listener.local_addr().unwrap()); - let process_id = pplx_space_public_api::process_id_for_session(session_id).to_string(); - let routes: Vec<_> = session - .bound - .iter() - .map(|&bound| { - let mut route = crate::tests::route_response_with_token(session_id, None); - route.backend.as_mut().unwrap().endpoint = endpoint.clone(); - route.adapter_state_json = session.adapter_state.to_string(); - route.backend_process_id = bound.then(|| process_id.clone()); - route.encode_to_vec() - }) - .collect(); - let event = |event| { - let mut framed = vec![0]; - let encoded = ProcessEvent { - process_id: process_id.clone(), - pid: Some(42), - event: Some(event), - } - .encode_to_vec(); - framed.extend_from_slice(&(encoded.len() as u32).to_be_bytes()); - framed.extend(encoded); - bytes::Bytes::from(framed) - }; - let exit = session.exits.then(|| { - event(spaced_process_event::Event::Exit( - pplx_space_sbx_mgr_client::proto::SpacedProcessExit { - outcome: Some( - pplx_space_sbx_mgr_client::proto::spaced_process_exit::Outcome::Exited( - pplx_space_sbx_mgr_client::proto::SpacedProcessExited { exit_code: 0 }, - ), - ), - }, - )) - }); - let started_events: Vec<_> = std::iter::once(event(spaced_process_event::Event::Started( - pplx_space_sbx_mgr_client::operations::ProcessStarted { start_time: None }, - ))) - .chain(exit.clone()) - .collect(); - let connected_events: Vec<_> = std::iter::once(event(spaced_process_event::Event::Connected( - pplx_space_sbx_mgr_client::proto::SpacedProcessConnected {}, - ))) - .chain(exit) - .collect(); - let bind = session.bind; - let process = session.process; - let route_lookups = Arc::new(std::sync::atomic::AtomicUsize::new(0)); - let fake = BindingFake { - endpoint, - release: Arc::new(tokio::sync::Semaphore::new(0)), - bind_started: Arc::new(tokio::sync::Notify::new()), - bound_process_ids: Arc::new(std::sync::Mutex::new(Vec::new())), - calls: Arc::new(std::sync::Mutex::new(Vec::new())), - started_stdin: Arc::new(std::sync::Mutex::new(Vec::new())), - }; - let release = Arc::clone(&fake.release); - let bind_started = Arc::clone(&fake.bind_started); - let bound_process_ids = Arc::clone(&fake.bound_process_ids); - let calls = Arc::clone(&fake.calls); - let started_stdin = Arc::clone(&fake.started_stdin); - let service = axum::Router::new().fallback(move |request: Request| { - let routes = routes.clone(); - let started_events = started_events.clone(); - let connected_events = connected_events.clone(); - let route_lookups = Arc::clone(&route_lookups); - let release = Arc::clone(&release); - let bind_started = Arc::clone(&bind_started); - let bound_process_ids = Arc::clone(&bound_process_ids); - let calls = Arc::clone(&calls); - let started_stdin = Arc::clone(&started_stdin); - async move { - let path = request.uri().path().to_string(); - calls.lock().unwrap().push(path.clone()); - if path.ends_with("/Check") { - return crate::tests::grpc_test_response(vec![8, 1]); - } - if path.ends_with("/ResolveDataPlaneSessionRoute") { - let lookup = route_lookups.fetch_add(1, Ordering::SeqCst); - return crate::tests::grpc_test_response( - routes[lookup.min(routes.len() - 1)].clone(), - ); - } - if path.ends_with("/BindDataPlaneSessionProcess") { - let body = request.into_body().collect().await.unwrap().to_bytes(); - let bound = BindDataPlaneSessionProcessRequest::decode(&body[5..]).unwrap(); - bound_process_ids.lock().unwrap().push(bound.process_id); - bind_started.notify_one(); - release.acquire().await.unwrap().forget(); - return match bind { - FakeBind::Succeeds => crate::tests::grpc_test_response(Vec::new()), - FakeBind::NotFound => { - tonic::Status::not_found("process-backed data-plane session not found") - .into_http::() - } - }; - } - let events = if path.ends_with("/SpacedStartProcess") { - let body = request.into_body().collect().await.unwrap().to_bytes(); - let start = SpacedStartProcessRequest::decode(&body[5..]).unwrap(); - started_stdin - .lock() - .unwrap() - .push(start.operation.unwrap().stdin); - started_events - } else if path.ends_with("/SpacedConnectProcess") { - match process { - FakeProcess::Running => connected_events, - FakeProcess::Missing => { - return pplx_space_common_grpc::mark_guest_process_error( - tonic::Status::not_found("process not found"), - ) - .into_http::(); - } - FakeProcess::SandboxMissing => { - return tonic::Status::not_found("sandbox not found").into_http::(); - } - FakeProcess::Unreachable => { - return tonic::Status::unavailable("worker unreachable") - .into_http::(); - } - } - } else { - panic!("unexpected call {path}"); - }; - let frames = futures_util::stream::iter( - events - .into_iter() - .map(|event| Ok::<_, Infallible>(hyper::body::Frame::data(event))), - ) - .chain(futures_util::stream::pending()); - Response::builder() - .header("content-type", "application/grpc") - .body(Body::new(http_body_util::StreamBody::new(frames))) - .unwrap() - } - }); - tokio::spawn(async move { - axum::serve(listener, service).await.unwrap(); - }); - fake -} - fn binding_fake_test_process() -> bool { pplx_space_test_env::enter_test_process(&[ ( @@ -643,10 +460,11 @@ fn binding_fake_test_process() -> bool { ]) } -async fn binding_fake_state(fake: &BindingFake) -> DataPlaneState { +/// A data plane whose cluster API is the fake at `endpoint`. +async fn fake_state(endpoint: &str) -> DataPlaneState { let mut state = crate::tests::test_data_plane_state().await; state.cluster_api = ClusterApiClients::service_only( - pplx_space_node_api_client::cluster::connect(fake.endpoint.clone(), "test") + pplx_space_node_api_client::cluster::connect(endpoint.to_string(), "test") .await .unwrap(), ); @@ -657,27 +475,27 @@ async fn binding_fake_state(fake: &BindingFake) -> DataPlaneState { async fn get_session_events( state: &DataPlaneState, session_id: DataPlaneSessionId, - last_event_id: Option<&str>, + last_event_id: Option, ) -> Response { let token = format!("{DATA_PLANE_TOKEN_PREFIX}{}", "c".repeat(64)); let mut request = Request::get(format!("/v1/sessions/{session_id}/events")) .header(header::AUTHORIZATION, format!("Bearer {token}")); if let Some(last_event_id) = last_event_id { - request = request.header("last-event-id", last_event_id); + request = request.header("last-event-id", last_event_id.to_string()); } tower::ServiceExt::oneshot(router(state.clone()), request.body(Body::empty()).unwrap()) .await .unwrap() } -/// Opens the session's event stream and forwards its body text, chunk by -/// chunk, until the body ends. +/// Opens the session's event stream, through the fake cluster API at +/// `endpoint`, and forwards its body text, chunk by chunk, until the body ends. async fn open_process_events( - fake: &BindingFake, + endpoint: &str, session_id: DataPlaneSessionId, - last_event_id: Option<&str>, + last_event_id: Option, ) -> (DataPlaneState, tokio::sync::mpsc::UnboundedReceiver) { - let state = binding_fake_state(fake).await; + let state = fake_state(endpoint).await; let response = get_session_events(&state, session_id, last_event_id).await; assert_eq!(response.status(), StatusCode::OK); let mut body = response.into_body(); @@ -724,7 +542,7 @@ async fn process_start_reaches_the_client_before_its_binding_commits() { } let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); let fake = spawn_binding_fake(session_id, false, FakeBind::Succeeds).await; - let (state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); // The bind is still held open, yet the start already reached the client. @@ -759,7 +577,7 @@ async fn process_exit_is_reported_only_after_its_binding_commits() { } let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); let fake = spawn_binding_fake(session_id, true, FakeBind::Succeeds).await; - let (_state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); read_until(&mut chunks, &mut seen, "process_started").await; @@ -791,7 +609,7 @@ async fn failed_binding_ends_the_process_stream_with_a_retryable_error() { } let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); let fake = spawn_binding_fake(session_id, false, FakeBind::NotFound).await; - let (state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); read_until(&mut chunks, &mut seen, "process_started").await; @@ -813,7 +631,7 @@ async fn binding_survives_a_client_that_disconnects_mid_bind() { } let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); let fake = spawn_binding_fake(session_id, false, FakeBind::Succeeds).await; - let (state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); read_until(&mut chunks, &mut seen, "process_started").await; @@ -841,6 +659,79 @@ async fn binding_survives_a_client_that_disconnects_mid_bind() { const PTY_SESSION: &str = r#"{"command":["sh"],"pty":{"rows":24,"cols":80}}"#; +/// How the fake worker answers a connect to the session's process. +#[derive(Clone, Copy)] +enum FakeProcess { + Running, + /// The guest has no such process. + Missing, + /// The node has no such sandbox. + SandboxMissing, + Unreachable, +} + +/// The process session a [`spawn_session_fake`] serves. +struct FakeSession { + /// The session's stored `CreateProcessRequest`. + adapter_state: &'static str, + /// Whether each route lookup, in order, reports the process as bound to + /// the session; the last answer repeats. + bound: &'static [bool], + /// Whether the worker reports the process's exit after its first event. + exits: bool, + bind: FakeBind, + process: FakeProcess, +} + +/// A [`ProcessFake`] for one process session whose start reports the process +/// and whose connect answers as `session.process` says, each followed by the +/// exit if `session.exits`. Binds wait for a `release` permit. +async fn spawn_session_fake(session_id: DataPlaneSessionId, session: FakeSession) -> ProcessFake { + let FakeSession { + adapter_state, + bound, + exits, + bind, + process, + } = session; + spawn_process_fake( + session_id, + FakeRoute { + adapter_state, + bound, + }, + Some(bind), + Arc::new(move |_, open| { + let mut replies = match (open, process) { + (FakeOpen::Start, _) => vec![started()], + (FakeOpen::Connect(_), FakeProcess::Running) => vec![connected()], + (FakeOpen::Connect(_), FakeProcess::Missing) => { + return vec![FakeReply::Refuse( + pplx_space_common_grpc::mark_guest_process_error(tonic::Status::not_found( + "process not found", + )), + )]; + } + (FakeOpen::Connect(_), FakeProcess::SandboxMissing) => { + return vec![FakeReply::Refuse(tonic::Status::not_found( + "sandbox not found", + ))]; + } + (FakeOpen::Connect(_), FakeProcess::Unreachable) => { + return vec![FakeReply::Refuse(tonic::Status::unavailable( + "worker unreachable", + ))]; + } + }; + if exits { + replies.push(exited()); + } + replies + }), + ) + .await +} + async fn error_body(response: Response) -> serde_json::Value { use http_body_util::BodyExt; let body = response.into_body().collect().await.unwrap().to_bytes(); @@ -867,7 +758,7 @@ async fn events_stream_refuses_to_start_pty_process_sessions() { }, ) .await; - let state = binding_fake_state(&fake).await; + let state = fake_state(&fake.endpoint).await; let response = get_session_events(&state, session_id, None).await; assert_eq!(response.status(), StatusCode::BAD_REQUEST); @@ -899,7 +790,7 @@ async fn events_stream_resumes_a_running_pty_process_before_its_binding_commits( }, ) .await; - let (_state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); fake.release.add_permits(1); @@ -943,7 +834,7 @@ async fn events_stream_does_not_refuse_a_pty_session_whose_sandbox_is_missing() }, ) .await; - let state = binding_fake_state(&fake).await; + let state = fake_state(&fake.endpoint).await; let response = get_session_events(&state, session_id, None).await; assert_eq!(response.status(), StatusCode::SERVICE_UNAVAILABLE); @@ -972,7 +863,7 @@ async fn events_stream_answers_a_failed_process_connect_as_retryable() { }, ) .await; - let state = binding_fake_state(&fake).await; + let state = fake_state(&fake.endpoint).await; let response = get_session_events(&state, session_id, None).await; assert_eq!(response.status(), StatusCode::SERVICE_UNAVAILABLE); @@ -1000,7 +891,7 @@ async fn events_stream_starts_stdin_process_sessions_with_stdin_at_eof() { }, ) .await; - let (_state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); read_until(&mut chunks, &mut seen, "process_started").await; @@ -1032,7 +923,7 @@ async fn events_stream_resumes_started_pty_process_sessions() { }, ) .await; - let (_state, mut chunks) = open_process_events(&fake, session_id, Some("3")).await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, Some(3)).await; let mut seen = String::new(); read_until(&mut chunks, &mut seen, "process_exited").await; @@ -1061,7 +952,7 @@ async fn events_stream_rereads_an_unbound_pty_route_before_refusing() { }, ) .await; - let (_state, mut chunks) = open_process_events(&fake, session_id, None).await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; let mut seen = String::new(); fake.release.add_permits(1); @@ -1104,7 +995,7 @@ async fn events_stream_answers_a_held_pty_session_with_a_retryable_conflict() { }, ) .await; - let state = binding_fake_state(&fake).await; + let state = fake_state(&fake.endpoint).await; let _held = state .native_sessions .try_acquire(session_id, SessionKind::Process) @@ -2103,3 +1994,1255 @@ async fn websocket_resize_refusal_carries_a_fixed_message() { "internal detail leaked: {seen}" ); } + +/// One reply of a fake guest process stream. +enum FakeReply { + Event(spaced_process_event::Event), + /// Ends the stream with this status. + End(tonic::Status), + /// Refuses the call outright, before any stream. + Refuse(tonic::Status), +} + +fn end(code: tonic::Code) -> FakeReply { + FakeReply::End(tonic::Status::new(code, "fake")) +} + +fn with_reason(mut status: tonic::Status, reason: &'static str) -> tonic::Status { + status.metadata_mut().insert( + pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY, + tonic::metadata::MetadataValue::from_static(reason), + ); + status +} + +/// Ends the stream as the guest does for a cursor past the output. +fn cursor_ahead() -> FakeReply { + FakeReply::End(with_reason( + tonic::Status::out_of_range("fake"), + pplx_space_common_core::spaced::PROCESS_OUTPUT_CURSOR_AHEAD, + )) +} + +/// Ends the stream as the guest does for a cursor before the oldest retained +/// output, `first_retained`, when it still holds the process. +fn lagged(first_retained: Option) -> FakeReply { + let mut status = with_reason( + tonic::Status::resource_exhausted( + pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED_MESSAGE, + ), + pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED, + ); + if let Some(first_retained) = first_retained { + status.metadata_mut().insert( + pplx_space_common_core::spaced::PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY, + first_retained.into(), + ); + } + FakeReply::End(status) +} + +/// Ends the stream as a guest older than the lag reason does on eviction. +fn untagged_lagged() -> FakeReply { + FakeReply::End(tonic::Status::resource_exhausted( + pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED_MESSAGE, + )) +} + +/// Refuses the call as a node does a route token that a refresh replaces, +/// such as an expired one. +fn refreshable_route_rejection() -> FakeReply { + let mut status = tonic::Status::permission_denied("route token expired"); + set_route_identity_rejection_metadata( + &mut status, + RouteIdentityRemediation::RefreshRoute, + None, + ); + FakeReply::Refuse(status) +} + +/// How the data plane opened a fake guest process stream. +#[derive(Clone, Copy, Debug, Eq, PartialEq)] +enum FakeOpen { + Start, + Connect(Option), +} + +fn started() -> FakeReply { + FakeReply::Event(spaced_process_event::Event::Started( + pplx_space_sbx_mgr_client::operations::ProcessStarted { start_time: None }, + )) +} + +/// A reconnect's first event, from a guest that does not say where the +/// stream starts. +fn connected() -> FakeReply { + FakeReply::Event(spaced_process_event::Event::Connected( + pplx_space_sbx_mgr_client::operations::ProcessConnected { + output_cursor: None, + }, + )) +} + +/// A reconnect's first event, from a guest that started the stream at +/// `start`, its oldest retained output, because the cursor's was evicted. +fn connected_at(start: u64) -> FakeReply { + FakeReply::Event(spaced_process_event::Event::Connected( + pplx_space_sbx_mgr_client::operations::ProcessConnected { + output_cursor: Some(start), + }, + )) +} + +fn stdout(line: &str) -> FakeReply { + FakeReply::Event(spaced_process_event::Event::Stdout( + pplx_space_sbx_mgr_client::operations::ProcessOutput { + data: line.as_bytes().to_vec(), + }, + )) +} + +fn exited() -> FakeReply { + FakeReply::Event(spaced_process_event::Event::Exit( + pplx_space_sbx_mgr_client::proto::SpacedProcessExit { + outcome: Some( + pplx_space_sbx_mgr_client::proto::spaced_process_exit::Outcome::Exited( + pplx_space_sbx_mgr_client::proto::SpacedProcessExited { exit_code: 0 }, + ), + ), + }, + )) +} + +/// What the guest sends for `open` from a process that wrote `lines` and +/// exited: a start or a cursor replays the output from that position on, a +/// cursor past the output fails, and a connect without a cursor gets only the +/// start and the exit. +fn journal_replay(lines: &[&str], open: FakeOpen) -> Vec { + let (mut replies, cursor) = match open { + FakeOpen::Start => (vec![started()], 0), + FakeOpen::Connect(None) => return vec![started(), exited()], + FakeOpen::Connect(Some(cursor)) if cursor as usize > lines.len() => { + return vec![connected(), cursor_ahead()]; + } + FakeOpen::Connect(Some(cursor)) => (vec![connected()], cursor), + }; + replies.extend(lines.iter().skip(cursor as usize).map(|line| stdout(line))); + replies.push(exited()); + replies +} + +type FakeReplies = Arc Vec + Send + Sync>; + +/// The route a [`ProcessFake`] resolves for its session. +#[derive(Clone, Copy)] +struct FakeRoute { + /// The session's stored `CreateProcessRequest`. + adapter_state: &'static str, + /// Whether each route lookup, in order, reports the process as bound to + /// the session; the last answer repeats. Once a bind succeeds, every + /// lookup reports it bound. + bound: &'static [bool], +} + +impl FakeRoute { + fn unbound() -> Self { + Self { + adapter_state: r#"{"command":["true"]}"#, + bound: &[false], + } + } + + fn bound() -> Self { + Self { + bound: &[true], + ..Self::unbound() + } + } +} + +/// A fake cluster API and worker for one native process session, whose route +/// is `route`. Every call, and the `stdin` flag of every start, is recorded. +/// Each process stream the data plane opens +/// is answered by `replies`, given how many opens came before it; a stream +/// without a closing status stays open. A bind succeeds at once, or with +/// `gated_bind`, answers as that says once the test adds a `release` permit. +struct ProcessFake { + endpoint: String, + bound: Arc, + opens: Arc>>, + release: Arc, + bind_started: Arc, + bound_process_ids: Arc>>, + calls: Arc>>, + started_stdin: Arc>>, +} + +impl ProcessFake { + fn called(&self, method: &str) -> bool { + self.calls + .lock() + .unwrap() + .iter() + .any(|path| path.ends_with(method)) + } +} + +async fn spawn_journal_fake( + session_id: DataPlaneSessionId, + bound: bool, + replies: FakeReplies, +) -> ProcessFake { + let route = if bound { + FakeRoute::bound() + } else { + FakeRoute::unbound() + }; + spawn_process_fake(session_id, route, None, replies).await +} + +async fn spawn_process_fake( + session_id: DataPlaneSessionId, + fake_route: FakeRoute, + gated_bind: Option, + replies: FakeReplies, +) -> ProcessFake { + use prost::Message as _; + let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.unwrap(); + let endpoint = format!("http://{}", listener.local_addr().unwrap()); + let process_id = pplx_space_public_api::process_id_for_session(session_id).to_string(); + let mut route = crate::tests::route_response_with_token(session_id, None); + route.backend.as_mut().unwrap().endpoint = endpoint.clone(); + route.adapter_state_json = fake_route.adapter_state.to_string(); + let lookups = fake_route.bound; + let route_lookups = Arc::new(std::sync::atomic::AtomicUsize::new(0)); + let fake = ProcessFake { + endpoint, + bound: Arc::new(AtomicBool::new(lookups[0])), + opens: Arc::new(std::sync::Mutex::new(Vec::new())), + release: Arc::new(tokio::sync::Semaphore::new(0)), + bind_started: Arc::new(tokio::sync::Notify::new()), + bound_process_ids: Arc::new(std::sync::Mutex::new(Vec::new())), + calls: Arc::new(std::sync::Mutex::new(Vec::new())), + started_stdin: Arc::new(std::sync::Mutex::new(Vec::new())), + }; + let bound = Arc::clone(&fake.bound); + let calls = Arc::clone(&fake.calls); + let started_stdin = Arc::clone(&fake.started_stdin); + let opens = Arc::clone(&fake.opens); + let release = Arc::clone(&fake.release); + let bind_started = Arc::clone(&fake.bind_started); + let bound_process_ids = Arc::clone(&fake.bound_process_ids); + let service = axum::Router::new().fallback(move |request: Request| { + let mut route = route.clone(); + let process_id = process_id.clone(); + let replies = Arc::clone(&replies); + let opens = Arc::clone(&opens); + let bound = Arc::clone(&bound); + let release = Arc::clone(&release); + let bind_started = Arc::clone(&bind_started); + let bound_process_ids = Arc::clone(&bound_process_ids); + let calls = Arc::clone(&calls); + let started_stdin = Arc::clone(&started_stdin); + let route_lookups = Arc::clone(&route_lookups); + async move { + let path = request.uri().path().to_string(); + calls.lock().unwrap().push(path.clone()); + if path.ends_with("/Check") { + return crate::tests::grpc_test_response(vec![8, 1]); + } + if path.ends_with("/ResolveDataPlaneSessionRoute") { + let lookup = route_lookups.fetch_add(1, Ordering::SeqCst); + let bound = bound.load(Ordering::SeqCst) || lookups[lookup.min(lookups.len() - 1)]; + route.backend_process_id = bound.then(|| process_id.clone()); + return crate::tests::grpc_test_response(route.encode_to_vec()); + } + if path.ends_with("/BindDataPlaneSessionProcess") { + let body = request.into_body().collect().await.unwrap().to_bytes(); + let request = BindDataPlaneSessionProcessRequest::decode(&body[5..]).unwrap(); + bound_process_ids.lock().unwrap().push(request.process_id); + if let Some(bind) = gated_bind { + bind_started.notify_one(); + release.acquire().await.unwrap().forget(); + if let FakeBind::NotFound = bind { + return tonic::Status::not_found( + "process-backed data-plane session not found", + ) + .into_http::(); + } + } + bound.store(true, Ordering::SeqCst); + return crate::tests::grpc_test_response(Vec::new()); + } + if path.ends_with("/RecordDataPlaneSessionReconnect") { + return crate::tests::grpc_test_response(Vec::new()); + } + let open = if path.ends_with("/SpacedStartProcess") { + let body = request.into_body().collect().await.unwrap().to_bytes(); + let start = SpacedStartProcessRequest::decode(&body[5..]).unwrap(); + started_stdin + .lock() + .unwrap() + .push(start.operation.unwrap().stdin); + FakeOpen::Start + } else { + assert!( + path.ends_with("/SpacedConnectProcess"), + "unexpected call {path}" + ); + let body = request.into_body().collect().await.unwrap().to_bytes(); + let operation = SpacedConnectProcessRequest::decode(&body[5..]) + .unwrap() + .operation + .unwrap(); + assert!( + operation.resume_from_oldest_retained, + "a connect asks to start at the oldest retained output" + ); + FakeOpen::Connect(operation.output_cursor) + }; + let opened = { + let mut opens = opens.lock().unwrap(); + opens.push(open); + opens.len() - 1 + }; + let mut frames = Vec::new(); + let mut trailers = None; + for reply in replies(opened, open) { + match reply { + FakeReply::Refuse(status) => return status.into_http::(), + FakeReply::Event(event) => { + let encoded = ProcessEvent { + process_id: process_id.clone(), + pid: Some(42), + event: Some(event), + } + .encode_to_vec(); + let mut framed = vec![0]; + framed.extend_from_slice(&(encoded.len() as u32).to_be_bytes()); + framed.extend(encoded); + frames.push(hyper::body::Frame::data(bytes::Bytes::from(framed))); + } + FakeReply::End(status) => { + let mut headers = status.into_http::().into_parts().0.headers; + headers.remove(header::CONTENT_TYPE); + trailers = Some(headers); + } + } + } + let ending = match trailers { + Some(trailers) => { + futures_util::stream::once( + async move { hyper::body::Frame::trailers(trailers) }, + ) + .boxed() + } + None => futures_util::stream::pending().boxed(), + }; + let frames = futures_util::stream::iter(frames) + .chain(ending) + .map(Ok::<_, Infallible>); + Response::builder() + .header("content-type", "application/grpc") + .body(Body::new(http_body_util::StreamBody::new(frames))) + .unwrap() + } + }); + tokio::spawn(async move { + axum::serve(listener, service).await.unwrap(); + }); + fake +} + +/// The complete SSE events in `body`, as each one's id and JSON frame. +fn sse_frames(body: &str) -> Vec<(Option, serde_json::Value)> { + let mut events: Vec<&str> = body.split("\n\n").collect(); + events.pop(); + events + .into_iter() + .filter_map(|event| { + let mut id = None; + let mut data = None; + for line in event.lines() { + if let Some(value) = line.strip_prefix("id:") { + id = Some(value.trim().parse().unwrap()); + } else if let Some(value) = line.strip_prefix("data:") { + data = Some(serde_json::from_str(value.trim()).unwrap()); + } + } + Some((id, data?)) + }) + .collect() +} + +fn frames_of_type<'a>( + frames: &'a [(Option, serde_json::Value)], + frame_type: &'a str, +) -> impl Iterator, serde_json::Value)> { + frames + .iter() + .filter(move |(_, frame)| frame["type"] == frame_type) +} + +fn stdout_text(frames: &[(Option, serde_json::Value)]) -> String { + frames_of_type(frames, "stdout") + .map(|(_, frame)| { + let data = BASE64_STANDARD + .decode(frame["data_base64"].as_str().unwrap()) + .unwrap(); + String::from_utf8(data).unwrap() + }) + .collect() +} + +fn resync_reasons(frames: &[(Option, serde_json::Value)]) -> Vec { + frames_of_type(frames, "resync_required") + .map(|(_, frame)| frame["reason"].as_str().unwrap().to_string()) + .collect() +} + +/// Reads one process event stream to its end. +async fn process_events_to_close( + endpoint: &str, + session_id: DataPlaneSessionId, + last_event_id: Option, +) -> Vec<(Option, serde_json::Value)> { + let (_state, mut chunks) = open_process_events(endpoint, session_id, last_event_id).await; + let mut seen = String::new(); + tokio::time::timeout(Duration::from_secs(30), async { + while let Some(chunk) = chunks.recv().await { + seen.push_str(&chunk); + } + }) + .await + .unwrap_or_else(|_| panic!("stream ends within 30s; saw {seen}")); + let frames = sse_frames(&seen); + assert_eq!(frames.last().unwrap().1["type"], "closed", "{seen}"); + let ids: Vec = frames.iter().filter_map(|(id, _)| *id).collect(); + assert!(ids.is_sorted_by(|a, b| a < b), "ids increase: {ids:?}"); + assert_identified_frames(&frames); + frames +} + +const JOURNAL: [&str; 4] = ["one\n", "two\n", "three\n", "four\n"]; + +fn assert_ids_above(frames: &[(Option, serde_json::Value)], last_event_id: u64) { + let ids: Vec = frames.iter().filter_map(|(id, _)| *id).collect(); + assert!( + ids.iter().all(|id| *id > last_event_id), + "ids {ids:?} after Last-Event-ID {last_event_id}" + ); +} + +/// The id a client resumes from: the last one it received. +fn last_id(frames: &[(Option, serde_json::Value)]) -> u64 { + frames.iter().rev().find_map(|(id, _)| *id).unwrap() +} + +/// Only output and `resync_required` carry an id. +fn assert_identified_frames(frames: &[(Option, serde_json::Value)]) { + for (id, frame) in frames { + let identified = matches!( + frame["type"].as_str(), + Some("stdout" | "stderr" | "resync_required") + ); + assert_eq!(id.is_some(), identified, "{frame}"); + } +} + +fn connects(cursors: &[Option]) -> Vec { + cursors.iter().copied().map(FakeOpen::Connect).collect() +} + +/// A client that drops its first stream, and so never sends `Last-Event-ID`, +/// still gets the process's whole retained output when it attaches again. +#[tokio::test] +async fn process_reattach_replays_retained_output_from_the_start() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| journal_replay(&JOURNAL, open)), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert_eq!(stdout_text(&frames), JOURNAL.concat()); + assert_eq!(resync_reasons(&frames), Vec::::new()); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0)])); +} + +/// `Last-Event-ID` resumes at the output after the last frame received: the +/// two streams together carry the output once, without a gap or a resync. +#[tokio::test] +async fn process_resume_continues_after_the_last_event_id() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| journal_replay(&JOURNAL, open)), + ) + .await; + let first = process_events_to_close(&fake.endpoint, session_id, None).await; + let received: Vec<_> = first + .iter() + .take_while(|(_, frame)| frame["seq"] != 3) + .cloned() + .collect(); + let last_event_id = last_id(&received); + + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(last_event_id)).await; + + assert_eq!(stdout_text(&received), "one\ntwo\n"); + assert_eq!(stdout_text(&resumed), "three\nfour\n"); + assert_eq!(resync_reasons(&resumed), Vec::::new()); + assert!( + resumed + .iter() + .filter_map(|(id, _)| *id) + .all(|id| id > last_event_id) + ); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0), Some(2)])); +} + +/// Output the guest evicted before the client asked for it is a real gap: +/// the stream reports it once and continues from the oldest output the guest +/// still retains, without reporting the process start again. Its ids keep +/// carrying positions, so a resume from the gap's id is exact. +#[tokio::test] +async fn evicted_process_output_continues_from_the_oldest_retained_output() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| match open { + FakeOpen::Connect(Some(cursor)) if cursor < 2 => vec![connected(), lagged(Some(2))], + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), "three\nfour\n"); + assert_eq!(frames_of_type(&frames, "process_started").count(), 1); + assert!( + frames_of_type(&frames, "error").next().is_none(), + "{frames:?}" + ); + + let gap = frames_of_type(&frames, "resync_required") + .next() + .unwrap() + .0 + .unwrap(); + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(gap)).await; + assert_eq!(resync_reasons(&resumed), Vec::::new()); + assert_eq!(stdout_text(&resumed), "three\nfour\n"); + assert_ids_above(&resumed, gap); + assert_eq!( + *fake.opens.lock().unwrap(), + connects(&[Some(0), Some(2), Some(2)]) + ); +} + +/// A guest that starts a lagged connect at its oldest retained output, and +/// says so, needs no reopen: the stream reports the gap once and continues +/// from there, with ids that keep their positions. +#[tokio::test] +async fn evicted_output_continues_where_the_guest_reports_the_stream_starts() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| match open { + FakeOpen::Connect(Some(cursor)) if cursor < 2 => { + let mut replies = vec![connected_at(2)]; + replies.extend( + journal_replay(&JOURNAL, FakeOpen::Connect(Some(2))) + .into_iter() + .skip(1), + ); + replies + } + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), "three\nfour\n"); + assert_eq!(frames_of_type(&frames, "process_started").count(), 1); + + let gap = frames_of_type(&frames, "resync_required") + .next() + .unwrap() + .0 + .unwrap(); + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(gap)).await; + assert_eq!(resync_reasons(&resumed), Vec::::new()); + assert_eq!(stdout_text(&resumed), "three\nfour\n"); + assert_ids_above(&resumed, gap); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0), Some(2)])); +} + +/// A guest older than the lag reason does not say where its retained output +/// starts: the stream reports the gap once, follows the live tail without +/// reporting the process start again, and a resume from what it sent next +/// carries no position, so it replays behind `resync_required` rather than +/// silently. +#[tokio::test] +async fn evicted_output_on_an_older_guest_is_reported_before_the_live_tail() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| match open { + FakeOpen::Connect(Some(cursor)) if cursor < 2 => vec![connected(), untagged_lagged()], + FakeOpen::Connect(None) => vec![connected(), stdout("live\n"), exited()], + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), "live\n"); + assert_eq!(frames_of_type(&frames, "process_started").count(), 1); + assert!( + frames_of_type(&frames, "error").next().is_none(), + "{frames:?}" + ); + + let last_event_id = last_id(&frames); + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(last_event_id)).await; + assert_eq!( + resync_reasons(&resumed), + ["cursor_replay_unavailable", "cursor_out_of_window"] + ); + assert_ids_above(&resumed, last_event_id); + assert_eq!( + *fake.opens.lock().unwrap(), + connects(&[Some(0), None, Some(0), None]) + ); +} + +/// A RESOURCE_EXHAUSTED the guest did not tag as a lag, such as a hop's +/// refusal of an oversized chunk, is not reported as evicted output: the +/// stream ends with a retryable error instead of skipping to the live tail. +#[tokio::test] +async fn untagged_resource_exhausted_is_not_an_output_gap() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, _| { + vec![ + connected(), + stdout(JOURNAL[0]), + FakeReply::End(tonic::Status::resource_exhausted( + "guest process output chunk is too large", + )), + ] + }), + ) + .await; + + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; + let mut seen = String::new(); + read_until(&mut chunks, &mut seen, "backend_stream_error").await; + let frames = sse_frames(&seen); + assert_eq!(resync_reasons(&frames), Vec::::new()); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0)])); +} + +/// A cursor past the output restarts at the start; when the start has been +/// evicted too, that is the same gap, reported once, whether the guest ends +/// the stream as lagged or starts it at its oldest retained output. +#[tokio::test] +async fn cursor_ahead_then_evicted_start_reports_one_gap() { + if !binding_fake_test_process() { + return; + } + for reports_start in [false, true] { + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(move |_, open| match open { + FakeOpen::Connect(Some(cursor)) if cursor < 2 && reports_start => { + let mut replies = vec![connected_at(2)]; + replies.extend( + journal_replay(&JOURNAL, FakeOpen::Connect(Some(2))) + .into_iter() + .skip(1), + ); + replies + } + FakeOpen::Connect(Some(cursor)) if cursor < 2 => vec![connected(), lagged(Some(2))], + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + let ahead = ProcessEventId::Position { + position: 10, + frame: 0, + } + .encode(); + + let frames = process_events_to_close(&fake.endpoint, session_id, Some(ahead)).await; + + assert_eq!( + resync_reasons(&frames), + ["cursor_out_of_window"], + "{reports_start}" + ); + assert_eq!(stdout_text(&frames), "three\nfour\n"); + assert_ids_above(&frames, ahead); + let opens = if reports_start { + connects(&[Some(10), Some(0)]) + } else { + connects(&[Some(10), Some(0), Some(2)]) + }; + assert_eq!(*fake.opens.lock().unwrap(), opens); + } +} + +/// A process that keeps writing can evict its oldest retained output before +/// a stream that moved there reads it, when the guest could not make the +/// stream its primary reader. Chasing the next oldest would lose that race +/// on every reopen, so the stream follows the live tail instead, whether the +/// guest reported the start or ended the stream as lagged. +#[tokio::test] +async fn evicted_output_that_falls_behind_again_follows_the_live_tail() { + if !binding_fake_test_process() { + return; + } + for reports_start in [false, true] { + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + // The oldest retained output moves past every cursor connected at. + Arc::new(move |_, open| match open { + FakeOpen::Connect(Some(cursor)) if reports_start => { + vec![connected_at(cursor + 1), lagged(Some(cursor + 2))] + } + FakeOpen::Connect(Some(cursor)) => vec![connected(), lagged(Some(cursor + 1))], + FakeOpen::Connect(None) => vec![connected(), stdout("live\n"), exited()], + FakeOpen::Start => panic!("unexpected start"), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert!( + frames_of_type(&frames, "error").next().is_none(), + "{frames:?}" + ); + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), "live\n"); + let opens = if reports_start { + connects(&[Some(0), None]) + } else { + connects(&[Some(0), Some(1), None]) + }; + assert_eq!(*fake.opens.lock().unwrap(), opens, "{reports_start}"); + } +} + +/// A guest that keeps refusing the cursor without ever sending output does +/// not keep the stream reopening: a start that is past the output too, a +/// guest that keeps moving the start past the output, and a live tail that +/// keeps falling behind, end with an error. +#[tokio::test] +async fn window_miss_reopens_without_progress_are_capped() { + if !binding_fake_test_process() { + return; + } + let ahead = ProcessEventId::Position { + position: 10, + frame: 0, + } + .encode(); + for (last_event_id, replies, opens) in [ + ( + Some(ahead), + (|_| vec![connected(), cursor_ahead()]) as fn(FakeOpen) -> Vec, + connects(&[Some(10), Some(0)]), + ), + ( + Some(ahead), + |open| match open { + FakeOpen::Connect(Some(0)) => vec![connected_at(5), cursor_ahead()], + _ => vec![connected(), cursor_ahead()], + }, + connects(&[Some(10), Some(0), Some(0), Some(0)]), + ), + ( + None, + |_| vec![connected(), lagged(None)], + connects(&[Some(0), None, None, None]), + ), + ] { + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = + spawn_journal_fake(session_id, true, Arc::new(move |_, open| replies(open))).await; + + let (_state, mut chunks) = + open_process_events(&fake.endpoint, session_id, last_event_id).await; + let mut seen = String::new(); + read_until(&mut chunks, &mut seen, "backend_stream_error").await; + let frames = sse_frames(&seen); + + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(*fake.opens.lock().unwrap(), opens); + } +} + +/// Output between window misses is progress: a stream that keeps falling +/// behind but keeps receiving output is not ended by the reopen cap. +#[tokio::test] +async fn window_misses_with_output_between_are_not_capped() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| { + let FakeOpen::Connect(Some(cursor)) = open else { + panic!("unexpected open {open:?}"); + }; + // Each reopen gets one line, then falls behind by one more. + if cursor >= 12 { + return vec![connected(), exited()]; + } + vec![connected(), stdout("line\n"), lagged(Some(cursor + 2))] + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert!( + frames_of_type(&frames, "error").next().is_none(), + "{frames:?}" + ); + assert_eq!(stdout_text(&frames), "line\n".repeat(6)); + assert_eq!(fake.opens.lock().unwrap().len(), 7); +} + +/// The reopen after a window miss uses the stream's route token; when the +/// node refuses it as one a refresh replaces, such as an expired token, the +/// stream refreshes its route and continues instead of failing. +#[tokio::test] +async fn window_miss_reopen_refreshes_a_refused_route() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|opened, open| match (opened, open) { + (0, _) => vec![connected(), lagged(Some(2))], + (1, _) => vec![refreshable_route_rejection()], + (_, open) => journal_replay(&JOURNAL, open), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert!( + frames_of_type(&frames, "error").next().is_none(), + "{frames:?}" + ); + assert_eq!(frames_of_type(&frames, "backend_reconnected").count(), 1); + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), "three\nfour\n"); + assert_eq!( + *fake.opens.lock().unwrap(), + connects(&[Some(0), Some(2), Some(2)]) + ); +} + +/// Backend reconnects and client resumes before a process's next output. +const IDLE_ROUNDS: usize = 300; + +/// The id of the output after the two lines the idle fakes start with. +fn third_line_id() -> u64 { + ProcessEventId::Position { + position: 3, + frame: 0, + } + .encode() +} + +/// How an idle fake answers `open`, the `opened`th: the lines from its cursor, +/// then, once `rounds` opens have gone by, a third line and the exit. +/// `fails` ends each earlier stream as an unavailable backend. +fn idle_replies(rounds: usize, fails: bool, opened: usize, open: FakeOpen) -> Vec { + let FakeOpen::Connect(Some(cursor)) = open else { + panic!("unexpected open {open:?}"); + }; + let lines = ["one\n", "two\n", "three\n"]; + let written = if opened > rounds { 3 } else { 2 }; + let mut replies = vec![connected()]; + replies.extend( + lines[..written] + .iter() + .skip(cursor as usize) + .map(|line| stdout(line)), + ); + if opened > rounds { + replies.push(exited()); + } else if fails { + replies.push(end(tonic::Code::Unavailable)); + } + replies +} + +/// The id of the frame that carries the third line. +fn third_line_frame_id(frames: &[(Option, serde_json::Value)]) -> Option { + frames_of_type(frames, "stdout") + .find(|(_, frame)| frame["seq"] == 3) + .and_then(|(id, _)| *id) +} + +/// Frames that carry no output carry no id either, so resumes against an +/// idle process, however many, spend none of the ids at its position: the +/// next output still carries it. +#[tokio::test] +async fn idle_resumes_keep_positional_ids() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|opened, open| idle_replies(IDLE_ROUNDS, false, opened, open)), + ) + .await; + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, None).await; + let mut seen = String::new(); + read_until(&mut chunks, &mut seen, &BASE64_STANDARD.encode("two\n")).await; + read_until(&mut chunks, &mut seen, "\n\n").await; + drop(chunks); + // Each resume reports the process and is dropped; like an EventSource, + // the client resumes from the last id it has received. + let mut last_event_id = last_id(&sse_frames(&seen)); + for _ in 0..IDLE_ROUNDS { + let (_state, mut chunks) = + open_process_events(&fake.endpoint, session_id, Some(last_event_id)).await; + let mut seen = String::new(); + read_until(&mut chunks, &mut seen, "process_started").await; + read_until(&mut chunks, &mut seen, "\n\n").await; + if let Some(id) = sse_frames(&seen).iter().rev().find_map(|(id, _)| *id) { + last_event_id = id; + } + } + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(last_event_id)).await; + assert_eq!(stdout_text(&resumed), "three\n"); + assert_eq!(third_line_frame_id(&resumed), Some(third_line_id())); +} + +/// Likewise, backend reconnects before the next output spend no ids at the +/// position, however many there are. +#[tokio::test] +async fn idle_backend_reconnects_keep_positional_ids() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|opened, open| idle_replies(IDLE_ROUNDS, true, opened, open)), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert_eq!( + frames_of_type(&frames, "backend_reconnected").count(), + IDLE_ROUNDS + 1 + ); + assert_eq!(resync_reasons(&frames), Vec::::new()); + assert_eq!(stdout_text(&frames), "one\ntwo\nthree\n"); + assert_eq!(third_line_frame_id(&frames), Some(third_line_id())); +} + +/// A bound attach whose first backend stream fails before it reports the +/// process still sends `process_started` once, from the reopened stream. +#[tokio::test] +async fn backend_failure_before_the_start_still_reports_it_once() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|opened, open| match opened { + 0 => vec![end(tonic::Code::Unavailable)], + _ => journal_replay(&JOURNAL, open), + }), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, None).await; + + assert_eq!(frames_of_type(&frames, "backend_reconnected").count(), 1); + assert_eq!(frames_of_type(&frames, "process_started").count(), 1); + assert_eq!(stdout_text(&frames), JOURNAL.concat()); + assert_eq!(resync_reasons(&frames), Vec::::new()); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0), Some(0)])); +} + +/// A backend reconnect after a resume reopens the guest stream at the output +/// position the client has reached; that replay is lossless, so the client is +/// not told to resync. +#[tokio::test] +async fn backend_reconnect_after_a_resume_continues_without_a_resync() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|opened, open| match (opened, open) { + // The resume's stream drops after one line. + (1, FakeOpen::Connect(Some(cursor))) => vec![ + connected(), + stdout(JOURNAL[cursor as usize]), + end(tonic::Code::Unavailable), + ], + (_, open) => journal_replay(&JOURNAL, open), + }), + ) + .await; + let first = process_events_to_close(&fake.endpoint, session_id, None).await; + let after_one = first + .iter() + .find(|(_, frame)| frame["seq"] == 1) + .unwrap() + .0 + .unwrap(); + + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(after_one)).await; + + assert_eq!(stdout_text(&resumed), "two\nthree\nfour\n"); + assert_eq!(frames_of_type(&resumed, "backend_reconnected").count(), 1); + assert_eq!(frames_of_type(&resumed, "process_started").count(), 1); + assert_eq!(resync_reasons(&resumed), Vec::::new()); + assert_eq!( + *fake.opens.lock().unwrap(), + connects(&[Some(0), Some(1), Some(2)]) + ); +} + +/// A `Last-Event-ID` past the process's output (forged, or another +/// session's) cannot leave the stream waiting for output to reach it: the +/// guest refuses it, and the stream replays the output from the start behind +/// `resync_required`. +#[tokio::test] +async fn resume_past_the_output_replays_it_behind_a_resync() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| journal_replay(&JOURNAL, open)), + ) + .await; + let ahead = ProcessEventId::Position { + position: 10, + frame: 0, + } + .encode(); + + let frames = process_events_to_close(&fake.endpoint, session_id, Some(ahead)).await; + + assert_ids_above(&frames, ahead); + assert_eq!(resync_reasons(&frames), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&frames), JOURNAL.concat()); + assert_eq!(frames_of_type(&frames, "process_started").count(), 1); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(10), Some(0)])); +} + +/// An id without a position, such as one an earlier data plane issued, is +/// never read as one: the stream replays the retained output behind +/// `resync_required`. +#[tokio::test] +async fn resume_from_an_untagged_id_replays_behind_a_resync() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| journal_replay(&JOURNAL, open)), + ) + .await; + + let frames = process_events_to_close(&fake.endpoint, session_id, Some(1_500_000)).await; + + assert_eq!(resync_reasons(&frames), ["cursor_replay_unavailable"]); + assert_eq!(stdout_text(&frames), JOURNAL.concat()); + assert_ids_above(&frames, 1_500_000); + assert_eq!(*fake.opens.lock().unwrap(), connects(&[Some(0)])); +} + +/// The attach that starts a process counts its output from the start, even +/// when the client sent another stream's `Last-Event-ID`: the stream says the +/// id did not apply, numbers its frames above it, and a later resume replays +/// behind `resync_required` rather than at a wrong position. +#[tokio::test] +async fn starting_attach_ignores_a_foreign_last_event_id() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + false, + Arc::new(|_, open| match open { + // Still running: the stream stays open after two lines. + FakeOpen::Start => vec![started(), stdout(JOURNAL[0]), stdout(JOURNAL[1])], + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + let foreign = ProcessEventId::Position { + position: 1, + frame: 0, + } + .encode(); + let (_state, mut chunks) = open_process_events(&fake.endpoint, session_id, Some(foreign)).await; + let mut seen = String::new(); + read_until(&mut chunks, &mut seen, &BASE64_STANDARD.encode(JOURNAL[1])).await; + read_until(&mut chunks, &mut seen, "\n\n").await; + drop(chunks); + tokio::time::timeout(Duration::from_secs(5), async { + while !fake.bound.load(Ordering::SeqCst) { + tokio::time::sleep(Duration::from_millis(10)).await; + } + }) + .await + .expect("the starting attach binds the process"); + let first = sse_frames(&seen); + assert_ids_above(&first, foreign); + assert_eq!(resync_reasons(&first), ["cursor_out_of_window"]); + assert_eq!(stdout_text(&first), "one\ntwo\n"); + + let last_event_id = last_id(&first); + let resumed = process_events_to_close(&fake.endpoint, session_id, Some(last_event_id)).await; + + assert_ids_above(&resumed, last_event_id); + assert_eq!(resync_reasons(&resumed), ["cursor_replay_unavailable"]); + assert_eq!(stdout_text(&resumed), JOURNAL.concat()); + assert_eq!( + *fake.opens.lock().unwrap(), + [FakeOpen::Start, FakeOpen::Connect(Some(0))] + ); +} + +/// An attach that finds the process already started, its binding never +/// persisted, connects at the client's position: a completed process replays +/// exactly what the client lacks, with no resync. +#[tokio::test] +async fn already_started_process_is_resumed_exactly() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + false, + Arc::new(|_, open| match open { + FakeOpen::Start => vec![FakeReply::Refuse(tonic::Status::already_exists("fake"))], + open => journal_replay(&JOURNAL, open), + }), + ) + .await; + let after_two = ProcessEventId::Position { + position: 2, + frame: 0, + } + .encode(); + + let frames = process_events_to_close(&fake.endpoint, session_id, Some(after_two)).await; + + assert_eq!(stdout_text(&frames), "three\nfour\n"); + assert_eq!(resync_reasons(&frames), Vec::::new()); + assert_ids_above(&frames, after_two); + assert_eq!( + *fake.opens.lock().unwrap(), + [FakeOpen::Start, FakeOpen::Connect(Some(2))] + ); +} + +/// A `Last-Event-ID` too close to the end of the id space to number a later +/// frame above is refused before anything is opened. +#[tokio::test] +async fn last_event_id_without_room_after_it_is_rejected() { + if !binding_fake_test_process() { + return; + } + let session_id = DataPlaneSessionId::new_for_kind(SessionKind::Process); + let fake = spawn_journal_fake( + session_id, + true, + Arc::new(|_, open| journal_replay(&JOURNAL, open)), + ) + .await; + let mut state = crate::tests::test_data_plane_state().await; + state.cluster_api = ClusterApiClients::service_only( + pplx_space_node_api_client::cluster::connect(fake.endpoint.clone(), "test") + .await + .unwrap(), + ); + let token = format!("{DATA_PLANE_TOKEN_PREFIX}{}", "c".repeat(64)); + let response = tower::ServiceExt::oneshot( + router(state), + Request::get(format!("/v1/sessions/{session_id}/events")) + .header(header::AUTHORIZATION, format!("Bearer {token}")) + .header("last-event-id", MAX_LAST_EVENT_ID.to_string()) + .body(Body::empty()) + .unwrap(), + ) + .await + .unwrap(); + + assert_eq!(response.status(), StatusCode::BAD_REQUEST); + assert!(fake.opens.lock().unwrap().is_empty()); +} diff --git a/crates/libs/data/plane/server/src/tests.rs b/crates/libs/data/plane/server/src/tests.rs index 6e56fc03d2..f4b26fb0d3 100644 --- a/crates/libs/data/plane/server/src/tests.rs +++ b/crates/libs/data/plane/server/src/tests.rs @@ -1,8 +1,5 @@ use super::*; -use crate::{ - native::{ProcessReplayState, first_frame_attach_token_from_recv}, - runtime_route::sweep_expired_ecw_routes, -}; +use crate::{native::first_frame_attach_token_from_recv, runtime_route::sweep_expired_ecw_routes}; use aws_lc_rs::rand::SystemRandom; use aws_lc_rs::signature::Ed25519KeyPair; use pplx_space_common_core::{ @@ -3763,47 +3760,29 @@ async fn first_frame_attach_token_times_out_at_deadline() { assert_eq!(result, Err(DataPlaneErrorCode::AttachDeadlineExceeded)); } -#[test] -fn process_sse_resume_emits_resync_at_next_event_id() { - let session_id = DataPlaneSessionId::Process(Default::default()); - let replay = ProcessReplayState::load(session_id, Some(41)); - - assert_eq!(replay.event_seq, 42); - assert_eq!(replay.backend_output_cursor, None); - assert_eq!(replay.pending.len(), 1); - - let fresh = ProcessReplayState::load(session_id, None); - assert_eq!(fresh.event_seq, 0); - assert!(fresh.pending.is_empty()); -} - -/// The public reconnection contract, shared by process and file-watch -/// sessions: `Last-Event-ID` resumes the live stream at `last + 1` behind a -/// `resync_required(cursor_replay_unavailable)` frame; no cursor, no frame. -/// Missed output is never replayed, so the backend cursor stays unset. +/// The file-watch reconnection contract: `Last-Event-ID` resumes the live +/// stream at `last + 1` behind a `resync_required(cursor_replay_unavailable)` +/// frame; no cursor, no frame. #[test] fn last_event_id_resume_is_a_cursor_replay_unavailable_resync() { - for kind in ["process", "file_watch"] { - assert_eq!(resume_resync_frame(kind, None), None, "{kind}"); - assert_eq!( - resume_resync_frame(kind, Some(41)), - Some(( - 42, - DataPlaneServerFrame::ResyncRequired { - reason: DataPlaneResyncReason::CursorReplayUnavailable, - }, - )), - "{kind}" - ); - // The largest cursor the request boundary admits still gets a fresh id. - assert_eq!( - resume_resync_frame(kind, Some(MAX_LAST_EVENT_ID)).map(|(seq, _)| seq), - Some(MAX_LAST_EVENT_ID + 1), - "{kind}" - ); - } + let kind = "file_watch"; + assert_eq!(resume_resync_frame(kind, None), None); + assert_eq!( + resume_resync_frame(kind, Some(41)), + Some(( + 42, + DataPlaneServerFrame::ResyncRequired { + reason: DataPlaneResyncReason::CursorReplayUnavailable, + }, + )) + ); + // The largest cursor the request boundary admits still gets a fresh id. + assert_eq!( + resume_resync_frame(kind, Some(MAX_LAST_EVENT_ID)).map(|(seq, _)| seq), + Some(MAX_LAST_EVENT_ID + 1) + ); assert_eq!( - resume_resync_frame("process", Some(0)).map(|(seq, _)| seq), + resume_resync_frame(kind, Some(0)).map(|(seq, _)| seq), Some(1) ); } diff --git a/crates/libs/node/api/sim/src/processes.rs b/crates/libs/node/api/sim/src/processes.rs index e7fa63ba6c..86f54117e6 100644 --- a/crates/libs/node/api/sim/src/processes.rs +++ b/crates/libs/node/api/sim/src/processes.rs @@ -9,8 +9,11 @@ //! //! Reconnects follow the guest's journal contract (`ConnectProcessRequest`): //! output records carry a sequence starting at `0`; a connect with an -//! `output_cursor` replays every record at or after that sequence, and a -//! connect without one follows the live tail and replays nothing. The +//! `output_cursor` replays every record at or after that sequence, a cursor +//! past the output ends the stream with the guest's tagged `OUT_OF_RANGE`, +//! and a connect without one follows the live tail and replays nothing. The +//! simulator retains all output, so it never reports a cursor as evicted, and +//! `ProcessConnected` reports that the stream starts at the cursor. The //! process table is per sandbox and is dropped with the sandbox. use std::collections::HashMap; @@ -225,7 +228,8 @@ enum ConnectMode { /// background start ends after `Started`, like production's stream. Start { background: bool }, /// Reattach: `Connected`, then the journal from `output_cursor`; `None` - /// is the live tail, which replays nothing. + /// is the live tail, which replays nothing, and a cursor past the output + /// fails. Connect { output_cursor: Option }, } @@ -247,10 +251,20 @@ fn event_stream(process: &SimProcess, mode: ConnectMode) -> SimProcessEventStrea } (started, 0) } - ConnectMode::Connect { output_cursor } => ( - sbx::spaced_process_event::Event::Connected(sbx::SpacedProcessConnected {}), - output_cursor.unwrap_or(tail).min(tail), - ), + ConnectMode::Connect { output_cursor } => { + // Nothing is evicted, so the stream starts at the cursor. + let connected = + sbx::spaced_process_event::Event::Connected(sbx::SpacedProcessConnected { + output_cursor, + }); + if output_cursor.is_some_and(|cursor| cursor > tail) { + return Box::pin(tokio_stream::iter(vec![ + Ok(event(&process_id, Some(pid), connected)), + Err(cursor_ahead_status()), + ])); + } + (connected, output_cursor.unwrap_or(tail)) + } }; let mut initial = vec![Ok(event(&process_id, Some(pid), first))]; initial.extend( @@ -282,6 +296,19 @@ fn event_stream(process: &SimProcess, mode: ConnectMode) -> SimProcessEventStrea Box::pin(tokio_stream::iter(initial).chain(exit)) } +/// The guest's status for a connect whose cursor is past the output. +fn cursor_ahead_status() -> Status { + let mut status = + Status::out_of_range("process output cursor is past the output the process has written"); + status.metadata_mut().insert( + pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY, + tonic::metadata::MetadataValue::from_static( + pplx_space_common_core::spaced::PROCESS_OUTPUT_CURSOR_AHEAD, + ), + ); + status +} + fn event( process_id: &str, pid: Option, diff --git a/crates/libs/node/api/sim/src/processes/tests.rs b/crates/libs/node/api/sim/src/processes/tests.rs index 15e1d439af..a0f2138805 100644 --- a/crates/libs/node/api/sim/src/processes/tests.rs +++ b/crates/libs/node/api/sim/src/processes/tests.rs @@ -46,10 +46,13 @@ async fn connect_replays_the_journal_from_the_cursor_only() { // Everything already delivered: nothing to replay. let at_tail = collect(table.connect("sbx", &process_id, Some(1)).await.unwrap()).await; - assert!(matches!( + assert_eq!( at_tail[0], - sbx::spaced_process_event::Event::Connected(_) - )); + sbx::spaced_process_event::Event::Connected(sbx::SpacedProcessConnected { + output_cursor: Some(1) + }), + "reports where it starts" + ); assert_eq!(stdout_count(&at_tail), 0); assert!(matches!( at_tail.last(), @@ -64,9 +67,28 @@ async fn connect_replays_the_journal_from_the_cursor_only() { let live = collect(table.connect("sbx", &process_id, None).await.unwrap()).await; assert_eq!(stdout_count(&live), 0); - // A cursor past the tail is clamped rather than panicking. - let beyond = collect(table.connect("sbx", &process_id, Some(99)).await.unwrap()).await; - assert_eq!(stdout_count(&beyond), 0); + // A cursor past the tail fails, as the guest's does, instead of + // skipping the output before it. + let beyond: Vec<_> = table + .connect("sbx", &process_id, Some(2)) + .await + .unwrap() + .collect() + .await; + assert_eq!(beyond.len(), 2); + assert!(matches!( + beyond[0].as_ref().unwrap().event, + Some(sbx::spaced_process_event::Event::Connected(_)) + )); + let error = beyond[1].as_ref().unwrap_err(); + assert_eq!(error.code(), tonic::Code::OutOfRange); + assert_eq!( + error + .metadata() + .get(pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY) + .and_then(|value| value.to_str().ok()), + Some(pplx_space_common_core::spaced::PROCESS_OUTPUT_CURSOR_AHEAD) + ); } /// Every execution-teardown path (stop, kill, delete, cleanup) ends the diff --git a/crates/libs/node/api/sim/src/worker/tests.rs b/crates/libs/node/api/sim/src/worker/tests.rs index 5dad827b08..6060f8380e 100644 --- a/crates/libs/node/api/sim/src/worker/tests.rs +++ b/crates/libs/node/api/sim/src/worker/tests.rs @@ -686,6 +686,7 @@ async fn stop_and_kill_end_the_sandbox_processes_before_a_restart() { process_id: process_id.clone(), timeout: None, output_cursor: None, + resume_from_oldest_retained: false, }), })) .await; diff --git a/crates/libs/public/api/src/lib.rs b/crates/libs/public/api/src/lib.rs index 937dd2ad5f..c570a4497a 100644 --- a/crates/libs/public/api/src/lib.rs +++ b/crates/libs/public/api/src/lib.rs @@ -1889,7 +1889,9 @@ pub struct DataPlaneAttachInfo { /// and validate the destination before sending credentials. pub url: String, /// HTTP SSE endpoint for this session, when supported. Attaching a command - /// starts execution; streams are live and do not replay missed output. + /// starts execution. Reconnecting with `Last-Event-ID` resumes with the + /// output after that event while the sandbox retains it, a bounded amount + /// per process; otherwise the stream sends `resync_required` first. pub events_url: Option, /// Session-scoped credential, not a management API token. Keep it secret /// and send it only to the verified attachment destination. diff --git a/crates/libs/sbx/mgr/server/src/service/grpc_spaced_process_snapshots.rs b/crates/libs/sbx/mgr/server/src/service/grpc_spaced_process_snapshots.rs index 33fe045d71..a247d4b6d3 100644 --- a/crates/libs/sbx/mgr/server/src/service/grpc_spaced_process_snapshots.rs +++ b/crates/libs/sbx/mgr/server/src/service/grpc_spaced_process_snapshots.rs @@ -223,6 +223,7 @@ impl SandboxManagerService { operation.process_id.clone(), proto_duration_to_std(operation.timeout), operation.output_cursor, + operation.resume_from_oldest_retained, ) .await?; // A reconnected foreground stream is the same liveness signal as the diff --git a/crates/libs/sbx/mgr/server/src/service/spaced_bridge.rs b/crates/libs/sbx/mgr/server/src/service/spaced_bridge.rs index cfaf5970db..252d02d0db 100644 --- a/crates/libs/sbx/mgr/server/src/service/spaced_bridge.rs +++ b/crates/libs/sbx/mgr/server/src/service/spaced_bridge.rs @@ -709,7 +709,9 @@ pub(super) fn process_event_to_spaced( HostEvent::Started(started) => SpacedEvent::Started(SpacedProcessStarted { start_time: started.start_time, }), - HostEvent::Connected(_) => SpacedEvent::Connected(SpacedProcessConnected {}), + HostEvent::Connected(connected) => SpacedEvent::Connected(SpacedProcessConnected { + output_cursor: connected.output_cursor, + }), HostEvent::Stdout(output) => SpacedEvent::Stdout(SpacedProcessOutput { data: output.data }), HostEvent::Stderr(output) => SpacedEvent::Stderr(SpacedProcessOutput { data: output.data }), HostEvent::Exit(exit) => { diff --git a/crates/libs/sbx/mgr/server/src/service/spaced_bridge/tests.rs b/crates/libs/sbx/mgr/server/src/service/spaced_bridge/tests.rs index 180c903096..409fdd8372 100644 --- a/crates/libs/sbx/mgr/server/src/service/spaced_bridge/tests.rs +++ b/crates/libs/sbx/mgr/server/src/service/spaced_bridge/tests.rs @@ -265,6 +265,32 @@ fn process_info_to_spaced_preserves_process_config() { assert_eq!(spaced.pty, Some(true)); } +/// The guest's report of where a reconnected stream starts reaches the data +/// plane, which relies on it to tell evicted output apart. +#[test] +fn process_event_to_spaced_keeps_the_connected_output_cursor() { + let event = host_proto::ProcessEvent { + process_id: "proc-1".to_string(), + pid: Some(123), + event: Some(host_proto::process_event::Event::Connected( + host_proto::ProcessConnected { + output_cursor: Some(9), + }, + )), + }; + + let spaced = process_event_to_spaced(event).unwrap(); + + assert_eq!( + spaced.event, + Some(crate::proto::spaced_process_event::Event::Connected( + SpacedProcessConnected { + output_cursor: Some(9) + } + )) + ); +} + #[tokio::test] async fn identity_fence_aborts_an_idle_stream() { let fence = RouteStreamFence::new(); diff --git a/crates/libs/sbx/mgr/server/src/service/tests.rs b/crates/libs/sbx/mgr/server/src/service/tests.rs index 65b32d784f..1d371139ac 100644 --- a/crates/libs/sbx/mgr/server/src/service/tests.rs +++ b/crates/libs/sbx/mgr/server/src/service/tests.rs @@ -16256,6 +16256,7 @@ pub(crate) mod service_tests { process_id: "process".to_string(), timeout: None, output_cursor: Some(7), + resume_from_oldest_retained: false, }, ), }); diff --git a/crates/libs/spaced/guest/execution/src/process.rs b/crates/libs/spaced/guest/execution/src/process.rs index 538604b6ff..6c346506c8 100644 --- a/crates/libs/spaced/guest/execution/src/process.rs +++ b/crates/libs/spaced/guest/execution/src/process.rs @@ -79,8 +79,8 @@ const PROCESS_OUTPUT_GUARANTEED_BYTES: usize = const PROCESS_OUTPUT_SHARED_BYTES: usize = PROCESS_OUTPUT_RETENTION_MAX_BYTES - PROCESS_RECORD_LIMIT * PROCESS_OUTPUT_GUARANTEED_BYTES; const PROCESS_OUTPUT_DRAIN_TIMEOUT: Duration = Duration::from_secs(1); -const PROCESS_OUTPUT_LAGGED_MESSAGE: &str = - "process output stream fell behind retained output buffer"; +const PROCESS_OUTPUT_CURSOR_AHEAD_MESSAGE: &str = + "process output cursor is past the output the process has written"; const PROCESS_CAPACITY_MESSAGE: &str = "too many retained processes"; // A start phase slower than this is logged with every phase's duration once // the spawn returns, so a slow start names its cause. The account lookup @@ -427,7 +427,7 @@ impl ProcessLaunch { )); claim.publish(Arc::clone(&record)); - let cursor = record.journal.cursor(Some(0)); + let cursor = record.journal.cursor(Some(0), false); let mut output_tasks = VecDeque::new(); if let Some(reader) = pty_reader { output_tasks.push_back(spawn_process_output_reader( @@ -1030,12 +1030,25 @@ impl ProcessEventJournal { .completed_at } - fn cursor(self: &Arc, requested: Option) -> ProcessJournalCursor { + /// A reader from `requested`, or from the live tail when `None`. With + /// `from_oldest_retained`, a cursor before the oldest retained output + /// starts there instead of lagging. That start is chosen under the lock + /// that also claims the primary reader's place, so no output written + /// meanwhile can evict it. + fn cursor( + self: &Arc, + requested: Option, + from_oldest_retained: bool, + ) -> ProcessJournalCursor { let mut state = self .state .lock() .expect("process output journal lock poisoned"); - let next_sequence = requested.unwrap_or(state.next_sequence); + let next_sequence = match requested { + Some(cursor) if from_oldest_retained => cursor.max(state.first_sequence), + Some(cursor) => cursor, + None => state.next_sequence, + }; // Only one reader controls the producer. Observers cannot stall an // existing consumer; after disconnect a new attachment can take over. let primary = if !state.backpressure_disabled @@ -1211,7 +1224,15 @@ impl ProcessEventJournal { .lock() .expect("process output journal lock poisoned"); if cursor < state.first_sequence { - return ProcessJournalRead::Lagged; + return ProcessJournalRead::Lagged { + first_sequence: state.first_sequence, + }; + } + // A cursor only ever advances over output it has read, so one past the + // end came from a caller, not from this journal: waiting for output to + // reach it would skip everything written before it. + if cursor > state.next_sequence { + return ProcessJournalRead::Ahead; } if cursor < state.next_sequence { let offset = (cursor - state.first_sequence) as usize; @@ -1282,7 +1303,8 @@ enum ProcessJournalRead { Event(ProcessEvent), Exit(ProcessEvent), Pending, - Lagged, + Lagged { first_sequence: u64 }, + Ahead, } #[derive(Clone, Copy)] @@ -1409,7 +1431,12 @@ impl ProcessRegistry { Some(record) } - fn replay(&self, process_id: &ProcessId, output_cursor: Option) -> Option { + fn replay( + &self, + process_id: &ProcessId, + output_cursor: Option, + from_oldest_retained: bool, + ) -> Option { let record = self.get_record(process_id)?; if output_cursor.is_none() && let Some(exit) = record.journal.exit() @@ -1421,7 +1448,7 @@ impl ProcessRegistry { } Some(ProcessReplay::Running { started: record.started.clone(), - cursor: record.journal.cursor(output_cursor), + cursor: record.journal.cursor(output_cursor, from_oldest_retained), }) } @@ -1542,9 +1569,10 @@ fn process_event_stream_with_prefix( return Some((Ok(event), (prefix, cursor))); } ProcessJournalRead::Exit(exit) => break Ok(exit), - ProcessJournalRead::Lagged => { - break Err(Status::resource_exhausted(PROCESS_OUTPUT_LAGGED_MESSAGE)); + ProcessJournalRead::Lagged { first_sequence } => { + break Err(process_output_lagged_status(Some(first_sequence))); } + ProcessJournalRead::Ahead => break Err(process_output_cursor_ahead_status()), ProcessJournalRead::Pending => { if current.changed.changed().await.is_err() { break evicted_process_journal_result(current); @@ -1557,15 +1585,46 @@ fn process_event_stream_with_prefix( )) } +fn process_output_cursor_ahead_status() -> Status { + let mut status = Status::out_of_range(PROCESS_OUTPUT_CURSOR_AHEAD_MESSAGE); + status.metadata_mut().insert( + pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY, + tonic::metadata::MetadataValue::from_static( + pplx_space_common_core::spaced::PROCESS_OUTPUT_CURSOR_AHEAD, + ), + ); + status +} + +/// The status that ends a stream whose cursor is before the oldest retained +/// output, naming where that output starts, `first_sequence`, so the caller +/// can continue from there. `None` once the journal itself is gone. +fn process_output_lagged_status(first_sequence: Option) -> Status { + let mut status = + Status::resource_exhausted(pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED_MESSAGE); + let metadata = status.metadata_mut(); + metadata.insert( + pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY, + tonic::metadata::MetadataValue::from_static( + pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED, + ), + ); + if let Some(first_sequence) = first_sequence { + metadata.insert( + pplx_space_common_core::spaced::PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY, + tonic::metadata::MetadataValue::from(first_sequence), + ); + } + status +} + fn evicted_process_journal_result(cursor: &ProcessJournalCursor) -> Result { match cursor.changed.borrow().clone() { ProcessJournalChange::Exit { event, next_sequence, } if cursor.next_sequence >= next_sequence => Ok(event), - ProcessJournalChange::Exit { .. } => { - Err(Status::resource_exhausted(PROCESS_OUTPUT_LAGGED_MESSAGE)) - } + ProcessJournalChange::Exit { .. } => Err(process_output_lagged_status(None)), ProcessJournalChange::OutputChanged => Err(Status::resource_exhausted( "process replay state was evicted", )), @@ -1587,13 +1646,19 @@ fn process_started_event(process_id: &ProcessId, pid: Option) -> Result) -> ProcessEvent { +fn process_connected_event( + process_id: &ProcessId, + pid: Option, + output_cursor: Option, +) -> ProcessEvent { ProcessEvent { process_id: process_id.as_str().to_string(), pid, event: Some( pplx_space_spaced_guest_protocol::proto::bridge_guest::process_event::Event::Connected( - pplx_space_spaced_guest_protocol::proto::bridge_guest::ProcessConnected {}, + pplx_space_spaced_guest_protocol::proto::bridge_guest::ProcessConnected { + output_cursor, + }, ), ), } @@ -2068,7 +2133,7 @@ impl Process for ExecutionService { let replay = self .inner .processes - .replay(&process_id, Some(0)) + .replay(&process_id, Some(0), false) .ok_or_else(|| Status::failed_precondition("process replay state expired"))?; return Ok(Response::new( replay_process_event_stream(replay) as Self::StartStream @@ -2195,7 +2260,11 @@ impl Process for ExecutionService { let replay = self .inner .processes - .replay(&process_id, request.output_cursor) + .replay( + &process_id, + request.output_cursor, + request.resume_from_oldest_retained, + ) .ok_or_else(|| Status::not_found("process not found"))?; let pid = match &replay { ProcessReplay::Running { started, .. } | ProcessReplay::Completed { started, .. } => { @@ -2203,10 +2272,13 @@ impl Process for ExecutionService { } }; let stream = match replay { - ProcessReplay::Running { cursor, .. } => process_event_stream_with_prefix( - vec![process_connected_event(&process_id, pid)], - Some(cursor), - ), + ProcessReplay::Running { cursor, .. } => { + let output_cursor = request.output_cursor.map(|_| cursor.next_sequence); + process_event_stream_with_prefix( + vec![process_connected_event(&process_id, pid, output_cursor)], + Some(cursor), + ) + } replay @ ProcessReplay::Completed { .. } => replay_process_event_stream(replay), }; tracing::debug!( diff --git a/crates/libs/spaced/guest/execution/src/process/tests.rs b/crates/libs/spaced/guest/execution/src/process/tests.rs index d792107bed..b1bc7ce61c 100644 --- a/crates/libs/spaced/guest/execution/src/process/tests.rs +++ b/crates/libs/spaced/guest/execution/src/process/tests.rs @@ -335,7 +335,7 @@ async fn losing_start_response_preserves_output_supervision_and_idempotency() { let mut changed = record.journal.subscribe(); while record.journal.tail_cursor() < 2 || (completed && !record.journal.is_completed()) - || (evicted && !matches!(record.journal.read(0), ProcessJournalRead::Lagged)) + || (evicted && !matches!(record.journal.read(0), ProcessJournalRead::Lagged { .. })) { changed.changed().await.unwrap(); } @@ -369,7 +369,10 @@ async fn losing_start_response_preserves_output_supervision_and_idempotency() { Err(error) => { assert!(evicted); assert_eq!(error.code(), tonic::Code::ResourceExhausted); - assert_eq!(error.message(), PROCESS_OUTPUT_LAGGED_MESSAGE); + assert_eq!( + error.message(), + pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED_MESSAGE + ); lagged = true; assert!(replay.next().await.is_none()); break; @@ -521,7 +524,7 @@ async fn process_journal_reports_lag_when_local_ring_evicts_output() { )); } assert!( - matches!(journal.read(0), ProcessJournalRead::Lagged), + matches!(journal.read(0), ProcessJournalRead::Lagged { .. }), "retention must charge tiny event overhead as well as payloads" ); assert!(matches!( @@ -545,7 +548,7 @@ async fn attached_output_backpressures_and_disconnect_releases_the_producer() { shared_bytes, )))); let process_id = ProcessId::new(); - let cursor = journal.cursor(Some(0)); + let cursor = journal.cursor(Some(0), false); let event = process_stdout_event(&process_id, Some(1), vec![b'a'; 8192]); while journal.try_append_output(event.clone()).is_none() {} let tail = journal.tail_cursor(); @@ -646,7 +649,8 @@ async fn fallback_drain_bounds_inherited_writer_despite_consuming_reader() { let id = ProcessId::new(); let pid = std::process::id(); let journal = Arc::new(ProcessEventJournal::new(output_slots())); - let mut stream = process_event_stream_with_prefix(Vec::new(), Some(journal.cursor(Some(0)))); + let mut stream = + process_event_stream_with_prefix(Vec::new(), Some(journal.cursor(Some(0), false))); let event = process_stdout_event(&id, Some(pid), vec![0; 8192]); while journal.try_append_output(event.clone()).is_none() {} let (blocked, mut pending) = tokio::sync::mpsc::channel(1); @@ -804,7 +808,7 @@ fn process_journal_drops_oversized_chunk_without_panicking() { vec![0; PROCESS_OUTPUT_RETENTION_BYTES + 1], )); - assert!(matches!(journal.read(0), ProcessJournalRead::Lagged)); + assert!(matches!(journal.read(0), ProcessJournalRead::Lagged { .. })); } #[test] @@ -823,7 +827,7 @@ fn output_pressure_is_isolated_to_one_process() { )); noisy.append_output(process_stdout_event(&noisy_id, Some(1), vec![1])); - assert!(matches!(noisy.read(0), ProcessJournalRead::Lagged)); + assert!(matches!(noisy.read(0), ProcessJournalRead::Lagged { .. })); assert!(matches!(quiet.read(0), ProcessJournalRead::Event(_))); } @@ -904,6 +908,138 @@ async fn evicted_cursor_reports_lag_before_terminal_event() { ); } +/// A cursor past the written output fails at once, whether the process is +/// still running or has exited, rather than waiting for output to reach it and +/// skipping everything written before. The end of the output stays valid. +#[tokio::test] +async fn cursor_past_the_output_fails_instead_of_waiting() { + for completed in [false, true] { + let journal = Arc::new(ProcessEventJournal::new(output_slots())); + let process_id = ProcessId::new(); + journal.append_output(process_stdout_event( + &process_id, + Some(1), + b"written".to_vec(), + )); + let exit = process_stdout_event(&process_id, Some(1), b"terminal".to_vec()); + if completed { + journal.complete(exit.clone()); + } + + let mut ahead = + process_event_stream_with_prefix(Vec::new(), Some(journal.cursor(Some(5), false))); + let error = tokio::time::timeout(Duration::from_secs(1), ahead.next()) + .await + .expect("a cursor past the output must not wait") + .unwrap() + .unwrap_err(); + assert_eq!( + error.code(), + tonic::Code::OutOfRange, + "completed: {completed}" + ); + assert_eq!( + error + .metadata() + .get(pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY) + .and_then(|value| value.to_str().ok()), + Some(pplx_space_common_core::spaced::PROCESS_OUTPUT_CURSOR_AHEAD) + ); + assert!(ahead.next().await.is_none()); + + let mut at_end = + process_event_stream_with_prefix(Vec::new(), Some(journal.cursor(Some(1), false))); + let next = tokio::time::timeout(Duration::from_millis(100), at_end.next()).await; + if completed { + assert_eq!(next.unwrap().unwrap().unwrap(), exit); + } else { + assert!(next.is_err(), "the end of a running process's output waits"); + } + } +} + +/// A cursor before the oldest retained output fails with a status that says +/// so and where that output starts, so the caller can continue from there +/// instead of jumping to the live tail. +#[tokio::test] +async fn lagged_cursor_reports_the_oldest_retained_output() { + use pplx_space_spaced_guest_protocol::proto::bridge_guest::process_event::Event; + + let journal = Arc::new(ProcessEventJournal::new(Arc::new(Semaphore::new(0)))); + let process_id = ProcessId::new(); + journal.append_output(process_stdout_event( + &process_id, + Some(1), + vec![0; PROCESS_OUTPUT_RETENTION_BYTES], + )); + journal.append_output(process_stdout_event(&process_id, Some(1), b"kept".to_vec())); + + let mut lagged = + process_event_stream_with_prefix(Vec::new(), Some(journal.cursor(Some(0), false))); + let error = lagged.next().await.unwrap().unwrap_err(); + assert_eq!(error.code(), tonic::Code::ResourceExhausted); + let metadata = |key| { + error + .metadata() + .get(key) + .and_then(|value| value.to_str().ok()) + .map(str::to_owned) + }; + assert_eq!( + metadata(pplx_space_common_core::spaced::ERROR_REASON_METADATA_KEY).as_deref(), + Some(pplx_space_common_core::spaced::PROCESS_OUTPUT_LAGGED) + ); + let first_sequence: u64 = + metadata(pplx_space_common_core::spaced::PROCESS_OUTPUT_FIRST_SEQUENCE_METADATA_KEY) + .expect("the oldest retained output") + .parse() + .unwrap(); + assert_eq!(first_sequence, 1); + assert!(lagged.next().await.is_none()); + + let mut retained = process_event_stream_with_prefix( + Vec::new(), + Some(journal.cursor(Some(first_sequence), false)), + ); + let event = retained.next().await.unwrap().unwrap(); + assert!(matches!(event.event, Some(Event::Stdout(output)) if output.data == b"kept")); +} + +/// A lagged cursor that asks for the oldest retained output starts there, +/// and holds it: the start is chosen under the lock that makes the reader +/// primary, so output written before it reads anything waits for it instead +/// of evicting that output, and the reader cannot lag again. +#[tokio::test] +async fn lagged_cursor_from_oldest_retained_starts_there_and_holds_it() { + use pplx_space_spaced_guest_protocol::proto::bridge_guest::process_event::Event; + + let journal = Arc::new(ProcessEventJournal::new(Arc::new(Semaphore::new(0)))); + let process_id = ProcessId::new(); + journal.append_output(process_stdout_event( + &process_id, + Some(1), + vec![0; PROCESS_OUTPUT_RETENTION_BYTES], + )); + journal.append_output(process_stdout_event(&process_id, Some(1), b"kept".to_vec())); + + let cursor = journal.cursor(Some(0), true); + assert_eq!( + cursor.next_sequence, 1, + "starts at the oldest retained output" + ); + let more = process_stdout_event(&process_id, Some(1), vec![0; 8192]); + let waited = (0..2 * PROCESS_OUTPUT_RETENTION_BYTES / 8192) + .any(|_| journal.try_append_output(more.clone()).is_some()); + assert!( + waited, + "later output waits for the reader instead of evicting" + ); + + let mut retained = process_event_stream_with_prefix(Vec::new(), Some(cursor)); + let event = retained.next().await.unwrap().unwrap(); + assert!(matches!(event.event, Some(Event::Stdout(output)) if output.data == b"kept")); +} + #[tokio::test] async fn login_tty_pty_supports_output_input_and_resize() { let prepared = prepare_pty(Some(PtySize { rows: 24, cols: 80 })).expect("open test pty"); diff --git a/crates/libs/spaced/guest/server/tests/it/process.rs b/crates/libs/spaced/guest/server/tests/it/process.rs index 4547603dc7..ee40caabc9 100644 --- a/crates/libs/spaced/guest/server/tests/it/process.rs +++ b/crates/libs/spaced/guest/server/tests/it/process.rs @@ -191,6 +191,7 @@ async fn bridge_guest_process_stalled_stream_does_not_block_reconnect_exit() { process_id: started.process_id, timeout: None, output_cursor: None, + resume_from_oldest_retained: false, })) .await .expect("connect response") @@ -244,10 +245,23 @@ async fn bridge_guest_process_connect_replays_from_output_cursor() { process_id: started.process_id, timeout: None, output_cursor: Some(0), + resume_from_oldest_retained: true, })) .await .expect("connect response") .into_inner(); + let first = connected + .next() + .await + .expect("connected event") + .expect("connected event response"); + assert_eq!( + first.event, + Some(Event::Connected(bridge_guest::ProcessConnected { + output_cursor: Some(0) + })), + "the stream reports where it starts" + ); let mut replayed = Vec::new(); tokio::time::timeout(std::time::Duration::from_secs(2), async { @@ -545,6 +559,7 @@ async fn bridge_guest_process_start_replays_output_while_cursorless_connect_retu process_id: started.process_id.clone(), timeout: None, output_cursor: None, + resume_from_oldest_retained: false, }) .await .expect("connect exited process") @@ -699,6 +714,7 @@ async fn bridge_guest_process_connect_and_signal_validation_work() { process_id: process_id.clone(), timeout: None, output_cursor: None, + resume_from_oldest_retained: false, }) .await .expect("connect process") @@ -798,6 +814,7 @@ async fn bridge_guest_process_connect_unknown_returns_not_found() { process_id: "missing".into(), timeout: None, output_cursor: None, + resume_from_oldest_retained: false, }) .await .expect_err("missing process rejected"); diff --git a/crates/libs/spaced/host/client/src/process.rs b/crates/libs/spaced/host/client/src/process.rs index 0061b3c8f4..ecfdac8d3b 100644 --- a/crates/libs/spaced/host/client/src/process.rs +++ b/crates/libs/spaced/host/client/src/process.rs @@ -12,11 +12,13 @@ pub(super) fn connect_process_request( process_id: &ProcessId, timeout: Option, output_cursor: Option, + resume_from_oldest_retained: bool, ) -> ConnectProcessRequest { ConnectProcessRequest { process_id: process_id.as_str().to_string(), timeout: timeout.map(proto_duration), output_cursor, + resume_from_oldest_retained, } } @@ -89,6 +91,7 @@ impl SpacedHostClient { process_id: String, timeout: Option, output_cursor: Option, + resume_from_oldest_retained: bool, ) -> Result, tonic::Status> { let process_id = ProcessId::parse(process_id).map_err(invalid_argument_status)?; let timeout = timeout @@ -108,6 +111,7 @@ impl SpacedHostClient { &process_id, timeout, output_cursor, + resume_from_oldest_retained, )) .await .map(Response::into_inner) diff --git a/crates/libs/spaced/host/client/src/tests.rs b/crates/libs/spaced/host/client/src/tests.rs index ee6f0f0a7b..879dbe7284 100644 --- a/crates/libs/spaced/host/client/src/tests.rs +++ b/crates/libs/spaced/host/client/src/tests.rs @@ -121,10 +121,11 @@ impl RejectingControlService { fn connect_process_request_preserves_output_cursor() { let process_id = ProcessId::new(); - let request = connect_process_request(&process_id, None, Some(7)); + let request = connect_process_request(&process_id, None, Some(7), true); assert_eq!(request.process_id, process_id.as_str()); assert_eq!(request.output_cursor, Some(7)); + assert!(request.resume_from_oldest_retained); } #[tokio::test] diff --git a/crates/libs/spaced/host/server/tests/it/process.rs b/crates/libs/spaced/host/server/tests/it/process.rs index 6859dc1f2e..a350950384 100644 --- a/crates/libs/spaced/host/server/tests/it/process.rs +++ b/crates/libs/spaced/host/server/tests/it/process.rs @@ -233,7 +233,7 @@ async fn process_connect_and_kill_relay_to_guest_bridge() { let client = fixture.client().await; let mut events = client - .connect_process_stream_with_cursor("proc-1".into(), None, None) + .connect_process_stream_with_cursor("proc-1".into(), None, None, false) .await .expect("connect response"); assert_eq!( diff --git a/crates/libs/spaced/host/server/tests/support/mock_bridge_guest.rs b/crates/libs/spaced/host/server/tests/support/mock_bridge_guest.rs index 10de0568e1..5d76e542ed 100644 --- a/crates/libs/spaced/host/server/tests/support/mock_bridge_guest.rs +++ b/crates/libs/spaced/host/server/tests/support/mock_bridge_guest.rs @@ -447,7 +447,9 @@ impl Process for MockBridgeGuest { pid: Some(123), event: Some( pplx_space_spaced_common::proto::bridge_guest::process_event::Event::Connected( - pplx_space_spaced_common::proto::bridge_guest::ProcessConnected {}, + pplx_space_spaced_common::proto::bridge_guest::ProcessConnected { + output_cursor: None, + }, ), ), })]; diff --git a/docs/api/schema-catalog.mjs b/docs/api/schema-catalog.mjs index ae6eb3c7a6..3cee223473 100644 --- a/docs/api/schema-catalog.mjs +++ b/docs/api/schema-catalog.mjs @@ -50,7 +50,7 @@ export const modelGroups = [ }, { name: 'Stream event models', - description: 'SSE events carry these frames. Streams are live, not replayable history; related WebSocket and file-watch types do not add supported creation endpoints.', + description: 'SSE events carry these frames. Streams are not durable history: a reconnect resumes only output the sandbox still retains; related WebSocket and file-watch types do not add supported creation endpoints.', models: [ ['DataPlaneServerFrame', 'Stream event', 'The tagged event payload carried by the stream, including output, resynchronization, errors and process exit.'], ['DataPlaneProcessExitStatus', 'Process exit status', 'How a streamed process ended; also inspect its exit code and any output loss or error.'], diff --git a/docs/architecture.md b/docs/architecture.md index ac6b450ae9..cc1b20fd40 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -261,7 +261,8 @@ they end or the pod's termination grace period kills the process. A second stop signal ends the drain the way the deadline does, but at once: a `Process.Start` still opening is cut the way SIGKILL would cut it. At the deadline: native event streams end, and a client that reconnects with `Last-Event-ID` resumes -the live stream but doesn't get the output it missed; native WebSockets close +a process's output after the last event it received while the guest still +retains it, and a file watch's live stream; native WebSockets close with 1012, including ones still opening their backend stream, and the client re-attaches the same session (a process or terminal session doesn't start its process again); ECW connect streams end with `unavailable` and need a new diff --git a/docs/first-sandbox.md b/docs/first-sandbox.md index ec069aefea..a1ae6f1584 100644 --- a/docs/first-sandbox.md +++ b/docs/first-sandbox.md @@ -85,7 +85,7 @@ Read `/openapi-m1.json` for exact request constraints and supported fields. This The example displays decoded stdout and stderr and saves the raw event stream in its run directory. Handle binary output separately rather than displaying it in a terminal. -Command output is a live stream, not durable log storage. Reconnecting with `Last-Event-ID` produces `resync_required`, not a replay of missed output. Keep the transcript when a stream fails; repeat a command only if repeating its effects is safe. +Command output is a live stream, not durable log storage. The sandbox retains a bounded amount of each process's recent output: reconnecting with `Last-Event-ID`, set to the last `id` received, exactly as received (only output and `resync_required` events carry one), resumes with the output after that event while it is retained, and otherwise produces `resync_required` first. After a process's first 2^33 - 1 output chunks, ids no longer carry its output position, and each reconnect replays the retained output behind `resync_required`. Keep the transcript when a stream fails; repeat a command only if repeating its effects is safe. ## Inspect and manage the sandbox diff --git a/docs/space/diagrams/data-plane-sigterm-drain.mmd b/docs/space/diagrams/data-plane-sigterm-drain.mmd index 3c06ab7430..eca28a9f1e 100644 --- a/docs/space/diagrams/data-plane-sigterm-drain.mmd +++ b/docs/space/diagrams/data-plane-sigterm-drain.mmd @@ -16,6 +16,6 @@ sequenceDiagram DP->>K: exit early else --shutdown-grace-secs set and passed, or a second stop signal DP->>L: cancel stream_shutdown_token - Note over L: native SSE: body ends → reconnect with Last-Event-ID
(live resume, missed output not replayed)
native WebSocket: close 1012
ECW connect: unavailable end-stream → reconnect
(unreported start: unknown, no retry)
streamed StreamInput: 409
other upgrades: closed + Note over L: native SSE: body ends → reconnect with Last-Event-ID
(resumes output the sandbox still retains)
native WebSocket: close 1012
ECW connect: unavailable end-stream → reconnect
(unreported start: unknown, no retry)
streamed StreamInput: 409
other upgrades: closed DP->>K: exit (after ≤ 5s cancel grace) end diff --git a/docs/space/diagrams/data-plane-sigterm-drain.png b/docs/space/diagrams/data-plane-sigterm-drain.png index 761eae4bea..abb1024676 100644 Binary files a/docs/space/diagrams/data-plane-sigterm-drain.png and b/docs/space/diagrams/data-plane-sigterm-drain.png differ diff --git a/docs/space/diagrams/data-plane-sigterm-drain.svg b/docs/space/diagrams/data-plane-sigterm-drain.svg index cef14696a5..30bcf4a0b7 100644 --- a/docs/space/diagrams/data-plane-sigterm-drain.svg +++ b/docs/space/diagrams/data-plane-sigterm-drain.svg @@ -1 +1 @@ -Live streams(child of stream_shutdown_token)New stream request(attach / SSE / ECW / upgrade)Data planeserve_and_drainKubeletLive streams(child of stream_shutdown_token)New stream request(attach / SSE / ECW / upgrade)Data planeserve_and_drainKubeletnew connections (probes too) refusedidle keep-alive connections closenative SSE: body ends → reconnect with Last-Event-ID(live resume, missed output not replayed)native WebSocket: close 1012ECW connect: unavailable end-stream → reconnect(unreported start: unknown, no retry)streamed StreamInput: 409other upgrades: closedalt[every stream ends before the deadline][--shutdown-grace-secs set and passed, or a second stop signal]SIGTERM (shutdown_token)1drain_started cancelledlistener stops accepting2request already in flight3503 + Retry-After: 1(+ Connection: close on HTTP/1)unattached WebSocket: close 10124keep running untouched5last connection / tracked task finishes6exit early7cancel stream_shutdown_token8exit (after ≤ 5s cancel grace)9 \ No newline at end of file +Live streams(child of stream_shutdown_token)New stream request(attach / SSE / ECW / upgrade)Data planeserve_and_drainKubeletLive streams(child of stream_shutdown_token)New stream request(attach / SSE / ECW / upgrade)Data planeserve_and_drainKubeletnew connections (probes too) refusedidle keep-alive connections closenative SSE: body ends → reconnect with Last-Event-ID(resumes output the sandbox still retains)native WebSocket: close 1012ECW connect: unavailable end-stream → reconnect(unreported start: unknown, no retry)streamed StreamInput: 409other upgrades: closedalt[every stream ends before the deadline][--shutdown-grace-secs set and passed, or a second stop signal]SIGTERM (shutdown_token)1drain_started cancelledlistener stops accepting2request already in flight3503 + Retry-After: 1(+ Connection: close on HTTP/1)unattached WebSocket: close 10124keep running untouched5last connection / tracked task finishes6exit early7cancel stream_shutdown_token8exit (after ≤ 5s cancel grace)9 \ No newline at end of file diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index eb6980de61..9dfa75f7e3 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -78,7 +78,7 @@ This prints sandbox listings and the saved creation/deletion operations, sandbox | Stream authentication fails | Use `attach.token`, not `SPACE_API_TOKEN`, and the correct session URL. Check expiry and attach promptly after creating the command. | | Example rejects an endpoint, events URL, or redirect | Use HTTPS except for loopback HTTP. Check the data-plane origin and session ID; correct the configuration rather than removing destination or redirect checks. | | HTTP stream succeeds but output is incomplete | Check for `process_exited`, its exit result, and any `error` or `resync_required` frame. A closed connection is not proof of successful execution. | -| Reconnect reports `resync_required` | Missed output is not replayed. Inspect the saved event transcript and query the process only if it is still running. Rerun only if repeating the command's effects is safe. | +| Reconnect reports `resync_required` | The stream could not resume exactly: output from before the reconnect may be missing or repeated. Check that the client sends the last `id` it received exactly as received. A process that has written more than 2^33 - 1 output chunks always resumes this way. Inspect the saved event transcript and query the process only if it is still running. Rerun only if repeating the command's effects is safe. | | Command exits nonzero | Read stderr and the exit result from the saved event transcript. Check that the executable and working directory exist inside the sandbox, not just on the host. | | Single-process GET returns `not_found` | This endpoint inspects a running process, not historical command results. It returns `not_found` before attachment and after exit. | diff --git a/proto/spaced/operations/v1/operations.proto b/proto/spaced/operations/v1/operations.proto index 9250f475b6..a89e66b8d8 100644 --- a/proto/spaced/operations/v1/operations.proto +++ b/proto/spaced/operations/v1/operations.proto @@ -228,7 +228,24 @@ message ConnectProcessRequest { // follows the live tail. Native public data-plane replay sets this to the // number of stdout/stderr events already durably captured so output emitted // while a client was disconnected is replayed from the guest journal. + // + // A cursor outside the retained output ends the stream with a status whose + // `space-error-reason` metadata names why: + // - past the output the process has written: OUT_OF_RANGE, + // `process-output-cursor-ahead`; + // - before the oldest output the guest still retains: RESOURCE_EXHAUSTED, + // `process-output-lagged`, with `space-process-output-first-sequence` + // metadata giving the cursor of that oldest output, in decimal, while the + // guest still holds the process. + // Older guests end a lagged stream with RESOURCE_EXHAUSTED and no reason, + // and wait for output to reach a cursor past it. optional uint64 output_cursor = 3; + // With `output_cursor` before the oldest output the guest still retains, + // start the stream at that oldest output instead of ending it as lagged. + // The guest chooses the start under the lock that also gives the stream + // its reader position, so output written meanwhile cannot evict it, and + // reports it in `ProcessConnected.output_cursor`. Older guests ignore it. + bool resume_from_oldest_retained = 4; } message ListProcessesRequest {} message ProcessInfo { @@ -276,7 +293,13 @@ message ProcessEvent { } } message ProcessStarted { optional google.protobuf.Timestamp start_time = 1; } -message ProcessConnected {} +message ProcessConnected { + // The journal cursor of the first output this stream sends, when the + // request set `output_cursor`: that cursor, or a later one when + // `resume_from_oldest_retained` moved the start past evicted output. + // Unset by older guests. + optional uint64 output_cursor = 1; +} message ProcessOutput { bytes data = 1; } message ProcessExit { oneof outcome { diff --git a/scripts/tests/smoke-spaced-rest.sh b/scripts/tests/smoke-spaced-rest.sh index 4a61ee1a47..0f10734b98 100755 --- a/scripts/tests/smoke-spaced-rest.sh +++ b/scripts/tests/smoke-spaced-rest.sh @@ -587,6 +587,7 @@ let status = null; let attached = false; let lastEventId = null; let eventIdsMonotonic = true; +let eventIdsOnOutputOnly = true; const timeout = setTimeout(() => { console.error('timed out waiting for command event stream'); @@ -612,16 +613,18 @@ function parseEvents(buffer) { else if (name === 'id') id = value; else if (name === 'data') data.push(value); } - if (data.length) events.push({ event, id: id === null ? null : Number(id), data: JSON.parse(data.join('\n')) }); + // Ids are opaque: keep them as received, to echo them exactly. + if (data.length) events.push({ event, id, data: JSON.parse(data.join('\n')) }); } return { events, rest }; } // Open one SSE connection and feed events to `onEvent` until it returns true. -// Every identified frame must carry exactly the previous id plus one. +// Every identified frame must carry a greater id than the one before, and +// only output and resync_required frames may carry one. async function readStream(resumeFrom, onEvent) { const headers = { Accept: 'text/event-stream', Authorization: `Bearer ${command.attach.token}` }; - if (resumeFrom !== null) headers['Last-Event-ID'] = String(resumeFrom); + if (resumeFrom !== null) headers['Last-Event-ID'] = resumeFrom; const response = await fetch(eventsUrl(command), { headers }); if (!response.ok || !response.body) { throw new Error(`command event stream returned HTTP ${response.status}`); @@ -637,10 +640,12 @@ async function readStream(resumeFrom, onEvent) { buffer = rest; for (const event of events) { if (event.id !== null) { - if (lastEventId !== null && event.id !== lastEventId + 1) eventIdsMonotonic = false; + if (lastEventId !== null && BigInt(event.id) <= BigInt(lastEventId)) eventIdsMonotonic = false; lastEventId = event.id; } if (event.event !== null && event.event !== event.data.type) eventIdsMonotonic = false; + const identified = ['stdout', 'stderr', 'resync_required'].includes(event.data.type); + if ((event.id !== null) !== identified) eventIdsOnOutputOnly = false; if (onEvent(event)) { await reader.cancel().catch(() => {}); return true; @@ -682,20 +687,18 @@ async function readStream(resumeFrom, onEvent) { } // Second connection: resume with Last-Event-ID. The contract is that the - // stream restarts with attached, then resync_required(cursor_replay_unavailable) - // at Last-Event-ID + 1, and the exited process still reports its exit. + // stream restarts with attached, resumes after Last-Event-ID without + // replaying output already received or asking to resync, and the exited + // process still reports its exit. const resumeFrom = lastEventId; - const resume = { attached_first: null, first_id: null, first_type: null, reason: null, exit_code: null }; + const resume = { attached_first: null, resync: null, stdout: '', exit_code: null }; let seen = 0; await readStream(resumeFrom, (event) => { const frame = event.data; seen += 1; if (seen === 1) resume.attached_first = frame.type === 'attached' && event.id === null; - if (event.id !== null && resume.first_id === null) { - resume.first_id = event.id; - resume.first_type = frame.type; - resume.reason = frame.reason === undefined ? null : frame.reason; - } + if (frame.type === 'resync_required' && resume.resync === null) resume.resync = frame.reason; + if (frame.type === 'stdout') resume.stdout += Buffer.from(frame.data_base64, 'base64').toString('utf8'); if (frame.type === 'process_exited') { resume.exit_code = frame.exit_code; return true; @@ -714,6 +717,7 @@ async function readStream(resumeFrom, onEvent) { exit_code: exitCode, status, event_ids_monotonic: eventIdsMonotonic, + event_ids_on_output_only: eventIdsOnOutputOnly, resume_from: resumeFrom, resume, })); @@ -840,11 +844,11 @@ assert_eq "$(jq -r '.attached' <<<"$command_result")" "true" "command stream att assert_eq "$(jq -r '.stdout' <<<"$command_result")" "$RUN_ID" "command stdout" assert_eq "$(jq -r '.stderr' <<<"$command_result")" "command-err" "command stderr" assert_eq "$(jq -r '.exit_code' <<<"$command_result")" "6" "command exit code" -assert_eq "$(jq -r '.event_ids_monotonic' <<<"$command_result")" "true" "command stream ids increase by one" +assert_eq "$(jq -r '.event_ids_monotonic' <<<"$command_result")" "true" "command stream ids increase" +assert_eq "$(jq -r '.event_ids_on_output_only' <<<"$command_result")" "true" "only output and resync_required carry ids" assert_eq "$(jq -r '.resume.attached_first' <<<"$command_result")" "true" "resumed stream starts with attached" -assert_eq "$(jq -r '.resume.first_type' <<<"$command_result")" "resync_required" "resumed stream announces resync" -assert_eq "$(jq -r '.resume.reason' <<<"$command_result")" "cursor_replay_unavailable" "resync reason" -assert_eq "$(jq -r '.resume.first_id' <<<"$command_result")" "$(jq -r '.resume_from + 1' <<<"$command_result")" "resumed ids continue from Last-Event-ID" +assert_eq "$(jq -r '.resume.resync' <<<"$command_result")" "null" "lossless resume does not resync" +assert_eq "$(jq -r '.resume.stdout' <<<"$command_result")" "" "resume does not replay received output" assert_eq "$(jq -r '.resume.exit_code' <<<"$command_result")" "6" "resumed stream reports the process exit" log "one-shot command event stream ok (Last-Event-ID resume verified)" diff --git a/shim/proto/spaced/operations/v1/operations.pb.go b/shim/proto/spaced/operations/v1/operations.pb.go index 946e81a1e9..9e86f5df4a 100644 --- a/shim/proto/spaced/operations/v1/operations.pb.go +++ b/shim/proto/spaced/operations/v1/operations.pb.go @@ -2577,9 +2577,27 @@ type ConnectProcessRequest struct { // follows the live tail. Native public data-plane replay sets this to the // number of stdout/stderr events already durably captured so output emitted // while a client was disconnected is replayed from the guest journal. - OutputCursor *uint64 `protobuf:"varint,3,opt,name=output_cursor,json=outputCursor,proto3,oneof" json:"output_cursor,omitempty"` - unknownFields protoimpl.UnknownFields - sizeCache protoimpl.SizeCache + // + // A cursor outside the retained output ends the stream with a status whose + // `space-error-reason` metadata names why: + // - past the output the process has written: OUT_OF_RANGE, + // `process-output-cursor-ahead`; + // - before the oldest output the guest still retains: RESOURCE_EXHAUSTED, + // `process-output-lagged`, with `space-process-output-first-sequence` + // metadata giving the cursor of that oldest output, in decimal, while the + // guest still holds the process. + // + // Older guests end a lagged stream with RESOURCE_EXHAUSTED and no reason, + // and wait for output to reach a cursor past it. + OutputCursor *uint64 `protobuf:"varint,3,opt,name=output_cursor,json=outputCursor,proto3,oneof" json:"output_cursor,omitempty"` + // With `output_cursor` before the oldest output the guest still retains, + // start the stream at that oldest output instead of ending it as lagged. + // The guest chooses the start under the lock that also gives the stream + // its reader position, so output written meanwhile cannot evict it, and + // reports it in `ProcessConnected.output_cursor`. Older guests ignore it. + ResumeFromOldestRetained bool `protobuf:"varint,4,opt,name=resume_from_oldest_retained,json=resumeFromOldestRetained,proto3" json:"resume_from_oldest_retained,omitempty"` + unknownFields protoimpl.UnknownFields + sizeCache protoimpl.SizeCache } func (x *ConnectProcessRequest) Reset() { @@ -2633,6 +2651,13 @@ func (x *ConnectProcessRequest) GetOutputCursor() uint64 { return 0 } +func (x *ConnectProcessRequest) GetResumeFromOldestRetained() bool { + if x != nil { + return x.ResumeFromOldestRetained + } + return false +} + type ListProcessesRequest struct { state protoimpl.MessageState `protogen:"open.v1"` unknownFields protoimpl.UnknownFields @@ -3387,7 +3412,12 @@ func (x *ProcessStarted) GetStartTime() *timestamppb.Timestamp { } type ProcessConnected struct { - state protoimpl.MessageState `protogen:"open.v1"` + state protoimpl.MessageState `protogen:"open.v1"` + // The journal cursor of the first output this stream sends, when the + // request set `output_cursor`: that cursor, or a later one when + // `resume_from_oldest_retained` moved the start past evicted output. + // Unset by older guests. + OutputCursor *uint64 `protobuf:"varint,1,opt,name=output_cursor,json=outputCursor,proto3,oneof" json:"output_cursor,omitempty"` unknownFields protoimpl.UnknownFields sizeCache protoimpl.SizeCache } @@ -3422,6 +3452,13 @@ func (*ProcessConnected) Descriptor() ([]byte, []int) { return file_spaced_operations_v1_operations_proto_rawDescGZIP(), []int{53} } +func (x *ProcessConnected) GetOutputCursor() uint64 { + if x != nil && x.OutputCursor != nil { + return *x.OutputCursor + } + return 0 +} + type ProcessOutput struct { state protoimpl.MessageState `protogen:"open.v1"` Data []byte `protobuf:"bytes,1,opt,name=data,proto3" json:"data,omitempty"` @@ -4152,12 +4189,13 @@ const file_spaced_operations_v1_operations_proto_rawDesc = "" + "\x04rows\x18\x01 \x01(\rR\x04rows\x12\x12\n" + "\x04cols\x18\x02 \x01(\rR\x04cols\"D\n" + "\tPtyConfig\x127\n" + - "\x04size\x18\x01 \x01(\v2#.space.spaced.operations.v1.PtySizeR\x04size\"\xb8\x01\n" + + "\x04size\x18\x01 \x01(\v2#.space.spaced.operations.v1.PtySizeR\x04size\"\xf7\x01\n" + "\x15ConnectProcessRequest\x12\x1d\n" + "\n" + "process_id\x18\x01 \x01(\tR\tprocessId\x128\n" + "\atimeout\x18\x02 \x01(\v2\x19.google.protobuf.DurationH\x00R\atimeout\x88\x01\x01\x12(\n" + - "\routput_cursor\x18\x03 \x01(\x04H\x01R\foutputCursor\x88\x01\x01B\n" + + "\routput_cursor\x18\x03 \x01(\x04H\x01R\foutputCursor\x88\x01\x01\x12=\n" + + "\x1bresume_from_oldest_retained\x18\x04 \x01(\bR\x18resumeFromOldestRetainedB\n" + "\n" + "\b_timeoutB\x10\n" + "\x0e_output_cursor\"\x16\n" + @@ -4216,8 +4254,10 @@ const file_spaced_operations_v1_operations_proto_rawDesc = "" + "\x0eProcessStarted\x12>\n" + "\n" + "start_time\x18\x01 \x01(\v2\x1a.google.protobuf.TimestampH\x00R\tstartTime\x88\x01\x01B\r\n" + - "\v_start_time\"\x12\n" + - "\x10ProcessConnected\"#\n" + + "\v_start_time\"N\n" + + "\x10ProcessConnected\x12(\n" + + "\routput_cursor\x18\x01 \x01(\x04H\x00R\foutputCursor\x88\x01\x01B\x10\n" + + "\x0e_output_cursor\"#\n" + "\rProcessOutput\x12\x12\n" + "\x04data\x18\x01 \x01(\fR\x04data\"\xbc\x02\n" + "\vProcessExit\x12C\n" + @@ -4445,6 +4485,7 @@ func file_spaced_operations_v1_operations_proto_init() { (*ProcessEvent_Exit)(nil), } file_spaced_operations_v1_operations_proto_msgTypes[52].OneofWrappers = []any{} + file_spaced_operations_v1_operations_proto_msgTypes[53].OneofWrappers = []any{} file_spaced_operations_v1_operations_proto_msgTypes[55].OneofWrappers = []any{ (*ProcessExit_Exited)(nil), (*ProcessExit_Signaled)(nil), diff --git a/space_smoke/m1_conformance.py b/space_smoke/m1_conformance.py index d3279ffdf6..9900f0e016 100644 --- a/space_smoke/m1_conformance.py +++ b/space_smoke/m1_conformance.py @@ -623,9 +623,9 @@ def exercise_command(self, command: Any) -> None: f"match process_started {streamed_process_id!r}" ) - # Reconnect with Last-Event-ID. The documented guarantee: the live - # stream resumes at last+1 behind resync_required, missed output is - # not replayed, and the process is still controllable. + # Reconnect with Last-Event-ID. The documented guarantee: the stream + # resumes with the output after that event, without a resync while + # the output is retained, and the process is still controllable. resumed: list[dict[str, object]] = [] second = self.read_session_events( api, command.session_id, first.last_id, resumed, @@ -634,21 +634,16 @@ def exercise_command(self, command: Any) -> None: ) if not second.attached_first: raise InvariantViolation("reconnected stream did not start with an attached frame") - if not second.identified: - raise InvariantViolation("reconnected stream delivered no identified events") - first_id, first_frame = second.identified[0] - if first_frame.get("type") != "resync_required": + # Only output and resync_required carry ids, so a resume that sends + # neither has none; any it does send must follow Last-Event-ID. + if second.identified and second.identified[0][0] <= first.last_id: raise InvariantViolation( - f"reconnect did not start with resync_required: {first_frame}" - ) - if first_frame.get("reason") != "cursor_replay_unavailable": - raise InvariantViolation( - f"unexpected resync reason on Last-Event-ID resume: {first_frame}" - ) - if first_id != first.last_id + 1: - raise InvariantViolation( - f"resumed stream restarted ids at {first_id}, expected {first.last_id + 1}" + f"resumed stream restarted ids at {second.identified[0][0]}, " + f"after {first.last_id}" ) + resyncs = [frame for frame in resumed if frame.get("type") == "resync_required"] + if resyncs: + raise InvariantViolation(f"lossless Last-Event-ID resume asked to resync: {resyncs}") frames.extend(resumed) exits = [frame for frame in frames if frame.get("type") == "process_exited"] @@ -657,8 +652,10 @@ def exercise_command(self, command: Any) -> None: for frame in exits: assert_known("process_exited.status", frame.get("status"), KNOWN_PROCESS_EXIT_STATUSES) stdout = stdout_of(frames) - if MARKER not in stdout: - raise InvariantViolation(f"session event stream omitted command output: {stdout!r}") + if stdout.count(MARKER) != 1: + raise InvariantViolation( + f"session event streams did not carry the command output once: {stdout!r}" + ) def read_session_events( self, @@ -671,7 +668,8 @@ def read_session_events( ) -> SessionRead: """Read one SSE connection until `stop()` holds, asserting id monotonicity. - Every identified frame must carry exactly the previous id plus one; + Every identified frame must carry a greater id than the one before, and + on a process stream only output and resync_required frames carry one; `on_connected` runs once the stream reports the process (started or reconnected), so process control can be exercised while attached. """ @@ -688,10 +686,14 @@ def read_session_events( if first: result.attached_first = frame.get("type") == "attached" and frame_id is None first = False + if (frame_id is not None) != ( + frame.get("type") in {"stdout", "stderr", "resync_required"} + ): + raise InvariantViolation(f"unexpected SSE id {frame_id} on {frame}") if frame_id is not None: - if result.last_id is not None and frame_id != result.last_id + 1: + if result.last_id is not None and frame_id <= result.last_id: raise InvariantViolation( - f"SSE ids must increase by one: got {frame_id} after {result.last_id}" + f"SSE ids must increase: got {frame_id} after {result.last_id}" ) result.last_id = frame_id result.identified.append((frame_id, frame)) diff --git a/space_smoke/scenarios/native_recovery_command_survives_data_plane_restart.py b/space_smoke/scenarios/native_recovery_command_survives_data_plane_restart.py index 40a821f1b2..2f34a967d4 100644 --- a/space_smoke/scenarios/native_recovery_command_survives_data_plane_restart.py +++ b/space_smoke/scenarios/native_recovery_command_survives_data_plane_restart.py @@ -36,8 +36,9 @@ def command_survives_data_plane_restart(fixture: KindNativeHardeningFixture) -> fixture, fixture.command(sandbox_id, ["sh", "-c", script], timeout_seconds=180), 201 ) with fixture.context.phase("start command and replace data-plane pods"): - # The SSE contract starts with attached, then process_started. - initial = attach_after_recovery(fixture, command, max_events=2) + # The SSE contract starts with attached, then process_started; the + # first output ("begun") is the first frame with an id. + initial = attach_after_recovery(fixture, command, max_events=3) fixture.context.verify( any(event.data.get("type") == "process_started" for event in initial.events), "fault requires an observed running guest process",