fix(pam-rdp): stable acceptor certificate

packages/pam/handlers/rdp/bridge_cgo_shared.go

@@ -17,6 +17,8 @@ import (
 	"net"
 	"time"
 	"unsafe"
+
+	"github.com/rs/zerolog/log"
 )
 
 func (p *RDPProxy) HandleConnection(ctx context.Context, clientConn net.Conn) error {
@@ -83,6 +85,11 @@ func (p *RDPProxy) handleConnectionWith(ctx context.Context, clientConn net.Conn
 	case err := <-waitErr:
 		if err != nil && !errors.Is(err, ErrInvalidHandle) {
 			cancelDrain()
+			log.Error().
+				Err(err).
+				Str("sessionId", p.config.SessionID).
+				Str("target", fmt.Sprintf("%s:%d", p.config.TargetHost, p.config.TargetPort)).
+				Msg("RDP bridge session failed")
 			return fmt.Errorf("rdp proxy: session: %w", err)
 		}
 		return nil
@@ -103,12 +110,31 @@ func (b *Bridge) Wait() error {
 	case C.RDP_BRIDGE_INVALID_HANDLE:
 		return ErrInvalidHandle
 	case C.RDP_BRIDGE_SESSION_ERROR, C.RDP_BRIDGE_THREAD_PANIC:
+		if msg := b.lastError(); msg != "" {
+			return fmt.Errorf("%w: %s", ErrSessionFailed, msg)
+		}
 		return ErrSessionFailed
 	default:
 		return fmt.Errorf("rdp bridge: wait returned unexpected status %d", int32(rc))
 	}
 }
 
+// lastError returns the Rust-side failure detail recorded by Wait, or "".
+func (b *Bridge) lastError() string {
+	const bufLen = 4096
+	buf := (*C.char)(C.malloc(C.size_t(bufLen)))
+	if buf == nil {
+		return ""
+	}
+	defer C.free(unsafe.Pointer(buf))
+
+	n := C.rdp_bridge_last_error(C.uint64_t(b.handle), buf, C.size_t(bufLen))
+	if n <= 0 {
+		return ""
+	}
+	return C.GoStringN(buf, C.int(n))
+}
+
 // Cancel is idempotent and safe from any goroutine.
 func (b *Bridge) Cancel() error {
 	rc := C.rdp_bridge_cancel(C.uint64_t(b.handle))

packages/pam/handlers/rdp/native/Cargo.toml

@@ -30,6 +30,7 @@ rcgen = "0.13"
 
 anyhow = "1"
 tracing = "0.1"
+tracing-subscriber = { version = "0.3", default-features = false, features = ["fmt", "registry"] }
 
 # Bundle zlib into the .a so cross-compile linkers don't need system -lz
 # per target arch. Pulled in transitively via flate2 (winscard -> sspi).

packages/pam/handlers/rdp/native/include/rdp_bridge.h

@@ -4,6 +4,7 @@
 #ifndef INFISICAL_RDP_BRIDGE_H
 #define INFISICAL_RDP_BRIDGE_H
 
+#include <stddef.h>
 #include <stdint.h>
 
 #ifdef __cplusplus
@@ -50,6 +51,10 @@ int32_t rdp_bridge_wait(uint64_t handle);
 int32_t rdp_bridge_cancel(uint64_t handle);
 int32_t rdp_bridge_free(uint64_t handle);
 
+/* Writes the last session error into `buf` NUL-terminated and returns its
+ * length excluding the NUL. 0 means none. Truncates on a UTF-8 boundary. */
+int32_t rdp_bridge_last_error(uint64_t handle, char *buf, size_t buf_len);
+
 /* Poll return codes (distinct number space from the bridge status codes
  * above; consumed by rdp_bridge_poll_event only). */
 #define RDP_POLL_OK                   0

packages/pam/handlers/rdp/native/src/bridge.rs

@@ -4,7 +4,7 @@
 
 use std::borrow::Cow;
 use std::sync::atomic::{AtomicU64, Ordering};
-use std::sync::Arc;
+use std::sync::{Arc, OnceLock};
 use std::time::{Duration, Instant};
 
 use anyhow::{Context, Result};
@@ -80,7 +80,16 @@ async fn run_mitm_native_inner(
     // 0.23 needs an explicit provider when more than one is compiled in.
     let _ = rustls::crypto::ring::default_provider().install_default();
 
+    info!(
+        target_host = %target.host,
+        target_port = target.port,
+        has_domain = target.domain.is_some(),
+        "bridge: starting native MITM session"
+    );
+
     let acceptor_username = target.username.clone();
+    // Don't split these across runtimes: the streams they return are bound to
+    // the runtime that created them.
     let (acceptor_output, connector_output) = tokio::try_join!(
         run_acceptor_half(client_tcp, acceptor_username),
         run_connector_half(target),
@@ -582,11 +591,7 @@ async fn run_acceptor_half(
     client_tcp: TcpStream,
     username: String,
 ) -> Result<(ErasedStream, bytes::BytesMut)> {
-    let (acceptor_public_key, _cert_der, certified_key) =
-        generate_acceptor_cert().context("generate acceptor cert")?;
-    let server_tls =
-        build_acceptor_tls_config(certified_key).context("build acceptor TLS config")?;
-    let server_tls = Arc::new(server_tls);
+    let (acceptor_public_key, server_tls) = acceptor_tls_material()?;
 
     let acceptor_framed = ironrdp_tokio::TokioFramed::new(client_tcp);
     let expected_creds = AcceptorCredentials {
@@ -626,16 +631,22 @@ async fn run_acceptor_half(
     };
 
     if acceptor.should_perform_credssp() {
-        ironrdp_acceptor::accept_credssp(
+        let credssp_start = Instant::now();
+        let result = ironrdp_acceptor::accept_credssp(
             &mut acceptor_framed,
             &mut acceptor,
             &mut ReqwestNetworkClient::new(),
             ironrdp_connector::ServerName::new("infisical-rdp-bridge"),
             acceptor_public_key,
             None,
         )
-        .await
-        .context("acceptor: CredSSP")?;
+        .await;
+        let elapsed_ms = credssp_start.elapsed().as_millis();
+        match &result {
+            Ok(_) => info!(elapsed_ms, "acceptor: CredSSP exchange finished"),
+            Err(e) => warn!(elapsed_ms, error = ?e, "acceptor: CredSSP failed"),
+        }
+        result.context("acceptor: CredSSP")?;
     }
     info!("acceptor: CredSSP complete");
 
@@ -789,19 +800,26 @@ where
     .context("CredsspSequence::init")?;
 
     let mut buf = WriteBuf::new();
+    let mut round = 0usize;
 
     loop {
+        round += 1;
         let client_state: ClientState = {
             let mut generator = sequence.process_ts_request(ts_request);
+            // sspi does KDC discovery inline here and blocks the runtime thread.
+            let mut step_start = Instant::now();
             let mut state = generator.start();
+            log_sspi_step(round, "start", step_start.elapsed());
             loop {
                 match state {
                     GeneratorState::Suspended(request) => {
                         let response = network_client
                             .send(&request)
                             .await
                             .context("CredSSP network request")?;
+                        step_start = Instant::now();
                         state = generator.resume(Ok(response));
+                        log_sspi_step(round, "resume", step_start.elapsed());
                     }
                     GeneratorState::Completed(result) => {
                         break result.map_err(|e| anyhow::anyhow!("CredSSP process: {e:?}"))?;
@@ -845,6 +863,42 @@ where
     Ok(())
 }
 
+/// Past this, an sspi step is blocking the runtime thread, not just being slow.
+const SSPI_STEP_STALL_WARN: Duration = Duration::from_millis(250);
+
+fn log_sspi_step(round: usize, phase: &'static str, elapsed: Duration) {
+    if elapsed >= SSPI_STEP_STALL_WARN {
+        warn!(
+            round,
+            phase,
+            elapsed_ms = elapsed.as_millis(),
+            "connector: sspi step blocked the runtime thread"
+        );
+    }
+}
+
+type AcceptorTls = (Vec<u8>, Arc<tokio_rustls::rustls::ServerConfig>);
+
+static ACCEPTOR_TLS: OnceLock<AcceptorTls> = OnceLock::new();
+
+/// Once per process, not per session: mstsc reconnects after the certificate
+/// dialog and rejects a cert that differs from the one the user approved.
+fn acceptor_tls_material() -> Result<AcceptorTls> {
+    if let Some(existing) = ACCEPTOR_TLS.get() {
+        return Ok(existing.clone());
+    }
+    let (public_key, _cert_der, certified_key) =
+        generate_acceptor_cert().context("generate acceptor cert")?;
+    let config =
+        Arc::new(build_acceptor_tls_config(certified_key).context("build acceptor TLS config")?);
+    // Racing sessions both generate one; the first to land wins.
+    let _ = ACCEPTOR_TLS.set((public_key, config));
+    Ok(ACCEPTOR_TLS
+        .get()
+        .expect("acceptor TLS material set")
+        .clone())
+}
+
 pub(crate) fn generate_acceptor_cert() -> Result<(Vec<u8>, Vec<u8>, rcgen::CertifiedKey)> {
     use x509_cert::der::Decode;
 

packages/pam/handlers/rdp/native/src/ffi.rs

@@ -165,6 +165,8 @@ struct BridgeEntry {
     // Set once the events channel has reported closed; subsequent polls
     // short-circuit to RDP_POLL_ENDED.
     events_ended: Mutex<bool>,
+    // Set by wait() on failure; Go reads it back via rdp_bridge_last_error.
+    last_error: Mutex<Option<String>>,
 }
 
 static HANDLES: LazyLock<Mutex<HashMap<u64, BridgeEntry>>> =
@@ -212,6 +214,7 @@ fn spawn_session(
     domain: Option<String>,
     flow: SessionFlow,
 ) -> anyhow::Result<u64> {
+    crate::logging::init();
     client_tcp.set_nonblocking(true)?;
     let cancel = CancellationToken::new();
     let cancel_for_thread = cancel.clone();
@@ -256,6 +259,7 @@ fn spawn_session(
         join: Mutex::new(Some(join)),
         events_rx: Mutex::new(Some(events_rx)),
         events_ended: Mutex::new(false),
+        last_error: Mutex::new(None),
     }))
 }
 
@@ -399,17 +403,65 @@ pub extern "C" fn rdp_bridge_wait(handle: u64) -> i32 {
             }
             Ok(Err(e)) => {
                 error!(handle, error = ?e, "rdp_bridge_wait: session failed");
+                // {e:#} renders the full context chain.
+                set_last_error(handle, format!("{e:#}"));
                 RDP_BRIDGE_SESSION_ERROR
             }
             Err(_) => {
                 error!(handle, "rdp_bridge_wait: session thread panicked");
+                set_last_error(handle, "session thread panicked".to_owned());
                 RDP_BRIDGE_THREAD_PANIC
             }
         },
         None => RDP_BRIDGE_OK,
     }
 }
 
+fn set_last_error(handle: u64, message: String) {
+    let handles = HANDLES.lock().expect("HANDLES poisoned");
+    if let Some(entry) = handles.get(&handle) {
+        *entry.last_error.lock().expect("last_error poisoned") = Some(message);
+    }
+}
+
+/// Writes the last session error into `buf` as a NUL-terminated string and
+/// returns its length excluding the NUL. 0 means no error. Truncates on a
+/// UTF-8 boundary.
+///
+/// # Safety
+///
+/// `buf` must be writable for `buf_len` bytes.
+#[no_mangle]
+pub unsafe extern "C" fn rdp_bridge_last_error(
+    handle: u64,
+    buf: *mut c_char,
+    buf_len: usize,
+) -> i32 {
+    if buf.is_null() || buf_len == 0 {
+        return RDP_BRIDGE_BAD_ARG;
+    }
+    let handles = HANDLES.lock().expect("HANDLES poisoned");
+    let Some(entry) = handles.get(&handle) else {
+        return RDP_BRIDGE_INVALID_HANDLE;
+    };
+    let guard = entry.last_error.lock().expect("last_error poisoned");
+    let Some(message) = guard.as_deref() else {
+        unsafe { *buf = 0 };
+        return 0;
+    };
+
+    let mut end = message.len().min(buf_len - 1);
+    while end > 0 && !message.is_char_boundary(end) {
+        end -= 1;
+    }
+    let bytes = &message.as_bytes()[..end];
+    unsafe {
+        std::ptr::copy_nonoverlapping(bytes.as_ptr(), buf.cast::<u8>(), end);
+        *buf.add(end) = 0;
+    }
+    i32::try_from(end).unwrap_or(i32::MAX)
+}
+
 #[no_mangle]
 pub extern "C" fn rdp_bridge_cancel(handle: u64) -> i32 {
     let handles = HANDLES.lock().expect("HANDLES poisoned");

packages/pam/handlers/rdp/native/src/lib.rs

@@ -7,4 +7,5 @@ pub mod cap_filter;
 pub mod config;
 pub mod events;
 pub mod ffi;
+pub mod logging;
 pub mod rdcleanpath;