Skip to content

Commit bfca0e9

Browse files
committed
Merge: plugin-host handshake observability + transient (re)spawn retry (v0.6.33)
2 parents a21e0c2 + a68844a commit bfca0e9

6 files changed

Lines changed: 236 additions & 27 deletions

File tree

Cargo.lock

Lines changed: 1 addition & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

crates/orchestrator-cli/Cargo.toml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
[package]
22
name = "orchestrator-cli"
3-
version = "0.6.32"
3+
version = "0.6.33"
44
edition = "2021"
55
license = "Elastic-2.0"
66
default-run = "animus"

crates/orchestrator-config/src/workflow_config/config_source_client.rs

Lines changed: 53 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -280,26 +280,54 @@ where
280280
F: FnMut(PluginHost) -> Fut,
281281
Fut: Future<Output = std::result::Result<T, ResidentCallError>>,
282282
{
283-
let (host, generation) = acquire_resident_host(&plugin, project_root).await?;
284-
match call(host).await {
285-
Ok(value) => Ok(value),
286-
Err(ResidentCallError::Other(err)) => Err(err),
287-
Err(ResidentCallError::Death(err)) => {
288-
// The warm host is presumed dead: reap it (only if it's still the
289-
// generation that failed — a concurrent caller may have already
290-
// replaced it), re-spawn once, retry.
291-
drop_resident_host_if_current(project_root, generation).await;
292-
let (host, _gen) = acquire_resident_host(&plugin, project_root).await?;
293-
match call(host).await {
294-
Ok(value) => Ok(value),
295-
Err(ResidentCallError::Other(retry_err)) => Err(retry_err),
296-
Err(ResidentCallError::Death(retry_err)) => Err(retry_err.context(format!(
297-
"config_source plugin {} still failing after one re-spawn (first error: {err})",
298-
plugin.name
299-
))),
283+
// Acquire (spawning if absent) + call, retrying transient spawn/handshake or
284+
// death-like failures with backoff. This covers BOTH the cold-start path (no
285+
// cached host yet — the first config load after daemon start) AND a warm host
286+
// dying mid-flight: a transient cold DB connect / fork / handshake pressure
287+
// self-heals rather than surfacing as a hard config error. Structured
288+
// ("Other") call errors propagate immediately — a genuine backend fault is
289+
// not retried. `attempt == 0` runs immediately; later attempts reap the last
290+
// generation and back off first.
291+
const RESPAWN_BACKOFF_MS: [u64; 2] = [150, 600];
292+
let mut generation: Option<u64> = None;
293+
let mut first_err_msg: Option<String> = None;
294+
let mut last_err: Option<anyhow::Error> = None;
295+
for attempt in 0..=RESPAWN_BACKOFF_MS.len() {
296+
if attempt > 0 {
297+
if let Some(gen) = generation {
298+
drop_resident_host_if_current(project_root, gen).await;
299+
}
300+
tokio::time::sleep(std::time::Duration::from_millis(RESPAWN_BACKOFF_MS[attempt - 1])).await;
301+
}
302+
let (host, gen) = match acquire_resident_host(&plugin, project_root).await {
303+
Ok(pair) => pair,
304+
Err(spawn_err) => {
305+
if first_err_msg.is_none() {
306+
first_err_msg = Some(format!("{spawn_err}"));
307+
}
308+
last_err = Some(spawn_err);
309+
continue;
310+
}
311+
};
312+
generation = Some(gen);
313+
match call(host).await {
314+
Ok(value) => return Ok(value),
315+
Err(ResidentCallError::Other(err)) => return Err(err),
316+
Err(ResidentCallError::Death(err)) => {
317+
if first_err_msg.is_none() {
318+
first_err_msg = Some(format!("{err}"));
319+
}
320+
last_err = Some(err);
300321
}
301322
}
302323
}
324+
let last_err = last_err.unwrap_or_else(|| anyhow!("config_source plugin {} unavailable", plugin.name));
325+
Err(last_err.context(format!(
326+
"config_source plugin {} still failing after {} attempts (first error: {})",
327+
plugin.name,
328+
RESPAWN_BACKOFF_MS.len() + 1,
329+
first_err_msg.unwrap_or_default()
330+
)))
303331
}
304332

305333
/// Return a clone of the resident host for `project_root` plus its generation
@@ -323,7 +351,14 @@ async fn acquire_resident_host(plugin: &DiscoveredPlugin, project_root: &Path) -
323351
// Spawn + handshake OUTSIDE the map lock so a slow spawn for one root never
324352
// blocks another root's cache lookups.
325353
let host = spawn_config_source_host(plugin).await?;
326-
host.handshake().await.with_context(|| format!("handshake with config_source plugin {}", plugin.name))?;
354+
// Tear the half-started child down on a handshake failure rather than leaking
355+
// it (its reader task would otherwise keep the process + slot alive). The
356+
// retry loop in `with_resident_host` re-spawns cleanly instead of piling up
357+
// orphaned config_source processes under transient handshake failures.
358+
if let Err(err) = host.handshake().await {
359+
let _ = host.clone().shutdown().await;
360+
return Err(err).with_context(|| format!("handshake with config_source plugin {}", plugin.name));
361+
}
327362

328363
// Decide the outcome WITHOUT holding the std Mutex across an `.await`: take
329364
// any host that needs reaping out under the lock, drop the guard, then await

crates/orchestrator-plugin-host/Cargo.toml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ semver = "1"
2525
sha2 = "0.10"
2626
thiserror = "2"
2727
toml = "0.8"
28+
regex = "1"
2829
serde = { version = "1", features = ["derive"] }
2930
serde_json = "1"
3031
serde_yaml = "0.9"
@@ -39,7 +40,6 @@ tempfile = "3"
3940
# Kept as a dev-dep so we don't pull syn into the production binary.
4041
syn = { version = "2", features = ["full", "extra-traits", "parsing"] }
4142
proc-macro2 = "1"
42-
regex = "1"
4343
animus-session-backend = { workspace = true }
4444

4545
[lints]

crates/orchestrator-plugin-host/src/host.rs

Lines changed: 146 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,80 @@ const WRITE_FRAME_TIMEOUT: Duration = Duration::from_secs(30);
6969
/// down and every awaiter observes [`HostError::ConnectionLost`].
7070
const READER_BUFFER_CAP: usize = 8 * 1024 * 1024;
7171

72+
/// How many trailing stderr lines to retain per plugin for failure diagnostics.
73+
const STDERR_TAIL_CAP: usize = 40;
74+
75+
/// Max bytes retained per captured stderr line (bounds memory for a plugin that
76+
/// emits pathologically long lines; the tail is diagnostics, not a full log).
77+
const MAX_STDERR_LINE_LEN: usize = 512;
78+
79+
/// Truncate `line` to at most [`MAX_STDERR_LINE_LEN`] bytes on a char boundary,
80+
/// appending an ellipsis when clipped. Keeps the ring buffer bounded.
81+
fn clip_stderr_line(line: String) -> String {
82+
if line.len() <= MAX_STDERR_LINE_LEN {
83+
return line;
84+
}
85+
let mut end = MAX_STDERR_LINE_LEN;
86+
while end > 0 && !line.is_char_boundary(end) {
87+
end -= 1;
88+
}
89+
format!("{}…", &line[..end])
90+
}
91+
92+
/// Matches a credential label anywhere in a stderr line, tolerating word breaks
93+
/// (`api key`, `api_key`, `api-key`) and any following separator/spacing. Once
94+
/// matched, everything from the label to end-of-line is masked, so the value is
95+
/// redacted regardless of how it is delimited or whether it spans tokens (PEM
96+
/// blob, JSON, `password = hunter2`, `Authorization: Bearer <tok>`).
97+
fn secret_marker_regex() -> &'static regex::Regex {
98+
static RE: std::sync::OnceLock<regex::Regex> = std::sync::OnceLock::new();
99+
RE.get_or_init(|| {
100+
regex::Regex::new(
101+
r"(?i)(pass(?:word|wd)?|pwd|secret|token|api[ _-]?key|access[ _-]?key|client[ _-]?secret|authorization|credential|private[ _-]?key|session[ _-]?key|bearer|basic)",
102+
)
103+
.expect("valid secret-marker regex")
104+
})
105+
}
106+
107+
/// Redact credentials from a stderr line before it is surfaced in a user-visible
108+
/// error, so secrets stay in operator logs and do not leak into RPC/CLI errors.
109+
///
110+
/// Two passes: (1) mask the password of any `scheme://user:pass@host` connection
111+
/// string (a Postgres plugin echoing its DATABASE_URL on a connect failure), even
112+
/// when no credential *label* is present; (2) if a credential label (`password`,
113+
/// `api key`, `Authorization`, `bearer`, ...) appears, keep the text up to and
114+
/// including the label and mask everything after it. This over-redacts the tail of
115+
/// such a line — the stderr tail is failure diagnostics, not a full log — but
116+
/// never leaks the value regardless of separator, spacing, or token spanning.
117+
fn redact_stderr_line(line: &str) -> String {
118+
let url_redacted = redact_url_userinfo(line);
119+
if let Some(m) = secret_marker_regex().find(&url_redacted) {
120+
return format!("{} ***", url_redacted[..m.end()].trim_end());
121+
}
122+
url_redacted
123+
}
124+
125+
/// Mask the password in any `scheme://user:pass@host` token: `user:***@host`.
126+
/// Uses the LAST `@` so an unescaped `@` inside the password cannot leave a
127+
/// suffix unmasked (`u:p@ss@host` -> `u:***@host`).
128+
fn redact_url_userinfo(line: &str) -> String {
129+
line.split(' ')
130+
.map(|token| {
131+
if let Some(scheme_end) = token.find("://") {
132+
let after = &token[scheme_end + 3..];
133+
if let Some(at) = after.rfind('@') {
134+
let userinfo = &after[..at];
135+
if let Some(colon) = userinfo.find(':') {
136+
return format!("{}{}:***@{}", &token[..scheme_end + 3], &userinfo[..colon], &after[at + 1..]);
137+
}
138+
}
139+
}
140+
token.to_string()
141+
})
142+
.collect::<Vec<_>>()
143+
.join(" ")
144+
}
145+
72146
/// Deadline the [`PluginHost::shutdown_transport`] flow waits for a transport
73147
/// plugin's `transport/shutdown` reply before moving on to the generic
74148
/// shutdown. Spec-compliant transports drain in-flight requests during this
@@ -541,6 +615,12 @@ pub struct PluginHostInner {
541615
/// guard and drop it eagerly after the child wait completes, ahead of the
542616
/// last `Arc` drop. In steady state nothing else touches this field.
543617
_process_slot: std::sync::Mutex<Option<BoxedProcessSlotGuard>>,
618+
/// Ring buffer of the plugin's most recent stderr lines (last
619+
/// [`STDERR_TAIL_CAP`]), captured by the stderr reader task. Surfaced in
620+
/// handshake / ConnectionLost errors so a plugin that dies during startup
621+
/// reports WHY (its stderr) instead of an opaque "connection lost". Empty
622+
/// for in-memory test hosts.
623+
stderr_tail: Arc<std::sync::Mutex<std::collections::VecDeque<String>>>,
544624
}
545625

546626
/// Single-process JSON-RPC plugin host.
@@ -722,18 +802,35 @@ impl PluginHost {
722802

723803
let stderr_plugin_name = name.clone();
724804
let stderr_sink = options.stderr_sink.clone();
805+
806+
let capacity = resolve_broadcast_capacity(options.notification_capacity, options.notification_buffer_hint);
807+
let host = Self::launch_with_slot(name, Box::new(stdout), Box::new(stdin), Some(child), capacity, process_slot);
808+
809+
// Capture the plugin's stderr into a bounded ring buffer (in addition to
810+
// the standard warn! + optional sink) so a startup/handshake failure can
811+
// report the plugin's own last words instead of a bare "connection lost".
812+
let stderr_tail = host.inner.stderr_tail.clone();
725813
tokio::spawn(async move {
726814
let mut lines = tokio::io::BufReader::new(stderr).lines();
727815
while let Ok(Some(line)) = lines.next_line().await {
728816
warn!(plugin = %stderr_plugin_name, "{}", line);
729817
if let Some(sink) = stderr_sink.as_ref() {
730818
sink(&stderr_plugin_name, &line);
731819
}
820+
if let Ok(mut buf) = stderr_tail.lock() {
821+
if buf.len() >= STDERR_TAIL_CAP {
822+
buf.pop_front();
823+
}
824+
// Redact BEFORE clipping: clipping first could split a
825+
// `scheme://user:pass@host` across the byte cutoff and defeat
826+
// the URL detector, leaking the password prefix. The raw line
827+
// still reaches operator logs above via `warn!`/`sink`.
828+
buf.push_back(clip_stderr_line(redact_stderr_line(&line)));
829+
}
732830
}
733831
});
734832

735-
let capacity = resolve_broadcast_capacity(options.notification_capacity, options.notification_buffer_hint);
736-
Ok(Self::launch_with_slot(name, Box::new(stdout), Box::new(stdin), Some(child), capacity, process_slot))
833+
Ok(host)
737834
}
738835

739836
/// Build a host from caller-supplied in-memory streams. Used by tests
@@ -829,6 +926,7 @@ impl PluginHost {
829926
reader_handle: std::sync::Mutex::new(None),
830927
alive: AtomicBool::new(true),
831928
_process_slot: std::sync::Mutex::new(process_slot),
929+
stderr_tail: Arc::new(std::sync::Mutex::new(std::collections::VecDeque::new())),
832930
});
833931

834932
let reader_inner = inner.clone();
@@ -931,6 +1029,23 @@ impl PluginHost {
9311029
///
9321030
/// Returns the plugin's [`InitializeResult`] on success and rejects on
9331031
/// protocol-version drift via [`check_protocol_compat`].
1032+
/// A short diagnostic suffix built from the plugin's captured stderr tail,
1033+
/// appended to startup/handshake failures so an opaque transport error
1034+
/// ("connection lost") carries the plugin's own last words. When the plugin
1035+
/// died without printing anything, that itself is the signal (killed by a
1036+
/// signal / OOM / exec failure).
1037+
fn stderr_tail_context(&self) -> String {
1038+
match self.inner.stderr_tail.lock() {
1039+
Ok(buf) if !buf.is_empty() => {
1040+
let tail: Vec<String> = buf.iter().rev().take(15).map(|line| redact_stderr_line(line)).collect();
1041+
let joined = tail.into_iter().rev().collect::<Vec<_>>().join("\n");
1042+
format!("; last plugin stderr:\n{joined}")
1043+
}
1044+
_ => "; plugin emitted no stderr before exit (likely killed by a signal / OOM, or an exec/fork failure)"
1045+
.to_string(),
1046+
}
1047+
}
1048+
9341049
pub async fn handshake(&self) -> Result<InitializeResult> {
9351050
const HANDSHAKE_TIMEOUT: Duration = Duration::from_secs(30);
9361051

@@ -943,7 +1058,9 @@ impl PluginHost {
9431058
let response = self
9441059
.request_raw_with_timeout("initialize", Some(serde_json::to_value(params)?), HANDSHAKE_TIMEOUT)
9451060
.await
946-
.map_err(|error| anyhow!("plugin '{}' initialize failed: {error}", self.inner.name))?;
1061+
.map_err(|error| {
1062+
anyhow!("plugin '{}' initialize failed: {error}{}", self.inner.name, self.stderr_tail_context())
1063+
})?;
9471064

9481065
if let Some(error) = response.error {
9491066
return Err(anyhow!("plugin initialize failed ({}): {}", error.code, error.message));
@@ -1508,6 +1625,32 @@ mod tests {
15081625

15091626
use super::*;
15101627

1628+
#[test]
1629+
fn redact_stderr_line_masks_credentials_without_leaking_tails() {
1630+
// URL userinfo password, even with no credential label and an '@' in it.
1631+
assert_eq!(
1632+
redact_stderr_line("connect failed postgres://user:p@ss@db:5432/x"),
1633+
"connect failed postgres://user:***@db:5432/x"
1634+
);
1635+
// Labelled secrets with assorted separators / spacing — value + rest of
1636+
// line masked, prefix kept.
1637+
assert_eq!(redact_stderr_line("db password = hunter2 for role app"), "db password ***");
1638+
assert_eq!(redact_stderr_line("using api key: sk-abc123 now"), "using api key ***");
1639+
assert_eq!(redact_stderr_line("Authorization: Bearer sk-xyz trailing"), "Authorization ***");
1640+
// Multi-token / PEM value cannot leak its tail.
1641+
assert_eq!(
1642+
redact_stderr_line("private_key=-----BEGIN KEY----- abcd -----END KEY-----"),
1643+
"private_key ***"
1644+
);
1645+
// Query-string credential in a URL without userinfo.
1646+
assert_eq!(
1647+
redact_stderr_line("cb https://h/x?client_id=a&client_secret=zzz"),
1648+
"cb https://h/x?client_id=a&client_secret ***"
1649+
);
1650+
// A line with no credential material is untouched.
1651+
assert_eq!(redact_stderr_line("could not connect to host db:5432"), "could not connect to host db:5432");
1652+
}
1653+
15111654
fn ok_initialize_response(id: Option<Value>, protocol_version: &str) -> RpcResponse {
15121655
RpcResponse::ok(
15131656
id,

crates/orchestrator-plugin-host/src/subject_router.rs

Lines changed: 34 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -451,10 +451,41 @@ impl LazyHosts {
451451
}
452452
}
453453

454-
/// Spawn + handshake a subject-backend plugin from its spec. Translates a
455-
/// spawn / handshake failure into an `RpcError` rather than panicking so a
456-
/// single broken backend fails just the route that touches it.
454+
/// Spawn + handshake a subject-backend plugin, retrying on transient
455+
/// failures (a cold DB connect, fork/handshake pressure under load) with
456+
/// backoff. Previously a single transient "connection lost" on (re)spawn
457+
/// surfaced as a hard board error; a couple of quick retries let the daemon
458+
/// self-heal instead. Backend bugs still fail fast after the attempts.
457459
async fn spawn_and_handshake(&self, spec: &SubjectPluginSpec) -> Result<PluginHost, RpcError> {
460+
const MAX_ATTEMPTS: usize = 3;
461+
// Backoff before each retry (not before the first attempt).
462+
const BACKOFF_MS: [u64; 2] = [150, 600];
463+
let mut last_err: Option<RpcError> = None;
464+
for attempt in 0..MAX_ATTEMPTS {
465+
match self.spawn_and_handshake_once(spec).await {
466+
Ok(host) => return Ok(host),
467+
Err(error) => {
468+
if let Some(delay) = BACKOFF_MS.get(attempt).copied() {
469+
tracing::warn!(
470+
plugin = %spec.name,
471+
attempt = attempt + 1,
472+
"subject_backend spawn/handshake failed ({}); retrying in {delay}ms",
473+
error.message
474+
);
475+
tokio::time::sleep(std::time::Duration::from_millis(delay)).await;
476+
}
477+
last_err = Some(error);
478+
}
479+
}
480+
}
481+
Err(last_err.unwrap_or_else(|| RpcError {
482+
code: animus_plugin_protocol::error_codes::INTERNAL_ERROR,
483+
message: format!("subject_backend plugin '{}' spawn failed after {MAX_ATTEMPTS} attempts", spec.name),
484+
data: None,
485+
}))
486+
}
487+
488+
async fn spawn_and_handshake_once(&self, spec: &SubjectPluginSpec) -> Result<PluginHost, RpcError> {
458489
let mut options =
459490
PluginSpawnOptions::for_manifest(spec.name.clone(), &spec.env_required, std::iter::empty::<String>(), None)
460491
.with_notification_buffer_hint(spec.notification_buffer_size);

0 commit comments

Comments
 (0)