From 4929576b500281522451cfd745ab750c7a99ab8d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Sun, 25 Oct 2026 23:20:53 -0400 Subject: [PATCH 01/19] fix(agent): reopen the NOW channel after it fails When the NOW virtual channel failed after negotiation, for example because the peer tore the DVC down while the RDP connection stayed up, DevolutionsSession.exe exited. The agent only starts it again on the next logon or unlock, so the session had no NOW host until then. A channel that fails after negotiation is now reopened after a delay that starts at 1 s and doubles up to 10 s, with a fresh negotiation deadline per channel. Reopening gives up once five consecutive reopened channels fail to negotiate, and shutdown interrupts every wait. A first channel that never negotiates still ends the process, so a client without a NOW listener does not keep it alive. The IO thread of a failed channel must stop within 10 s, so that it releases its channel handle before the next open. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 15 +- devolutions-session/src/dvc/task.rs | 407 +++++++++++++++++++++++++--- 2 files changed, 383 insertions(+), 39 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index a4dcc6a109..5877daaa48 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -78,15 +78,17 @@ impl DvcInitializationError { } } -/// Counters and signalling shared between the DVC IO thread and the DVC task. +/// Counters and signalling shared between the DVC IO thread and the DVC task for one channel. /// /// Beyond diagnostics, this gates the negotiation deadline, which must not start before the -/// channel is open. +/// channel is open, and records whether negotiation completed, which decides whether a failed +/// channel is reopened. #[derive(Debug, Default)] pub struct DvcInitializationProgress { open_attempts: AtomicU32, channel_opened: AtomicBool, channel_opened_notify: Notify, + negotiated: AtomicBool, } impl DvcInitializationProgress { @@ -132,6 +134,15 @@ impl DvcInitializationProgress { pub fn channel_opened(&self) -> bool { self.channel_opened.load(Ordering::Relaxed) } + + pub fn mark_negotiated(&self) { + self.negotiated.store(true, Ordering::Relaxed); + } + + /// Whether the client completed capability negotiation on this channel. + pub fn negotiated(&self) -> bool { + self.negotiated.load(Ordering::Relaxed) + } } struct DvcIoContext { diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index f346602ac1..c77c0d2a80 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -4,7 +4,7 @@ use std::sync::Arc; use anyhow::{Context, bail}; use async_trait::async_trait; use devolutions_agent_shared::temp_file::{BATCH_UTF8_PREAMBLE, POWERSHELL_UTF8_ENCODING_PREAMBLE, TmpFileGuard}; -use devolutions_gateway_task::{ChildTask, Task}; +use devolutions_gateway_task::{ChildTask, ShutdownSignal, Task}; use now_proto_pdu::ironrdp_core::IntoOwned; use now_proto_pdu::{ ComApartmentStateKind, NowChannelCapsetMsg, NowChannelCloseMsg, NowChannelHeartbeatMsg, NowChannelMessage, @@ -50,6 +50,14 @@ use crate::dvc::window_monitor::{WindowMonitorConfig, run_window_monitor}; const DEFAULT_HEARTBEAT_INTERVAL: core::time::Duration = core::time::Duration::from_secs(60); const HANDSHAKE_TIMEOUT: core::time::Duration = core::time::Duration::from_secs(5); +/// Delay before reopening a channel after the first failure; it doubles with each consecutive failed reopen. +const REOPEN_DELAY_FLOOR: core::time::Duration = core::time::Duration::from_secs(1); +const REOPEN_DELAY_CAP: core::time::Duration = core::time::Duration::from_secs(10); +/// Number of consecutive reopened channels that may fail to negotiate before the process gives up. +const MAX_CONSECUTIVE_FAILED_REOPENS: usize = 5; +/// Time the IO thread of a lost channel has to release it before the process gives up. +const IO_THREAD_STOP_TIMEOUT: core::time::Duration = core::time::Duration::from_secs(10); + const GENERIC_ERROR_CODE_ENCODING: u32 = 0x00000001; const GENERIC_ERROR_CODE_TOO_LONG_ERROR: u32 = 0x00000002; const GENERIC_ERROR_CODE_OTHER: u32 = 0xFFFFFFFF; @@ -63,62 +71,176 @@ impl Task for DvcIoTask { const NAME: &'static str = "DVC processing"; - async fn run(self, shutdown_signal: devolutions_gateway_task::ShutdownSignal) -> Self::Output { - let (write_tx, write_rx) = winapi_signaled_mpsc_channel()?; - let (read_tx, read_rx) = bounded_mpsc_channel()?; + async fn run(self, shutdown_signal: ShutdownSignal) -> Self::Output { + let channel_shutdown_signal = shutdown_signal.clone(); - // WinAPI event to terminate DVC IO thread. - let io_thread_shutdown_event = Event::new_unnamed()?; + serve_dvc(move || serve_channel(channel_shutdown_signal.clone()), shutdown_signal).await + } +} - let cloned_shutdown_event = io_thread_shutdown_event.clone(); +/// How serving one DVC channel ended. +#[derive(Debug)] +enum ChannelOutcome { + /// The channel was closed on purpose, by either peer or by shutdown, and must not be reopened. + Ended, + /// The channel failed before the client completed negotiation. + NotNegotiated(anyhow::Error), + /// The channel failed after the client completed negotiation. + Lost(anyhow::Error), +} - let init_progress = Arc::new(DvcInitializationProgress::default()); - let io_thread_progress = Arc::clone(&init_progress); +impl ChannelOutcome { + fn new(result: anyhow::Result<()>, init_progress: &DvcInitializationProgress) -> Self { + match result { + Ok(()) => Self::Ended, + Err(error) if init_progress.negotiated() => Self::Lost(error), + Err(error) => Self::NotNegotiated(error), + } + } +} - info!( - "Starting NowProto DVC v{}.{}", - NowProtoVersion::CURRENT.major, - NowProtoVersion::CURRENT.minor - ); +/// Serves DVC channels until one ends on purpose, reopening a channel lost after negotiation. +/// +/// A first channel that never negotiates is not reopened: the client likely has no NOW listener, and reopening would +/// keep a process alive that nobody can reach. +/// Once a client has negotiated, a failed channel is reopened after a delay that grows with each consecutive reopen +/// that fails to negotiate, until [`MAX_CONSECUTIVE_FAILED_REOPENS`] of them. +async fn serve_dvc(mut serve_channel: F, mut shutdown_signal: ShutdownSignal) -> anyhow::Result<()> +where + F: FnMut() -> Fut, + Fut: Future>, +{ + // `None` until a negotiated channel is lost. + let mut failed_reopens: Option = None; - // Spawning thread is relatively short operation, so it could be executed synchronously. - let io_thread = std::thread::spawn(move || { - let io_thread_result = run_dvc_io(write_rx, read_tx, cloned_shutdown_event, &io_thread_progress); + loop { + if let Some(failed_reopens) = failed_reopens { + select! { + () = tokio::time::sleep(reopen_delay(failed_reopens)) => {} + _ = shutdown_signal.wait() => return Ok(()), + } + } - if let Err(error) = io_thread_result { - error!(%error, "DVC IO thread failed"); + match serve_channel().await? { + ChannelOutcome::Ended => return Ok(()), + ChannelOutcome::Lost(error) => { + warn!( + error = format!("{error:#}"), + "Lost the negotiated DVC channel; reopening it" + ); + failed_reopens = Some(0); } - }); + ChannelOutcome::NotNegotiated(error) => { + let Some(previous_failures) = failed_reopens else { + return Err(error); + }; + + let failures = previous_failures + 1; - // Join thread some time in future. - tokio::task::spawn_blocking(move || { - if let Err(panic_payload) = io_thread.join() { - if let Some(s) = panic_payload.downcast_ref::<&dyn std::fmt::Debug>() { - error!("DVC IO thread panic: {:?}", s); + if failures < MAX_CONSECUTIVE_FAILED_REOPENS { + warn!( + error = format!("{error:#}"), + failures, "Failed to reopen the DVC channel" + ); + failed_reopens = Some(failures); } else { - error!("DVC IO thread join failed."); + return Err(error.context(format!("failed to reopen the DVC channel {failures} consecutive times"))); } } - }); + } + } +} + +fn reopen_delay(failed_reopens: usize) -> core::time::Duration { + let factor = u32::try_from(failed_reopens) + .ok() + .and_then(|exponent| 2u32.checked_pow(exponent)) + .unwrap_or(u32::MAX); - info!("Processing DVC messages..."); + REOPEN_DELAY_FLOOR.saturating_mul(factor).min(REOPEN_DELAY_CAP) +} + +/// Opens one DVC channel and serves it until it ends. +/// +/// Errors only when the process cannot go on serving channels at all. +async fn serve_channel(mut shutdown_signal: ShutdownSignal) -> anyhow::Result { + let (write_tx, write_rx) = winapi_signaled_mpsc_channel()?; + let (read_tx, read_rx) = bounded_mpsc_channel()?; - let process_result = process_messages(read_rx, write_tx, shutdown_signal, &init_progress).await; + // WinAPI event to terminate DVC IO thread. + let io_thread_shutdown_event = Event::new_unnamed()?; - // Send shutdown signal to IO thread to release WTS channel resources. - info!("Shutting down DVC IO thread"); - let _ = io_thread_shutdown_event.set(); + let cloned_shutdown_event = io_thread_shutdown_event.clone(); - process_result?; + // Each channel gets its own progress, and therefore its own negotiation deadline. + let init_progress = Arc::new(DvcInitializationProgress::default()); + let io_thread_progress = Arc::clone(&init_progress); - Ok(()) + info!( + "Starting NowProto DVC v{}.{}", + NowProtoVersion::CURRENT.major, + NowProtoVersion::CURRENT.minor + ); + + // Spawning thread is relatively short operation, so it could be executed synchronously. + let io_thread = std::thread::spawn(move || { + let io_thread_result = run_dvc_io(write_rx, read_tx, cloned_shutdown_event, &io_thread_progress); + + if let Err(error) = io_thread_result { + error!(%error, "DVC IO thread failed"); + } + }); + + // Joined on a plain thread rather than the blocking pool, because the runtime waits for its blocking tasks when it + // shuts down, so an IO thread that never stops would keep the process alive. + let (io_thread_stopped_tx, io_thread_stopped_rx) = tokio::sync::oneshot::channel::<()>(); + std::thread::spawn(move || { + if let Err(panic_payload) = io_thread.join() { + if let Some(s) = panic_payload.downcast_ref::<&dyn std::fmt::Debug>() { + error!("DVC IO thread panic: {:?}", s); + } else { + error!("DVC IO thread join failed."); + } + } + + let _ = io_thread_stopped_tx.send(()); + }); + + info!("Processing DVC messages..."); + + let process_result = process_messages(read_rx, write_tx, shutdown_signal.clone(), &init_progress).await; + + // Send shutdown signal to IO thread to release WTS channel resources. + info!("Shutting down DVC IO thread"); + let _ = io_thread_shutdown_event.set(); + + let outcome = ChannelOutcome::new(process_result, &init_progress); + + // UNTESTED: a failed channel may be reopened, so its IO thread must release the WTS handle before the next open, + // and a thread that does not stop must end the process, because the agent does not replace a process that is + // still running. + // An ended channel is never reopened, so the process exits without depending on the thread. + // The thread can block in its synchronous `WriteFile`; when changing the IO thread or its join, check that the + // timeout still bounds that wait and that nothing on the runtime still waits for the thread. + if let ChannelOutcome::Lost(error) | ChannelOutcome::NotNegotiated(error) = &outcome { + select! { + stopped = tokio::time::timeout(IO_THREAD_STOP_TIMEOUT, io_thread_stopped_rx) => { + if stopped.is_err() { + error!(error = format!("{error:#}"), "DVC channel failed"); + bail!("DVC IO thread did not stop within {IO_THREAD_STOP_TIMEOUT:?}"); + } + } + _ = shutdown_signal.wait() => return Ok(ChannelOutcome::Ended), + } } + + Ok(outcome) } async fn process_messages( mut read_rx: Receiver, dvc_tx: WinapiSignaledSender, - mut shutdown_signal: devolutions_gateway_task::ShutdownSignal, + mut shutdown_signal: ShutdownSignal, init_progress: &DvcInitializationProgress, ) -> anyhow::Result<()> { let (io_notification_tx, mut task_rx) = mpsc::channel(100); @@ -201,6 +323,7 @@ async fn process_messages( pwsh_executable.clone(), ); + init_progress.mark_negotiated(); info!("DVC negotiation completed"); loop { @@ -1324,19 +1447,192 @@ unsafe extern "C" { #[cfg(test)] mod tests { + use core::task::Poll; use core::time::Duration; + use std::collections::VecDeque; - use devolutions_gateway_task::ShutdownHandle; + use anyhow::anyhow; + use devolutions_gateway_task::{ShutdownHandle, ShutdownSignal}; use futures::poll; use now_proto_pdu::{ NowChannelCapsetMsg, NowChannelCloseMsg, NowChannelMessage, NowExecCapsetFlags, NowMessage, NowSessionCapsetFlags, NowSystemCapsetFlags, OwnedNowMessage, }; + use tokio::time::Instant; - use super::{DEFAULT_HEARTBEAT_INTERVAL, heartbeat_timer, process_messages, spawn_heartbeat}; + use super::{ + ChannelOutcome, DEFAULT_HEARTBEAT_INTERVAL, MAX_CONSECUTIVE_FAILED_REOPENS, REOPEN_DELAY_CAP, + REOPEN_DELAY_FLOOR, heartbeat_timer, process_messages, serve_dvc, spawn_heartbeat, + }; use crate::dvc::channel::{bounded_mpsc_channel, winapi_signaled_mpsc_channel}; use crate::dvc::io::DvcInitializationProgress; + /// A negotiated channel whose IO ends, as when the client tears the DVC down while the RDP connection stays up, + /// must be told apart from one that never negotiated, because only the former is reopened. + // oracle: scaffold + #[tokio::test] + async fn read_channel_closing_after_negotiation_loses_the_channel() { + let (write_tx, _write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + read_tx + .send(NowChannelCapsetMsg::default().into()) + .await + .expect("queue client capset"); + drop(read_tx); + + let result = process_messages(read_rx, write_tx, shutdown_signal, &init_progress).await; + + let outcome = ChannelOutcome::new(result, &init_progress); + assert!(matches!(outcome, ChannelOutcome::Lost(_)), "{outcome:?}"); + } + + /// A channel whose IO ends before the client negotiates, as with a client that has no NOW listener, must not be + /// classified as lost, so it is never reopened. + // oracle: scaffold + #[tokio::test] + async fn read_channel_closing_before_negotiation_is_not_negotiated() { + let (write_tx, _write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + drop(read_tx); + + let result = process_messages(read_rx, write_tx, shutdown_signal, &init_progress).await; + + let outcome = ChannelOutcome::new(result, &init_progress); + assert!(matches!(outcome, ChannelOutcome::NotNegotiated(_)), "{outcome:?}"); + } + + /// A channel the client closes on purpose must end rather than be reopened against the client's will. + // oracle: spec Devolutions/now-proto@7519c6ff6cfa45bb70c3a3c67df2024d482eda53:protocols/docs/NOW-spec.md §NOW_CHANNEL_CLOSE_MSG + #[tokio::test] + async fn client_channel_close_ends_the_channel() { + let (write_tx, _write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + read_tx + .send(NowChannelCapsetMsg::default().into()) + .await + .expect("queue client capset"); + read_tx + .send(NowChannelCloseMsg::default().into()) + .await + .expect("queue channel close"); + + let result = process_messages(read_rx, write_tx, shutdown_signal, &init_progress).await; + + let outcome = ChannelOutcome::new(result, &init_progress); + assert!(matches!(outcome, ChannelOutcome::Ended), "{outcome:?}"); + } + + /// A first channel that never negotiates must end the loop with its error, so a client without a NOW listener + /// does not keep the process alive reopening a channel nobody serves. + // oracle: scaffold + #[tokio::test(start_paused = true)] + async fn unnegotiated_first_channel_is_not_reopened() { + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + + let (result, _) = serve_script([not_negotiated()], shutdown_signal).await; + + assert!(result.is_err()); + } + + // oracle: scaffold + #[tokio::test(start_paused = true)] + async fn ended_channel_is_not_reopened() { + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + + let (result, _) = serve_script([ChannelOutcome::Ended], shutdown_signal).await; + + result.expect("an ended channel ends the loop cleanly"); + } + + // oracle: scaffold + #[tokio::test(start_paused = true)] + async fn lost_channel_is_reopened_after_a_delay() { + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + + let (result, served_at) = serve_script([lost(), ChannelOutcome::Ended], shutdown_signal).await; + + result.expect("the reopened channel ends the loop cleanly"); + assert!(REOPEN_DELAY_FLOOR <= served_at[1] - served_at[0]); + } + + /// A client that stopped serving NOW must not be retried forever, nor in a tight loop. + #[tokio::test(start_paused = true)] + async fn reopen_gives_up_after_consecutive_unnegotiated_channels() { + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let script = core::iter::once(lost()) + .chain(core::iter::repeat_with(not_negotiated).take(MAX_CONSECUTIVE_FAILED_REOPENS)); + + let (result, served_at) = serve_script(script, shutdown_signal).await; + + // oracle: scaffold + assert!(result.is_err()); + + let delays = served_at.windows(2).map(|w| w[1] - w[0]).collect::>(); + // oracle: property monotonic + assert!(delays.windows(2).all(|w| w[0] <= w[1]), "{delays:?}"); + // oracle: scaffold + assert!( + delays + .iter() + .all(|delay| REOPEN_DELAY_FLOOR <= *delay && *delay <= REOPEN_DELAY_CAP), + "{delays:?}" + ); + } + + /// A reopened channel that negotiates shows the client serves NOW again, so earlier failures must not count + /// toward giving up. + // oracle: scaffold + #[tokio::test(start_paused = true)] + async fn negotiated_reopen_resets_the_failure_budget() { + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let failures = || core::iter::repeat_with(not_negotiated).take(MAX_CONSECUTIVE_FAILED_REOPENS - 1); + let script = core::iter::once(lost()) + .chain(failures()) + .chain(core::iter::once(lost())) + .chain(failures()) + .chain(core::iter::once(ChannelOutcome::Ended)); + + let (result, _) = serve_script(script, shutdown_signal).await; + + result.expect("failures before a negotiated reopen do not end the loop"); + } + + /// A shutdown requested while waiting to reopen must end the loop at once, without opening another channel. + // oracle: scaffold + #[tokio::test(start_paused = true)] + async fn shutdown_during_reopen_delay_stops_without_reopening() { + let (shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let mut served = 0; + + let mut serve = Box::pin(serve_dvc( + || { + served += 1; + async { Ok(lost()) } + }, + shutdown_signal, + )); + + assert!(poll!(serve.as_mut()).is_pending()); + shutdown_handle.signal(); + + let Poll::Ready(result) = poll!(serve.as_mut()) else { + panic!("the loop is still waiting after shutdown"); + }; + result.expect("shutdown ends the loop cleanly"); + + drop(serve); + assert_eq!(served, 1); + } + /// The negotiation reply must be the downgraded capset, so the client sees the capabilities /// and heartbeat interval the agent applies rather than the server default, which carries no /// interval at all. @@ -1529,4 +1825,41 @@ mod tests { "expected a heartbeat, got {message:?}" ); } + + /// Serves `outcomes` in order and returns the loop result with the instant each channel was served. + /// + /// Panics unless the loop serves every outcome and no more. + async fn serve_script( + outcomes: impl IntoIterator, + shutdown_signal: ShutdownSignal, + ) -> (anyhow::Result<()>, Vec) { + let mut outcomes = outcomes.into_iter().collect::>(); + let mut served_at = Vec::new(); + + let result = serve_dvc( + || { + served_at.push(Instant::now()); + let outcome = outcomes.pop_front().expect("channel served more times than scripted"); + async { Ok(outcome) } + }, + shutdown_signal, + ) + .await; + + assert!( + outcomes.is_empty(), + "{} scripted channels were never served", + outcomes.len() + ); + + (result, served_at) + } + + fn lost() -> ChannelOutcome { + ChannelOutcome::Lost(anyhow!("channel lost")) + } + + fn not_negotiated() -> ChannelOutcome { + ChannelOutcome::NotNegotiated(anyhow!("channel not negotiated")) + } } From 6881303fa25c6087685407ae88ead179b047c8f1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Sun, 25 Oct 2026 23:21:23 -0400 Subject: [PATCH 02/19] fix(agent): pass argv[0] to the session process CreateProcessAsUserW hands lpCommandLine to the new process as its whole command line, and the C runtime reads the first token as argv[0]. The command line held only "--session ", so DevolutionsSession.exe took "--session" as its module name and never saw the flag, and its logs carried no session id. The command line now starts with the module path. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-agent/src/session_manager.rs | 36 ++++++++++++++++++++++-- 1 file changed, 33 insertions(+), 3 deletions(-) diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index 28c461ca55..9852f3568a 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -4,7 +4,7 @@ use std::collections::BTreeMap; use std::fmt::Debug; use async_trait::async_trait; -use camino::Utf8PathBuf; +use camino::{Utf8Path, Utf8PathBuf}; use ceviche::controller::Session; use devolutions_gateway_task::{ShutdownSignal, Task}; use tokio::sync::{RwLock, mpsc}; @@ -349,7 +349,7 @@ fn start_session_process(session: &Session) -> anyhow::Result<()> { } let session_app_path = session_app_path(); - let command_line = CommandLine::new(vec!["--session".to_owned(), session.to_string()]); + let command_line = session_command_line(&session_app_path, session); info!(%session, "Starting `{session_app_path}`"); @@ -389,6 +389,18 @@ fn start_session_process(session: &Session) -> anyhow::Result<()> { } } +/// Builds the session process command line. +/// +/// The process receives the command line unchanged as its whole command line, so it must start with the module name +/// that the process reads as `argv[0]`. +fn session_command_line(session_app_path: &Utf8Path, session: &Session) -> CommandLine { + CommandLine::new(vec![ + session_app_path.as_str().to_owned(), + "--session".to_owned(), + session.to_string(), + ]) +} + fn session_app_path() -> Utf8PathBuf { let mut current_dir = Utf8PathBuf::from_path_buf(std::env::current_exe().expect("BUG: can't get current exe path")) .expect("BUG: OS should always return valid UTF-8 executable path"); @@ -401,12 +413,30 @@ fn session_app_path() -> Utf8PathBuf { #[cfg(test)] mod tests { - use super::{GatewaySession, Session, SessionKind, SessionReadiness, SessionReadinessEvent}; + use camino::Utf8Path; + use win_api_wrappers::utils::CommandLine; + + use super::{GatewaySession, Session, SessionKind, SessionReadiness, SessionReadinessEvent, session_command_line}; fn make_session(kind: SessionKind, readiness: SessionReadiness) -> GatewaySession { GatewaySession::new(Session::new(1), kind, readiness) } + /// The session process reads its arguments after `argv[0]`, so a command line without the module name loses the + /// first one. + #[test] + fn session_command_line_starts_with_the_module_name() { + let session_app_path = Utf8Path::new(r"C:\Program Files\Devolutions\Agent\DevolutionsSession.exe"); + + let command_line = session_command_line(session_app_path, &Session::new(3)).to_command_line(); + + let argv = CommandLine::from_command_line(&command_line).0; + // oracle: spec CreateProcessAsUserW §Parameters + assert_eq!(argv[0], session_app_path.as_str()); + // oracle: scaffold + assert_eq!(argv[1..], ["--session", "3"]); + } + #[test] fn new_user_session_waits_for_logon() { assert!(SessionReadiness::WaitingForLogon.is_satisfied_by(SessionReadinessEvent::Logon)); From 602a4481cd85ee7bb2b058ff66de5efb5ca60d2c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Sun, 25 Oct 2026 23:21:23 -0400 Subject: [PATCH 03/19] fix(agent): survive session process lookup failures A failure to enumerate processes while handling a logon or unlock returned an error from the session manager task. The service only logs a failed task, so the agent stopped starting DevolutionsSession.exe in any session until the service restarted. The failure is now logged and the session stays waiting, so the next logon or unlock retries. The process is not started without a lookup result, to avoid running two instances in one session. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-agent/src/session_manager.rs | 100 ++++++++++++++++------- 1 file changed, 71 insertions(+), 29 deletions(-) diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index 9852f3568a..a37e18a92a 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -148,6 +148,51 @@ impl SessionManagerCtx { .get(&session.to_string()) .is_some_and(|session| session.is_ready_to_start(event)) } + + /// Starts the session process in a registered session unless it is already running. + /// + /// The session is marked ready only once its process is known to run, so that a failure leaves it waiting for the + /// next readiness event. + fn start_process_if_not_running( + &mut self, + session: &Session, + is_running: impl FnOnce(&Session) -> anyhow::Result, + start: impl FnOnce(&Session) -> anyhow::Result<()>, + ) { + let Some(gw_session) = self.get_session_mut(session) else { + warn!(%session, "Session is not yet registered"); + return; + }; + + match is_running(session) { + Ok(true) => { + gw_session.set_session_ready(); + return; + } + Ok(false) => {} + Err(error) => { + // Starting a process without knowing whether one already runs could start a second one. + error!( + error = format!("{error:#}"), + %session, + "Failed to check whether the session process is running" + ); + return; + } + } + + info!(%session, "Starting session process"); + + match start(session) { + Ok(()) => { + info!(%session, "Session process started"); + gw_session.set_session_ready(); + } + Err(error) => { + error!(%error, %session, "Failed to start session process"); + } + } + } } pub struct SessionManager { @@ -257,7 +302,7 @@ impl Task for SessionManager { // session app on logon, if not yet started. let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Logon) { - start_session_process_if_not_running(&mut ctx, &id)?; + start_session_process_if_not_running(&mut ctx, &id); } } AgentServiceEvent::SessionUnlock(id) => { @@ -265,7 +310,7 @@ impl Task for SessionManager { let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Unlock) { - start_session_process_if_not_running(&mut ctx, &id)?; + start_session_process_if_not_running(&mut ctx, &id); } } AgentServiceEvent::SessionLogoff(id) => { @@ -295,32 +340,8 @@ impl Task for SessionManager { } /// Starts Devolutions Session process in the target session. -fn start_session_process_if_not_running(ctx: &mut SessionManagerCtx, session: &Session) -> anyhow::Result<()> { - match ctx.get_session_mut(session) { - Some(gw_session) => { - if is_session_running_in_session(session)? { - gw_session.set_session_ready(); - return Ok(()); - } - - info!(%session, "Starting session process"); - - match start_session_process(session) { - Ok(()) => { - info!(%session, "Session process started"); - gw_session.set_session_ready(); - } - Err(error) => { - error!(%error, %session, "Failed to start session process"); - } - } - } - None => { - warn!(%session, "Session is not yet registered"); - } - }; - - Ok(()) +fn start_session_process_if_not_running(ctx: &mut SessionManagerCtx, session: &Session) { + ctx.start_process_if_not_running(session, is_session_running_in_session, start_session_process); } /// Terminates Devolutions Session process in the target session. @@ -416,7 +437,10 @@ mod tests { use camino::Utf8Path; use win_api_wrappers::utils::CommandLine; - use super::{GatewaySession, Session, SessionKind, SessionReadiness, SessionReadinessEvent, session_command_line}; + use super::{ + GatewaySession, Session, SessionKind, SessionManagerCtx, SessionReadiness, SessionReadinessEvent, + session_command_line, + }; fn make_session(kind: SessionKind, readiness: SessionReadiness) -> GatewaySession { GatewaySession::new(Session::new(1), kind, readiness) @@ -437,6 +461,24 @@ mod tests { assert_eq!(argv[1..], ["--session", "3"]); } + /// A failure to look up the session process must neither end the session manager nor mark the session ready, so + /// that the next readiness event retries. + // oracle: scaffold + #[test] + fn process_lookup_failure_leaves_the_session_waiting() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + ctx.register_session(&session, SessionKind::Remote, SessionReadiness::WaitingForLogon); + + ctx.start_process_if_not_running( + &session, + |_| Err(anyhow::anyhow!("process lookup failed")), + |_| panic!("the process was started although the lookup failed"), + ); + + assert!(ctx.should_start_session(&session, SessionReadinessEvent::Logon)); + } + #[test] fn new_user_session_waits_for_logon() { assert!(SessionReadiness::WaitingForLogon.is_satisfied_by(SessionReadinessEvent::Logon)); From 2b36bd6577fe94f175f27c8f93772a2eed17b066 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:05:41 -0400 Subject: [PATCH 04/19] fix(agent): exit with a failure code when serving fails The agent needs to tell a session process that failed from one that ended on purpose, so that it relaunches only the former. The process exits with a failure code when a task fails or panics, and with success otherwise. A client that never negotiates the first channel no longer counts as a failure, because it likely has no NOW listener and relaunching would not help. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/task.rs | 18 ++++++++++++---- devolutions-session/src/main.rs | 33 +++++++++++++++++++++++------ 2 files changed, 41 insertions(+), 10 deletions(-) diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index c77c0d2a80..1638bc9e1a 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -105,6 +105,9 @@ impl ChannelOutcome { /// keep a process alive that nobody can reach. /// Once a client has negotiated, a failed channel is reopened after a delay that grows with each consecutive reopen /// that fails to negotiate, until [`MAX_CONSECUTIVE_FAILED_REOPENS`] of them. +/// +/// Errors only when a negotiated client can no longer be served, which makes the process exit with a failure code +/// that the agent answers by relaunching it. async fn serve_dvc(mut serve_channel: F, mut shutdown_signal: ShutdownSignal) -> anyhow::Result<()> where F: FnMut() -> Fut, @@ -132,7 +135,13 @@ where } ChannelOutcome::NotNegotiated(error) => { let Some(previous_failures) = failed_reopens else { - return Err(error); + // Not a failure: the client likely has no NOW listener, and the agent relaunches a process that + // exits with an error. + warn!( + error = format!("{error:#}"), + "The client did not negotiate the DVC channel" + ); + return Ok(()); }; let failures = previous_failures + 1; @@ -1531,8 +1540,9 @@ mod tests { assert!(matches!(outcome, ChannelOutcome::Ended), "{outcome:?}"); } - /// A first channel that never negotiates must end the loop with its error, so a client without a NOW listener - /// does not keep the process alive reopening a channel nobody serves. + /// A first channel that never negotiates must end the loop, so a client without a NOW listener does not keep the + /// process alive reopening a channel nobody serves. + /// It ends without an error, because the agent relaunches a process that exits with one. // oracle: scaffold #[tokio::test(start_paused = true)] async fn unnegotiated_first_channel_is_not_reopened() { @@ -1540,7 +1550,7 @@ mod tests { let (result, _) = serve_script([not_negotiated()], shutdown_signal).await; - assert!(result.is_err()); + result.expect("a client without a NOW listener is not a failure"); } // oracle: scaffold diff --git a/devolutions-session/src/main.rs b/devolutions-session/src/main.rs index cfde821c90..ac9ca15e8f 100644 --- a/devolutions-session/src/main.rs +++ b/devolutions-session/src/main.rs @@ -14,6 +14,8 @@ use ::{ #[macro_use] extern crate tracing; +use std::process::ExitCode; + use anyhow::Context; use devolutions_gateway_task::{ChildTask, ShutdownHandle, ShutdownSignal}; #[cfg(all(windows, feature = "dvc"))] @@ -22,7 +24,7 @@ use devolutions_session::{ConfHandle, get_data_dir, init_log}; use tokio::runtime::Runtime; use tokio::task::JoinHandle; -fn main() -> anyhow::Result<()> { +fn main() -> anyhow::Result { // Ensure per-user data dir exists. std::fs::create_dir_all(get_data_dir()).context("failed to create data directory")?; @@ -49,11 +51,15 @@ fn main() -> anyhow::Result<()> { info!("Waiting for shutdown signal"); - runtime.block_on(join_handle)?; + let tasks_succeeded = runtime.block_on(join_handle)?; info!("Exiting Devolutions Session"); - Ok(()) + if tasks_succeeded { + Ok(ExitCode::SUCCESS) + } else { + Ok(ExitCode::FAILURE) + } } /// Returns the session ID the Devolutions Agent passed via `--session`, if any. @@ -74,7 +80,12 @@ fn session_id_from_args() -> Option { None } -pub fn start() -> anyhow::Result<(Runtime, ShutdownHandle, JoinHandle<()>)> { +/// Spawns the tasks and returns a handle that resolves to whether every task ended without an error. +// UNTESTED: the process exits with a failure code exactly when a task failed or panicked. +// The agent relaunches the process on a failure code and leaves it stopped on success, so a task that fails while this +// still reports success leaves the session without a NOW channel. +// When changing how tasks are joined, check that every failure still clears the flag. +pub fn start() -> anyhow::Result<(Runtime, ShutdownHandle, JoinHandle)> { let runtime = tokio::runtime::Builder::new_multi_thread() .enable_all() .build() @@ -90,13 +101,21 @@ pub fn start() -> anyhow::Result<(Runtime, ShutdownHandle, JoinHandle<()>)> { let mut join_all = futures::future::select_all(tasks.inner.into_iter().map(|child| Box::pin(child.join()))); let join_handle = runtime.spawn(async { + let mut succeeded = true; + loop { let (result, _, rest) = join_all.await; match result { Ok(Ok(())) => trace!("A task terminated gracefully"), - Ok(Err(error)) => error!(error = format!("{error:#}"), "A task failed"), - Err(error) => error!(%error, "Something went very wrong with a task"), + Ok(Err(error)) => { + error!(error = format!("{error:#}"), "A task failed"); + succeeded = false; + } + Err(error) => { + error!(%error, "Something went very wrong with a task"); + succeeded = false; + } } if rest.is_empty() { @@ -105,6 +124,8 @@ pub fn start() -> anyhow::Result<(Runtime, ShutdownHandle, JoinHandle<()>)> { join_all = futures::future::select_all(rest); } } + + succeeded }); Ok((runtime, shutdown_handle, join_handle)) From 6ca7e695555a0ebc14aa340972caa2a69eebca3f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:13:50 -0400 Subject: [PATCH 05/19] fix(agent): make NOW channel IO fully overlapped The NOW channel handle is opened for overlapped IO, but messages were written with a synchronous `WriteFile` whose byte count was never checked, so a client slow to read stalled the loop, including its reads, and a short write went unnoticed. Writes are now overlapped, one at a time, and a short write ends the channel, because the rest cannot be sent as a separate DVC message. When the processing queue was full, the loop closed the channel. It now keeps the decoded messages and stops reading until the queue has room, which holds the client back instead. A read shorter than the channel PDU header ended the loop as if the channel had closed; it is now an error that reports the byte count. Pending reads and writes are cancelled, and waited for, before their buffers are freed. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/Cargo.toml | 3 + devolutions-session/src/dvc/io.rs | 704 ++++++++++++++++++++++------ devolutions-session/src/dvc/task.rs | 4 +- 3 files changed, 553 insertions(+), 158 deletions(-) diff --git a/devolutions-session/Cargo.toml b/devolutions-session/Cargo.toml index 9f225aa690..a2b402d2a9 100644 --- a/devolutions-session/Cargo.toml +++ b/devolutions-session/Cargo.toml @@ -61,7 +61,10 @@ optional = true features = [ "Win32_Foundation", "Win32_Globalization", + "Win32_Security", "Win32_Storage_FileSystem", + "Win32_System_IO", + "Win32_System_Pipes", "Win32_System_Shutdown", "Win32_UI_Accessibility", "Win32_UI_WindowsAndMessaging", diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index 5877daaa48..f63b167367 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -1,3 +1,4 @@ +use std::collections::VecDeque; use std::sync::atomic::{AtomicBool, AtomicU32, Ordering}; use std::time::{Duration, Instant}; @@ -11,10 +12,10 @@ use win_api_wrappers::event::Event; use win_api_wrappers::utils::Pipe; use win_api_wrappers::wts::WtsVirtualChannel; use windows::Win32::Foundation::{ - ERROR_GEN_FAILURE, ERROR_IO_PENDING, GetLastError, HANDLE, WAIT_EVENT, WAIT_OBJECT_0, WAIT_TIMEOUT, + ERROR_GEN_FAILURE, ERROR_IO_PENDING, GetLastError, HANDLE, WAIT_OBJECT_0, WAIT_TIMEOUT, }; use windows::Win32::Storage::FileSystem::{ReadFile, WriteFile}; -use windows::Win32::System::IO::{GetOverlappedResult, OVERLAPPED}; +use windows::Win32::System::IO::{CancelIoEx, GetOverlappedResult, OVERLAPPED}; use windows::Win32::System::RemoteDesktop::CHANNEL_PDU_HEADER; use windows::Win32::System::Threading::{INFINITE, WaitForMultipleObjects, WaitForSingleObject}; use windows::core::Owned; @@ -146,18 +147,14 @@ impl DvcInitializationProgress { } struct DvcIoContext { + // Declared first so that its pending IO is cancelled before the WTS channel closes. + io: Box, _wts: WtsVirtualChannel, - channel_file: Owned, - pdu_chunk_buffer: Box<[u8]>, - overlapped: OVERLAPPED, - bytes_read: u32, - message_dissector: NowMessageDissector, - read_event: Event, } /// Run main DVC IO loop for `Devolutions::Now::Agent` channel. pub fn run_dvc_io( - mut write_rx: WinapiSignaledReceiver>, + write_rx: WinapiSignaledReceiver>, read_tx: Sender>, stop_event: Event, progress: &DvcInitializationProgress, @@ -167,124 +164,266 @@ pub fn run_dvc_io( return Ok(()); }; - loop { - let events = [context.read_event.raw(), write_rx.raw_wait_handle(), stop_event.raw()]; - - const WAIT_OBJECT_READ_DVC: WAIT_EVENT = WAIT_OBJECT_0; - const WAIT_OBJECT_WRITE_DVC: WAIT_EVENT = WAIT_EVENT(WAIT_OBJECT_0.0 + 1); - const WAIT_OBJECT_STOP: WAIT_EVENT = WAIT_EVENT(WAIT_OBJECT_0.0 + 2); - - // SAFETY: No preconditions. - let wait_status = unsafe { WaitForMultipleObjects(&events, false, INFINITE) }; - - match wait_status { - // Read event is signaled (incoming data from DVC channel). - WAIT_OBJECT_READ_DVC => { - trace!("DVC channel read event is signaled"); - - // SAFETY: No preconditions. - unsafe { - GetOverlappedResult( - *context.channel_file, - &context.overlapped, - &mut context.bytes_read, - false, - ) - }?; - - if context.bytes_read - < u32::try_from(size_of::()) - .expect("CHANNEL_PDU_HEADER size always fits into u32") - { - // Channel is closed abruptly; abort loop. - return Ok(()); - } + context.io.serve(write_rx, &read_tx, &stop_event) +} - let chunk_data_size = usize::try_from(context.bytes_read) - .expect("read size can't be breater than CHANNEL_CHUNK_LENGTH, therefore it should fit into usize") - .checked_sub(size_of::()) - .expect("read size is less than header size; Correctness of this should be ensured by the OS"); +/// Interval at which decoded messages are offered again to a full processing queue. +const INBOUND_RETRY_INTERVAL_MS: u32 = 10; - const HEADER_SIZE: usize = size_of::(); +/// Overlapped IO state of one open DVC channel. +/// +/// Reads and writes are both overlapped, so that a client slow to read never stops the loop from reading, and the +/// loop never blocks on the processing task. +/// Must stay boxed while IO is pending, because the OS writes to the `OVERLAPPED` structures and buffers. +struct DvcIo { + file: Owned, + + read_buffer: Box<[u8]>, + read_overlapped: OVERLAPPED, + read_event: Event, + read_pending: bool, + message_dissector: NowMessageDissector, + /// Decoded messages the processing task has no room for yet. + /// + /// No read is issued while this is not empty, which bounds it to the messages of one read. + inbound: VecDeque>, - let messages = context - .message_dissector - .dissect(&context.pdu_chunk_buffer[HEADER_SIZE..HEADER_SIZE + chunk_data_size]) - .context("failed to dissect DVC messages"); + write_buffer: Vec, + write_overlapped: OVERLAPPED, + write_event: Event, + write_pending: bool, +} - let messages = match messages { - Ok(messages) => messages, - Err(err) => { - error!(?err, "Failed to dissect DVC messages"); - return Err(err); - } - }; +#[derive(Clone, Copy)] +enum DvcIoWake { + Stop, + ReadCompleted, + WriteCompleted, + Outbound, +} - // Send all messages over the channel. - for message in messages { - debug!(?message, "DVC message received"); - forward_to_processor(&read_tx, message)?; - } - // Prepare async read file operation one more time. - // SAFETY: No preconditions. - let result = unsafe { - ReadFile( - *context.channel_file, - Some(&mut context.pdu_chunk_buffer), - None, - Some(&mut context.overlapped), - ) - }; +impl DvcIo { + fn new(file: Owned) -> anyhow::Result> { + let read_event = Event::new_unnamed()?; + let write_event = Event::new_unnamed()?; + + // All DVC messages should be under CHANNEL_CHUNK_LENGTH size, but sometimes RDP stack + // sends a few messages together; 128Kb buffer should be enough to hold a few dozen messages. + Ok(Box::new(Self { + file, + read_buffer: vec![0u8; 128 * 1024].into_boxed_slice(), + read_overlapped: OVERLAPPED { + hEvent: read_event.raw(), + ..Default::default() + }, + read_event, + read_pending: false, + message_dissector: NowMessageDissector::default(), + inbound: VecDeque::new(), + write_buffer: Vec::new(), + write_overlapped: OVERLAPPED { + hEvent: write_event.raw(), + ..Default::default() + }, + write_event, + write_pending: false, + })) + } - ensure_overlapped_io_result(result)?; + fn serve( + &mut self, + mut write_rx: WinapiSignaledReceiver>, + read_tx: &Sender>, + stop_event: &Event, + ) -> anyhow::Result<()> { + loop { + self.forward_inbound(read_tx)?; + + if self.inbound.is_empty() && !self.read_pending { + self.start_read()?; } - // Write event is signaled (outgoing data to DVC channel). - WAIT_OBJECT_WRITE_DVC => { - trace!("DVC channel write event is signaled"); - let message_to_write = write_rx.try_recv()?; - let message_bytes = now_proto_pdu::ironrdp_core::encode_vec(&message_to_write)?; + // The stop event comes first so that it wins over a busy channel. + let mut wakes = vec![(stop_event.raw(), DvcIoWake::Stop)]; - let mut dw_written: u32 = 0; + if self.read_pending { + wakes.push((self.read_event.raw(), DvcIoWake::ReadCompleted)); + } - // SAFETY: No preconditions. - unsafe { WriteFile(*context.channel_file, Some(&message_bytes), Some(&mut dw_written), None)? } + // One write at a time: further messages wait in `write_rx`, which holds back the processing task. + if self.write_pending { + wakes.push((self.write_event.raw(), DvcIoWake::WriteCompleted)); + } else { + wakes.push((write_rx.raw_wait_handle(), DvcIoWake::Outbound)); } - WAIT_OBJECT_STOP => { - info!("DVC IO thread is stopped"); - // Stop event is signaled; abort loop. - return Ok(()); + + let handles: Vec = wakes.iter().map(|(handle, _)| *handle).collect(); + let timeout = if self.inbound.is_empty() { + INFINITE + } else { + INBOUND_RETRY_INTERVAL_MS + }; + + // SAFETY: All handles are valid for the duration of the call. + let wait_status = unsafe { WaitForMultipleObjects(&handles, false, timeout) }; + + if wait_status == WAIT_TIMEOUT { + continue; } - _ => { - // Spurious wakeup or wait failure + + let wake = usize::try_from(wait_status.0.wrapping_sub(WAIT_OBJECT_0.0)) + .ok() + .and_then(|index| wakes.get(index)) + .map(|(_, wake)| *wake); + + match wake { + Some(DvcIoWake::Stop) => { + info!("DVC IO thread is stopped"); + return Ok(()); + } + Some(DvcIoWake::ReadCompleted) => self.complete_read()?, + Some(DvcIoWake::WriteCompleted) => self.complete_write()?, + Some(DvcIoWake::Outbound) => { + trace!("DVC channel write event is signaled"); + + let message = write_rx.try_recv()?; + self.start_write(&message)?; + } + None => { + return Err(windows::core::Error::from_win32()) + .with_context(|| format!("waiting for DVC IO failed with status {:#X}", wait_status.0)); + } } + } + } + + fn start_read(&mut self) -> windows::core::Result<()> { + // SAFETY: The buffer and `OVERLAPPED` live in this boxed struct, whose `Drop` waits for the read to finish. + let result = unsafe { + ReadFile( + *self.file, + Some(&mut self.read_buffer), + None, + Some(&mut self.read_overlapped), + ) }; + ensure_overlapped_io_result(result)?; + self.read_pending = true; + + Ok(()) } -} -/// Hands a decoded message to the processing task without blocking. -/// -/// The send is non-blocking because the IO thread also services outbound writes: -/// blocking here while the processing task awaits an outbound send would deadlock both sides. -/// A full queue therefore ends the channel rather than dropping the message. -/// NOW capability responses carry no request id, so a lost request would silently shift every later response the -/// client matches by send order. -/// -/// Returning an error makes [`run_dvc_io`] exit, which drops [`DvcIoContext`] and with it the WTS channel handle. -// UNTESTED: the client observes a DVC close when this returns an error. -// The close happens through `Drop` of `DvcIoContext` when `run_dvc_io` returns, and requires a live RDP session to -// observe. -// When changing the IO loop, keep `run_dvc_io` returning the error rather than continuing. -fn forward_to_processor(read_tx: &Sender>, message: NowMessage<'static>) -> anyhow::Result<()> { - match read_tx.try_send(message) { - Ok(()) => Ok(()), - Err(TrySendError::Full(_)) => { - error!("Closing the DVC channel because the processing task fell behind incoming messages"); - anyhow::bail!("DVC input queue overflow"); + fn complete_read(&mut self) -> anyhow::Result<()> { + trace!("DVC channel read event is signaled"); + + self.read_pending = false; + let mut bytes_read: u32 = 0; + + // SAFETY: The read was issued on this handle with this `OVERLAPPED`, and has completed. + unsafe { GetOverlappedResult(*self.file, &self.read_overlapped, &mut bytes_read, false) }?; + + const HEADER_SIZE: usize = size_of::(); + + let bytes_read = usize::try_from(bytes_read).expect("u32 fits into usize on Windows"); + let payload = self.read_buffer.get(HEADER_SIZE..bytes_read).with_context(|| { + format!("DVC read returned {bytes_read} bytes, fewer than the {HEADER_SIZE}-byte channel PDU header") + })?; + + let messages = match self.message_dissector.dissect(payload) { + Ok(messages) => messages, + Err(error) => { + error!(?error, "Failed to dissect DVC messages"); + return Err(error.context("failed to dissect DVC messages")); + } + }; + + for message in messages { + debug!(?message, "DVC message received"); + self.inbound.push_back(message); } - Err(error @ TrySendError::Closed(_)) => { - error!("DVC message was dropped due to closed channel"); - Err(error.into()) + + Ok(()) + } + + /// Hands decoded messages to the processing task, keeping those it has no room for. + /// + /// The send never blocks, because the loop also services outbound writes: blocking here while the processing task + /// awaits an outbound send would deadlock both sides. + /// Kept messages stop further reads until the queue has room, so a slow processing task holds back the client + /// rather than losing a message. + /// NOW capability responses carry no request id, so a lost request would silently shift every later response the + /// client matches by send order. + fn forward_inbound(&mut self, read_tx: &Sender>) -> anyhow::Result<()> { + while let Some(message) = self.inbound.pop_front() { + match read_tx.try_send(message) { + Ok(()) => {} + Err(TrySendError::Full(message)) => { + trace!(pending = self.inbound.len() + 1, "DVC processing queue is full"); + self.inbound.push_front(message); + break; + } + Err(TrySendError::Closed(_)) => { + anyhow::bail!("the DVC message processing task has stopped"); + } + } + } + + Ok(()) + } + + fn start_write(&mut self, message: &NowMessage<'static>) -> anyhow::Result<()> { + self.write_buffer = now_proto_pdu::ironrdp_core::encode_vec(message)?; + + // SAFETY: The buffer and `OVERLAPPED` live in this boxed struct, whose `Drop` waits for the write to finish. + let result = unsafe { + WriteFile( + *self.file, + Some(&self.write_buffer), + None, + Some(&mut self.write_overlapped), + ) + }; + ensure_overlapped_io_result(result)?; + self.write_pending = true; + + Ok(()) + } + + fn complete_write(&mut self) -> anyhow::Result<()> { + self.write_pending = false; + let mut bytes_written: u32 = 0; + + // SAFETY: The write was issued on this handle with this `OVERLAPPED`, and has completed. + unsafe { GetOverlappedResult(*self.file, &self.write_overlapped, &mut bytes_written, false) }?; + + let bytes_written = usize::try_from(bytes_written).expect("u32 fits into usize on Windows"); + + // The rest of a short write cannot be sent in a second write: the client decodes each DVC message on its own. + if bytes_written != self.write_buffer.len() { + anyhow::bail!("DVC write sent {bytes_written} of {} bytes", self.write_buffer.len()); + } + + Ok(()) + } +} + +impl Drop for DvcIo { + fn drop(&mut self) { + let pending = [ + (self.read_pending, &self.read_overlapped), + (self.write_pending, &self.write_overlapped), + ]; + + for (_, overlapped) in pending.into_iter().filter(|(pending, _)| *pending) { + let mut bytes_transferred: u32 = 0; + + // The OS writes to the buffer and `OVERLAPPED` until the operation finishes, so it must finish before + // they are freed. Errors are ignored: the operation may complete before it is cancelled, and a failed + // operation is finished all the same. + // SAFETY: The handle and `OVERLAPPED` are those of an issued operation, and are still alive. + let _ = unsafe { CancelIoEx(*self.file, Some(overlapped)) }; + // SAFETY: Same as above. + let _ = unsafe { GetOverlappedResult(*self.file, overlapped, &mut bytes_transferred, true) }; } } } @@ -380,42 +519,16 @@ fn initialize_dvc() -> Result, DvcInitializationError> { error, })?; - // All DVC messages should be under CHANNEL_CHUNK_LENGTH size, but sometimes RDP stack - // sends a few messages together; 128Kb buffer should be enough to hold a few dozen messages. - let pdu_chunk_buffer = vec![0u8; 128 * 1024].into_boxed_slice(); - let read_event = Event::new_unnamed().map_err(|error| DvcInitializationError { + let io = DvcIo::new(channel_file).map_err(|error| DvcInitializationError { stage: DvcInitializationStage::StartRead, error, })?; - let overlapped = OVERLAPPED { - hEvent: read_event.raw(), - ..Default::default() - }; - Ok(Box::new(DvcIoContext { - _wts: wts, - channel_file, - pdu_chunk_buffer, - overlapped, - bytes_read: 0, - message_dissector: NowMessageDissector::default(), - read_event, - })) + Ok(Box::new(DvcIoContext { io, _wts: wts })) } fn start_initial_read(context: &mut DvcIoContext) -> Result<(), windows::core::Error> { - // Prepare async read operation. - // SAFETY: Both `channel_file` and event passed to `overlapped` are valid during this call, - // therefore it is safe to call. - let read_result: Result<(), windows::core::Error> = unsafe { - ReadFile( - *context.channel_file, - Some(&mut context.pdu_chunk_buffer), - None, - Some(&mut context.overlapped), - ) - }; - ensure_overlapped_io_result(read_result)?; + context.io.start_read()?; trace!("DVC channel opened"); @@ -483,35 +596,314 @@ mod tests { use std::time::Duration; use futures::poll; - use now_proto_pdu::{NowChannelHeartbeatMsg, NowMessage}; + use now_proto_pdu::NowMessage; use tokio::sync::mpsc; - use super::{DVC_RETRY_DELAYS, DvcInitializationProgress, dvc_retry_delay, forward_to_processor}; + use std::sync::atomic::{AtomicU32, Ordering}; + use std::time::Instant; + + use now_proto_pdu::ironrdp_core::encode_vec; + use now_proto_pdu::{NowExecDataMsg, NowExecDataStreamKind}; + use win_api_wrappers::event::Event; + use windows::Win32::Foundation::{ERROR_MORE_DATA, GENERIC_READ, GENERIC_WRITE, HANDLE}; + use windows::Win32::Storage::FileSystem::{ + CreateFileW, FILE_FLAG_FIRST_PIPE_INSTANCE, FILE_FLAG_OVERLAPPED, FILE_FLAGS_AND_ATTRIBUTES, FILE_SHARE_NONE, + OPEN_EXISTING, PIPE_ACCESS_DUPLEX, ReadFile, WriteFile, + }; + use windows::Win32::System::Pipes::{ + CreateNamedPipeW, PIPE_READMODE_MESSAGE, PIPE_REJECT_REMOTE_CLIENTS, PIPE_TYPE_MESSAGE, PIPE_WAIT, + PeekNamedPipe, + }; + use windows::core::{Owned, PCWSTR}; + + use super::{DVC_RETRY_DELAYS, DvcInitializationProgress, DvcIo, dvc_retry_delay}; + use crate::dvc::channel::{WinapiSignaledSender, winapi_signaled_mpsc_channel}; + + /// A connected message-mode pipe standing in for the DVC: the loop serves the overlapped server end, and the test + /// plays the client on the synchronous end. + fn dvc_pipe() -> (usize, Owned) { + static NEXT_PIPE: AtomicU32 = AtomicU32::new(0); - /// A full input queue must end the IO loop instead of dropping the message: the processing - /// task is still alive, so a silent drop would desynchronize the client's order-based - /// response matching with nothing to signal it. + let name = format!( + r"\\.\pipe\devolutions-session-dvc-io-test-{}-{}", + std::process::id(), + NEXT_PIPE.fetch_add(1, Ordering::Relaxed) + ); + let name: Vec = name.encode_utf16().chain(Some(0)).collect(); + + // SAFETY: The name is a valid null-terminated string. + let server = unsafe { + CreateNamedPipeW( + PCWSTR(name.as_ptr()), + PIPE_ACCESS_DUPLEX | FILE_FLAG_OVERLAPPED | FILE_FLAG_FIRST_PIPE_INSTANCE, + PIPE_TYPE_MESSAGE | PIPE_READMODE_MESSAGE | PIPE_WAIT | PIPE_REJECT_REMOTE_CLIENTS, + 1, + PIPE_BUFFER_SIZE, + PIPE_BUFFER_SIZE, + 0, + None, + ) + }; + assert!(!server.is_invalid(), "{}", windows::core::Error::from_win32()); + + // SAFETY: The name is a valid null-terminated string. + let client = unsafe { + CreateFileW( + PCWSTR(name.as_ptr()), + (GENERIC_READ | GENERIC_WRITE).0, + FILE_SHARE_NONE, + None, + OPEN_EXISTING, + FILE_FLAGS_AND_ATTRIBUTES(0), + None, + ) + } + .expect("connect to the test pipe"); + + // The raw value crosses to the IO thread, which takes ownership of it. + // SAFETY: Both handles were just opened and are owned by nothing else. + (server.0 as usize, unsafe { Owned::new(client) }) + } + + const PIPE_BUFFER_SIZE: u32 = 4 * 1024; + + struct RunningDvcIo { + write_tx: WinapiSignaledSender>, + read_rx: mpsc::Receiver>, + stop_event: Event, + thread: std::thread::JoinHandle>, + } + + fn run_dvc_io_on(server: usize, read_queue_capacity: usize) -> RunningDvcIo { + let (write_tx, write_rx) = winapi_signaled_mpsc_channel().expect("create the write queue"); + let (read_tx, read_rx) = mpsc::channel(read_queue_capacity); + let stop_event = Event::new_unnamed().expect("create the stop event"); + let thread_stop_event = stop_event.clone(); + + let thread = std::thread::spawn(move || { + // SAFETY: The handle was opened by `dvc_pipe`, which gave up ownership of it. + let file = unsafe { Owned::new(HANDLE(server as *mut _)) }; + let mut io = DvcIo::new(file)?; + io.serve(write_rx, &read_tx, &thread_stop_event) + }); + + RunningDvcIo { + write_tx, + read_rx, + stop_event, + thread, + } + } + + impl RunningDvcIo { + fn recv(&mut self) -> NowMessage<'static> { + let deadline = Instant::now() + TEST_TIMEOUT; + + loop { + if let Ok(message) = self.read_rx.try_recv() { + return message; + } + + assert!(Instant::now() < deadline, "no message reached the processing queue"); + std::thread::sleep(Duration::from_millis(5)); + } + } + + fn join(self) -> anyhow::Result<()> { + let deadline = Instant::now() + TEST_TIMEOUT; + + while !self.thread.is_finished() { + assert!(Instant::now() < deadline, "the DVC IO loop did not stop"); + std::thread::sleep(Duration::from_millis(5)); + } + + self.thread.join().expect("the DVC IO loop panicked") + } + + fn stop(self) -> anyhow::Result<()> { + self.stop_event.set().expect("set the stop event"); + self.join() + } + } + + /// Writes one channel read as the RDP stack delivers it: an 8-byte `CHANNEL_PDU_HEADER`, then the data. + fn write_pdu(client: &Owned, data: &[u8]) { + const CHANNEL_FLAG_FIRST_AND_LAST: u32 = 0x3; + + let mut pdu = u32::try_from(data.len()) + .expect("test data fits") + .to_le_bytes() + .to_vec(); + pdu.extend_from_slice(&CHANNEL_FLAG_FIRST_AND_LAST.to_le_bytes()); + pdu.extend_from_slice(data); + + write_raw(client, &pdu); + } + + fn write_raw(client: &Owned, bytes: &[u8]) { + let mut written = 0; + // SAFETY: The handle and buffer are valid for the duration of the synchronous call. + unsafe { WriteFile(**client, Some(bytes), Some(&mut written), None) }.expect("write to the test pipe"); + assert_eq!(written as usize, bytes.len()); + } + + fn read_exact(client: &Owned, len: usize) -> Vec { + let mut bytes = vec![0; len]; + let mut filled = 0; + + while filled < len { + let mut read = 0; + // SAFETY: The handle and buffer are valid for the duration of the synchronous call. + let result = unsafe { ReadFile(**client, Some(&mut bytes[filled..]), Some(&mut read), None) }; + + // A message larger than the buffer is read in parts, each reported as `ERROR_MORE_DATA`. + if let Err(error) = result { + assert_eq!(error.code(), ERROR_MORE_DATA.to_hresult(), "read from the test pipe"); + } + + filled += read as usize; + } + + bytes + } + + fn encoded(message: &NowMessage<'_>) -> Vec { + encode_vec(message).expect("encode a NOW message") + } + + fn exec_data(session_id: u32, data: Vec) -> NowMessage<'static> { + NowExecDataMsg::new(session_id, NowExecDataStreamKind::Stdin, false, data) + .expect("build an exec data message") + .into() + } + + // oracle: scaffold + #[test] + fn read_shorter_than_the_channel_header_is_an_error_with_its_length() { + let (server, client) = dvc_pipe(); + let running = run_dvc_io_on(server, 1); + + write_raw(&client, &[0; 4]); + + let error = running.join().expect_err("a 4-byte read cannot hold a channel header"); + let message = format!("{error:#}"); + assert!(message.contains("4 bytes"), "unexpected error: {message}"); + } + + /// An empty channel PDU carries no message and must not end the loop, so a later message still arrives. + // oracle: scaffold + #[test] + fn empty_channel_pdu_is_skipped() { + let (server, client) = dvc_pipe(); + let mut running = run_dvc_io_on(server, 1); + let message = exec_data(1, b"after".to_vec()); + + write_pdu(&client, &[]); + write_pdu(&client, &encoded(&message)); + + assert_eq!(encoded(&running.recv()), encoded(&message)); + running.stop().expect("the loop stops cleanly"); + } + + /// A client that does not read our output must not stop us from reading its input; with a synchronous write the + /// loop would block until the client reads. + // oracle: mutant + #[test] + fn reads_continue_while_a_large_write_is_pending() { + let (server, client) = dvc_pipe(); + let mut running = run_dvc_io_on(server, 1); + + let outbound = exec_data(1, vec![0xA5; 1024 * 1024]); + let outbound_bytes = encoded(&outbound); + running.write_tx.try_send(outbound).expect("queue the outbound message"); + + // The write is in flight once its first bytes are visible to the client. + let deadline = Instant::now() + TEST_TIMEOUT; + loop { + let mut available = 0; + // SAFETY: The handle is valid, and only the byte count is requested. + unsafe { PeekNamedPipe(*client, None, 0, None, Some(&mut available), None) }.expect("peek the test pipe"); + + if available > 0 { + break; + } + + assert!(Instant::now() < deadline, "the outbound write never started"); + std::thread::sleep(Duration::from_millis(5)); + } + + let inbound = exec_data(2, b"stdin".to_vec()); + write_pdu(&client, &encoded(&inbound)); + assert_eq!(encoded(&running.recv()), encoded(&inbound)); + + // The outbound message arrives whole, as a single pipe message. + assert_eq!(read_exact(&client, outbound_bytes.len()), outbound_bytes); + + running.stop().expect("the loop stops cleanly"); + } + + /// A full processing queue must hold messages back rather than drop them or end the channel: the client matches + /// responses by send order, so a gap would desynchronize it. + // oracle: mutant #[test] - fn full_input_queue_is_an_error_not_a_drop() { - let (read_tx, mut read_rx) = mpsc::channel::>(1); - let heartbeat = || NowMessage::from(NowChannelHeartbeatMsg::default()); + fn full_processing_queue_holds_messages_back_in_order() { + let (server, client) = dvc_pipe(); + let mut running = run_dvc_io_on(server, 1); + let messages: Vec<_> = (1..=3).map(|session_id| exec_data(session_id, vec![0; 16])).collect(); + + for message in &messages { + write_pdu(&client, &encoded(message)); + } - forward_to_processor(&read_tx, heartbeat()).expect("first message fits the queue"); + // Give the loop time to read past the queue's capacity before anything is received. + std::thread::sleep(Duration::from_millis(200)); + assert!(!running.thread.is_finished(), "the loop ended on a full queue"); - let error = forward_to_processor(&read_tx, heartbeat()).expect_err("second message overflows the queue"); - assert!(error.to_string().contains("overflow"), "unexpected error: {error}"); + for message in &messages { + assert_eq!(encoded(&running.recv()), encoded(message)); + } - // The queued message is intact, and no further message was forwarded. - assert!(read_rx.try_recv().is_ok()); - assert!(read_rx.try_recv().is_err()); + running.stop().expect("the loop stops cleanly"); } + /// Stopping with a read and a write in flight must cancel both and return. + // oracle: scaffold #[test] - fn closed_input_queue_is_an_error() { - let (read_tx, read_rx) = mpsc::channel::>(1); + fn stop_cancels_pending_io() { + let (server, _client) = dvc_pipe(); + let running = run_dvc_io_on(server, 1); + + running + .write_tx + .try_send(exec_data(1, vec![0; 1024 * 1024])) + .expect("queue the outbound message"); + std::thread::sleep(Duration::from_millis(100)); + + running.stop().expect("the loop stops cleanly"); + } + + // oracle: scaffold + #[test] + fn closed_processing_queue_is_an_error() { + let (server, client) = dvc_pipe(); + let running = run_dvc_io_on(server, 1); + let RunningDvcIo { + write_tx, + read_rx, + stop_event, + thread, + } = running; drop(read_rx); - forward_to_processor(&read_tx, NowChannelHeartbeatMsg::default().into()).expect_err("closed queue is reported"); + write_pdu(&client, &encoded(&exec_data(1, Vec::new()))); + + let running = RunningDvcIo { + write_tx, + read_rx: mpsc::channel(1).1, + stop_event, + thread, + }; + running.join().expect_err("a closed processing queue ends the loop"); } #[test] diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 1638bc9e1a..32dfe230d0 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -229,8 +229,8 @@ async fn serve_channel(mut shutdown_signal: ShutdownSignal) -> anyhow::Result { From 52e0f1cb62027a8ac479347a9de6af1857661c14 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:18:01 -0400 Subject: [PATCH 06/19] fix(agent): keep draining output while writing stdin A process that writes output before reading its input blocks once its output pipe is full. Writing stdin on the thread that drains that output deadlocked both sides as soon as the input exceeded the stdin pipe buffer, and waiting for that write in the channel task also stopped it from forwarding process output and exit notifications. Stdin is now written by a thread of its own, fed through a bounded queue. The channel task holds back further client messages while a stdin send waits on that queue, which keeps input ordered and pushes back on the client, but keeps forwarding process events. A failed stdin write discards later input instead of failing the session; the process exit is still reported. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/process.rs | 228 +++++++++++++++++-------- devolutions-session/src/dvc/task.rs | 43 ++++- 2 files changed, 196 insertions(+), 75 deletions(-) diff --git a/devolutions-session/src/dvc/process.rs b/devolutions-session/src/dvc/process.rs index 95efb007e1..33f4430f30 100644 --- a/devolutions-session/src/dvc/process.rs +++ b/devolutions-session/src/dvc/process.rs @@ -1,8 +1,8 @@ use std::collections::HashMap; use now_proto_pdu::{NowExecDataStreamKind, NowStatusError}; -use tokio::sync::mpsc::Sender; -use tracing::{error, info, trace}; +use tokio::sync::mpsc::{Receiver, Sender}; +use tracing::{debug, error, info, trace, warn}; use win_api_wrappers::event::Event; use win_api_wrappers::handle::Handle; use win_api_wrappers::process::{Process, post_message_for_pid}; @@ -21,7 +21,9 @@ use windows::Win32::System::Threading::{ use windows::Win32::UI::WindowsAndMessaging::{SW_HIDE, WM_QUIT}; use windows::core::PCWSTR; -use crate::dvc::channel::{WinapiSignaledReceiver, WinapiSignaledSender, winapi_signaled_mpsc_channel}; +use crate::dvc::channel::{ + WinapiSignaledReceiver, WinapiSignaledSender, bounded_mpsc_channel, winapi_signaled_mpsc_channel, +}; use crate::dvc::encoding::{DataEncoding, InputEncoder, OutputDecoder}; use crate::dvc::env::make_environment_block; use crate::dvc::fs::TmpFileGuard; @@ -62,15 +64,17 @@ impl From> for pub enum ProcessIoInputEvent { AbortExecution(u32), CancelExecution, - DataIn { - data: Vec, - /// If last is set, then stdin pipe should be closed. Any consecutive DataIn messages - /// will be ignored. - last: bool, - }, TerminateIo, } +/// Input for the process stdin. +#[derive(Debug)] +pub struct StdinChunk { + data: Vec, + /// Closes stdin after this chunk; later chunks are ignored. + last: bool, +} + /// Message, sent from Process IO thread to task to finalize process execution. #[derive(Debug)] pub enum ServerChannelEvent { @@ -195,9 +199,6 @@ impl WinApiProcessCtx { // wait for process to exit continue; } - ProcessIoInputEvent::DataIn { .. } => { - // DataIn messages ignored. - } ProcessIoInputEvent::TerminateIo => { info!(session_id, "Terminating IO loop"); @@ -226,10 +227,9 @@ impl WinApiProcessCtx { info!(session_id, ?self.encoding, "Process IO redirection loop has started"); - // Encoding transcoders for stdin/stdout/stderr. + // Encoding transcoders for stdout/stderr. let mut stdout_decoder = OutputDecoder::new(self.encoding); let mut stderr_decoder = OutputDecoder::new(self.encoding); - let mut stdin_encoder = InputEncoder::new(self.encoding); // Events for overlapped IO let stdout_read_event = Event::new_unnamed()?; @@ -325,61 +325,6 @@ impl WinApiProcessCtx { // wait for process to exit continue; } - ProcessIoInputEvent::DataIn { data, last } => { - trace!(session_id, "Received data to write to stdin pipe"); - - let pipe_handle = match self.stdin_write_pipe.as_ref() { - Some(pipe) => pipe.handle.raw(), - None => { - // Ignore data, as stdin pipe was already closed. - continue; - } - }; - - // Transcode UTF-8 input to the process encoding. - let encoded_data = stdin_encoder.encode(&data); - - if !encoded_data.is_empty() { - let mut bytes_written: u32 = 0; - - // Send data to stdin pipe in a blocking manner. - // SAFETY: pipe and input buffer are ensured to be valid via - // borrowing rules. - unsafe { - WriteFile( - pipe_handle, - Some(&*encoded_data), - Some(&mut bytes_written as *mut _), - None, - ) - }?; - } - - if last { - // Flush any remaining encoder state before closing. - let flushed = stdin_encoder.flush(); - if !flushed.is_empty() { - let mut bytes_written: u32 = 0; - // SAFETY: pipe and input buffer are ensured to be valid via - // borrowing rules. - unsafe { - WriteFile( - self.stdin_write_pipe - .as_ref() - .expect("BUG: stdin pipe closed unexpectedly") - .handle - .raw(), - Some(&flushed), - Some(&mut bytes_written as *mut _), - None, - ) - }?; - } - - // Close stdin pipe. - self.stdin_write_pipe = None; - } - } ProcessIoInputEvent::TerminateIo => { info!(session_id, "Terminating IO loop"); @@ -554,6 +499,52 @@ impl WinApiProcessCtx { } } +/// Writes stdin chunks to the process until the last one, then closes its stdin. +/// +/// Runs on a thread of its own because the write blocks until the process reads: in the IO loop, it would stop +/// stdout and stderr from being drained, and a process blocked on full output pipes never reads its input. +/// After a failed write, later input is discarded: the process no longer reads stdin, and its exit is reported by the +/// IO loop. +fn write_stdin(session_id: u32, pipe: Pipe, mut encoder: InputEncoder, mut stdin_rx: Receiver) { + while let Some(StdinChunk { data, last }) = stdin_rx.blocking_recv() { + let mut bytes = encoder.encode(&data).into_owned(); + + if last { + bytes.extend(encoder.flush()); + } + + if let Err(error) = write_all(&pipe, &bytes) { + warn!(session_id, %error, "Failed to write to the process stdin; discarding further input"); + return; + } + + if last { + break; + } + } + + trace!(session_id, "Closing the process stdin"); +} + +fn write_all(pipe: &Pipe, mut bytes: &[u8]) -> anyhow::Result<()> { + while !bytes.is_empty() { + let mut bytes_written: u32 = 0; + + // SAFETY: The pipe is a synchronous handle, and the buffer outlives the call. + unsafe { WriteFile(pipe.handle.raw(), Some(bytes), Some(&mut bytes_written), None) }?; + + let bytes_written = usize::try_from(bytes_written).expect("u32 fits into usize on Windows"); + + if bytes_written == 0 { + anyhow::bail!("stdin write made no progress"); + } + + bytes = bytes.get(bytes_written..).unwrap_or_default(); + } + + Ok(()) +} + /// Builder for process execution session. pub struct WinApiProcessBuilder { executable: String, @@ -673,6 +664,21 @@ impl WinApiProcessBuilder { // Create channel for `task` -> `Process IO thread` communication let (input_event_tx, input_event_rx) = winapi_signaled_mpsc_channel()?; + let mut process_ctx = process_ctx; + let stdin_tx = match process_ctx.stdin_write_pipe.take() { + Some(pipe) => { + let (stdin_tx, stdin_rx) = bounded_mpsc_channel()?; + let encoder = InputEncoder::new(encoding); + + std::thread::Builder::new() + .name(format!("process-{session_id}-stdin")) + .spawn(move || write_stdin(session_id, pipe, encoder, stdin_rx))?; + + Some(stdin_tx) + } + None => None, + }; + let io_notification_tx = io_notification_tx.expect("BUG: io_notification_tx must be Some for non-detached mode"); @@ -695,6 +701,7 @@ impl WinApiProcessBuilder { Ok(Some(WinApiProcess { input_event_tx, + stdin_tx, join_handle, _temp_files: temp_files, })) @@ -875,6 +882,8 @@ fn prepare_process_with_io_redirection( /// Represents spawned process with IO redirection. pub struct WinApiProcess { input_event_tx: WinapiSignaledSender, + /// `None` without IO redirection. + stdin_tx: Option>, join_handle: std::thread::JoinHandle<()>, _temp_files: Vec, } @@ -898,10 +907,23 @@ impl WinApiProcess { self.input_event_tx.send(ProcessIoInputEvent::CancelExecution).await } - pub async fn send_stdin(&self, data: Vec, last: bool) -> anyhow::Result<()> { - self.input_event_tx - .send(ProcessIoInputEvent::DataIn { data, last }) - .await + /// Returns a send of `data` to the process stdin that waits while the stdin queue is full. + /// + /// The send owns what it needs, so the caller can keep serving process output while it waits: the process may not + /// read its stdin until its output is drained. + /// Input for a process that no longer reads stdin is discarded. + pub fn send_stdin(&self, data: Vec, last: bool) -> impl Future + Send + 'static { + let stdin_tx = self.stdin_tx.clone(); + + async move { + let Some(stdin_tx) = stdin_tx else { + return; + }; + + if stdin_tx.send(StdinChunk { data, last }).await.is_err() { + debug!("Discarding input for a closed process stdin"); + } + } } pub async fn shutdown(&self) -> anyhow::Result<()> { @@ -913,3 +935,63 @@ impl WinApiProcess { self.join_handle.is_finished() } } + +#[cfg(test)] +mod tests { + use std::time::Duration; + + use super::*; + + /// A process that fills its output before reading stdin must still get all of a large input. + /// + /// The input exceeds the stdin pipe buffer, so a stdin write that blocks the output drain deadlocks. + // oracle: spec Windows anonymous pipes block a writer until the reader frees buffer space + #[tokio::test(flavor = "multi_thread")] + async fn large_stdin_after_output_completes() { + const SESSION_ID: u32 = 1; + const OUTPUT_LINES: u32 = 3000; + const INPUT_LINES: u32 = 5000; + + let (io_notification_tx, mut io_notification_rx) = tokio::sync::mpsc::channel(100); + let process = WinApiProcessBuilder::new("cmd.exe") + .with_command_line(&format!( + "/d /c (for /L %i in (1,1,{OUTPUT_LINES}) do @echo output-line-%i) & sort" + )) + .with_io_redirection(true) + .with_encoding(DataEncoding::Raw) + .run(SESSION_ID, io_notification_tx) + .expect("start cmd.exe"); + + let input: String = (0..INPUT_LINES).map(|i| format!("input-line-{i:05}\r\n")).collect(); + let feed = tokio::spawn(process.send_stdin(input.into_bytes(), true)); + + let mut stdout = Vec::new(); + let exit_code = tokio::time::timeout(Duration::from_secs(60), async { + loop { + match io_notification_rx.recv().await.expect("notification channel open") { + ServerChannelEvent::SessionDataOut { + stream: NowExecDataStreamKind::Stdout, + data, + .. + } => stdout.extend(data), + ServerChannelEvent::SessionExited { exit_code, .. } => break exit_code, + ServerChannelEvent::SessionFailed { error, .. } => panic!("process failed: {error}"), + _ => {} + } + } + }) + .await + .expect("process exits instead of deadlocking on stdin"); + + feed.await.expect("stdin feed completes"); + + let stdout = String::from_utf8(stdout).expect("ASCII output"); + assert_eq!(exit_code, 0); + assert!(stdout.contains(&format!("output-line-{OUTPUT_LINES}"))); + assert!(stdout.contains(&format!("input-line-{:05}", INPUT_LINES - 1))); + assert_eq!( + stdout.matches("input-line-").count(), + usize::try_from(INPUT_LINES).expect("u32 fits into usize") + ); + } +} diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 32dfe230d0..5d3dbcf5b4 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -335,13 +335,28 @@ async fn process_messages( init_progress.mark_negotiated(); info!("DVC negotiation completed"); + // Process output keeps being served while stdin waits, because the process may not read stdin until its output + // is drained. + let mut pending_stdin: Option<(u32, StdinSend)> = None; + loop { select! { - read_result = read_rx.recv() => { + () = async { + match pending_stdin.as_mut() { + Some((_, send)) => send.await, + None => std::future::pending().await, + } + } => { + pending_stdin = None; + } + read_result = read_rx.recv(), if pending_stdin.is_none() => { match read_result { Some(message) => { match processor.process_message(message).await { Ok(ProcessMessageAction::Continue) => {} + Ok(ProcessMessageAction::SendStdin { session_id, send }) => { + pending_stdin = Some((session_id, send)); + } Ok(ProcessMessageAction::Shutdown) => { info!("Received channel shutdown message..."); return Ok(()); @@ -403,6 +418,7 @@ async fn process_messages( ServerChannelEvent::SessionExited { session_id, exit_code } => { info!(session_id, %exit_code, "Session exited"); processor.remove_session(session_id); + discard_pending_stdin(&mut pending_stdin, session_id); let message = NowExecResultMsg::new_success(session_id, exit_code); dvc_tx.send(message.into()).await?; @@ -410,6 +426,7 @@ async fn process_messages( ServerChannelEvent::SessionFailed { session_id, error } => { error!(session_id, %error, "Session error"); processor.remove_session(session_id); + discard_pending_stdin(&mut pending_stdin, session_id); handle_exec_error(&dvc_tx, session_id, error).await; } @@ -548,10 +565,27 @@ fn find_pwsh_executable() -> Option { String::from_utf16(&buffer[..len]).ok() } +type StdinSend = std::pin::Pin + Send>>; + +/// Drops a stdin send for a session that has ended, so its input no longer holds back other messages. +fn discard_pending_stdin(pending_stdin: &mut Option<(u32, StdinSend)>, ended_session_id: u32) { + if pending_stdin + .as_ref() + .is_some_and(|(session_id, _)| *session_id == ended_session_id) + { + *pending_stdin = None; + } +} + enum ProcessMessageAction { Continue, Shutdown, Restart(NowChannelCapsetMsg), + /// Stdin for a session; later messages wait for it so input stays ordered and a full stdin queue pushes back. + SendStdin { + session_id: u32, + send: StdinSend, + }, } struct MessageProcessor { @@ -722,7 +756,12 @@ impl MessageProcessor { } }; - process.send_stdin(data_msg.data().to_vec(), data_msg.is_last()).await?; + let send = process.send_stdin(data_msg.data().to_vec(), data_msg.is_last()); + + return Ok(ProcessMessageAction::SendStdin { + session_id, + send: Box::pin(send), + }); } NowMessage::Session(NowSessionMessage::MsgBoxReq(request)) => { let tx = self.dvc_tx.clone(); From 3a2f5206358e5b91f05e41bbbafbb40547515f2d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:19:22 -0400 Subject: [PATCH 07/19] fix(agent): relaunch the session process after it fails The session process is started only on logon or unlock, so a crash or a failure to serve the NOW channel left the session without a channel host until the user logged on again. The agent now watches each process it starts. A nonzero exit while the remote session is still ready relaunches it after a delay that starts at 2 seconds and doubles up to 60 seconds per consecutive quick failure. After 5 quick failures it waits for the next logon or unlock. Exit code 0 means the process ended on purpose and is not relaunched. A launch id keeps the exit of a replaced, disconnected or logged-off process from starting another one. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-agent/src/session_manager.rs | 482 ++++++++++++++++++++++- 1 file changed, 467 insertions(+), 15 deletions(-) diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index a37e18a92a..97b1e48ba3 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -2,6 +2,7 @@ use std::collections::BTreeMap; use std::fmt::Debug; +use std::time::{Duration, Instant}; use async_trait::async_trait; use camino::{Utf8Path, Utf8PathBuf}; @@ -9,7 +10,8 @@ use ceviche::controller::Session; use devolutions_gateway_task::{ShutdownSignal, Task}; use tokio::sync::{RwLock, mpsc}; use win_api_wrappers::process::{ - StartupInfo, create_process_in_session, is_process_running_in_session, terminate_process_by_name_in_session, + Process, StartupInfo, create_process_in_session, is_process_running_in_session, + terminate_process_by_name_in_session, }; use win_api_wrappers::utils::{CommandLine, WideString}; use win_api_wrappers::wts::session_has_logged_in_user; @@ -73,6 +75,10 @@ struct GatewaySession { session: Session, kind: SessionKind, readiness: SessionReadiness, + /// Launch id of the last process this agent started in the session, if any. + launch_id: Option, + /// Number of consecutive quick failures of the session process. + consecutive_failures: u32, } // NOTE: `ceviche::controller::Session` do not implement `Debug` for session. @@ -82,6 +88,8 @@ impl Debug for GatewaySession { .field("session", &self.session.id) .field("kind", &self.kind) .field("readiness", &self.readiness) + .field("launch_id", &self.launch_id) + .field("consecutive_failures", &self.consecutive_failures) .finish() } } @@ -92,6 +100,8 @@ impl GatewaySession { session, kind, readiness, + launch_id: None, + consecutive_failures: 0, } } @@ -119,12 +129,55 @@ impl GatewaySession { fn set_waiting_for_logon(&mut self) { self.readiness = SessionReadiness::WaitingForLogon; + self.consecutive_failures = 0; } + + /// Whether the process started with `launch_id` is the one this session still wants running. + fn wants_launch(&self, launch_id: u64) -> bool { + self.kind().is_remote() && self.readiness == SessionReadiness::Ready && self.launch_id == Some(launch_id) + } +} + +/// Exit of a session process started by this agent. +#[derive(Debug, Clone, Copy)] +struct ProcessExit { + session_id: u32, + launch_id: u64, + exit_code: u32, + run_time: Duration, +} + +/// Events the session manager sends to itself. +#[derive(Debug)] +enum InternalEvent { + ProcessExited(ProcessExit), + RelaunchDue { session_id: u32, launch_id: u64 }, +} + +/// Delay before relaunching a process that failed for the first time. +const RELAUNCH_DELAY_FLOOR: Duration = Duration::from_secs(2); + +/// Upper bound of the relaunch delay. +const RELAUNCH_DELAY_CAP: Duration = Duration::from_secs(60); + +/// Run time after which a failure no longer counts as failing on start. +const STABLE_RUN_TIME: Duration = Duration::from_secs(60); + +/// Number of consecutive quick failures after which relaunching stops until the next logon or unlock. +const MAX_CONSECUTIVE_FAILURES: u32 = 5; + +/// Delay before relaunching after the `consecutive_failures`-th consecutive quick failure, counting from 1. +fn relaunch_delay(consecutive_failures: u32) -> Duration { + let doublings = consecutive_failures.saturating_sub(1); + 2u32.checked_pow(doublings) + .and_then(|factor| RELAUNCH_DELAY_FLOOR.checked_mul(factor)) + .map_or(RELAUNCH_DELAY_CAP, |delay| delay.min(RELAUNCH_DELAY_CAP)) } #[derive(Default, Debug)] struct SessionManagerCtx { sessions: BTreeMap, + last_launch_id: u64, } impl SessionManagerCtx { @@ -153,12 +206,17 @@ impl SessionManagerCtx { /// /// The session is marked ready only once its process is known to run, so that a failure leaves it waiting for the /// next readiness event. + /// A process started here gets a fresh launch id, passed to `start` and recorded on the session, so that reports + /// about an earlier process can be told apart. + /// A process found already running keeps the recorded launch id, because nothing tells whether this agent started it. fn start_process_if_not_running( &mut self, session: &Session, is_running: impl FnOnce(&Session) -> anyhow::Result, - start: impl FnOnce(&Session) -> anyhow::Result<()>, + start: impl FnOnce(&Session, u64) -> anyhow::Result<()>, ) { + let launch_id = self.last_launch_id + 1; + let Some(gw_session) = self.get_session_mut(session) else { warn!(%session, "Session is not yet registered"); return; @@ -183,16 +241,83 @@ impl SessionManagerCtx { info!(%session, "Starting session process"); - match start(session) { + match start(session, launch_id) { Ok(()) => { - info!(%session, "Session process started"); + info!(%session, launch_id, "Session process started"); gw_session.set_session_ready(); + gw_session.launch_id = Some(launch_id); + self.last_launch_id = launch_id; } Err(error) => { error!(%error, %session, "Failed to start session process"); } } } + + /// Decides what to do about the exit of a session process this agent started. + /// + /// Returns the delay after which to relaunch the process, or `None` when it must not be relaunched. + fn handle_process_exit(&mut self, exit: &ProcessExit) -> Option { + let ProcessExit { + session_id, + launch_id, + exit_code, + run_time, + } = *exit; + + let Some(gw_session) = self + .get_session_mut(&Session::new(session_id)) + .filter(|gw_session| gw_session.wants_launch(launch_id)) + else { + debug!( + session = session_id, + launch_id, exit_code, "Ignored exit of an unwanted session process" + ); + return None; + }; + + if exit_code == 0 { + info!(session = session_id, launch_id, "Session process ended"); + return None; + } + + if STABLE_RUN_TIME <= run_time { + gw_session.consecutive_failures = 0; + } + gw_session.consecutive_failures += 1; + + if MAX_CONSECUTIVE_FAILURES <= gw_session.consecutive_failures { + error!( + session = session_id, + launch_id, + exit_code = format!("{exit_code:#010X}"), + consecutive_failures = gw_session.consecutive_failures, + "Session process keeps failing; waiting for the next logon or unlock" + ); + gw_session.readiness = SessionReadiness::WaitingForLogonOrUnlock; + gw_session.consecutive_failures = 0; + return None; + } + + let delay = relaunch_delay(gw_session.consecutive_failures); + warn!( + session = session_id, + launch_id, + exit_code = format!("{exit_code:#010X}"), + ?run_time, + ?delay, + "Session process failed; relaunching" + ); + + Some(delay) + } + + /// Whether a relaunch scheduled after the exit of the process started with `launch_id` is still wanted. + fn should_relaunch(&self, session_id: u32, launch_id: u64) -> bool { + self.sessions + .get(&Session::new(session_id).to_string()) + .is_some_and(|gw_session| gw_session.wants_launch(launch_id)) + } } pub struct SessionManager { @@ -234,8 +359,27 @@ impl Task for SessionManager { info!("Starting session manager..."); + // The loop keeps a sender, so the receiver never reports a closed channel. + let (internal_tx, mut internal_rx) = mpsc::unbounded_channel(); + loop { tokio::select! { + Some(event) = internal_rx.recv() => { + let mut ctx = ctx.write().await; + match event { + InternalEvent::ProcessExited(exit) => { + if let Some(delay) = ctx.handle_process_exit(&exit) { + schedule_relaunch(&internal_tx, exit.session_id, exit.launch_id, delay); + } + } + InternalEvent::RelaunchDue { session_id, launch_id } => { + if ctx.should_relaunch(session_id, launch_id) { + info!(session = session_id, "Relaunching session process"); + start_session_process_if_not_running(&mut ctx, &Session::new(session_id), &internal_tx); + } + } + } + } event = service_event_rx.recv() => { info!("Received service event"); @@ -302,7 +446,7 @@ impl Task for SessionManager { // session app on logon, if not yet started. let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Logon) { - start_session_process_if_not_running(&mut ctx, &id); + start_session_process_if_not_running(&mut ctx, &id, &internal_tx); } } AgentServiceEvent::SessionUnlock(id) => { @@ -310,7 +454,7 @@ impl Task for SessionManager { let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Unlock) { - start_session_process_if_not_running(&mut ctx, &id); + start_session_process_if_not_running(&mut ctx, &id, &internal_tx); } } AgentServiceEvent::SessionLogoff(id) => { @@ -340,8 +484,80 @@ impl Task for SessionManager { } /// Starts Devolutions Session process in the target session. -fn start_session_process_if_not_running(ctx: &mut SessionManagerCtx, session: &Session) { - ctx.start_process_if_not_running(session, is_session_running_in_session, start_session_process); +/// +/// A process started here is watched, and its exit is reported through `internal_tx`. +/// A process found already running, such as one started by an earlier agent instance, is not watched, so its exit is +/// not relaunched until the next logon or unlock. +fn start_session_process_if_not_running( + ctx: &mut SessionManagerCtx, + session: &Session, + internal_tx: &mpsc::UnboundedSender, +) { + ctx.start_process_if_not_running(session, is_session_running_in_session, |session, launch_id| { + let process = start_session_process(session)?; + watch_session_process(process, session.id, launch_id, internal_tx.clone()); + Ok(()) + }); +} + +/// Reports the exit of `process` to the session manager from a dedicated thread. +/// +/// The thread blocks until the process exits, which may outlive the session manager. +fn watch_session_process( + process: Process, + session_id: u32, + launch_id: u64, + internal_tx: mpsc::UnboundedSender, +) { + let started_at = Instant::now(); + + // UNTESTED: the watcher is a detached `std::thread`, never a `tokio::task::spawn_blocking` task, and is never + // joined, because the runtime waits for blocking tasks at shutdown and a long-lived process would then hang the + // service stop. + // When changing this, check that stopping the service with a running session process returns promptly. + let spawn_result = std::thread::Builder::new() + .name(format!("session-{session_id}-process-watcher")) + .spawn(move || { + let exit_code = match process.wait(None).and_then(|_| process.exit_code()) { + Ok(exit_code) => exit_code, + Err(error) => { + error!(%error, session = session_id, "Failed to wait for session process exit"); + return; + } + }; + + let exit = ProcessExit { + session_id, + launch_id, + exit_code, + run_time: started_at.elapsed(), + }; + + // The session manager is gone once it shuts down, and then nothing is left to relaunch the process. + let _ = internal_tx.send(InternalEvent::ProcessExited(exit)); + }); + + if let Err(error) = spawn_result { + error!(%error, session = session_id, "Failed to watch session process"); + } +} + +/// Sends a relaunch-due event for the process started with `launch_id` after `delay`. +fn schedule_relaunch( + internal_tx: &mpsc::UnboundedSender, + session_id: u32, + launch_id: u64, + delay: Duration, +) { + let internal_tx = internal_tx.clone(); + + // UNTESTED: the timer is a detached task that nothing awaits, so that shutting down the session manager does not + // wait for a pending relaunch. + // When changing this, check that stopping the service during a relaunch delay returns promptly. + tokio::spawn(async move { + tokio::time::sleep(delay).await; + let _ = internal_tx.send(InternalEvent::RelaunchDue { session_id, launch_id }); + }); } /// Terminates Devolutions Session process in the target session. @@ -364,7 +580,7 @@ fn is_session_running_in_session(session: &Session) -> anyhow::Result { Ok(is_running) } -fn start_session_process(session: &Session) -> anyhow::Result<()> { +fn start_session_process(session: &Session) -> anyhow::Result { if !session_has_logged_in_user(session.id)? { anyhow::bail!("Session {} does not have a logged in user", session); } @@ -399,9 +615,9 @@ fn start_session_process(session: &Session) -> anyhow::Result<()> { ); match start_result { - Ok(_) => { - info!(%session, "{SESSION_BINARY} started"); - Ok(()) + Ok(process_information) => { + info!(%session, process_id = process_information.process_id, "{SESSION_BINARY} started"); + Ok(process_information.process) } Err(error) => { error!(%error, %session, "Failed to start {SESSION_BINARY}"); @@ -434,12 +650,14 @@ fn session_app_path() -> Utf8PathBuf { #[cfg(test)] mod tests { + use std::time::Duration; + use camino::Utf8Path; use win_api_wrappers::utils::CommandLine; use super::{ - GatewaySession, Session, SessionKind, SessionManagerCtx, SessionReadiness, SessionReadinessEvent, - session_command_line, + GatewaySession, ProcessExit, Session, SessionKind, SessionManagerCtx, SessionReadiness, SessionReadinessEvent, + relaunch_delay, session_command_line, }; fn make_session(kind: SessionKind, readiness: SessionReadiness) -> GatewaySession { @@ -473,7 +691,7 @@ mod tests { ctx.start_process_if_not_running( &session, |_| Err(anyhow::anyhow!("process lookup failed")), - |_| panic!("the process was started although the lookup failed"), + |_, _| panic!("the process was started although the lookup failed"), ); assert!(ctx.should_start_session(&session, SessionReadinessEvent::Logon)); @@ -526,6 +744,240 @@ mod tests { assert!(session.is_ready_to_start(SessionReadinessEvent::Unlock)); } + /// Registers a remote session and starts its process through the production path, returning its launch id. + fn start_ready_remote_session(ctx: &mut SessionManagerCtx, session: &Session) -> u64 { + ctx.register_session(session, SessionKind::Remote, SessionReadiness::WaitingForLogon); + start_again(ctx, session) + } + + /// Starts the process of an already registered session as a relaunch would, returning its launch id. + fn start_again(ctx: &mut SessionManagerCtx, session: &Session) -> u64 { + let mut launched = None; + ctx.start_process_if_not_running( + session, + |_| Ok(false), + |_, launch_id| { + launched = Some(launch_id); + Ok(()) + }, + ); + launched.expect("the process was not started") + } + + fn failed_exit(session: &Session, launch_id: u64, run_time: Duration) -> ProcessExit { + ProcessExit { + session_id: session.id, + launch_id, + exit_code: 0xC000_0005, + run_time, + } + } + + const QUICK_RUN: Duration = Duration::from_secs(1); + + /// A process that crashes while its session still wants it must come back, or the channel it hosts stays unserved. + // oracle: scaffold + #[test] + fn failed_exit_of_ready_remote_session_schedules_relaunch_after_the_floor_delay() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + + let delay = ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + + assert_eq!(delay, Some(Duration::from_secs(2))); + assert!(ctx.should_relaunch(session.id, launch_id)); + } + + /// Back-off keeps a process that fails on start from being relaunched in a tight loop. + // oracle: scaffold + #[test] + fn relaunch_delay_doubles_per_consecutive_failure_and_is_capped() { + assert_eq!(relaunch_delay(1), Duration::from_secs(2)); + assert_eq!(relaunch_delay(2), Duration::from_secs(4)); + assert_eq!(relaunch_delay(3), Duration::from_secs(8)); + assert_eq!(relaunch_delay(6), Duration::from_secs(60)); + assert_eq!(relaunch_delay(u32::MAX), Duration::from_secs(60)); + } + + /// Consecutive quick failures of relaunched processes grow the delay. + // oracle: scaffold + #[test] + fn second_quick_failure_doubles_the_delay() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + let launch_id = start_again(&mut ctx, &session); + + let delay = ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + + assert_eq!(delay, Some(Duration::from_secs(4))); + } + + /// A process that ran for a while before failing is not failing on start, so it is relaunched promptly. + // oracle: scaffold + #[test] + fn long_run_before_failure_resets_the_delay() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + let launch_id = start_again(&mut ctx, &session); + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + let launch_id = start_again(&mut ctx, &session); + + let delay = ctx.handle_process_exit(&failed_exit(&session, launch_id, Duration::from_secs(60))); + + assert_eq!(delay, Some(Duration::from_secs(2))); + } + + /// A process that keeps failing on start is given up on, and the next logon or unlock tries again. + // oracle: scaffold + #[test] + fn repeated_quick_failures_give_up_until_the_next_logon_or_unlock() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let mut launch_id = start_ready_remote_session(&mut ctx, &session); + for _ in 0..4 { + assert!( + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)) + .is_some() + ); + launch_id = start_again(&mut ctx, &session); + } + + let delay = ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + + assert_eq!(delay, None); + assert!(ctx.should_start_session(&session, SessionReadinessEvent::Logon)); + assert!(ctx.should_start_session(&session, SessionReadinessEvent::Unlock)); + } + + /// Exit code 0 means the process ended on purpose, such as when the client has no listener for the channel. + // oracle: scaffold + #[test] + fn clean_exit_is_not_relaunched() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + let exit = ProcessExit { + exit_code: 0, + ..failed_exit(&session, launch_id, QUICK_RUN) + }; + + assert_eq!(ctx.handle_process_exit(&exit), None); + assert!(!ctx.should_start_session(&session, SessionReadinessEvent::Logon)); + } + + /// The exit of a process replaced by a later launch says nothing about the current one. + // oracle: scaffold + #[test] + fn exit_of_a_replaced_launch_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let old_launch_id = start_ready_remote_session(&mut ctx, &session); + start_again(&mut ctx, &session); + + assert_eq!( + ctx.handle_process_exit(&failed_exit(&session, old_launch_id, QUICK_RUN)), + None + ); + } + + /// A reconnected session terminates the old process, whose exit must not start a second one. + // oracle: scaffold + #[test] + fn exit_after_remote_reconnect_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.register_session(&session, SessionKind::Remote, SessionReadiness::WaitingForUnlock); + + assert_eq!( + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)), + None + ); + } + + /// A disconnected session terminates its process and wants none. + // oracle: scaffold + #[test] + fn exit_after_disconnect_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.unregister_session(&session); + + assert_eq!( + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)), + None + ); + } + + /// The system stops the process at logoff, and the next logon starts it. + // oracle: scaffold + #[test] + fn exit_after_logoff_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.get_session_mut(&session) + .expect("the session is registered") + .set_waiting_for_logon(); + + assert_eq!( + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)), + None + ); + } + + /// A console session never hosts the process, so a stray report for one must not start it. + // oracle: scaffold + #[test] + fn exit_in_console_session_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.register_session(&session, SessionKind::Console, SessionReadiness::Ready); + ctx.get_session_mut(&session) + .expect("the session is registered") + .launch_id = Some(launch_id); + + assert_eq!( + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)), + None + ); + } + + /// A session that logged off during the delay must not have the process started when the delay ends. + // oracle: scaffold + #[test] + fn relaunch_due_after_logoff_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + ctx.get_session_mut(&session) + .expect("the session is registered") + .set_waiting_for_logon(); + + assert!(!ctx.should_relaunch(session.id, launch_id)); + } + + /// A relaunch scheduled for a launch that was since replaced must not start another process. + // oracle: scaffold + #[test] + fn relaunch_due_for_a_replaced_launch_is_ignored() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + let launch_id = start_ready_remote_session(&mut ctx, &session); + ctx.handle_process_exit(&failed_exit(&session, launch_id, QUICK_RUN)); + start_again(&mut ctx, &session); + + assert!(!ctx.should_relaunch(session.id, launch_id)); + } + #[test] fn ready_remote_session_is_not_started_twice() { let session = make_session(SessionKind::Remote, SessionReadiness::Ready); From 2c7573efba01a76d08beb83bfbc12d184c796e75 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:59:35 -0400 Subject: [PATCH 08/19] fix(agent): start NOW hosts in active RDP sessions Discover active RDP sessions when the service starts and adopt an existing NOW host or launch a watched host without another logon. Recheck current session state when replaying remote-connect events, while retaining queued notifications during discovery. Wait for the previous host to exit before reconciling a reconnect. Keep incomplete termination retryable on later readiness events, and retry transient lookup or process-creation errors during recovery with bounded backoff instead of stranding a ready session. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- crates/win-api-wrappers/src/process.rs | 55 ++- crates/win-api-wrappers/src/wts.rs | 31 ++ devolutions-agent/src/session_manager.rs | 540 +++++++++++++++++++++-- 3 files changed, 581 insertions(+), 45 deletions(-) diff --git a/crates/win-api-wrappers/src/process.rs b/crates/win-api-wrappers/src/process.rs index 6bad228d1f..cc00e0b032 100644 --- a/crates/win-api-wrappers/src/process.rs +++ b/crates/win-api-wrappers/src/process.rs @@ -12,7 +12,7 @@ use anyhow::{Context, Result, bail}; use tracing::{error, warn}; use windows::Win32::Foundation::{ E_INVALIDARG, ERROR_INCORRECT_SIZE, ERROR_NO_MORE_FILES, FILETIME, FreeLibrary, HANDLE, HMODULE, HWND, LPARAM, - MAX_PATH, WAIT_EVENT, WAIT_FAILED, WPARAM, + MAX_PATH, WAIT_EVENT, WAIT_FAILED, WAIT_OBJECT_0, WPARAM, }; use windows::Win32::Security::{TOKEN_ACCESS_MASK, TOKEN_ADJUST_PRIVILEGES, TOKEN_QUERY}; use windows::Win32::System::Com::{COINIT_APARTMENTTHREADED, COINIT_DISABLE_OLE1DDE}; @@ -31,8 +31,8 @@ use windows::Win32::System::Threading::{ CREATE_UNICODE_ENVIRONMENT, CreateProcessAsUserW, CreateRemoteThread, EXTENDED_STARTUPINFO_PRESENT, GetCurrentProcess, GetCurrentProcessId, GetExitCodeProcess, GetProcessTimes, INFINITE, LPPROC_THREAD_ATTRIBUTE_LIST, LPTHREAD_START_ROUTINE, OpenProcess, OpenProcessToken, PEB, PROCESS_ACCESS_RIGHTS, - PROCESS_BASIC_INFORMATION, PROCESS_CREATION_FLAGS, PROCESS_INFORMATION, PROCESS_NAME_WIN32, PROCESS_TERMINATE, - QueryFullProcessImageNameW, STARTUPINFOEXW, STARTUPINFOW, STARTUPINFOW_FLAGS, TerminateProcess, + PROCESS_BASIC_INFORMATION, PROCESS_CREATION_FLAGS, PROCESS_INFORMATION, PROCESS_NAME_WIN32, PROCESS_SYNCHRONIZE, + PROCESS_TERMINATE, QueryFullProcessImageNameW, STARTUPINFOEXW, STARTUPINFOW, STARTUPINFOW_FLAGS, TerminateProcess, WaitForSingleObject, }; use windows::Win32::UI::Shell::{SEE_MASK_NOCLOSEPROCESS, SHELLEXECUTEINFOW, ShellExecuteExW}; @@ -961,14 +961,27 @@ fn is_process_running_impl(process_name: &str, session_id: Option) -> Resul } pub fn terminate_process_by_name(process_name: &str) -> Result { - terminate_process_by_name_impl(process_name, None) + terminate_process_by_name_impl(process_name, None, None) } pub fn terminate_process_by_name_in_session(process_name: &str, session_id: u32) -> Result { - terminate_process_by_name_impl(process_name, Some(session_id)) + terminate_process_by_name_impl(process_name, Some(session_id), None) } -fn terminate_process_by_name_impl(process_name: &str, session_id: Option) -> Result { +/// Terminates a process in the session and waits for its exit before returning success. +pub fn terminate_process_by_name_in_session_and_wait( + process_name: &str, + session_id: u32, + timeout_ms: u32, +) -> Result { + terminate_process_by_name_impl(process_name, Some(session_id), Some(timeout_ms)) +} + +fn terminate_process_by_name_impl( + process_name: &str, + session_id: Option, + timeout_ms: Option, +) -> Result { for process in ProcessEntry32Iterator::new()? { if let Some(session_id) = session_id { let actual_session = match process_id_to_session(process.process_id()) { @@ -984,22 +997,46 @@ fn terminate_process_by_name_impl(process_name: &str, session_id: Option) - } if str::eq_ignore_ascii_case(process.executable_name()?.as_str(), process_name) { - // SAFETY: `OpenProcess` is always safe to call and returns a valid handle on success. - let process = unsafe { OpenProcess(PROCESS_TERMINATE, false, process.process_id()) }; + let rights = if timeout_ms.is_some() { + PROCESS_TERMINATE | PROCESS_SYNCHRONIZE + } else { + PROCESS_TERMINATE + }; + // SAFETY: OpenProcess has no outstanding preconditions and returns an owned handle on success. + let process = unsafe { OpenProcess(rights, false, process.process_id()) }; match process { Ok(process) => { + // SAFETY: OpenProcess returned a valid handle owned by the caller. + let process = unsafe { Handle::new_owned(process) }?; // SAFETY: `OpenProcess` ensures that the handle is valid. unsafe { - if let Err(error) = TerminateProcess(process, 1) { + if let Err(error) = TerminateProcess(process.raw(), 1) { + if timeout_ms.is_some() { + return Err(error.into()); + } warn!(process_name, session_id, %error, "TerminateProcess failed"); return Ok(false); } } + if let Some(timeout_ms) = timeout_ms { + // SAFETY: The handle is valid and was opened with SYNCHRONIZE. + let wait = unsafe { WaitForSingleObject(process.raw(), timeout_ms) }; + if wait == WAIT_FAILED { + return Err(Error::last_error().into()); + } + if wait != WAIT_OBJECT_0 { + bail!("process termination did not complete within {timeout_ms} ms"); + } + } + return Ok(true); } Err(error) => { + if timeout_ms.is_some() { + return Err(error.into()); + } warn!(process_name, session_id, %error, "OpenProcess failed"); continue; } diff --git a/crates/win-api-wrappers/src/wts.rs b/crates/win-api-wrappers/src/wts.rs index e509018456..acc2b969c1 100644 --- a/crates/win-api-wrappers/src/wts.rs +++ b/crates/win-api-wrappers/src/wts.rs @@ -196,6 +196,37 @@ pub fn get_session_domain_name(session_id: u32) -> anyhow::Result { query_session_information_string(session_id, RemoteDesktop::WTSDomainName) } +/// Checks for RDP protocol type 2, as defined by [`WTS_INFO_CLASS` "Constants"][protocol]. +/// +/// [protocol]: https://learn.microsoft.com/en-us/windows/win32/api/wtsapi32/ne-wtsapi32-wts_info_class#constants +pub fn session_uses_rdp(session_id: u32) -> anyhow::Result { + let mut buffer = windows::core::PWSTR::null(); + let mut len = 0; + + // SAFETY: Both output pointers are valid for the duration of the call. + unsafe { + WTSQuerySessionInformationW( + Some(WTS_CURRENT_SERVER_HANDLE), + session_id, + RemoteDesktop::WTSClientProtocolType, + &mut buffer, + &mut len, + )?; + } + + // SAFETY: A successful query returns memory allocated by WTS, released by WtsMemory. + let buffer = unsafe { WtsMemory::from_raw(buffer.as_ptr()) }; + if buffer.as_ptr().is_null() || len != 2 + /* ClientProtocolType */ + { + anyhow::bail!("WTSClientProtocolType returned an invalid buffer"); + } + + // SAFETY: WTSClientProtocolType returns one aligned USHORT, and its length was checked above. + let protocol = unsafe { *buffer.as_ptr() }; + Ok(protocol == 2) +} + pub fn send_message_to_session( session_id: u32, title: &str, diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index 97b1e48ba3..8ed9417d83 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -11,10 +11,10 @@ use devolutions_gateway_task::{ShutdownSignal, Task}; use tokio::sync::{RwLock, mpsc}; use win_api_wrappers::process::{ Process, StartupInfo, create_process_in_session, is_process_running_in_session, - terminate_process_by_name_in_session, + terminate_process_by_name_in_session_and_wait, }; use win_api_wrappers::utils::{CommandLine, WideString}; -use win_api_wrappers::wts::session_has_logged_in_user; +use win_api_wrappers::wts::{WTSConnectState, get_sessions, session_has_logged_in_user, session_uses_rdp}; use windows::Win32::System::Threading::{ CREATE_NEW_CONSOLE, CREATE_UNICODE_ENVIRONMENT, NORMAL_PRIORITY_CLASS, STARTF_USESHOWWINDOW, }; @@ -79,6 +79,8 @@ struct GatewaySession { launch_id: Option, /// Number of consecutive quick failures of the session process. consecutive_failures: u32, + /// A reconnect must finish terminating its old host before lookup can adopt another one. + termination_pending: bool, } // NOTE: `ceviche::controller::Session` do not implement `Debug` for session. @@ -102,6 +104,7 @@ impl GatewaySession { readiness, launch_id: None, consecutive_failures: 0, + termination_pending: false, } } @@ -214,18 +217,18 @@ impl SessionManagerCtx { session: &Session, is_running: impl FnOnce(&Session) -> anyhow::Result, start: impl FnOnce(&Session, u64) -> anyhow::Result<()>, - ) { + ) -> bool { let launch_id = self.last_launch_id + 1; let Some(gw_session) = self.get_session_mut(session) else { warn!(%session, "Session is not yet registered"); - return; + return false; }; match is_running(session) { Ok(true) => { gw_session.set_session_ready(); - return; + return true; } Ok(false) => {} Err(error) => { @@ -235,7 +238,7 @@ impl SessionManagerCtx { %session, "Failed to check whether the session process is running" ); - return; + return false; } } @@ -247,9 +250,11 @@ impl SessionManagerCtx { gw_session.set_session_ready(); gw_session.launch_id = Some(launch_id); self.last_launch_id = launch_id; + true } Err(error) => { error!(%error, %session, "Failed to start session process"); + false } } } @@ -284,15 +289,29 @@ impl SessionManagerCtx { if STABLE_RUN_TIME <= run_time { gw_session.consecutive_failures = 0; } + warn!( + session = session_id, + launch_id, + exit_code = format!("{exit_code:#010X}"), + ?run_time, + "Session process failed" + ); + + self.retry_failed_launch(session_id, launch_id) + } + + fn retry_failed_launch(&mut self, session_id: u32, launch_id: u64) -> Option { + let gw_session = self + .get_session_mut(&Session::new(session_id)) + .filter(|gw_session| gw_session.wants_launch(launch_id))?; gw_session.consecutive_failures += 1; if MAX_CONSECUTIVE_FAILURES <= gw_session.consecutive_failures { error!( session = session_id, launch_id, - exit_code = format!("{exit_code:#010X}"), consecutive_failures = gw_session.consecutive_failures, - "Session process keeps failing; waiting for the next logon or unlock" + "Session process recovery keeps failing; waiting for the next logon or unlock" ); gw_session.readiness = SessionReadiness::WaitingForLogonOrUnlock; gw_session.consecutive_failures = 0; @@ -303,10 +322,8 @@ impl SessionManagerCtx { warn!( session = session_id, launch_id, - exit_code = format!("{exit_code:#010X}"), - ?run_time, ?delay, - "Session process failed; relaunching" + "Scheduling session process recovery" ); Some(delay) @@ -350,7 +367,75 @@ impl Task for SessionManager { const NAME: &'static str = "SessionManager"; - async fn run(self, mut shutdown_signal: ShutdownSignal) -> anyhow::Result<()> { + async fn run(self, shutdown_signal: ShutdownSignal) -> anyhow::Result<()> { + self.run_with(shutdown_signal, &WindowsSessionSystem).await + } +} + +trait SessionSystem: Sync { + fn active_remote_sessions(&self) -> anyhow::Result>; + fn has_logged_in_user(&self, session: &Session) -> anyhow::Result; + fn is_running(&self, session: &Session) -> anyhow::Result; + fn start_watched( + &self, + session: &Session, + launch_id: u64, + internal_tx: &mpsc::UnboundedSender, + ) -> anyhow::Result<()>; + fn terminate(&self, session: &Session) -> anyhow::Result<()>; +} + +struct WindowsSessionSystem; + +impl SessionSystem for WindowsSessionSystem { + fn active_remote_sessions(&self) -> anyhow::Result> { + let mut active_sessions = Vec::new(); + for session in get_sessions()? { + if session.state != WTSConnectState::Active { + continue; + } + + match session_uses_rdp(session.session_id) { + Ok(true) => active_sessions.push(Session::new(session.session_id)), + Ok(false) => {} + Err(error) => { + warn!( + session_id = session.session_id, + %error, + "Failed to query the protocol of an existing session" + ); + } + } + } + Ok(active_sessions) + } + + fn has_logged_in_user(&self, session: &Session) -> anyhow::Result { + session_has_logged_in_user(session.id) + } + + fn is_running(&self, session: &Session) -> anyhow::Result { + is_session_running_in_session(session) + } + + fn start_watched( + &self, + session: &Session, + launch_id: u64, + internal_tx: &mpsc::UnboundedSender, + ) -> anyhow::Result<()> { + let process = start_session_process(session)?; + watch_session_process(process, session.id, launch_id, internal_tx.clone()); + Ok(()) + } + + fn terminate(&self, session: &Session) -> anyhow::Result<()> { + terminate_session_process(session) + } +} + +impl SessionManager { + async fn run_with(self, mut shutdown_signal: ShutdownSignal, system: &dyn SessionSystem) -> anyhow::Result<()> { let Self { mut service_event_rx, ctx, @@ -362,6 +447,22 @@ impl Task for SessionManager { // The loop keeps a sender, so the receiver never reports a closed channel. let (internal_tx, mut internal_rx) = mpsc::unbounded_channel(); + // Keep queued SCM events so disconnects during enumeration still stop their hosts. + // UNTESTED: SCM delivers session changes while WTS enumeration runs. + // When changing service startup, verify this ordering in a live RDP session. + match system.active_remote_sessions() { + Ok(sessions) => { + let mut ctx = ctx.write().await; + for session in sessions { + ctx.register_session(&session, SessionKind::Remote, SessionReadiness::WaitingForLogonOrUnlock); + start_session_process_if_not_running(&mut ctx, system, &session, &internal_tx); + } + } + Err(error) => { + error!(%error, "Failed to enumerate existing remote sessions"); + } + } + loop { tokio::select! { Some(event) = internal_rx.recv() => { @@ -375,7 +476,11 @@ impl Task for SessionManager { InternalEvent::RelaunchDue { session_id, launch_id } => { if ctx.should_relaunch(session_id, launch_id) { info!(session = session_id, "Relaunching session process"); - start_session_process_if_not_running(&mut ctx, &Session::new(session_id), &internal_tx); + if !start_session_process_if_not_running(&mut ctx, system, &Session::new(session_id), &internal_tx) + && let Some(delay) = ctx.retry_failed_launch(session_id, launch_id) + { + schedule_relaunch(&internal_tx, session_id, launch_id, delay); + } } } } @@ -404,15 +509,14 @@ impl Task for SessionManager { } AgentServiceEvent::SessionDisconnect(id) => { info!(%id, "Session disconnected"); - terminate_session_process(&id); + if let Err(error) = system.terminate(&id) { + error!(%id, %error, "Failed to terminate disconnected session process"); + } ctx.write().await.unregister_session(&id); } AgentServiceEvent::SessionRemoteConnect(id) => { info!(%id, "Remote session connected"); - // Terminate old session process if it is already running. - terminate_session_process(&id); - - let readiness = match session_has_logged_in_user(id.id) { + let readiness = match system.has_logged_in_user(&id) { Ok(true) => SessionReadiness::WaitingForUnlock, Ok(false) => SessionReadiness::WaitingForLogon, Err(error) => { @@ -428,6 +532,22 @@ impl Task for SessionManager { { let mut ctx = ctx.write().await; ctx.register_session(&id, SessionKind::Remote, readiness); + ctx.get_session_mut(&id).expect("session was just registered").termination_pending = true; + + if !finish_session_termination(&mut ctx, system, &id) { + continue; + } + + // A queued connect may predate the startup snapshot and its user's logon. + match system.active_remote_sessions() { + Ok(sessions) if sessions.iter().any(|session| session.id == id.id) => { + start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); + } + Ok(_) => {} + Err(error) => { + error!(%id, %error, "Failed to check whether the remote session is active"); + } + } } } AgentServiceEvent::SessionRemoteDisconnect(id) => { @@ -435,7 +555,9 @@ impl Task for SessionManager { // Terminate session process when remote session is disconnected // (NOTE: depending on the system settings, session could // still be running in the background after RDP disconnect). - terminate_session_process(&id); + if let Err(error) = system.terminate(&id) { + error!(%id, %error, "Failed to terminate disconnected session process"); + } ctx.write().await.unregister_session(&id); } AgentServiceEvent::SessionLogon(id) => { @@ -446,7 +568,7 @@ impl Task for SessionManager { // session app on logon, if not yet started. let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Logon) { - start_session_process_if_not_running(&mut ctx, &id, &internal_tx); + start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); } } AgentServiceEvent::SessionUnlock(id) => { @@ -454,7 +576,7 @@ impl Task for SessionManager { let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Unlock) { - start_session_process_if_not_running(&mut ctx, &id, &internal_tx); + start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); } } AgentServiceEvent::SessionLogoff(id) => { @@ -490,14 +612,32 @@ impl Task for SessionManager { /// not relaunched until the next logon or unlock. fn start_session_process_if_not_running( ctx: &mut SessionManagerCtx, + system: &dyn SessionSystem, session: &Session, internal_tx: &mpsc::UnboundedSender, -) { - ctx.start_process_if_not_running(session, is_session_running_in_session, |session, launch_id| { - let process = start_session_process(session)?; - watch_session_process(process, session.id, launch_id, internal_tx.clone()); - Ok(()) - }); +) -> bool { + if !finish_session_termination(ctx, system, session) { + return false; + } + ctx.start_process_if_not_running( + session, + |session| system.is_running(session), + |session, launch_id| system.start_watched(session, launch_id, internal_tx), + ) +} + +fn finish_session_termination(ctx: &mut SessionManagerCtx, system: &dyn SessionSystem, session: &Session) -> bool { + let Some(gw_session) = ctx.get_session_mut(session) else { + return false; + }; + if gw_session.termination_pending { + if let Err(error) = system.terminate(session) { + error!(%session, %error, "Failed to finish terminating the previous session process"); + return false; + } + gw_session.termination_pending = false; + } + true } /// Reports the exit of `process` to the session manager from a dedicated thread. @@ -561,18 +701,16 @@ fn schedule_relaunch( } /// Terminates Devolutions Session process in the target session. -fn terminate_session_process(session: &Session) { - match terminate_process_by_name_in_session(SESSION_BINARY, session.id) { - Ok(false) => { +fn terminate_session_process(session: &Session) -> anyhow::Result<()> { + match terminate_process_by_name_in_session_and_wait(SESSION_BINARY, session.id, 1_000)? { + false => { trace!(%session, "Session process is not running"); } - Ok(true) => { + true => { info!(%session, "Session process terminated"); } - Err(error) => { - error!(%error, %session, "Failed to terminate session process"); - } } + Ok(()) } fn is_session_running_in_session(session: &Session) -> anyhow::Result { @@ -650,16 +788,346 @@ fn session_app_path() -> Utf8PathBuf { #[cfg(test)] mod tests { + use std::collections::{BTreeSet, VecDeque}; + use std::sync::Mutex; use std::time::Duration; use camino::Utf8Path; + use devolutions_gateway_task::{ChildTask, ShutdownHandle}; + use tokio::sync::mpsc; use win_api_wrappers::utils::CommandLine; use super::{ - GatewaySession, ProcessExit, Session, SessionKind, SessionManagerCtx, SessionReadiness, SessionReadinessEvent, - relaunch_delay, session_command_line, + AgentServiceEvent, GatewaySession, InternalEvent, ProcessExit, Session, SessionKind, SessionManager, + SessionManagerCtx, SessionReadiness, SessionReadinessEvent, SessionSystem, relaunch_delay, + session_command_line, }; + #[derive(Debug, PartialEq, Eq)] + enum HostAction { + Started(u32), + Stopped(u32), + FoundRunning(u32), + } + + struct TestSessionSystem { + active_sessions: Vec, + events: mpsc::Sender, + events_during_snapshot: Mutex>, + lookup_failures: Mutex>, + termination_failures: Mutex>, + running: Mutex>, + exit_on_start: Mutex>, + actions: mpsc::UnboundedSender, + } + + impl SessionSystem for TestSessionSystem { + fn active_remote_sessions(&self) -> anyhow::Result> { + for event in std::mem::take(&mut *self.events_during_snapshot.lock().expect("snapshot events lock")) { + assert!(self.events.try_send(event).is_ok(), "session event queue has capacity"); + } + Ok(self.active_sessions.iter().copied().map(Session::new).collect()) + } + + fn has_logged_in_user(&self, _session: &Session) -> anyhow::Result { + Ok(true) + } + + fn is_running(&self, session: &Session) -> anyhow::Result { + if self + .lookup_failures + .lock() + .expect("lookup failure lock") + .pop_front() + .unwrap_or(false) + { + anyhow::bail!("process lookup failed"); + } + let running = self + .running + .lock() + .expect("running processes lock") + .contains(&session.id); + if running { + self.actions + .send(HostAction::FoundRunning(session.id)) + .expect("host observer remains open"); + } + Ok(running) + } + + fn start_watched( + &self, + session: &Session, + launch_id: u64, + internal_tx: &mpsc::UnboundedSender, + ) -> anyhow::Result<()> { + assert!( + self.running.lock().expect("running processes lock").insert(session.id), + "duplicate host launch" + ); + self.actions + .send(HostAction::Started(session.id)) + .expect("host observer remains open"); + if let Some(exit_code) = self.exit_on_start.lock().expect("process exit lock").take() { + self.running.lock().expect("running processes lock").remove(&session.id); + internal_tx + .send(InternalEvent::ProcessExited(ProcessExit { + session_id: session.id, + launch_id, + exit_code, + run_time: Duration::ZERO, + })) + .expect("session manager remains open"); + } + Ok(()) + } + + fn terminate(&self, session: &Session) -> anyhow::Result<()> { + if self + .termination_failures + .lock() + .expect("termination failure lock") + .pop_front() + .unwrap_or(false) + { + anyhow::bail!("previous process is still terminating"); + } + if self.running.lock().expect("running processes lock").remove(&session.id) { + self.actions + .send(HostAction::Stopped(session.id)) + .expect("host observer remains open"); + } + Ok(()) + } + } + + fn start_test_manager( + active_sessions: Vec, + running: BTreeSet, + events_during_snapshot: Vec, + lookup_failures: Vec, + exit_on_start: Option, + termination_failures: Vec, + ) -> ( + ShutdownHandle, + ChildTask>, + mpsc::UnboundedReceiver, + ) { + let manager = SessionManager::default(); + let (shutdown, signal) = ShutdownHandle::new(); + let (actions, observations) = mpsc::unbounded_channel(); + let system = TestSessionSystem { + active_sessions, + events: manager.service_event_tx(), + events_during_snapshot: Mutex::new(events_during_snapshot), + lookup_failures: Mutex::new(lookup_failures.into()), + termination_failures: Mutex::new(termination_failures.into()), + running: Mutex::new(running), + exit_on_start: Mutex::new(exit_on_start), + actions, + }; + let task = ChildTask::spawn(async move { manager.run_with(signal, &system).await }); + (shutdown, task, observations) + } + + async fn next_action(actions: &mut mpsc::UnboundedReceiver) -> HostAction { + tokio::time::timeout(Duration::from_secs(10), actions.recv()) + .await + .expect("session manager did not act") + .expect("session manager stopped") + } + + // oracle: reference deployed Agent 2BD6884A9E49A9D6FE80F6036907C48BECF180C0DBDD7AD93C3C7B80D571FA45 + // launches a missing host in an already-active RDP session without new logon or unlock events. + #[tokio::test] + async fn already_active_remote_session_launches_without_new_events() { + let (shutdown, task, mut actions) = start_test_manager(vec![42], BTreeSet::new(), vec![], vec![], None, vec![]); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant replayed connection events leave an active session waiting for an already-past logon. + #[tokio::test] + async fn reconnect_during_snapshot_restores_an_already_active_host() { + let (shutdown, task, mut actions) = start_test_manager( + vec![42], + BTreeSet::new(), + vec![ + AgentServiceEvent::SessionRemoteDisconnect(Session::new(42)), + AgentServiceEvent::SessionRemoteConnect(Session::new(42)), + ], + vec![], + None, + vec![], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Stopped(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: reference deployed Agent 2BD6884A9E49A9D6FE80F6036907C48BECF180C0DBDD7AD93C3C7B80D571FA45 + // adopts an existing host on restart without replacing it. + #[tokio::test] + async fn already_running_startup_host_is_adopted() { + let (shutdown, task, mut actions) = + start_test_manager(vec![42], BTreeSet::from([42]), vec![], vec![], None, vec![]); + + assert_eq!(next_action(&mut actions).await, HostAction::FoundRunning(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + assert!( + actions.try_recv().is_err(), + "startup must neither stop nor duplicate the host" + ); + } + + // oracle: mutant discarding notifications during the initial snapshot leaves a disconnected host running. + #[tokio::test] + async fn disconnect_during_snapshot_stops_the_host() { + let (shutdown, task, mut actions) = start_test_manager( + vec![42], + BTreeSet::new(), + vec![AgentServiceEvent::SessionRemoteDisconnect(Session::new(42))], + vec![], + None, + vec![], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Stopped(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant a session absent from the snapshot loses its queued connection or logon event. + #[tokio::test] + async fn connection_during_snapshot_launches_after_logon() { + let (shutdown, task, mut actions) = start_test_manager( + vec![], + BTreeSet::new(), + vec![ + AgentServiceEvent::SessionRemoteConnect(Session::new(42)), + AgentServiceEvent::SessionLogon(Session::new(42)), + ], + vec![], + None, + vec![], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant a transient lookup error kills the manager instead of allowing a readiness retry. + #[tokio::test] + async fn process_lookup_failure_does_not_stop_later_readiness_events() { + let (shutdown, task, mut actions) = start_test_manager( + vec![], + BTreeSet::new(), + vec![ + AgentServiceEvent::SessionRemoteConnect(Session::new(42)), + AgentServiceEvent::SessionLogon(Session::new(42)), + AgentServiceEvent::SessionUnlock(Session::new(42)), + ], + vec![true], + None, + vec![], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant startup launches bypass the process-exit notification and relaunch path. + #[tokio::test] + async fn failed_startup_host_is_relaunched_through_the_watched_path() { + let (shutdown, task, mut actions) = + start_test_manager(vec![42], BTreeSet::new(), vec![], vec![], Some(1), vec![]); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant a transient lookup failure during relaunch leaves the session Ready without another retry. + #[tokio::test] + async fn relaunch_lookup_failure_is_retried_without_another_service_event() { + let (shutdown, task, mut actions) = + start_test_manager(vec![42], BTreeSet::new(), vec![], vec![false, true], Some(1), vec![]); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + // oracle: mutant reconnect adopts the old host before its asynchronous termination completes. + #[tokio::test] + async fn reconnect_does_not_adopt_a_host_still_terminating() { + let (shutdown, task, mut actions) = start_test_manager( + vec![42], + BTreeSet::from([42]), + vec![ + AgentServiceEvent::SessionRemoteConnect(Session::new(42)), + AgentServiceEvent::SessionUnlock(Session::new(42)), + ], + vec![], + None, + vec![true], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::FoundRunning(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Stopped(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + fn make_session(kind: SessionKind, readiness: SessionReadiness) -> GatewaySession { GatewaySession::new(Session::new(1), kind, readiness) } From 7c94a23607d27e465a57054af75d4c3ef38ffaad Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 08:59:35 -0400 Subject: [PATCH 09/19] fix(agent): observe NOW loss while stdin is blocked A full child stdin queue must not stop transport-loss detection. Race message processing against an independent IO-loop notification so a blocked stdin send cannot prevent channel recovery. Publish that notification before waiting for pending IO cancellation. This starts the teardown deadline even if cancellation stalls, while keeping the buffers owned by the IO thread until completion. Preserve an already-completed normal protocol close as a successful host exit. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 7 +++- devolutions-session/src/dvc/task.rs | 61 +++++++++++++++++++++++++++-- 2 files changed, 64 insertions(+), 4 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index f63b167367..a4db8d0322 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -158,13 +158,18 @@ pub fn run_dvc_io( read_tx: Sender>, stop_event: Event, progress: &DvcInitializationProgress, + io_loop_ended_tx: tokio::sync::oneshot::Sender<()>, ) -> Result<(), anyhow::Error> { let Some(mut context) = initialize_dvc_with_retry(&stop_event, progress)? else { info!("DVC IO thread stopped during initialization"); return Ok(()); }; - context.io.serve(write_rx, &read_tx, &stop_event) + let result = context.io.serve(write_rx, &read_tx, &stop_event); + + // Notify processing before cancellation cleanup, which can block until pending IO completes. + let _ = io_loop_ended_tx.send(()); + result } /// Interval at which decoded messages are offered again to a full processing queue. diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 5d3dbcf5b4..eb4628b4ec 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -184,6 +184,7 @@ async fn serve_channel(mut shutdown_signal: ShutdownSignal) -> anyhow::Result anyhow::Result anyhow::Result anyhow::Result>, + io_loop_ended: tokio::sync::oneshot::Receiver<()>, +) -> anyhow::Result<()> { + select! { + biased; + result = processing => result, + _ = io_loop_ended => bail!("DVC IO loop ended"), + } +} + async fn process_messages( mut read_rx: Receiver, dvc_tx: WinapiSignaledSender, @@ -1510,11 +1532,44 @@ mod tests { use super::{ ChannelOutcome, DEFAULT_HEARTBEAT_INTERVAL, MAX_CONSECUTIVE_FAILED_REOPENS, REOPEN_DELAY_CAP, - REOPEN_DELAY_FLOOR, heartbeat_timer, process_messages, serve_dvc, spawn_heartbeat, + REOPEN_DELAY_FLOOR, heartbeat_timer, process_messages, process_until_io_ends, serve_dvc, spawn_heartbeat, }; use crate::dvc::channel::{bounded_mpsc_channel, winapi_signaled_mpsc_channel}; use crate::dvc::io::DvcInitializationProgress; + // oracle: mutant a full stdin queue prevents a closed DVC from interrupting the processing loop. + #[tokio::test] + async fn io_loss_interrupts_processing_while_stdin_is_backpressured() { + let (stdin_tx, _stdin_rx) = tokio::sync::mpsc::channel(1); + stdin_tx.send(()).await.expect("fill stdin queue"); + let processing = async move { + stdin_tx.send(()).await.expect("stdin queue remains open"); + Ok(()) + }; + let (io_loop_ended_tx, io_loop_ended_rx) = tokio::sync::oneshot::channel(); + io_loop_ended_tx.send(()).expect("publish IO loop exit"); + + let result = tokio::time::timeout( + Duration::from_secs(1), + process_until_io_ends(processing, io_loop_ended_rx), + ) + .await + .expect("IO loss interrupts the blocked stdin send"); + + assert!(result.is_err(), "transport loss must enter channel recovery"); + } + + // oracle: mutant IO teardown changes an already-completed normal protocol close into a transport failure. + #[tokio::test] + async fn completed_protocol_close_stays_normal_when_io_also_ends() { + let (io_loop_ended_tx, io_loop_ended_rx) = tokio::sync::oneshot::channel(); + io_loop_ended_tx.send(()).expect("publish IO loop exit"); + + process_until_io_ends(async { Ok(()) }, io_loop_ended_rx) + .await + .expect("normal protocol close remains normal"); + } + /// A negotiated channel whose IO ends, as when the client tears the DVC down while the RDP connection stays up, /// must be told apart from one that never negotiated, because only the former is reopened. // oracle: scaffold From aea17aa294951f6f15f612488f5d032454645bbb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 09:48:09 -0400 Subject: [PATCH 10/19] fix(agent): detect NOW loss while inbound is held back While the processing queue is full, the IO loop issues no read, so a client that disconnects during stdin backpressure went unnoticed until the next heartbeat write, or forever when heartbeats are disabled, and the channel was never reopened. While messages are held back, write a heartbeat whenever no write has started for a second. A closed channel fails that write, which ends the IO loop and reopens the channel. No inbound message is discarded. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 67 +++++++++++++++++++++++++++++-- 1 file changed, 63 insertions(+), 4 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index a4db8d0322..fc8e873c2c 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -3,7 +3,7 @@ use std::sync::atomic::{AtomicBool, AtomicU32, Ordering}; use std::time::{Duration, Instant}; use anyhow::Context; -use now_proto_pdu::NowMessage; +use now_proto_pdu::{NowChannelHeartbeatMsg, NowMessage}; use tokio::sync::Notify; use tokio::sync::mpsc::Sender; use tokio::sync::mpsc::error::TrySendError; @@ -175,6 +175,13 @@ pub fn run_dvc_io( /// Interval at which decoded messages are offered again to a full processing queue. const INBOUND_RETRY_INTERVAL_MS: u32 = 10; +/// Longest time without a write while decoded messages are held back. +/// +/// No read is pending while messages are held back, so only a write can observe a closed channel. +/// Without this probe, a client lost during stdin backpressure goes unnoticed until the next heartbeat, or forever +/// when heartbeats are disabled, and the channel is never reopened. +const BACKLOG_PROBE_INTERVAL: Duration = Duration::from_secs(1); + /// Overlapped IO state of one open DVC channel. /// /// Reads and writes are both overlapped, so that a client slow to read never stops the loop from reading, and the @@ -197,6 +204,7 @@ struct DvcIo { write_overlapped: OVERLAPPED, write_event: Event, write_pending: bool, + last_write_started: Instant, } #[derive(Clone, Copy)] @@ -232,6 +240,7 @@ impl DvcIo { }, write_event, write_pending: false, + last_write_started: Instant::now(), })) } @@ -244,8 +253,16 @@ impl DvcIo { loop { self.forward_inbound(read_tx)?; - if self.inbound.is_empty() && !self.read_pending { - self.start_read()?; + if self.inbound.is_empty() { + if !self.read_pending { + self.start_read()?; + } + } else if !self.write_pending && self.last_write_started.elapsed() >= BACKLOG_PROBE_INTERVAL { + // NOW clients already accept unsolicited heartbeats, which are sent even when none was negotiated. + // Messages are only held back after negotiation, once stdin backpressure stops the processing task. + trace!("Probing the DVC channel while inbound messages are held back"); + self.start_write(&NowChannelHeartbeatMsg::default().into()) + .context("probing the DVC channel while inbound messages are held back")?; } // The stop event comes first so that it wins over a busy channel. @@ -388,6 +405,7 @@ impl DvcIo { Some(&mut self.write_overlapped), ) }; + self.last_write_started = Instant::now(); ensure_overlapped_io_result(result)?; self.write_pending = true; @@ -608,7 +626,7 @@ mod tests { use std::time::Instant; use now_proto_pdu::ironrdp_core::encode_vec; - use now_proto_pdu::{NowExecDataMsg, NowExecDataStreamKind}; + use now_proto_pdu::{NowChannelHeartbeatMsg, NowExecDataMsg, NowExecDataStreamKind}; use win_api_wrappers::event::Event; use windows::Win32::Foundation::{ERROR_MORE_DATA, GENERIC_READ, GENERIC_WRITE, HANDLE}; use windows::Win32::Storage::FileSystem::{ @@ -871,6 +889,47 @@ mod tests { running.stop().expect("the loop stops cleanly"); } + /// A client that goes away while the processing queue is full must still end the loop, so the channel is reopened. + /// + /// No read is pending while messages are held back, so only a write can observe the closed channel. + // oracle: mutant + #[test] + fn closed_channel_ends_the_loop_while_messages_are_held_back() { + let (server, client) = dvc_pipe(); + let running = run_dvc_io_on(server, 1); + + for session_id in 1..=3 { + write_pdu(&client, &encoded(&exec_data(session_id, vec![0; 16]))); + } + + std::thread::sleep(Duration::from_millis(200)); + drop(client); + + running.join().expect_err("a closed channel ends the loop"); + } + + /// Probing a held-back channel must not disturb it: the client gets heartbeats, and every message still arrives. + // oracle: mutant + #[test] + fn held_back_channel_is_probed_with_heartbeats() { + let (server, client) = dvc_pipe(); + let mut running = run_dvc_io_on(server, 1); + let messages: Vec<_> = (1..=3).map(|session_id| exec_data(session_id, vec![0; 16])).collect(); + + for message in &messages { + write_pdu(&client, &encoded(message)); + } + + let heartbeat = encoded(&NowChannelHeartbeatMsg::default().into()); + assert_eq!(read_exact(&client, heartbeat.len()), heartbeat); + + for message in &messages { + assert_eq!(encoded(&running.recv()), encoded(message)); + } + + running.stop().expect("the loop stops cleanly"); + } + /// Stopping with a read and a write in flight must cancel both and return. // oracle: scaffold #[test] From 4b9122d7431f1421d2c8158e8cb067b247bada34 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 09:55:57 -0400 Subject: [PATCH 11/19] test(agent): fail instead of hang without the NOW probe Wait for client-visible bytes with a deadline before reading the probe heartbeat, so a missing probe fails the test rather than blocking the test run on a synchronous pipe read. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 33 +++++++++++++++++++------------ 1 file changed, 20 insertions(+), 13 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index fc8e873c2c..fbec593080 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -790,6 +790,24 @@ mod tests { bytes } + /// Waits until the client has bytes to read, so that a following [`read_exact`] cannot block forever. + fn wait_for_outbound(client: &Owned, failure: &str) { + let deadline = Instant::now() + TEST_TIMEOUT; + + loop { + let mut available = 0; + // SAFETY: The handle is valid, and only the byte count is requested. + unsafe { PeekNamedPipe(**client, None, 0, None, Some(&mut available), None) }.expect("peek the test pipe"); + + if available > 0 { + return; + } + + assert!(Instant::now() < deadline, "{failure}"); + std::thread::sleep(Duration::from_millis(5)); + } + } + fn encoded(message: &NowMessage<'_>) -> Vec { encode_vec(message).expect("encode a NOW message") } @@ -841,19 +859,7 @@ mod tests { running.write_tx.try_send(outbound).expect("queue the outbound message"); // The write is in flight once its first bytes are visible to the client. - let deadline = Instant::now() + TEST_TIMEOUT; - loop { - let mut available = 0; - // SAFETY: The handle is valid, and only the byte count is requested. - unsafe { PeekNamedPipe(*client, None, 0, None, Some(&mut available), None) }.expect("peek the test pipe"); - - if available > 0 { - break; - } - - assert!(Instant::now() < deadline, "the outbound write never started"); - std::thread::sleep(Duration::from_millis(5)); - } + wait_for_outbound(&client, "the outbound write never started"); let inbound = exec_data(2, b"stdin".to_vec()); write_pdu(&client, &encoded(&inbound)); @@ -921,6 +927,7 @@ mod tests { } let heartbeat = encoded(&NowChannelHeartbeatMsg::default().into()); + wait_for_outbound(&client, "the held-back channel was never probed"); assert_eq!(read_exact(&client, heartbeat.len()), heartbeat); for message in &messages { From b6a15ed2e8ecafb6f50f33e06f7cce0f54798338 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 10:07:07 -0400 Subject: [PATCH 12/19] fix(agent): probe NOW backlog only with heartbeats on The backlog probe sent heartbeats to every client, including one that negotiated a zero heartbeat interval. The NOW specification says zero disables periodic heartbeats and grants no permission for others. The processing task now publishes whether the negotiated capabilities enable heartbeats, and the IO thread probes a held-back channel only when they do. Clients that omit the interval keep the 60-second default and are still probed. A client that disables heartbeats and disconnects while its messages are held back is still not noticed until the processing task drains the backlog. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 69 +++++++++++++++++++++++++---- devolutions-session/src/dvc/task.rs | 67 ++++++++++++++++++++++++++-- 2 files changed, 125 insertions(+), 11 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index fbec593080..7c5d0849d9 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -90,6 +90,7 @@ pub struct DvcInitializationProgress { channel_opened: AtomicBool, channel_opened_notify: Notify, negotiated: AtomicBool, + heartbeats_enabled: AtomicBool, } impl DvcInitializationProgress { @@ -144,6 +145,18 @@ impl DvcInitializationProgress { pub fn negotiated(&self) -> bool { self.negotiated.load(Ordering::Relaxed) } + + /// Records whether the negotiated capabilities let the server send heartbeats. + pub fn set_heartbeats_enabled(&self, enabled: bool) { + self.heartbeats_enabled.store(enabled, Ordering::Relaxed); + } + + /// Whether the client accepted heartbeats on this channel. + /// + /// A client that negotiated a zero interval disabled them, so it is never sent one. + pub fn heartbeats_enabled(&self) -> bool { + self.heartbeats_enabled.load(Ordering::Relaxed) + } } struct DvcIoContext { @@ -165,7 +178,7 @@ pub fn run_dvc_io( return Ok(()); }; - let result = context.io.serve(write_rx, &read_tx, &stop_event); + let result = context.io.serve(write_rx, &read_tx, &stop_event, progress); // Notify processing before cancellation cleanup, which can block until pending IO completes. let _ = io_loop_ended_tx.send(()); @@ -175,11 +188,11 @@ pub fn run_dvc_io( /// Interval at which decoded messages are offered again to a full processing queue. const INBOUND_RETRY_INTERVAL_MS: u32 = 10; -/// Longest time without a write while decoded messages are held back. +/// Longest time without a write while decoded messages are held back, on a channel with heartbeats enabled. /// /// No read is pending while messages are held back, so only a write can observe a closed channel. -/// Without this probe, a client lost during stdin backpressure goes unnoticed until the next heartbeat, or forever -/// when heartbeats are disabled, and the channel is never reopened. +/// Without this probe, a client lost during stdin backpressure goes unnoticed until the next periodic heartbeat. +/// A client that disabled heartbeats gets no probe, so its loss stays unnoticed while messages are held back. const BACKLOG_PROBE_INTERVAL: Duration = Duration::from_secs(1); /// Overlapped IO state of one open DVC channel. @@ -249,6 +262,7 @@ impl DvcIo { mut write_rx: WinapiSignaledReceiver>, read_tx: &Sender>, stop_event: &Event, + progress: &DvcInitializationProgress, ) -> anyhow::Result<()> { loop { self.forward_inbound(read_tx)?; @@ -257,9 +271,15 @@ impl DvcIo { if !self.read_pending { self.start_read()?; } - } else if !self.write_pending && self.last_write_started.elapsed() >= BACKLOG_PROBE_INTERVAL { - // NOW clients already accept unsolicited heartbeats, which are sent even when none was negotiated. - // Messages are only held back after negotiation, once stdin backpressure stops the processing task. + } else if progress.heartbeats_enabled() + && !self.write_pending + && self.last_write_started.elapsed() >= BACKLOG_PROBE_INTERVAL + { + // A heartbeat is the only message the server may send unprompted, and only when the client enabled + // heartbeats; NOW clients take one at any time, since they only watch for missing ones. + // UNTESTED: the probe must wait for any pending write, because `start_write` replaces the buffer the + // OS is still sending, and must stay spaced by `BACKLOG_PROBE_INTERVAL` so a held-back channel is not + // flooded; when changing this condition, check both still hold. trace!("Probing the DVC channel while inbound messages are held back"); self.start_write(&NowChannelHeartbeatMsg::default().into()) .context("probing the DVC channel while inbound messages are held back")?; @@ -698,16 +718,22 @@ mod tests { } fn run_dvc_io_on(server: usize, read_queue_capacity: usize) -> RunningDvcIo { + run_dvc_io_with_heartbeats(server, read_queue_capacity, true) + } + + fn run_dvc_io_with_heartbeats(server: usize, read_queue_capacity: usize, heartbeats_enabled: bool) -> RunningDvcIo { let (write_tx, write_rx) = winapi_signaled_mpsc_channel().expect("create the write queue"); let (read_tx, read_rx) = mpsc::channel(read_queue_capacity); let stop_event = Event::new_unnamed().expect("create the stop event"); let thread_stop_event = stop_event.clone(); let thread = std::thread::spawn(move || { + let progress = DvcInitializationProgress::default(); + progress.set_heartbeats_enabled(heartbeats_enabled); // SAFETY: The handle was opened by `dvc_pipe`, which gave up ownership of it. let file = unsafe { Owned::new(HANDLE(server as *mut _)) }; let mut io = DvcIo::new(file)?; - io.serve(write_rx, &read_tx, &thread_stop_event) + io.serve(write_rx, &read_tx, &thread_stop_event, &progress) }); RunningDvcIo { @@ -937,6 +963,33 @@ mod tests { running.stop().expect("the loop stops cleanly"); } + /// A client that disabled heartbeats must never be sent one, even to probe a held-back channel. + // oracle: mutant + #[test] + fn held_back_channel_is_not_probed_when_heartbeats_are_disabled() { + let (server, client) = dvc_pipe(); + let mut running = run_dvc_io_with_heartbeats(server, 1, false); + let messages: Vec<_> = (1..=3).map(|session_id| exec_data(session_id, vec![0; 16])).collect(); + + for message in &messages { + write_pdu(&client, &encoded(message)); + } + + // Twice the probe interval, so a probe would have been written by now. + std::thread::sleep(super::BACKLOG_PROBE_INTERVAL * 2); + + let mut available = 0; + // SAFETY: The handle is valid, and only the byte count is requested. + unsafe { PeekNamedPipe(*client, None, 0, None, Some(&mut available), None) }.expect("peek the test pipe"); + assert_eq!(available, 0, "a client that disabled heartbeats was sent one"); + + for message in &messages { + assert_eq!(encoded(&running.recv()), encoded(message)); + } + + running.stop().expect("the loop stops cleanly"); + } + /// Stopping with a read and a write in flight must cancel both and return. // oracle: scaffold #[test] diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index eb4628b4ec..19390742a0 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -342,6 +342,7 @@ async fn process_messages( reason = "the task handle is a drop guard; it is assigned, never inspected" )] let mut _heartbeat = spawn_heartbeat(dvc_tx.clone(), downgraded_caps.heartbeat_interval()); + init_progress.set_heartbeats_enabled(heartbeats_enabled(downgraded_caps.heartbeat_interval())); // Reply with the negotiated capset so the client sees the capabilities and heartbeat interval // the agent applies, not the server default that omits the interval. @@ -391,6 +392,7 @@ async fn process_messages( let server_caps = default_server_caps(pwsh_executable.is_some()); let downgraded_caps = client_caps.downgrade(&server_caps); _heartbeat = spawn_heartbeat(dvc_tx.clone(), downgraded_caps.heartbeat_interval()); + init_progress.set_heartbeats_enabled(heartbeats_enabled(downgraded_caps.heartbeat_interval())); // Old exec sessions will be abandoned (IO loops will terminate // on old processor `Drop`). @@ -514,18 +516,24 @@ fn spawn_heartbeat( /// `NOW_CHANNEL_SET_HEARTBEAT`. /// Without a negotiated interval, [`DEFAULT_HEARTBEAT_INTERVAL`] applies. fn heartbeat_timer(negotiated_interval: Option) -> Option { - let period = negotiated_interval.unwrap_or(DEFAULT_HEARTBEAT_INTERVAL); - - if period.is_zero() { + if !heartbeats_enabled(negotiated_interval) { return None; } + let period = negotiated_interval.unwrap_or(DEFAULT_HEARTBEAT_INTERVAL); let mut timer = tokio::time::interval_at(Instant::now() + period, period); timer.set_missed_tick_behavior(MissedTickBehavior::Delay); Some(timer) } +/// Whether the server may send heartbeats for a negotiated interval. +/// +/// Only a zero interval disables them; without a negotiated interval, [`DEFAULT_HEARTBEAT_INTERVAL`] applies. +fn heartbeats_enabled(negotiated_interval: Option) -> bool { + !negotiated_interval.unwrap_or(DEFAULT_HEARTBEAT_INTERVAL).is_zero() +} + fn default_server_caps(pwsh_available: bool) -> NowChannelCapsetMsg { let mut exec_flags = NowExecCapsetFlags::STYLE_RUN | NowExecCapsetFlags::STYLE_PROCESS @@ -1930,6 +1938,59 @@ mod tests { ); } + /// The IO thread probes a held-back channel with heartbeats only while this flag is set, so it must follow every + /// negotiation: on by default, off for a zero interval, and on again when renegotiated to a nonzero one. + // oracle: mutant + #[tokio::test(start_paused = true)] + async fn processing_loop_publishes_whether_heartbeats_are_enabled() { + let (write_tx, mut write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + let mut loop_future = Box::pin(process_messages(read_rx, write_tx, shutdown_signal, &init_progress)); + + let capsets = [ + (NowChannelCapsetMsg::default(), true), + (capset_with_zero_heartbeat_interval(), false), + ( + NowChannelCapsetMsg::default() + .with_heartbeat_interval(Duration::from_secs(30)) + .expect("30 s is a valid heartbeat interval"), + true, + ), + ]; + + for (capset, expected) in capsets { + read_tx.send(capset.into()).await.expect("queue client capset"); + assert!(poll!(loop_future.as_mut()).is_pending()); + write_rx.try_recv().expect("negotiation reply was sent"); + + assert_eq!(init_progress.heartbeats_enabled(), expected); + } + } + + /// A client capset that disables heartbeats. + /// + /// `with_heartbeat_interval` refuses zero, but the wire format still carries it, so it is decoded from bytes. + fn capset_with_zero_heartbeat_interval() -> NowChannelCapsetMsg { + const NOW_CHANNEL_SET_HEARTBEAT: u8 = 0x01; + const MSG_FLAGS_OFFSET: usize = 6; + + // The default capset already encodes a zero interval; only the flag announcing it is missing. + let mut bytes = now_proto_pdu::ironrdp_core::encode_vec(&OwnedNowMessage::from(NowChannelCapsetMsg::default())) + .expect("encode a capset"); + *bytes.get_mut(MSG_FLAGS_OFFSET).expect("the capset has a header") |= NOW_CHANNEL_SET_HEARTBEAT; + + let message: NowMessage<'_> = now_proto_pdu::ironrdp_core::decode(&bytes).expect("decode the capset"); + let NowMessage::Channel(NowChannelMessage::Capset(capset)) = message else { + panic!("expected a capset, got {message:?}"); + }; + assert_eq!(capset.heartbeat_interval(), Some(Duration::ZERO)); + + capset + } + /// Serves `outcomes` in order and returns the loop result with the instant each channel was served. /// /// Panics unless the loop serves every outcome and no more. From 000b4b6bc6ca6693f553dc36433fc255508adf99 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 10:16:56 -0400 Subject: [PATCH 13/19] fix(agent): keep detached NOW launches out of IO setup Return after every detached launch, including Process requests without temporary files. Previously those requests started the child and then panicked because attached IO setup requires a notification sender. Keep the background wait for temporary-file cleanup when needed, and cover both detached builder completion and subsequent execution on the same NOW channel. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/process.rs | 36 +++++++++----- devolutions-session/src/dvc/task.rs | 68 +++++++++++++++++++++++++- 2 files changed, 89 insertions(+), 15 deletions(-) diff --git a/devolutions-session/src/dvc/process.rs b/devolutions-session/src/dvc/process.rs index 33f4430f30..54e05dd76c 100644 --- a/devolutions-session/src/dvc/process.rs +++ b/devolutions-session/src/dvc/process.rs @@ -641,21 +641,22 @@ impl WinApiProcessBuilder { prepare_process(session_id, command_line, current_directory, self.env, encoding)? }; - // For detached mode, spawn a thread that waits for process exit and keeps temp files alive - if detached && !temp_files.is_empty() { - std::thread::spawn(move || { - let _temp_files = temp_files; - - // Wait for process to exit (indefinitely) - if let Err(error) = process_ctx.process.wait(None) { - error!(%error, session_id, "Failed to wait for detached process"); - return; - } + if detached { + if !temp_files.is_empty() { + std::thread::spawn(move || { + let _temp_files = temp_files; + + // Wait for process exit to keep its temporary files alive. + if let Err(error) = process_ctx.process.wait(None) { + error!(%error, session_id, "Failed to wait for detached process"); + return; + } - info!(session_id, "Detached process exited"); + info!(session_id, "Detached process exited"); - // Temp files will be cleaned up when this thread exits - }); + // Temporary files are cleaned up when this thread exits. + }); + } info!(session_id, "Detached process started successfully"); return Ok(None); @@ -942,6 +943,15 @@ mod tests { use super::*; + // oracle: regression #2156 detached Process without temporary files must not panic after launch. + #[test] + fn detached_process_without_temp_files_returns_success() { + WinApiProcessBuilder::new("cmd.exe") + .with_command_line("/d /c exit 0") + .run_detached(1) + .expect("detached launch returns successfully without an IO notification channel"); + } + /// A process that fills its output before reading stdin must still get all of a large input. /// /// The input exceeds the stdin pipe buffer, so a stdin write that blocks the output drain deadlocks. diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 19390742a0..493795a194 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -1533,8 +1533,8 @@ mod tests { use devolutions_gateway_task::{ShutdownHandle, ShutdownSignal}; use futures::poll; use now_proto_pdu::{ - NowChannelCapsetMsg, NowChannelCloseMsg, NowChannelMessage, NowExecCapsetFlags, NowMessage, - NowSessionCapsetFlags, NowSystemCapsetFlags, OwnedNowMessage, + NowChannelCapsetMsg, NowChannelCloseMsg, NowChannelMessage, NowExecCapsetFlags, NowExecMessage, + NowExecProcessMsg, NowExecResultMsg, NowMessage, NowSessionCapsetFlags, NowSystemCapsetFlags, OwnedNowMessage, }; use tokio::time::Instant; @@ -1545,6 +1545,70 @@ mod tests { use crate::dvc::channel::{bounded_mpsc_channel, winapi_signaled_mpsc_channel}; use crate::dvc::io::DvcInitializationProgress; + // oracle: regression #2156 detached Process must leave the channel alive for subsequent execution. + #[tokio::test] + async fn detached_process_keeps_channel_available_for_execution() { + let (write_tx, mut write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + read_tx + .send(NowChannelCapsetMsg::default().into()) + .await + .expect("queue client capset"); + read_tx + .send( + NowExecProcessMsg::new(1, "cmd.exe") + .expect("valid executable") + .with_parameters("/d /c exit 0") + .expect("valid parameters") + .with_detached() + .into(), + ) + .await + .expect("queue detached process"); + + let mut processing = Box::pin(process_messages(read_rx, write_tx, shutdown_signal, &init_progress)); + tokio::time::timeout(Duration::from_secs(10), async { + loop { + tokio::select! { + result = &mut processing => panic!("processing ended before fresh execution completed: {result:?}"), + () = tokio::time::sleep(Duration::from_millis(10)) => {} + } + + while let Ok(message) = write_rx.try_recv() { + if let NowMessage::Exec(NowExecMessage::Result(result)) = message { + if result.session_id() == 1 { + assert_eq!(result, NowExecResultMsg::new_success(1, 0)); + read_tx + .send( + NowExecProcessMsg::new(2, "cmd.exe") + .expect("valid executable") + .with_parameters("/d /c exit 7") + .expect("valid parameters") + .into(), + ) + .await + .expect("queue fresh execution after detached acknowledgment"); + } else { + assert_eq!(result, NowExecResultMsg::new_success(2, 7)); + return; + } + } + } + } + }) + .await + .expect("fresh execution completes without the detached launch killing the host"); + + read_tx + .send(NowChannelCloseMsg::default().into()) + .await + .expect("queue channel close"); + processing.await.expect("channel still accepts a normal close"); + } + // oracle: mutant a full stdin queue prevents a closed DVC from interrupting the processing loop. #[tokio::test] async fn io_loss_interrupts_processing_while_stdin_is_backpressured() { From 4194366366e4ef0b72a5983bea90f634bd83f82e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 10:33:39 -0400 Subject: [PATCH 14/19] fix(agent): keep NOW run directory alive during launch The Run handler passed lpDirectory from a WideString consumed inside Option::map, so ShellExecuteW received a pointer into a freed buffer. Borrow the string instead so the buffer outlives the call. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/task.rs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 493795a194..359ae4aca3 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -917,14 +917,16 @@ impl MessageProcessor { info!(session_id, "Executing ShellExecuteW"); - // SAFETY: All buffers are valid, therefore `ShellExecuteW` is safe to call. + // UNTESTED: Keep the directory buffer alive through ShellExecuteW; consuming it creates a dangling pointer. + // Check the borrow when changing argument conversion; a successful launch cannot prove pointer validity. + // SAFETY: All buffers are borrowed from locals that remain alive through the call. let hinstance = unsafe { ShellExecuteW( None, operation.as_pcwstr(), command.as_pcwstr(), parameters.as_pcwstr(), - directory.map(|d| d.as_pcwstr()).unwrap_or(PCWSTR::null()), + directory.as_ref().map_or_else(PCWSTR::null, WideString::as_pcwstr), // Activate and show window SW_RESTORE, ) From 502608a239522e0eb97331299b9f633d11822d05 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 10:50:12 -0400 Subject: [PATCH 15/19] docs(agent): note that NOW exec children outlive their channel Ending a NOW channel or renegotiating capabilities stops only the IO of attached execution sessions. Their processes keep running and no later channel can reach them. The NOW specification does not define the fate of execution sessions when the channel ends, so this behavior is kept and documented where the sessions are owned. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/task.rs | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 359ae4aca3..4bb2bdc467 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -623,6 +623,10 @@ struct MessageProcessor { io_notification_tx: Sender, #[allow(dead_code)] // Not yet used. capabilities: NowChannelCapsetMsg, + /// Attached execution sessions of this channel. + /// + /// Ending the channel or renegotiating capabilities stops only their IO; the processes keep running. + /// No later channel or negotiation can reach them, because each starts with no sessions. sessions: HashMap, rdm_handler: RdmMessageProcessor, /// Resolved pwsh executable path; `None` when pwsh is not installed. From 3fc0a6e7bf85cee9258203ba98ffc88a2074df4f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 12:05:06 -0400 Subject: [PATCH 16/19] fix(agent): end NOW exec trees with their channel An attached execution started through NOW kept running after its channel ended, whether the client closed it, the transport was lost, the client renegotiated, or the host exited. No later channel can reach such a process, so every disconnect during a running execution left it, and anything it started, in the user's session. Attached executions now start suspended, join a job object owned by the channel's message processor, and only then run, so every process they start joins the job too. The job kills its processes when its last handle closes: when the processor is dropped at channel end or renegotiation, and when the host exits or crashes. A process that cannot join the job is killed and the execution fails. Detached executions stay outside the job and keep running. Processes left running by an attached execution that already exited are now killed when the channel ends as well. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/Cargo.toml | 1 + devolutions-session/src/dvc/process.rs | 149 +++++++++++++------ devolutions-session/src/dvc/task.rs | 193 +++++++++++++++++++++++-- 3 files changed, 287 insertions(+), 56 deletions(-) diff --git a/devolutions-session/Cargo.toml b/devolutions-session/Cargo.toml index a2b402d2a9..b4f86bddea 100644 --- a/devolutions-session/Cargo.toml +++ b/devolutions-session/Cargo.toml @@ -64,6 +64,7 @@ features = [ "Win32_Security", "Win32_Storage_FileSystem", "Win32_System_IO", + "Win32_System_JobObjects", "Win32_System_Pipes", "Win32_System_Shutdown", "Win32_UI_Accessibility", diff --git a/devolutions-session/src/dvc/process.rs b/devolutions-session/src/dvc/process.rs index 54e05dd76c..6a94b3d097 100644 --- a/devolutions-session/src/dvc/process.rs +++ b/devolutions-session/src/dvc/process.rs @@ -7,16 +7,21 @@ use win_api_wrappers::event::Event; use win_api_wrappers::handle::Handle; use win_api_wrappers::process::{Process, post_message_for_pid}; use win_api_wrappers::security::attributes::SecurityAttributesInit; +use win_api_wrappers::thread::Thread; use win_api_wrappers::utils::{Pipe, WideString}; use windows::Win32::Foundation::{ - CloseHandle, ERROR_BROKEN_PIPE, ERROR_HANDLE_EOF, GetLastError, LPARAM, WAIT_EVENT, WAIT_OBJECT_0, WPARAM, + ERROR_BROKEN_PIPE, ERROR_HANDLE_EOF, GetLastError, LPARAM, WAIT_EVENT, WAIT_OBJECT_0, WPARAM, }; use windows::Win32::Storage::FileSystem::{ReadFile, WriteFile}; use windows::Win32::System::IO::{GetOverlappedResult, OVERLAPPED}; +use windows::Win32::System::JobObjects::{ + AssignProcessToJobObject, CreateJobObjectW, JOB_OBJECT_LIMIT_KILL_ON_JOB_CLOSE, JOBOBJECT_BASIC_LIMIT_INFORMATION, + JOBOBJECT_EXTENDED_LIMIT_INFORMATION, JobObjectExtendedLimitInformation, SetInformationJobObject, +}; use windows::Win32::System::Threading::{ - CREATE_NEW_CONSOLE, CREATE_NEW_PROCESS_GROUP, CREATE_UNICODE_ENVIRONMENT, CreateProcessW, INFINITE, - NORMAL_PRIORITY_CLASS, PROCESS_INFORMATION, STARTF_USESHOWWINDOW, STARTF_USESTDHANDLES, STARTUPINFOW, - WaitForMultipleObjects, + CREATE_NEW_CONSOLE, CREATE_NEW_PROCESS_GROUP, CREATE_SUSPENDED, CREATE_UNICODE_ENVIRONMENT, CreateProcessW, + INFINITE, NORMAL_PRIORITY_CLASS, PROCESS_CREATION_FLAGS, PROCESS_INFORMATION, STARTF_USESHOWWINDOW, + STARTF_USESTDHANDLES, STARTUPINFOW, WaitForMultipleObjects, }; use windows::Win32::UI::WindowsAndMessaging::{SW_HIDE, WM_QUIT}; use windows::core::PCWSTR; @@ -609,6 +614,7 @@ impl WinApiProcessBuilder { mut self, session_id: u32, io_notification_tx: Option>, + job: Option<&ProcessJob>, detached: bool, ) -> Result, ExecError> { let command_line = format!("\"{}\" {}", self.executable, self.command_line) @@ -636,9 +642,9 @@ impl WinApiProcessBuilder { let encoding = self.encoding; let process_ctx = if io_redirection { - prepare_process_with_io_redirection(session_id, command_line, current_directory, self.env, encoding)? + prepare_process_with_io_redirection(session_id, command_line, current_directory, self.env, encoding, job)? } else { - prepare_process(session_id, command_line, current_directory, self.env, encoding)? + prepare_process(session_id, command_line, current_directory, self.env, encoding, job)? }; if detached { @@ -709,13 +715,16 @@ impl WinApiProcessBuilder { } /// Starts process execution and spawns IO thread to redirect stdio to/from dvc. + /// + /// The process joins `job` before it runs, so it and every process it starts are killed when the job is dropped. pub fn run( self, session_id: u32, io_notification_tx: Sender, + job: &ProcessJob, ) -> Result { Ok(self - .run_impl(session_id, Some(io_notification_tx), false)? + .run_impl(session_id, Some(io_notification_tx), Some(job), false)? .expect("result should be non-optional when running in non-detached mode")) } @@ -724,17 +733,101 @@ impl WinApiProcessBuilder { /// Returns immediately after spawning. pub fn run_detached(self, session_id: u32) -> Result<(), ExecError> { // Result always empty and therefore ignored in detached mode. - self.run_impl(session_id, None, true)?; + self.run_impl(session_id, None, None, true)?; Ok(()) } } +/// Job object whose processes are killed when it is dropped, or when the host exits or crashes. +pub struct ProcessJob(Handle); + +impl ProcessJob { + pub fn new() -> anyhow::Result { + // SAFETY: Creating an unnamed job object with default security attributes has no preconditions. + // The handle is not inheritable, so no child process can keep the job open. + let job = unsafe { CreateJobObjectW(None, PCWSTR::null()) }?; + // SAFETY: `job` was just created and nothing else owns it. + let job = unsafe { Handle::new_owned(job) }?; + + let limits = JOBOBJECT_EXTENDED_LIMIT_INFORMATION { + BasicLimitInformation: JOBOBJECT_BASIC_LIMIT_INFORMATION { + LimitFlags: JOB_OBJECT_LIMIT_KILL_ON_JOB_CLOSE, + ..Default::default() + }, + ..Default::default() + }; + + // SAFETY: `limits` is a JOBOBJECT_EXTENDED_LIMIT_INFORMATION of the size passed, and outlives the call. + unsafe { + SetInformationJobObject( + job.raw(), + JobObjectExtendedLimitInformation, + (&raw const limits).cast(), + u32::try_from(size_of_val(&limits)).expect("JOBOBJECT_EXTENDED_LIMIT_INFORMATION size fits into u32"), + ) + }?; + + Ok(Self(job)) + } +} + +fn creation_flags(job: Option<&ProcessJob>, has_environment_block: bool) -> PROCESS_CREATION_FLAGS { + let mut flags = NORMAL_PRIORITY_CLASS | CREATE_NEW_PROCESS_GROUP | CREATE_NEW_CONSOLE; + + if has_environment_block { + flags |= CREATE_UNICODE_ENVIRONMENT; + } + + // A process that ran before joining its job could start processes outside it. + if job.is_some() { + flags |= CREATE_SUSPENDED; + } + + flags +} + +/// Takes ownership of the handles returned by `CreateProcessW` for a process created with [`creation_flags`], and +/// lets the process run. +/// +/// With a job, the process joins it first, and is killed if it cannot. +fn start_created_process( + process_information: &PROCESS_INFORMATION, + job: Option<&ProcessJob>, +) -> Result { + // SAFETY: `CreateProcessW` returned these handles, and nothing else owns them. + let thread = Thread::from(unsafe { Handle::new_owned(process_information.hThread) }.map_err(anyhow::Error::from)?); + // SAFETY: Same as above. + let process = + Process::from(unsafe { Handle::new_owned(process_information.hProcess) }.map_err(anyhow::Error::from)?); + + if let Some(job) = job { + // SAFETY: Both handles are valid for the duration of the call. + let started = unsafe { AssignProcessToJobObject(job.0.raw(), process.handle.raw()) } + .map_err(anyhow::Error::from) + .and_then(|()| thread.resume()); + + if let Err(error) = started { + // UNTESTED: a process that cannot join its job must be killed, not left running where no channel can + // end it. No test makes AssignProcessToJobObject or ResumeThread fail; when changing this path, check + // that every failure after CreateProcessW still terminates the suspended process. + if let Err(error) = process.terminate(1) { + error!(%error, "Failed to kill a process that could not join its job"); + } + + return Err(error.context("failed to start the process in its job").into()); + } + } + + Ok(process) +} + fn prepare_process( session_id: u32, mut command_line: WideString, current_directory: WideString, env: HashMap, encoding: DataEncoding, + job: Option<&ProcessJob>, ) -> Result { let mut process_information = PROCESS_INFORMATION::default(); @@ -746,12 +839,6 @@ fn prepare_process( let environment_block = (!env.is_empty()).then(|| make_environment_block(env)).transpose()?; - let mut creation_flags = NORMAL_PRIORITY_CLASS | CREATE_NEW_PROCESS_GROUP | CREATE_NEW_CONSOLE; - - if environment_block.is_some() { - creation_flags |= CREATE_UNICODE_ENVIRONMENT; - } - // SAFETY: All parameters constructed above are valid and safe to use. unsafe { CreateProcessW( @@ -760,7 +847,7 @@ fn prepare_process( None, None, true, - creation_flags, + creation_flags(job, environment_block.is_some()), environment_block.as_ref().map(|block| block.as_ptr() as *const _), current_directory.as_pcwstr(), &startup_info as *const _, @@ -768,18 +855,7 @@ fn prepare_process( )?; } - // The thread handle returned by CreateProcessW is only needed if you want to manage or - // wait on the primary thread of the new process. Since we only need to manage the process - // itself and not its main thread, we close the thread handle immediately to avoid - // resource leaks. - - // SAFETY: FFI call with no outstanding precondition. - unsafe { CloseHandle(process_information.hThread) }?; - - let process_handle = Process::from( - // SAFETY: process_information is valid and contains valid process handle. - unsafe { Handle::new_owned(process_information.hProcess) }.map_err(anyhow::Error::from)?, - ); + let process_handle = start_created_process(&process_information, job)?; let pid = process_information.dwProcessId; @@ -800,6 +876,7 @@ fn prepare_process_with_io_redirection( current_directory: WideString, env: HashMap, encoding: DataEncoding, + job: Option<&ProcessJob>, ) -> Result { let mut process_information = PROCESS_INFORMATION::default(); @@ -830,11 +907,6 @@ fn prepare_process_with_io_redirection( let environment_block = (!env.is_empty()).then(|| make_environment_block(env)).transpose()?; - let mut creation_flags = NORMAL_PRIORITY_CLASS | CREATE_NEW_PROCESS_GROUP | CREATE_NEW_CONSOLE; - if environment_block.is_some() { - creation_flags |= CREATE_UNICODE_ENVIRONMENT; - } - // SAFETY: All parameters constructed above are valid and safe to use. unsafe { CreateProcessW( @@ -843,7 +915,7 @@ fn prepare_process_with_io_redirection( Some(security_attributes.as_ptr()), None, true, - creation_flags, + creation_flags(job, environment_block.is_some()), environment_block.as_ref().map(|block| block.as_ptr() as *const _), current_directory.as_pcwstr(), &startup_info as *const _, @@ -851,19 +923,13 @@ fn prepare_process_with_io_redirection( )?; } - // SAFETY: FFI call with no outstanding precondition. - unsafe { CloseHandle(process_information.hThread) }?; - // Handles were duplicated by CreateProcessW, so we can close them immediately. // Explicitly drop handles just for clarity. drop(stdout_write_pipe); drop(stderr_write_pipe); drop(stdin_read_pipe); - let process_handle = Process::from( - // SAFETY: process_information is valid and contains valid process handle. - unsafe { Handle::new_owned(process_information.hProcess) }.map_err(anyhow::Error::from)?, - ); + let process_handle = start_created_process(&process_information, job)?; let pid = process_information.dwProcessId; @@ -963,13 +1029,14 @@ mod tests { const INPUT_LINES: u32 = 5000; let (io_notification_tx, mut io_notification_rx) = tokio::sync::mpsc::channel(100); + let job = ProcessJob::new().expect("create job"); let process = WinApiProcessBuilder::new("cmd.exe") .with_command_line(&format!( "/d /c (for /L %i in (1,1,{OUTPUT_LINES}) do @echo output-line-%i) & sort" )) .with_io_redirection(true) .with_encoding(DataEncoding::Raw) - .run(SESSION_ID, io_notification_tx) + .run(SESSION_ID, io_notification_tx, &job) .expect("start cmd.exe"); let input: String = (0..INPUT_LINES).map(|i| format!("input-line-{i:05}\r\n")).collect(); diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 4bb2bdc467..87eb37bdec 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -42,7 +42,7 @@ use windows::core::PCWSTR; use crate::dvc::channel::{WinapiSignaledSender, bounded_mpsc_channel, winapi_signaled_mpsc_channel}; use crate::dvc::encoding::DataEncoding; use crate::dvc::io::{DvcInitializationProgress, run_dvc_io}; -use crate::dvc::process::{ExecError, ServerChannelEvent, WinApiProcess, WinApiProcessBuilder}; +use crate::dvc::process::{ExecError, ProcessJob, ServerChannelEvent, WinApiProcess, WinApiProcessBuilder}; use crate::dvc::rdm::RdmMessageProcessor; use crate::dvc::window_monitor::{WindowMonitorConfig, run_window_monitor}; @@ -394,8 +394,7 @@ async fn process_messages( _heartbeat = spawn_heartbeat(dvc_tx.clone(), downgraded_caps.heartbeat_interval()); init_progress.set_heartbeats_enabled(heartbeats_enabled(downgraded_caps.heartbeat_interval())); - // Old exec sessions will be abandoned (IO loops will terminate - // on old processor `Drop`). + // Dropping the old processor ends its exec sessions and the processes they started. processor = MessageProcessor::new( downgraded_caps.clone(), dvc_tx.clone(), @@ -625,9 +624,13 @@ struct MessageProcessor { capabilities: NowChannelCapsetMsg, /// Attached execution sessions of this channel. /// - /// Ending the channel or renegotiating capabilities stops only their IO; the processes keep running. - /// No later channel or negotiation can reach them, because each starts with no sessions. + /// Ending the channel or renegotiating capabilities drops this processor, which stops their IO and kills them with + /// `process_job`; no later channel or negotiation could reach them, because each starts with no sessions. sessions: HashMap, + /// Job of the attached executions and the processes they start; created by the first attached execution. + /// + /// Processes left running by an attached execution that already exited are killed with it too. + process_job: Option, rdm_handler: RdmMessageProcessor, /// Resolved pwsh executable path; `None` when pwsh is not installed. pwsh_executable: Option, @@ -650,6 +653,7 @@ impl MessageProcessor { io_notification_tx, capabilities, sessions: HashMap::new(), + process_job: None, rdm_handler, pwsh_executable, window_monitor_shutdown_tx: None, @@ -657,6 +661,13 @@ impl MessageProcessor { } } + fn process_job(&mut self) -> Result<&ProcessJob, ExecError> { + Ok(match &mut self.process_job { + Some(job) => job, + slot @ None => slot.insert(ProcessJob::new()?), + }) + } + async fn ensure_session_id_free(&self, session_id: u32) -> Result<(), ExecError> { if self.sessions.contains_key(&session_id) { warn!(session_id, "Session ID is in use"); @@ -981,9 +992,11 @@ impl MessageProcessor { return Ok(()); } - let process = run_process - .with_io_redirection(exec_msg.is_with_io_redirection()) - .run(exec_msg.session_id(), self.io_notification_tx.clone())?; + let process = run_process.with_io_redirection(exec_msg.is_with_io_redirection()).run( + exec_msg.session_id(), + self.io_notification_tx.clone(), + self.process_job()?, + )?; self.sessions.insert(exec_msg.session_id(), process); @@ -1028,9 +1041,11 @@ impl MessageProcessor { return Ok(()); } - let process = run_batch - .with_io_redirection(batch_msg.is_with_io_redirection()) - .run(batch_msg.session_id(), self.io_notification_tx.clone())?; + let process = run_batch.with_io_redirection(batch_msg.is_with_io_redirection()).run( + batch_msg.session_id(), + self.io_notification_tx.clone(), + self.process_job()?, + )?; self.sessions.insert(batch_msg.session_id(), process); @@ -1090,7 +1105,11 @@ impl MessageProcessor { let process = run_process .with_io_redirection(winps_msg.is_with_io_redirection()) - .run(winps_msg.session_id(), self.io_notification_tx.clone())?; + .run( + winps_msg.session_id(), + self.io_notification_tx.clone(), + self.process_job()?, + )?; self.sessions.insert(winps_msg.session_id(), process); @@ -1155,9 +1174,11 @@ impl MessageProcessor { return Ok(()); } - let process = run_process - .with_io_redirection(pwsh_msg.is_with_io_redirection()) - .run(pwsh_msg.session_id(), self.io_notification_tx.clone())?; + let process = run_process.with_io_redirection(pwsh_msg.is_with_io_redirection()).run( + pwsh_msg.session_id(), + self.io_notification_tx.clone(), + self.process_job()?, + )?; self.sessions.insert(pwsh_msg.session_id(), process); @@ -1543,6 +1564,9 @@ mod tests { NowExecProcessMsg, NowExecResultMsg, NowMessage, NowSessionCapsetFlags, NowSystemCapsetFlags, OwnedNowMessage, }; use tokio::time::Instant; + use win_api_wrappers::process::Process; + use windows::Win32::Foundation::{WAIT_OBJECT_0, WAIT_TIMEOUT}; + use windows::Win32::System::Threading::{PROCESS_SYNCHRONIZE, PROCESS_TERMINATE}; use super::{ ChannelOutcome, DEFAULT_HEARTBEAT_INTERVAL, MAX_CONSECUTIVE_FAILED_REOPENS, REOPEN_DELAY_CAP, @@ -1615,6 +1639,145 @@ mod tests { processing.await.expect("channel still accepts a normal close"); } + /// An attached execution and the processes it started must not outlive their channel, because no other channel + /// can reach them. + // oracle: regression #2156 attached exec children survived the loss of their channel. + #[tokio::test] + async fn attached_exec_tree_ends_with_its_channel() { + let (write_tx, mut write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + read_tx + .send(NowChannelCapsetMsg::default().into()) + .await + .expect("queue client capset"); + read_tx + .send( + NowExecProcessMsg::new(1, "powershell.exe") + .expect("valid executable") + .with_parameters( + "-NoProfile -NonInteractive -Command \ + $g = Start-Process ping.exe -ArgumentList '-n 600 127.0.0.1' -WindowStyle Hidden -PassThru; \ + [Console]::Out.WriteLine([string]$PID + ' ' + $g.Id); Start-Sleep 600", + ) + .expect("valid parameters") + .with_io_redirection() + .into(), + ) + .await + .expect("queue attached process"); + + let mut processing = Box::pin(process_messages(read_rx, write_tx, shutdown_signal, &init_progress)); + let mut stdout = Vec::new(); + let tree = tokio::time::timeout(Duration::from_secs(30), async { + loop { + tokio::select! { + result = &mut processing => panic!("processing ended before the process tree started: {result:?}"), + () = tokio::time::sleep(Duration::from_millis(10)) => {} + } + + while let Ok(message) = write_rx.try_recv() { + if let NowMessage::Exec(NowExecMessage::Data(data)) = message { + stdout.extend_from_slice(data.data()); + } + } + + if let Some(line) = String::from_utf8_lossy(&stdout) + .lines() + .next() + .filter(|_| stdout.contains(&b'\n')) + { + // Opened right away so that the process IDs cannot be reused before the assertions. + return line + .split_whitespace() + .map(|pid| { + Process::get_by_pid(pid.parse().expect("process ID"), PROCESS_SYNCHRONIZE) + .expect("open process in the tree") + }) + .collect::>(); + } + } + }) + .await + .expect("attached process reports its tree"); + assert_eq!(tree.len(), 2, "child and grandchild"); + + drop(read_tx); + let result = processing.await; + assert!(result.is_err(), "channel loss ends processing with an error"); + + for process in &tree { + assert_eq!( + process.wait(Some(10_000)).expect("wait for process"), + WAIT_OBJECT_0, + "process in the attached tree outlived its channel" + ); + } + } + + /// A detached execution is fire-and-forget, so it must outlive the channel that started it. + // oracle: mutant attached-tree cleanup also kills detached launches. + #[tokio::test] + async fn detached_exec_outlives_its_channel() { + let pid_file = std::env::temp_dir().join(format!("now-detached-exec-{}.pid", std::process::id())); + let _ = std::fs::remove_file(&pid_file); + let (write_tx, mut write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); + let (read_tx, read_rx) = bounded_mpsc_channel().expect("create inbound channel"); + let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); + let init_progress = DvcInitializationProgress::default(); + + read_tx + .send(NowChannelCapsetMsg::default().into()) + .await + .expect("queue client capset"); + read_tx + .send( + NowExecProcessMsg::new(1, "powershell.exe") + .expect("valid executable") + .with_parameters(format!( + "-NoProfile -NonInteractive -Command \ + Set-Content -LiteralPath '{}' -Value $PID; Start-Sleep 600", + pid_file.display() + )) + .expect("valid parameters") + .with_detached() + .into(), + ) + .await + .expect("queue detached process"); + + let mut processing = Box::pin(process_messages(read_rx, write_tx, shutdown_signal, &init_progress)); + let process = tokio::time::timeout(Duration::from_secs(30), async { + loop { + tokio::select! { + result = &mut processing => panic!("processing ended before the detached process started: {result:?}"), + () = tokio::time::sleep(Duration::from_millis(10)) => {} + } + + while write_rx.try_recv().is_ok() {} + + let pid = std::fs::read_to_string(&pid_file).unwrap_or_default(); + if let Ok(pid) = pid.trim().parse() { + return Process::get_by_pid(pid, PROCESS_SYNCHRONIZE | PROCESS_TERMINATE) + .expect("open detached process"); + } + } + }) + .await + .expect("detached process reports its ID"); + + drop(read_tx); + let result = processing.await; + assert!(result.is_err(), "channel loss ends processing with an error"); + + let outlived = process.wait(Some(1_000)).expect("wait for process") == WAIT_TIMEOUT; + process.terminate(1).expect("clean up detached process"); + let _ = std::fs::remove_file(&pid_file); + assert!(outlived, "detached process ended with its channel"); + } + // oracle: mutant a full stdin queue prevents a closed DVC from interrupting the processing loop. #[tokio::test] async fn io_loss_interrupts_processing_while_stdin_is_backpressured() { From 9ac4fed2cf909acf7c0dd390bf430fbc578003c4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 12:05:10 -0400 Subject: [PATCH 17/19] style(agent): apply nightly rustfmt to NOW DVC IO tests Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-session/src/dvc/io.rs | 12 ++++-------- 1 file changed, 4 insertions(+), 8 deletions(-) diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index 7c5d0849d9..dd81ed1439 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -636,17 +636,13 @@ impl IoRedirectionPipes { #[cfg(test)] mod tests { - use std::time::Duration; - - use futures::poll; - use now_proto_pdu::NowMessage; - use tokio::sync::mpsc; - use std::sync::atomic::{AtomicU32, Ordering}; - use std::time::Instant; + use std::time::{Duration, Instant}; + use futures::poll; use now_proto_pdu::ironrdp_core::encode_vec; - use now_proto_pdu::{NowChannelHeartbeatMsg, NowExecDataMsg, NowExecDataStreamKind}; + use now_proto_pdu::{NowChannelHeartbeatMsg, NowExecDataMsg, NowExecDataStreamKind, NowMessage}; + use tokio::sync::mpsc; use win_api_wrappers::event::Event; use windows::Win32::Foundation::{ERROR_MORE_DATA, GENERIC_READ, GENERIC_WRITE, HANDLE}; use windows::Win32::Storage::FileSystem::{ From 4db884572abd433305f4bb448e19284869d8b24b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 12:07:45 -0400 Subject: [PATCH 18/19] test(agent): give NOW DVC tests strong oracles Replace the scaffold and bare mutant markers on the NOW host and session manager tests with the fault each test catches, and cite the CreatePipe remarks for the blocking anonymous-pipe write. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- devolutions-agent/src/session_manager.rs | 30 ++++++++++++------------ devolutions-session/src/dvc/io.rs | 18 +++++++------- devolutions-session/src/dvc/process.rs | 2 +- devolutions-session/src/dvc/task.rs | 20 ++++++++-------- 4 files changed, 35 insertions(+), 35 deletions(-) diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index 8ed9417d83..131295ece9 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -1143,13 +1143,13 @@ mod tests { let argv = CommandLine::from_command_line(&command_line).0; // oracle: spec CreateProcessAsUserW §Parameters assert_eq!(argv[0], session_app_path.as_str()); - // oracle: scaffold + // oracle: mutant session arguments are dropped, reordered, or merged into the module name assert_eq!(argv[1..], ["--session", "3"]); } /// A failure to look up the session process must neither end the session manager nor mark the session ready, so /// that the next readiness event retries. - // oracle: scaffold + // oracle: mutant a process lookup failure ends the session manager or marks the session ready #[test] fn process_lookup_failure_leaves_the_session_waiting() { let session = Session::new(1); @@ -1244,7 +1244,7 @@ mod tests { const QUICK_RUN: Duration = Duration::from_secs(1); /// A process that crashes while its session still wants it must come back, or the channel it hosts stays unserved. - // oracle: scaffold + // oracle: mutant a failed exit of a ready remote session schedules no relaunch, or one before the floor delay #[test] fn failed_exit_of_ready_remote_session_schedules_relaunch_after_the_floor_delay() { let session = Session::new(1); @@ -1258,7 +1258,7 @@ mod tests { } /// Back-off keeps a process that fails on start from being relaunched in a tight loop. - // oracle: scaffold + // oracle: mutant the relaunch delay does not double per consecutive failure, or exceeds its cap #[test] fn relaunch_delay_doubles_per_consecutive_failure_and_is_capped() { assert_eq!(relaunch_delay(1), Duration::from_secs(2)); @@ -1269,7 +1269,7 @@ mod tests { } /// Consecutive quick failures of relaunched processes grow the delay. - // oracle: scaffold + // oracle: mutant a second quick failure keeps the first delay #[test] fn second_quick_failure_doubles_the_delay() { let session = Session::new(1); @@ -1284,7 +1284,7 @@ mod tests { } /// A process that ran for a while before failing is not failing on start, so it is relaunched promptly. - // oracle: scaffold + // oracle: mutant a failure after a long run keeps the grown delay #[test] fn long_run_before_failure_resets_the_delay() { let session = Session::new(1); @@ -1301,7 +1301,7 @@ mod tests { } /// A process that keeps failing on start is given up on, and the next logon or unlock tries again. - // oracle: scaffold + // oracle: mutant repeated quick failures relaunch forever, or block the next logon or unlock #[test] fn repeated_quick_failures_give_up_until_the_next_logon_or_unlock() { let session = Session::new(1); @@ -1323,7 +1323,7 @@ mod tests { } /// Exit code 0 means the process ended on purpose, such as when the client has no listener for the channel. - // oracle: scaffold + // oracle: mutant a clean exit is relaunched #[test] fn clean_exit_is_not_relaunched() { let session = Session::new(1); @@ -1339,7 +1339,7 @@ mod tests { } /// The exit of a process replaced by a later launch says nothing about the current one. - // oracle: scaffold + // oracle: mutant the exit of a replaced launch relaunches the process #[test] fn exit_of_a_replaced_launch_is_ignored() { let session = Session::new(1); @@ -1354,7 +1354,7 @@ mod tests { } /// A reconnected session terminates the old process, whose exit must not start a second one. - // oracle: scaffold + // oracle: mutant an exit after a remote reconnect starts a second process #[test] fn exit_after_remote_reconnect_is_ignored() { let session = Session::new(1); @@ -1369,7 +1369,7 @@ mod tests { } /// A disconnected session terminates its process and wants none. - // oracle: scaffold + // oracle: mutant an exit after a disconnect relaunches the process #[test] fn exit_after_disconnect_is_ignored() { let session = Session::new(1); @@ -1384,7 +1384,7 @@ mod tests { } /// The system stops the process at logoff, and the next logon starts it. - // oracle: scaffold + // oracle: mutant an exit after logoff relaunches the process #[test] fn exit_after_logoff_is_ignored() { let session = Session::new(1); @@ -1401,7 +1401,7 @@ mod tests { } /// A console session never hosts the process, so a stray report for one must not start it. - // oracle: scaffold + // oracle: mutant an exit reported for the console session starts the process #[test] fn exit_in_console_session_is_ignored() { let session = Session::new(1); @@ -1419,7 +1419,7 @@ mod tests { } /// A session that logged off during the delay must not have the process started when the delay ends. - // oracle: scaffold + // oracle: mutant a relaunch falling due after logoff starts the process #[test] fn relaunch_due_after_logoff_is_ignored() { let session = Session::new(1); @@ -1434,7 +1434,7 @@ mod tests { } /// A relaunch scheduled for a launch that was since replaced must not start another process. - // oracle: scaffold + // oracle: mutant a relaunch falling due for a replaced launch starts another process #[test] fn relaunch_due_for_a_replaced_launch_is_ignored() { let session = Session::new(1); diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index dd81ed1439..dfb2299da4 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -840,7 +840,7 @@ mod tests { .into() } - // oracle: scaffold + // oracle: mutant a read shorter than the channel header ends the loop as a close, or loses its length #[test] fn read_shorter_than_the_channel_header_is_an_error_with_its_length() { let (server, client) = dvc_pipe(); @@ -854,7 +854,7 @@ mod tests { } /// An empty channel PDU carries no message and must not end the loop, so a later message still arrives. - // oracle: scaffold + // oracle: mutant an empty channel PDU ends the loop or drops the next message #[test] fn empty_channel_pdu_is_skipped() { let (server, client) = dvc_pipe(); @@ -870,7 +870,7 @@ mod tests { /// A client that does not read our output must not stop us from reading its input; with a synchronous write the /// loop would block until the client reads. - // oracle: mutant + // oracle: mutant a pending write blocks reads from the client #[test] fn reads_continue_while_a_large_write_is_pending() { let (server, client) = dvc_pipe(); @@ -895,7 +895,7 @@ mod tests { /// A full processing queue must hold messages back rather than drop them or end the channel: the client matches /// responses by send order, so a gap would desynchronize it. - // oracle: mutant + // oracle: mutant a full processing queue drops, reorders, or ends on held-back messages #[test] fn full_processing_queue_holds_messages_back_in_order() { let (server, client) = dvc_pipe(); @@ -920,7 +920,7 @@ mod tests { /// A client that goes away while the processing queue is full must still end the loop, so the channel is reopened. /// /// No read is pending while messages are held back, so only a write can observe the closed channel. - // oracle: mutant + // oracle: mutant a closed channel goes unnoticed while messages are held back #[test] fn closed_channel_ends_the_loop_while_messages_are_held_back() { let (server, client) = dvc_pipe(); @@ -937,7 +937,7 @@ mod tests { } /// Probing a held-back channel must not disturb it: the client gets heartbeats, and every message still arrives. - // oracle: mutant + // oracle: mutant probing a held-back channel sends no heartbeat, or disturbs held-back messages #[test] fn held_back_channel_is_probed_with_heartbeats() { let (server, client) = dvc_pipe(); @@ -960,7 +960,7 @@ mod tests { } /// A client that disabled heartbeats must never be sent one, even to probe a held-back channel. - // oracle: mutant + // oracle: mutant a client that disabled heartbeats is sent probe heartbeats #[test] fn held_back_channel_is_not_probed_when_heartbeats_are_disabled() { let (server, client) = dvc_pipe(); @@ -987,7 +987,7 @@ mod tests { } /// Stopping with a read and a write in flight must cancel both and return. - // oracle: scaffold + // oracle: mutant stopping with IO in flight hangs or leaves the IO pending #[test] fn stop_cancels_pending_io() { let (server, _client) = dvc_pipe(); @@ -1002,7 +1002,7 @@ mod tests { running.stop().expect("the loop stops cleanly"); } - // oracle: scaffold + // oracle: mutant a closed processing queue ends the loop without an error #[test] fn closed_processing_queue_is_an_error() { let (server, client) = dvc_pipe(); diff --git a/devolutions-session/src/dvc/process.rs b/devolutions-session/src/dvc/process.rs index 6a94b3d097..97a02fa543 100644 --- a/devolutions-session/src/dvc/process.rs +++ b/devolutions-session/src/dvc/process.rs @@ -1021,7 +1021,7 @@ mod tests { /// A process that fills its output before reading stdin must still get all of a large input. /// /// The input exceeds the stdin pipe buffer, so a stdin write that blocks the output drain deadlocks. - // oracle: spec Windows anonymous pipes block a writer until the reader frees buffer space + // oracle: spec CreatePipe §Remarks #[tokio::test(flavor = "multi_thread")] async fn large_stdin_after_output_completes() { const SESSION_ID: u32 = 1; diff --git a/devolutions-session/src/dvc/task.rs b/devolutions-session/src/dvc/task.rs index 87eb37bdec..2a5b1618f4 100644 --- a/devolutions-session/src/dvc/task.rs +++ b/devolutions-session/src/dvc/task.rs @@ -1813,7 +1813,7 @@ mod tests { /// A negotiated channel whose IO ends, as when the client tears the DVC down while the RDP connection stays up, /// must be told apart from one that never negotiated, because only the former is reopened. - // oracle: scaffold + // oracle: mutant a channel lost after negotiation is classified as not negotiated or ended #[tokio::test] async fn read_channel_closing_after_negotiation_loses_the_channel() { let (write_tx, _write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); @@ -1835,7 +1835,7 @@ mod tests { /// A channel whose IO ends before the client negotiates, as with a client that has no NOW listener, must not be /// classified as lost, so it is never reopened. - // oracle: scaffold + // oracle: mutant a channel ending before negotiation is classified as lost #[tokio::test] async fn read_channel_closing_before_negotiation_is_not_negotiated() { let (write_tx, _write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); @@ -1878,7 +1878,7 @@ mod tests { /// A first channel that never negotiates must end the loop, so a client without a NOW listener does not keep the /// process alive reopening a channel nobody serves. /// It ends without an error, because the agent relaunches a process that exits with one. - // oracle: scaffold + // oracle: mutant an unnegotiated first channel is reopened or ends with an error #[tokio::test(start_paused = true)] async fn unnegotiated_first_channel_is_not_reopened() { let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); @@ -1888,7 +1888,7 @@ mod tests { result.expect("a client without a NOW listener is not a failure"); } - // oracle: scaffold + // oracle: mutant an ended channel is reopened or ends with an error #[tokio::test(start_paused = true)] async fn ended_channel_is_not_reopened() { let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); @@ -1898,7 +1898,7 @@ mod tests { result.expect("an ended channel ends the loop cleanly"); } - // oracle: scaffold + // oracle: mutant a lost channel is not reopened, or is reopened before the floor delay #[tokio::test(start_paused = true)] async fn lost_channel_is_reopened_after_a_delay() { let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); @@ -1918,13 +1918,13 @@ mod tests { let (result, served_at) = serve_script(script, shutdown_signal).await; - // oracle: scaffold + // oracle: mutant reopening never gives up, or gives up without an error assert!(result.is_err()); let delays = served_at.windows(2).map(|w| w[1] - w[0]).collect::>(); // oracle: property monotonic assert!(delays.windows(2).all(|w| w[0] <= w[1]), "{delays:?}"); - // oracle: scaffold + // oracle: mutant a reopen delay falls below the floor or above the cap assert!( delays .iter() @@ -1935,7 +1935,7 @@ mod tests { /// A reopened channel that negotiates shows the client serves NOW again, so earlier failures must not count /// toward giving up. - // oracle: scaffold + // oracle: mutant a negotiated reopen keeps earlier failures in the give-up budget #[tokio::test(start_paused = true)] async fn negotiated_reopen_resets_the_failure_budget() { let (_shutdown_handle, shutdown_signal) = ShutdownHandle::new(); @@ -1952,7 +1952,7 @@ mod tests { } /// A shutdown requested while waiting to reopen must end the loop at once, without opening another channel. - // oracle: scaffold + // oracle: mutant a shutdown during the reopen delay waits it out or opens another channel #[tokio::test(start_paused = true)] async fn shutdown_during_reopen_delay_stops_without_reopening() { let (shutdown_handle, shutdown_signal) = ShutdownHandle::new(); @@ -2173,7 +2173,7 @@ mod tests { /// The IO thread probes a held-back channel with heartbeats only while this flag is set, so it must follow every /// negotiation: on by default, off for a zero interval, and on again when renegotiated to a nonzero one. - // oracle: mutant + // oracle: mutant the heartbeat flag ignores renegotiation or a zero interval #[tokio::test(start_paused = true)] async fn processing_loop_publishes_whether_heartbeats_are_enabled() { let (write_tx, mut write_rx) = winapi_signaled_mpsc_channel().expect("create outbound channel"); From b0bf2e27d4e8cc921c18e83112785cdc50a2ce89 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Moreau?= Date: Mon, 26 Oct 2026 14:06:10 -0400 Subject: [PATCH 19/19] fix(agent): recover the NOW channel host Retry pre-launch recovery after transient lookup, launch, and termination failures. Bound disabled-heartbeat DVC backpressure and cancel blocked synchronous stdin writers during teardown. Treat an already-signaled process handle as completed termination. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- crates/win-api-wrappers/src/process.rs | 46 +++- devolutions-agent/src/session_manager.rs | 280 +++++++++++++++++++++-- devolutions-session/src/dvc/io.rs | 119 ++++++++-- devolutions-session/src/dvc/process.rs | 110 ++++++++- 4 files changed, 506 insertions(+), 49 deletions(-) diff --git a/crates/win-api-wrappers/src/process.rs b/crates/win-api-wrappers/src/process.rs index cc00e0b032..a2f3598740 100644 --- a/crates/win-api-wrappers/src/process.rs +++ b/crates/win-api-wrappers/src/process.rs @@ -12,7 +12,7 @@ use anyhow::{Context, Result, bail}; use tracing::{error, warn}; use windows::Win32::Foundation::{ E_INVALIDARG, ERROR_INCORRECT_SIZE, ERROR_NO_MORE_FILES, FILETIME, FreeLibrary, HANDLE, HMODULE, HWND, LPARAM, - MAX_PATH, WAIT_EVENT, WAIT_FAILED, WAIT_OBJECT_0, WPARAM, + MAX_PATH, WAIT_EVENT, WAIT_FAILED, WAIT_OBJECT_0, WAIT_TIMEOUT, WPARAM, }; use windows::Win32::Security::{TOKEN_ACCESS_MASK, TOKEN_ADJUST_PRIVILEGES, TOKEN_QUERY}; use windows::Win32::System::Com::{COINIT_APARTMENTTHREADED, COINIT_DISABLE_OLE1DDE}; @@ -1010,14 +1010,17 @@ fn terminate_process_by_name_impl( // SAFETY: OpenProcess returned a valid handle owned by the caller. let process = unsafe { Handle::new_owned(process) }?; // SAFETY: `OpenProcess` ensures that the handle is valid. - unsafe { - if let Err(error) = TerminateProcess(process.raw(), 1) { - if timeout_ms.is_some() { - return Err(error.into()); + if let Err(error) = unsafe { TerminateProcess(process.raw(), 1) } { + if timeout_ms.is_some() { + // SAFETY: The handle has SYNCHRONIZE access when termination is awaited. + let wait = unsafe { WaitForSingleObject(process.raw(), 0) }; + if termination_failure_is_complete(wait)? { + return Ok(true); } - warn!(process_name, session_id, %error, "TerminateProcess failed"); - return Ok(false); + return Err(error.into()); } + warn!(process_name, session_id, %error, "TerminateProcess failed"); + return Ok(false); } if let Some(timeout_ms) = timeout_ms { @@ -1047,6 +1050,15 @@ fn terminate_process_by_name_impl( Ok(false) } +fn termination_failure_is_complete(wait: WAIT_EVENT) -> Result { + match wait { + WAIT_OBJECT_0 => Ok(true), + WAIT_TIMEOUT => Ok(false), + WAIT_FAILED => Err(Error::last_error().into()), + status => bail!("unexpected process wait status {:#X}", status.0), + } +} + /// Get the Windows session ID for a given process ID. pub fn process_id_to_session(pid: u32) -> Result { let mut session_id = 0; @@ -1122,3 +1134,23 @@ pub fn post_message_for_pid(pid: u32, msg: u32, wparam: WPARAM, lparam: LPARAM) Ok(()) } + +#[cfg(test)] +mod tests { + use windows::Win32::Foundation::{WAIT_OBJECT_0, WAIT_TIMEOUT}; + + use super::termination_failure_is_complete; + + /// TerminateProcess may lose a race with normal process exit; a signaled process handle means termination is done. + // oracle: spec TerminateProcess §Remarks + #[test] + fn already_signaled_process_is_treated_as_terminated() { + assert!(termination_failure_is_complete(WAIT_OBJECT_0).expect("read process state")); + } + + // oracle: spec WaitForSingleObject §Return value + #[test] + fn running_process_is_not_treated_as_terminated() { + assert!(!termination_failure_is_complete(WAIT_TIMEOUT).expect("read process state")); + } +} diff --git a/devolutions-agent/src/session_manager.rs b/devolutions-agent/src/session_manager.rs index 131295ece9..fa02c7b03a 100644 --- a/devolutions-agent/src/session_manager.rs +++ b/devolutions-agent/src/session_manager.rs @@ -79,6 +79,8 @@ struct GatewaySession { launch_id: Option, /// Number of consecutive quick failures of the session process. consecutive_failures: u32, + /// Generation of a start request that has not started or adopted a process yet. + start_retry_id: Option, /// A reconnect must finish terminating its old host before lookup can adopt another one. termination_pending: bool, } @@ -92,6 +94,7 @@ impl Debug for GatewaySession { .field("readiness", &self.readiness) .field("launch_id", &self.launch_id) .field("consecutive_failures", &self.consecutive_failures) + .field("start_retry_id", &self.start_retry_id) .finish() } } @@ -104,6 +107,7 @@ impl GatewaySession { readiness, launch_id: None, consecutive_failures: 0, + start_retry_id: None, termination_pending: false, } } @@ -133,6 +137,7 @@ impl GatewaySession { fn set_waiting_for_logon(&mut self) { self.readiness = SessionReadiness::WaitingForLogon; self.consecutive_failures = 0; + self.start_retry_id = None; } /// Whether the process started with `launch_id` is the one this session still wants running. @@ -155,6 +160,7 @@ struct ProcessExit { enum InternalEvent { ProcessExited(ProcessExit), RelaunchDue { session_id: u32, launch_id: u64 }, + StartRetryDue { session_id: u32, retry_id: u64 }, } /// Delay before relaunching a process that failed for the first time. @@ -181,6 +187,7 @@ fn relaunch_delay(consecutive_failures: u32) -> Duration { struct SessionManagerCtx { sessions: BTreeMap, last_launch_id: u64, + last_start_retry_id: u64, } impl SessionManagerCtx { @@ -329,6 +336,64 @@ impl SessionManagerCtx { Some(delay) } + fn begin_start_retry(&mut self, session: &Session) -> Option { + let key = session.to_string(); + if !self.sessions.contains_key(&key) { + return None; + } + + self.last_start_retry_id += 1; + let retry_id = self.last_start_retry_id; + let gw_session = self.sessions.get_mut(&key)?; + gw_session.start_retry_id = Some(retry_id); + gw_session.consecutive_failures = 0; + Some(retry_id) + } + + fn complete_start_retry(&mut self, session_id: u32, retry_id: u64) { + if let Some(gw_session) = self + .get_session_mut(&Session::new(session_id)) + .filter(|gw_session| gw_session.start_retry_id == Some(retry_id)) + { + gw_session.start_retry_id = None; + } + } + + fn retry_failed_start(&mut self, session_id: u32, retry_id: u64) -> Option { + let gw_session = self + .get_session_mut(&Session::new(session_id)) + .filter(|gw_session| gw_session.start_retry_id == Some(retry_id))?; + gw_session.consecutive_failures += 1; + + if MAX_CONSECUTIVE_FAILURES <= gw_session.consecutive_failures { + error!( + session = session_id, + retry_id, + consecutive_failures = gw_session.consecutive_failures, + "Session process recovery keeps failing; waiting for the next logon or unlock" + ); + gw_session.readiness = SessionReadiness::WaitingForLogonOrUnlock; + gw_session.consecutive_failures = 0; + gw_session.start_retry_id = None; + return None; + } + + let delay = relaunch_delay(gw_session.consecutive_failures); + warn!( + session = session_id, + retry_id, + ?delay, + "Scheduling session process start retry" + ); + Some(delay) + } + + fn should_retry_start(&self, session_id: u32, retry_id: u64) -> bool { + self.sessions + .get(&Session::new(session_id).to_string()) + .is_some_and(|gw_session| gw_session.start_retry_id == Some(retry_id)) + } + /// Whether a relaunch scheduled after the exit of the process started with `launch_id` is still wanted. fn should_relaunch(&self, session_id: u32, launch_id: u64) -> bool { self.sessions @@ -455,7 +520,7 @@ impl SessionManager { let mut ctx = ctx.write().await; for session in sessions { ctx.register_session(&session, SessionKind::Remote, SessionReadiness::WaitingForLogonOrUnlock); - start_session_process_if_not_running(&mut ctx, system, &session, &internal_tx); + request_session_process_start(&mut ctx, system, &session, false, &internal_tx); } } Err(error) => { @@ -483,6 +548,26 @@ impl SessionManager { } } } + InternalEvent::StartRetryDue { session_id, retry_id } => { + if ctx.should_retry_start(session_id, retry_id) { + match system.active_remote_sessions() { + Ok(sessions) if sessions.iter().any(|session| session.id == session_id) => { + if start_session_process_if_not_running(&mut ctx, system, &Session::new(session_id), &internal_tx) { + ctx.complete_start_retry(session_id, retry_id); + } else if let Some(delay) = ctx.retry_failed_start(session_id, retry_id) { + schedule_start_retry(&internal_tx, session_id, retry_id, delay); + } + } + Ok(_) => ctx.complete_start_retry(session_id, retry_id), + Err(error) => { + error!(%error, session = session_id, "Failed to check whether the remote session is active for start retry"); + if let Some(delay) = ctx.retry_failed_start(session_id, retry_id) { + schedule_start_retry(&internal_tx, session_id, retry_id, delay); + } + } + } + } + } } } event = service_event_rx.recv() => { @@ -533,21 +618,7 @@ impl SessionManager { let mut ctx = ctx.write().await; ctx.register_session(&id, SessionKind::Remote, readiness); ctx.get_session_mut(&id).expect("session was just registered").termination_pending = true; - - if !finish_session_termination(&mut ctx, system, &id) { - continue; - } - - // A queued connect may predate the startup snapshot and its user's logon. - match system.active_remote_sessions() { - Ok(sessions) if sessions.iter().any(|session| session.id == id.id) => { - start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); - } - Ok(_) => {} - Err(error) => { - error!(%id, %error, "Failed to check whether the remote session is active"); - } - } + request_session_process_start(&mut ctx, system, &id, true, &internal_tx); } } AgentServiceEvent::SessionRemoteDisconnect(id) => { @@ -568,7 +639,7 @@ impl SessionManager { // session app on logon, if not yet started. let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Logon) { - start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); + request_session_process_start(&mut ctx, system, &id, false, &internal_tx); } } AgentServiceEvent::SessionUnlock(id) => { @@ -576,7 +647,7 @@ impl SessionManager { let mut ctx = ctx.write().await; if ctx.should_start_session(&id, SessionReadinessEvent::Unlock) { - start_session_process_if_not_running(&mut ctx, system, &id, &internal_tx); + request_session_process_start(&mut ctx, system, &id, false, &internal_tx); } } AgentServiceEvent::SessionLogoff(id) => { @@ -619,6 +690,15 @@ fn start_session_process_if_not_running( if !finish_session_termination(ctx, system, session) { return false; } + start_registered_session_process(ctx, system, session, internal_tx) +} + +fn start_registered_session_process( + ctx: &mut SessionManagerCtx, + system: &dyn SessionSystem, + session: &Session, + internal_tx: &mpsc::UnboundedSender, +) -> bool { ctx.start_process_if_not_running( session, |session| system.is_running(session), @@ -626,6 +706,41 @@ fn start_session_process_if_not_running( ) } +fn request_session_process_start( + ctx: &mut SessionManagerCtx, + system: &dyn SessionSystem, + session: &Session, + verify_active_remote_session: bool, + internal_tx: &mpsc::UnboundedSender, +) { + let Some(retry_id) = ctx.begin_start_retry(session) else { + return; + }; + + let mut should_start = finish_session_termination(ctx, system, session); + if should_start && verify_active_remote_session { + match system.active_remote_sessions() { + Ok(sessions) => { + should_start = sessions.iter().any(|active| active.id == session.id); + if !should_start { + ctx.complete_start_retry(session.id, retry_id); + return; + } + } + Err(error) => { + error!(%error, %session, "Failed to check whether the remote session is active"); + should_start = false; + } + } + } + + if should_start && start_registered_session_process(ctx, system, session, internal_tx) { + ctx.complete_start_retry(session.id, retry_id); + } else if let Some(delay) = ctx.retry_failed_start(session.id, retry_id) { + schedule_start_retry(internal_tx, session.id, retry_id, delay); + } +} + fn finish_session_termination(ctx: &mut SessionManagerCtx, system: &dyn SessionSystem, session: &Session) -> bool { let Some(gw_session) = ctx.get_session_mut(session) else { return false; @@ -640,6 +755,19 @@ fn finish_session_termination(ctx: &mut SessionManagerCtx, system: &dyn SessionS true } +fn schedule_start_retry( + internal_tx: &mpsc::UnboundedSender, + session_id: u32, + retry_id: u64, + delay: Duration, +) { + let internal_tx = internal_tx.clone(); + tokio::spawn(async move { + tokio::time::sleep(delay).await; + let _ = internal_tx.send(InternalEvent::StartRetryDue { session_id, retry_id }); + }); +} + /// Reports the exit of `process` to the session manager from a dedicated thread. /// /// The thread blocks until the process exits, which may outlive the session manager. @@ -815,6 +943,7 @@ mod tests { events: mpsc::Sender, events_during_snapshot: Mutex>, lookup_failures: Mutex>, + launch_failures: Mutex>, termination_failures: Mutex>, running: Mutex>, exit_on_start: Mutex>, @@ -862,6 +991,15 @@ mod tests { launch_id: u64, internal_tx: &mpsc::UnboundedSender, ) -> anyhow::Result<()> { + if self + .launch_failures + .lock() + .expect("launch failure lock") + .pop_front() + .unwrap_or(false) + { + anyhow::bail!("session process launch failed"); + } assert!( self.running.lock().expect("running processes lock").insert(session.id), "duplicate host launch" @@ -913,6 +1051,30 @@ mod tests { ShutdownHandle, ChildTask>, mpsc::UnboundedReceiver, + ) { + start_test_manager_with_launch_failures( + active_sessions, + running, + events_during_snapshot, + lookup_failures, + Vec::new(), + exit_on_start, + termination_failures, + ) + } + + fn start_test_manager_with_launch_failures( + active_sessions: Vec, + running: BTreeSet, + events_during_snapshot: Vec, + lookup_failures: Vec, + launch_failures: Vec, + exit_on_start: Option, + termination_failures: Vec, + ) -> ( + ShutdownHandle, + ChildTask>, + mpsc::UnboundedReceiver, ) { let manager = SessionManager::default(); let (shutdown, signal) = ShutdownHandle::new(); @@ -922,6 +1084,7 @@ mod tests { events: manager.service_event_tx(), events_during_snapshot: Mutex::new(events_during_snapshot), lookup_failures: Mutex::new(lookup_failures.into()), + launch_failures: Mutex::new(launch_failures.into()), termination_failures: Mutex::new(termination_failures.into()), running: Mutex::new(running), exit_on_start: Mutex::new(exit_on_start), @@ -953,6 +1116,29 @@ mod tests { .expect("session manager result"); } + /// A transient startup process launch failure is retried without waiting for another readiness event. + // oracle: mutant an active startup session remains without a host after one launch failure. + #[tokio::test] + async fn startup_launch_failure_is_retried_without_a_new_event() { + let (shutdown, task, mut actions) = start_test_manager_with_launch_failures( + vec![42], + BTreeSet::new(), + vec![], + vec![false, false], + vec![true, false], + None, + vec![], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + // oracle: mutant replayed connection events leave an active session waiting for an already-past logon. #[tokio::test] async fn reconnect_during_snapshot_restores_an_already_active_host() { @@ -1086,6 +1272,46 @@ mod tests { .expect("session manager result"); } + /// A transient startup process lookup failure is retried without waiting for another readiness event. + // oracle: mutant an active startup session remains without a host after one process lookup failure. + #[tokio::test] + async fn startup_lookup_failure_is_retried_without_a_new_event() { + let (shutdown, task, mut actions) = + start_test_manager(vec![42], BTreeSet::new(), vec![], vec![true, false], None, vec![]); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + + /// A reconnect termination failure is retried without another logon or unlock event. + // oracle: mutant a transient reconnect termination failure prevents host recovery until another service event. + #[tokio::test] + async fn reconnect_termination_failure_is_retried_without_a_new_event() { + let (shutdown, task, mut actions) = start_test_manager( + vec![42], + BTreeSet::new(), + vec![AgentServiceEvent::SessionRemoteConnect(Session::new(42))], + vec![], + None, + vec![true, false], + ); + + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Stopped(42)); + assert_eq!(next_action(&mut actions).await, HostAction::Started(42)); + + shutdown.signal(); + task.join() + .await + .expect("session manager task") + .expect("session manager result"); + } + // oracle: mutant a transient lookup failure during relaunch leaves the session Ready without another retry. #[tokio::test] async fn relaunch_lookup_failure_is_retried_without_another_service_event() { @@ -1165,6 +1391,24 @@ mod tests { assert!(ctx.should_start_session(&session, SessionReadinessEvent::Logon)); } + /// Start retries use the existing exponential backoff and stop after the configured failure bound. + // oracle: mutant prelaunch recovery retries forever or skips its exponential backoff. + #[test] + fn prelaunch_retries_are_bounded_until_a_new_readiness_event() { + let session = Session::new(1); + let mut ctx = SessionManagerCtx::default(); + ctx.register_session(&session, SessionKind::Remote, SessionReadiness::WaitingForLogon); + let retry_id = ctx.begin_start_retry(&session).expect("session is registered"); + + assert_eq!(ctx.retry_failed_start(1, retry_id), Some(Duration::from_secs(2))); + assert_eq!(ctx.retry_failed_start(1, retry_id), Some(Duration::from_secs(4))); + assert_eq!(ctx.retry_failed_start(1, retry_id), Some(Duration::from_secs(8))); + assert_eq!(ctx.retry_failed_start(1, retry_id), Some(Duration::from_secs(16))); + assert_eq!(ctx.retry_failed_start(1, retry_id), None); + assert!(!ctx.should_retry_start(1, retry_id)); + assert!(ctx.should_start_session(&session, SessionReadinessEvent::Logon)); + } + #[test] fn new_user_session_waits_for_logon() { assert!(SessionReadiness::WaitingForLogon.is_satisfied_by(SessionReadinessEvent::Logon)); diff --git a/devolutions-session/src/dvc/io.rs b/devolutions-session/src/dvc/io.rs index dfb2299da4..1573109807 100644 --- a/devolutions-session/src/dvc/io.rs +++ b/devolutions-session/src/dvc/io.rs @@ -191,9 +191,10 @@ const INBOUND_RETRY_INTERVAL_MS: u32 = 10; /// Longest time without a write while decoded messages are held back, on a channel with heartbeats enabled. /// /// No read is pending while messages are held back, so only a write can observe a closed channel. -/// Without this probe, a client lost during stdin backpressure goes unnoticed until the next periodic heartbeat. -/// A client that disabled heartbeats gets no probe, so its loss stays unnoticed while messages are held back. +/// Without inbound progress, a probe or timeout is needed to observe a lost client. const BACKLOG_PROBE_INTERVAL: Duration = Duration::from_secs(1); +/// Maximum time a disabled-heartbeat channel may remain without progress while messages are held back. +const BACKLOG_STALL_TIMEOUT: Duration = Duration::from_secs(30); /// Overlapped IO state of one open DVC channel. /// @@ -212,6 +213,8 @@ struct DvcIo { /// /// No read is issued while this is not empty, which bounds it to the messages of one read. inbound: VecDeque>, + backlog_stall_timeout: Duration, + inbound_blocked_since: Option, write_buffer: Vec, write_overlapped: OVERLAPPED, @@ -246,6 +249,8 @@ impl DvcIo { read_pending: false, message_dissector: NowMessageDissector::default(), inbound: VecDeque::new(), + backlog_stall_timeout: BACKLOG_STALL_TIMEOUT, + inbound_blocked_since: None, write_buffer: Vec::new(), write_overlapped: OVERLAPPED { hEvent: write_event.raw(), @@ -271,18 +276,31 @@ impl DvcIo { if !self.read_pending { self.start_read()?; } - } else if progress.heartbeats_enabled() - && !self.write_pending - && self.last_write_started.elapsed() >= BACKLOG_PROBE_INTERVAL - { - // A heartbeat is the only message the server may send unprompted, and only when the client enabled - // heartbeats; NOW clients take one at any time, since they only watch for missing ones. - // UNTESTED: the probe must wait for any pending write, because `start_write` replaces the buffer the - // OS is still sending, and must stay spaced by `BACKLOG_PROBE_INTERVAL` so a held-back channel is not - // flooded; when changing this condition, check both still hold. - trace!("Probing the DVC channel while inbound messages are held back"); - self.start_write(&NowChannelHeartbeatMsg::default().into()) - .context("probing the DVC channel while inbound messages are held back")?; + } else { + if !progress.heartbeats_enabled() + && self + .inbound_blocked_since + .is_some_and(|since| since.elapsed() >= self.backlog_stall_timeout) + { + anyhow::bail!( + "inbound DVC messages remained backpressured for {:?}", + self.backlog_stall_timeout + ); + } + + if progress.heartbeats_enabled() + && !self.write_pending + && self.last_write_started.elapsed() >= BACKLOG_PROBE_INTERVAL + { + // A heartbeat is the only message the server may send unprompted, and only when the client + // enabled heartbeats; NOW clients take one at any time, since they only watch for missing ones. + // UNTESTED: the probe must wait for any pending write, because `start_write` replaces the buffer + // the OS is still sending, and must stay spaced by `BACKLOG_PROBE_INTERVAL` so a held-back + // channel is not flooded; when changing this condition, check both still hold. + trace!("Probing the DVC channel while inbound messages are held back"); + self.start_write(&NowChannelHeartbeatMsg::default().into()) + .context("probing the DVC channel while inbound messages are held back")?; + } } // The stop event comes first so that it wins over a busy channel. @@ -398,8 +416,9 @@ impl DvcIo { fn forward_inbound(&mut self, read_tx: &Sender>) -> anyhow::Result<()> { while let Some(message) = self.inbound.pop_front() { match read_tx.try_send(message) { - Ok(()) => {} + Ok(()) => self.inbound_blocked_since = None, Err(TrySendError::Full(message)) => { + self.inbound_blocked_since.get_or_insert_with(Instant::now); trace!(pending = self.inbound.len() + 1, "DVC processing queue is full"); self.inbound.push_front(message); break; @@ -718,6 +737,20 @@ mod tests { } fn run_dvc_io_with_heartbeats(server: usize, read_queue_capacity: usize, heartbeats_enabled: bool) -> RunningDvcIo { + run_dvc_io_with_timeout( + server, + read_queue_capacity, + heartbeats_enabled, + super::BACKLOG_STALL_TIMEOUT, + ) + } + + fn run_dvc_io_with_timeout( + server: usize, + read_queue_capacity: usize, + heartbeats_enabled: bool, + backlog_stall_timeout: Duration, + ) -> RunningDvcIo { let (write_tx, write_rx) = winapi_signaled_mpsc_channel().expect("create the write queue"); let (read_tx, read_rx) = mpsc::channel(read_queue_capacity); let stop_event = Event::new_unnamed().expect("create the stop event"); @@ -729,6 +762,7 @@ mod tests { // SAFETY: The handle was opened by `dvc_pipe`, which gave up ownership of it. let file = unsafe { Owned::new(HANDLE(server as *mut _)) }; let mut io = DvcIo::new(file)?; + io.backlog_stall_timeout = backlog_stall_timeout; io.serve(write_rx, &read_tx, &thread_stop_event, &progress) }); @@ -986,6 +1020,61 @@ mod tests { running.stop().expect("the loop stops cleanly"); } + /// The disabled-heartbeat backlog timeout remains at the chosen 30-second recovery limit. + // oracle: mutant the backlog timeout changes away from 30 seconds. + #[test] + fn disabled_heartbeat_backlog_timeout_is_thirty_seconds() { + assert_eq!(super::BACKLOG_STALL_TIMEOUT, Duration::from_secs(30)); + } + + /// A blocked stdin sender and full processing queue cannot hide a closed DVC when heartbeats are disabled. + // oracle: mutant disabled-heartbeat backpressure can stall indefinitely after peer closure. + #[tokio::test(flavor = "multi_thread")] + async fn closed_channel_with_disabled_heartbeats_ends_saturated_backlog() { + let (server, client) = dvc_pipe(); + let running = run_dvc_io_with_timeout(server, 1, false, Duration::from_secs(1)); + let RunningDvcIo { + write_tx, + mut read_rx, + stop_event: _, + thread, + } = running; + let (stdin_tx, _stdin_rx) = mpsc::channel(1); + stdin_tx.try_send(()).expect("fill the stdin queue"); + let (blocked_tx, blocked_rx) = tokio::sync::oneshot::channel(); + let processing = tokio::spawn(async move { + let message = read_rx.recv().await.expect("first DVC message reaches processing"); + blocked_tx.send(message).expect("test is waiting for the first message"); + stdin_tx.send(()).await.expect("stdin queue remains open"); + }); + + write_pdu(&client, &encoded(&exec_data(1, vec![0; 16]))); + blocked_rx.await.expect("processing consumes the first message"); + write_pdu(&client, &encoded(&exec_data(2, vec![0; 16]))); + write_pdu(&client, &encoded(&exec_data(3, vec![0; 16]))); + + tokio::time::sleep(Duration::from_millis(100)).await; + drop(client); + + let deadline = Instant::now() + TEST_TIMEOUT; + while !thread.is_finished() { + assert!(Instant::now() < deadline, "the stalled saturated DVC did not end"); + std::thread::sleep(Duration::from_millis(5)); + } + + let error = thread + .join() + .expect("the DVC IO loop does not panic") + .expect_err("a stalled saturated channel ends with an error"); + assert!( + format!("{error:#}").contains("remained backpressured"), + "unexpected error: {error:#}" + ); + processing.abort(); + let _ = processing.await; + drop(write_tx); + } + /// Stopping with a read and a write in flight must cancel both and return. // oracle: mutant stopping with IO in flight hangs or leaves the IO pending #[test] diff --git a/devolutions-session/src/dvc/process.rs b/devolutions-session/src/dvc/process.rs index 97a02fa543..de3eeebf45 100644 --- a/devolutions-session/src/dvc/process.rs +++ b/devolutions-session/src/dvc/process.rs @@ -1,4 +1,7 @@ use std::collections::HashMap; +use std::os::windows::io::AsRawHandle as _; +use std::thread::JoinHandle; +use std::time::{Duration, Instant}; use now_proto_pdu::{NowExecDataStreamKind, NowStatusError}; use tokio::sync::mpsc::{Receiver, Sender}; @@ -10,10 +13,11 @@ use win_api_wrappers::security::attributes::SecurityAttributesInit; use win_api_wrappers::thread::Thread; use win_api_wrappers::utils::{Pipe, WideString}; use windows::Win32::Foundation::{ - ERROR_BROKEN_PIPE, ERROR_HANDLE_EOF, GetLastError, LPARAM, WAIT_EVENT, WAIT_OBJECT_0, WPARAM, + ERROR_BROKEN_PIPE, ERROR_HANDLE_EOF, ERROR_NOT_FOUND, GetLastError, HANDLE, LPARAM, WAIT_EVENT, WAIT_OBJECT_0, + WPARAM, }; use windows::Win32::Storage::FileSystem::{ReadFile, WriteFile}; -use windows::Win32::System::IO::{GetOverlappedResult, OVERLAPPED}; +use windows::Win32::System::IO::{CancelSynchronousIo, GetOverlappedResult, OVERLAPPED}; use windows::Win32::System::JobObjects::{ AssignProcessToJobObject, CreateJobObjectW, JOB_OBJECT_LIMIT_KILL_ON_JOB_CLOSE, JOBOBJECT_BASIC_LIMIT_INFORMATION, JOBOBJECT_EXTENDED_LIMIT_INFORMATION, JobObjectExtendedLimitInformation, SetInformationJobObject, @@ -550,6 +554,60 @@ fn write_all(pipe: &Pipe, mut bytes: &[u8]) -> anyhow::Result<()> { Ok(()) } +const STDIN_WRITER_STOP_TIMEOUT: Duration = Duration::from_secs(2); + +struct StdinWriter { + sender: Option>, + thread: Option>, +} + +impl StdinWriter { + fn stop(&mut self) -> anyhow::Result<()> { + drop(self.sender.take()); + + let Some(thread) = self.thread.take() else { + return Ok(()); + }; + + let deadline = Instant::now() + STDIN_WRITER_STOP_TIMEOUT; + while !thread.is_finished() && Instant::now() < deadline { + // SAFETY: The join handle owns this valid thread handle until it is dropped. + if let Err(error) = unsafe { CancelSynchronousIo(HANDLE(thread.as_raw_handle() as *mut _)) } + && error.code() != ERROR_NOT_FOUND.to_hresult() + { + warn!(%error, "Failed to cancel synchronous process stdin write"); + } + + std::thread::sleep(Duration::from_millis(10)); + } + + if thread.is_finished() { + if thread.join().is_err() { + anyhow::bail!("process stdin writer thread panicked"); + } + return Ok(()); + } + + // UNTESTED: A writer that does not stop remains detached with its pipe and write buffer alive, because + // freeing either while WriteFile is pending would be unsafe. When changing this timeout, check that cleanup + // remains bounded and the pending write's memory stays owned. + error!( + timeout = ?STDIN_WRITER_STOP_TIMEOUT, + "Process stdin writer did not stop after cancellation" + ); + drop(thread); + anyhow::bail!("process stdin writer did not stop within {STDIN_WRITER_STOP_TIMEOUT:?}") + } +} + +impl Drop for StdinWriter { + fn drop(&mut self) { + if let Err(error) = self.stop() { + error!(%error, "Failed to stop process stdin writer"); + } + } +} + /// Builder for process execution session. pub struct WinApiProcessBuilder { executable: String, @@ -672,16 +730,19 @@ impl WinApiProcessBuilder { let (input_event_tx, input_event_rx) = winapi_signaled_mpsc_channel()?; let mut process_ctx = process_ctx; - let stdin_tx = match process_ctx.stdin_write_pipe.take() { + let stdin_writer = match process_ctx.stdin_write_pipe.take() { Some(pipe) => { let (stdin_tx, stdin_rx) = bounded_mpsc_channel()?; let encoder = InputEncoder::new(encoding); - std::thread::Builder::new() + let thread = std::thread::Builder::new() .name(format!("process-{session_id}-stdin")) .spawn(move || write_stdin(session_id, pipe, encoder, stdin_rx))?; - Some(stdin_tx) + Some(StdinWriter { + sender: Some(stdin_tx), + thread: Some(thread), + }) } None => None, }; @@ -708,7 +769,7 @@ impl WinApiProcessBuilder { Ok(Some(WinApiProcess { input_event_tx, - stdin_tx, + stdin_writer, join_handle, _temp_files: temp_files, })) @@ -950,8 +1011,8 @@ fn prepare_process_with_io_redirection( pub struct WinApiProcess { input_event_tx: WinapiSignaledSender, /// `None` without IO redirection. - stdin_tx: Option>, - join_handle: std::thread::JoinHandle<()>, + stdin_writer: Option, + join_handle: JoinHandle<()>, _temp_files: Vec, } @@ -980,7 +1041,11 @@ impl WinApiProcess { /// read its stdin until its output is drained. /// Input for a process that no longer reads stdin is discarded. pub fn send_stdin(&self, data: Vec, last: bool) -> impl Future + Send + 'static { - let stdin_tx = self.stdin_tx.clone(); + let stdin_tx = self + .stdin_writer + .as_ref() + .and_then(|writer| writer.sender.as_ref()) + .cloned(); async move { let Some(stdin_tx) = stdin_tx else { @@ -1071,4 +1136,31 @@ mod tests { usize::try_from(INPUT_LINES).expect("u32 fits into usize") ); } + + /// Dropping an attached execution must cancel a synchronous stdin write blocked by a child that does not read. + // oracle: mutant dropping an execution leaves its synchronous stdin writer blocked. + #[tokio::test(flavor = "multi_thread")] + async fn dropping_process_stops_a_blocked_stdin_writer() { + const SESSION_ID: u32 = 1; + + let (io_notification_tx, _io_notification_rx) = tokio::sync::mpsc::channel(100); + let job = ProcessJob::new().expect("create job"); + let process = WinApiProcessBuilder::new("cmd.exe") + .with_command_line("/d /c ping -n 600 127.0.0.1 > nul") + .with_io_redirection(true) + .run(SESSION_ID, io_notification_tx, &job) + .expect("start cmd.exe"); + + process.send_stdin(vec![b'x'; 1024 * 1024], false).await; + std::thread::sleep(Duration::from_millis(100)); + + let started_at = Instant::now(); + drop(process); + assert!( + started_at.elapsed() < STDIN_WRITER_STOP_TIMEOUT / 2, + "dropping the process did not stop the blocked stdin writer promptly" + ); + + drop(job); + } }