From 90affb02b861c295180bb416decc602b32af6a58 Mon Sep 17 00:00:00 2001 From: Steve Brown Date: Sat, 24 Oct 2026 01:55:53 -0400 Subject: [PATCH] fix(runtime): reject noisy ONNX sessions and quiet default diagnostics --- docs/book/src/config/embedding.md | 21 +++++ src/index/embedder.rs | 3 +- src/index/embedder/runtime.rs | 9 +- src/main.rs | 15 ++- src/runtime_check.rs | 150 ++++++++++++++++++++++++++++++ 5 files changed, 188 insertions(+), 10 deletions(-) create mode 100644 src/runtime_check.rs diff --git a/docs/book/src/config/embedding.md b/docs/book/src/config/embedding.md index 36203811..3477be2d 100644 --- a/docs/book/src/config/embedding.md +++ b/docs/book/src/config/embedding.md @@ -44,3 +44,24 @@ Controls contextual embedding, where chunks are embedded with surrounding source - The embedding model is downloaded automatically on first run and cached in `~/.cache/bobbin/models/`. - Contextual embedding enriches each chunk with surrounding lines before computing its vector, improving search relevance at the cost of slightly longer indexing time. - Increasing `batch_size` may improve indexing throughput but uses more memory. + +## Native runtime validation + +Before loading a local ONNX model, Bobbin validates session creation in a +bounded child process. This adds one model-load check per model/runtime pair +in a process. The check does not download libraries or activate CUDA. + +Some system builds of ONNX Runtime link an ONNX library with static schema +registration enabled. Creating a session then registers the schemas again, +producing hundreds of native `Schema error` messages even when session creation +returns success. This packaging interaction is also tracked in +[the ONNX Runtime ecosystem](https://github.com/microsoft/vcpkg/issues/49060). +Bobbin rejects that runtime with one diagnostic rather than claiming healthy +semantic retrieval. Keyword search does not require an embedding runtime. +Use a compatible release-bundled runtime, or set `ORT_DYLIB_PATH` to one; +Bobbin does not replace a system library or silently turn semantic search into +keyword search. + +Normal CLI logging defaults to warnings. `RUST_LOG` remains an explicit logging +override; dependency INFO diagnostics, which can contain absolute index paths, +are no longer printed by default. diff --git a/src/index/embedder.rs b/src/index/embedder.rs index a00516d1..9f337819 100644 --- a/src/index/embedder.rs +++ b/src/index/embedder.rs @@ -360,6 +360,7 @@ impl OnnxEmbedder { // Auto-resolve ONNX Runtime library at well-known system paths. // The `load-dynamic` ort feature reads ORT_DYLIB_PATH at first use. auto_resolve_ort_dylib(use_gpu); + crate::runtime_check::validate(model_path)?; let mut builder = Session::builder().map_err(|e| { let hint = if std::env::var("ORT_DYLIB_PATH").is_err() { @@ -397,7 +398,7 @@ impl OnnxEmbedder { .map_err(|e| { anyhow::anyhow!( "Failed to load ONNX model from {}: {}", - model_path.display(), + model_path.file_name().unwrap_or_default().to_string_lossy(), e ) })?; diff --git a/src/index/embedder/runtime.rs b/src/index/embedder/runtime.rs index 3cc2fff1..f4c6df0d 100644 --- a/src/index/embedder/runtime.rs +++ b/src/index/embedder/runtime.rs @@ -46,7 +46,7 @@ pub(crate) fn auto_resolve_ort_dylib(prefer_gpu: bool) { if prefer_gpu && has_cuda { set_ort_env(candidate, dir); - eprintln!("auto-detected GPU ONNX Runtime at {}", candidate); + tracing::debug!("auto-detected GPU ONNX Runtime"); return; } if best_cpu.is_none() { @@ -59,12 +59,9 @@ pub(crate) fn auto_resolve_ort_dylib(prefer_gpu: bool) { let dir = Path::new(cpu_path).parent().unwrap(); set_ort_env(cpu_path, dir); if prefer_gpu { - eprintln!( - "warning: GPU requested but no CUDA ONNX Runtime found, using CPU at {}", - cpu_path - ); + eprintln!("warning: GPU requested but no CUDA ONNX Runtime found, using CPU"); } else { - eprintln!("auto-detected ONNX Runtime at {}", cpu_path); + tracing::debug!("auto-detected CPU ONNX Runtime"); } } } diff --git a/src/main.rs b/src/main.rs index 98d1a19d..6081057b 100644 --- a/src/main.rs +++ b/src/main.rs @@ -1,4 +1,4 @@ -use anyhow::Result; +use anyhow::{Context, Result}; use clap::Parser; pub mod access; @@ -22,6 +22,7 @@ mod operational_metrics; pub mod plate; pub mod reactions; mod read_path; +mod runtime_check; mod search; mod storage; pub mod tags; @@ -203,6 +204,13 @@ mod ort_loader_tests { } fn main() -> Result<()> { + let mut args = std::env::args_os().skip(1); + if args.next().as_deref() == Some(std::ffi::OsStr::new(runtime_check::PROBE)) { + let model = args.next().context("ONNX validation requires a model")?; + anyhow::ensure!(args.next().is_none(), "Unexpected ONNX validation arguments"); + ensure_ort_dylib(); + return runtime_check::run_probe(std::path::Path::new(&model)); + } let cli = Cli::parse(); cli.prepare_gpu()?; ensure_ort_dylib(); @@ -214,8 +222,9 @@ async fn run(cli: Cli) -> Result<()> { tracing_subscriber::fmt() .with_writer(std::io::stderr) .with_env_filter( - tracing_subscriber::EnvFilter::from_default_env() - .add_directive(tracing::Level::INFO.into()), + tracing_subscriber::EnvFilter::builder() + .with_default_directive(tracing::Level::WARN.into()) + .from_env_lossy(), ) .init(); diff --git a/src/runtime_check.rs b/src/runtime_check.rs new file mode 100644 index 00000000..de35bde4 --- /dev/null +++ b/src/runtime_check.rs @@ -0,0 +1,150 @@ +//! Validate native model loading in isolation before committing it to this process. +//! Some system ONNX builds register their schemas twice when a session is created. +//! Those messages bypass ORT logging entirely (C++ stderr), so a logger cannot fix +//! them. A runtime producing them is rejected, never presented as healthy. +use anyhow::{bail, Context, Result}; +use std::io::{Read, Seek, SeekFrom}; +use std::path::{Path, PathBuf}; +use std::process::{Child, Command, Stdio}; +use std::sync::{Mutex, OnceLock}; +use std::time::{Duration, Instant}; + +// Reap on every error path, including a failed poll or diagnostic-file read. +struct ProbeChild(Child); +impl Drop for ProbeChild { + fn drop(&mut self) { + let _ = self.0.kill(); + let _ = self.0.wait(); + } +} + +pub const PROBE: &str = "--internal-check-onnx-session"; + +/// Runs before CLI preparation: no downloads, GPU probe, indexing or live writes. +pub fn run_probe(model: &Path) -> Result<()> { + let _session = ort::session::Session::builder()? + .with_intra_threads(1)? + .commit_from_file(model)?; + Ok(()) +} + +fn diagnostic_failure(success: bool, stderr: &[u8]) -> Option<&'static str> { + if String::from_utf8_lossy(stderr).contains("Schema error: Trying to register schema") { + Some("ONNX runtime rejected: duplicate schema registration; use a compatible bundled runtime via ORT_DYLIB_PATH") + } else if !success { + Some("ONNX runtime could not load the model; check the model and ORT_DYLIB_PATH") + } else { + None + } +} + +pub fn validate(model: &Path) -> Result<()> { + // Cache successes only. A failed runtime must never earn a usable receipt. + static CHECKED: OnceLock)>>> = OnceLock::new(); + let key = (model.to_path_buf(), std::env::var_os("ORT_DYLIB_PATH")); + let mut checked = CHECKED + .get_or_init(Default::default) + .lock() + .map_err(|_| anyhow::anyhow!("ONNX validation state unavailable"))?; + if checked.contains(&key) { + return Ok(()); + } + let mut command = Command::new(std::env::current_exe()?); + command.arg(PROBE).arg(model); + check_command(command, Duration::from_secs(30), 1024 * 1024)?; + checked.push(key); + Ok(()) +} + +fn check_command(mut command: Command, deadline: Duration, limit: u64) -> Result<()> { + let mut diagnostics = tempfile::tempfile().context("Cannot prepare ONNX validation")?; + let mut child = ProbeChild( + command + .stdin(Stdio::null()) + .stdout(Stdio::null()) + .stderr(diagnostics.try_clone()?) + .spawn() + .context("Cannot start ONNX validation")?, + ); + let start = Instant::now(); + let status = loop { + if let Some(status) = child.0.try_wait()? { + break status; + } + if start.elapsed() > deadline || diagnostics.metadata()?.len() > limit { + let _ = child.0.kill(); + let _ = child.0.wait(); + bail!("ONNX validation exceeded its resource bound; semantic model unavailable"); + } + std::thread::sleep(Duration::from_millis(10)); + }; + diagnostics.seek(SeekFrom::Start(0))?; + let mut stderr = Vec::new(); + diagnostics.take(limit + 1).read_to_end(&mut stderr)?; + if stderr.len() as u64 > limit { + bail!("ONNX validation exceeded its diagnostic bound; semantic model unavailable"); + } + if let Some(message) = diagnostic_failure(status.success(), &stderr) { + bail!("{message}"); + } + // Unknown native diagnostics remain visible as one notice, never as a false + // claim that the runtime was silent. Debug diagnostics are explicitly opt-in. + if !stderr.is_empty() { + eprintln!("warning: ONNX runtime validation emitted diagnostics"); + tracing::debug!(diagnostics = %String::from_utf8_lossy(&stderr), "ONNX validation details"); + } + Ok(()) +} + +#[cfg(test)] +mod tests { + #[test] + #[cfg(unix)] + fn child_success_does_not_hide_native_schema_failure() { + let mut cmd = std::process::Command::new("sh"); + cmd.args([ + "-c", + "printf 'Schema error: Trying to register schema with name Abs\n' >&2", + ]); + let err = super::check_command(cmd, std::time::Duration::from_secs(2), 4096).unwrap_err(); + assert!(err.to_string().contains("duplicate schema")); + assert!(!err.to_string().contains("name Abs")); + let mut control = std::process::Command::new("sh"); + control.args(["-c", "exit 0"]); + super::check_command(control, std::time::Duration::from_secs(2), 4096).unwrap(); + } + + #[test] + #[cfg(unix)] + fn child_failure_and_diagnostic_overflow_remain_errors() { + for script in [ + "printf 'cannot read /private/model.onnx' >&2; exit 7", + "printf '%0800d' 0 >&2", + ] { + let mut cmd = std::process::Command::new("sh"); + cmd.args(["-c", script]); + let err = super::check_command(cmd, std::time::Duration::from_secs(2), 64).unwrap_err(); + assert!(!err.to_string().contains("/private")); + } + } + + #[test] + #[cfg(unix)] + fn timed_out_child_is_killed_and_reaped() { + let dir = tempfile::tempdir().unwrap(); + let pidfile = dir.path().join("pid"); + let mut cmd = std::process::Command::new("sh"); + cmd.args(["-c", "printf '%s' $$ > \"$1\"; exec sleep 10", "probe"]) + .arg(&pidfile); + let start = std::time::Instant::now(); + assert!(super::check_command(cmd, std::time::Duration::from_secs(1), 4096).is_err()); + assert!(start.elapsed() < std::time::Duration::from_secs(5)); + let pid = std::fs::read_to_string(pidfile).unwrap(); + assert!(!std::process::Command::new("kill") + .args(["-0", &pid]) + .output() + .unwrap() + .status + .success()); + } +}