Public release release-e7c2b3ac175d

Source commit: e7c2b3ac175db426791c02779841c5df1d0ffdff

Public tree identity: sha256:4f0b7cd828932c06d56f2406788f89b2050ef56c1e1a4f76f55341d387d78e46
This commit is contained in:
Clusterflux release 2026-07-29 02:53:56 +02:00
parent 9f43c6276a
commit cfd4f19da2
16 changed files with 1386 additions and 313 deletions

View file

@ -2,7 +2,7 @@ use std::collections::{BTreeMap, BTreeSet, HashMap};
use std::io::Read;
use std::path::PathBuf;
use std::process::Stdio;
use std::sync::atomic::{AtomicBool, Ordering};
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
use std::sync::{Arc, Mutex};
use std::thread;
use std::time::{Duration, Instant};
@ -46,6 +46,40 @@ use validation::{
resolve_task_export, task_descriptors, verify_environment_digest, verify_source_snapshot,
};
#[derive(Debug)]
struct AssignmentExecutionError {
message: String,
stdout_source_bytes: u64,
stderr_source_bytes: u64,
}
impl std::fmt::Display for AssignmentExecutionError {
fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
formatter.write_str(&self.message)
}
}
impl std::error::Error for AssignmentExecutionError {}
fn execution_error_with_log_bytes(
message: impl Into<String>,
stdout_source_bytes: &AtomicU64,
stderr_source_bytes: &AtomicU64,
) -> Box<dyn std::error::Error> {
Box::new(AssignmentExecutionError {
message: message.into(),
stdout_source_bytes: stdout_source_bytes.load(Ordering::Relaxed),
stderr_source_bytes: stderr_source_bytes.load(Ordering::Relaxed),
})
}
pub(crate) fn assignment_error_log_bytes(error: &(dyn std::error::Error + 'static)) -> (u64, u64) {
error
.downcast_ref::<AssignmentExecutionError>()
.map(|error| (error.stdout_source_bytes, error.stderr_source_bytes))
.unwrap_or((0, 0))
}
pub(crate) fn run_verified_wasmtime_assignment(
args: &Args,
task: &RuntimeTask,
@ -95,6 +129,8 @@ pub(crate) fn run_verified_wasmtime_assignment(
return Err("Wasm entrypoint assignment omitted its descriptor export".into());
}
};
let command_stdout_source_bytes = Arc::new(AtomicU64::new(0));
let command_stderr_source_bytes = Arc::new(AtomicU64::new(0));
let (stdout, boundary_result) = match abi {
WasmExportAbi::EntrypointV1 | WasmExportAbi::TaskV1 => {
let invocation = WasmTaskInvocation::new(
@ -102,18 +138,28 @@ pub(crate) fn run_verified_wasmtime_assignment(
task_spec.task_instance.clone(),
task_spec.args.clone(),
);
let result = WasmtimeTaskRuntime::new()?.run_task_export_verified_with_task_host(
&module,
expected_bundle_digest,
export,
&invocation,
Box::new(CoordinatorWasmTaskHost::new(
args,
task,
node_private_key,
let result = WasmtimeTaskRuntime::new()?
.run_task_export_verified_with_task_host(
&module,
)?),
)?;
expected_bundle_digest,
export,
&invocation,
Box::new(CoordinatorWasmTaskHost::new(
args,
task,
node_private_key,
&module,
Arc::clone(&command_stdout_source_bytes),
Arc::clone(&command_stderr_source_bytes),
)?),
)
.map_err(|error| {
execution_error_with_log_bytes(
error.to_string(),
&command_stdout_source_bytes,
&command_stderr_source_bytes,
)
})?;
if std::env::var_os("CLUSTERFLUX_DEBUG_CONTROL_TRACE").is_some() {
eprintln!(
"clusterflux debug control: Wasm assignment returned for task {}",
@ -122,17 +168,35 @@ pub(crate) fn run_verified_wasmtime_assignment(
}
match result.outcome {
WasmTaskOutcome::Completed => {
let boundary = result.result.ok_or("completed Wasm task omitted result")?;
let boundary = result.result.ok_or_else(|| {
execution_error_with_log_bytes(
"completed Wasm task omitted result",
&command_stdout_source_bytes,
&command_stderr_source_bytes,
)
})?;
(
format!("{}\n", serde_json::to_string(&boundary)?),
format!(
"{}\n",
serde_json::to_string(&boundary).map_err(|error| {
execution_error_with_log_bytes(
error.to_string(),
&command_stdout_source_bytes,
&command_stderr_source_bytes,
)
})?
),
Some(boundary),
)
}
WasmTaskOutcome::Failed => {
return Err(result
.error
.unwrap_or_else(|| "Wasm task failed without an error".to_owned())
.into())
return Err(execution_error_with_log_bytes(
result
.error
.unwrap_or_else(|| "Wasm task failed without an error".to_owned()),
&command_stdout_source_bytes,
&command_stderr_source_bytes,
))
}
}
}
@ -140,12 +204,18 @@ pub(crate) fn run_verified_wasmtime_assignment(
let task_id = TaskInstanceId::new(task.task.clone());
let artifacts = TaskArtifactStore::new(task_id.clone(), NodeId::new(args.node.clone()));
let manifest = artifacts.flush();
let stdout_source_bytes = command_stdout_source_bytes
.load(Ordering::Relaxed)
.saturating_add(stdout.len() as u64);
let stderr_source_bytes = command_stderr_source_bytes.load(Ordering::Relaxed);
Ok((
CommandOutput {
virtual_thread: task_id,
status_code: Some(0),
stdout,
stderr: String::new(),
stdout_source_bytes,
stderr_source_bytes,
stdout_truncated: false,
stderr_truncated: false,
log_backpressured: false,
@ -176,6 +246,8 @@ struct CoordinatorWasmTaskHost {
next_handle_id: u64,
handles: Arc<Mutex<HashMap<u64, TaskSpec>>>,
command_status: Arc<Mutex<Option<String>>>,
command_stdout_source_bytes: Arc<AtomicU64>,
command_stderr_source_bytes: Arc<AtomicU64>,
cancellation_requested: Arc<AtomicBool>,
abort_requested: Arc<AtomicBool>,
debug_control: Arc<WasmDebugControl>,
@ -188,6 +260,8 @@ impl CoordinatorWasmTaskHost {
parent: &RuntimeTask,
node_private_key: &str,
module: &[u8],
command_stdout_source_bytes: Arc<AtomicU64>,
command_stderr_source_bytes: Arc<AtomicU64>,
) -> Result<Self, Box<dyn std::error::Error>> {
let task_spec = parent
.task_spec
@ -268,6 +342,8 @@ impl CoordinatorWasmTaskHost {
next_handle_id: 1,
handles,
command_status,
command_stdout_source_bytes,
command_stderr_source_bytes,
cancellation_requested,
abort_requested,
debug_control,
@ -293,7 +369,16 @@ impl CoordinatorWasmTaskHost {
runtime_task_from_assignment(assignment).map_err(|error| error.to_string())?;
let execution =
run_verified_wasmtime_assignment(&self.args, &runtime_task, &self.node_private_key);
let (terminal_state, status_code, stdout, stderr, result, retained) = match execution {
let (
terminal_state,
status_code,
stdout,
stderr,
stdout_source_bytes,
stderr_source_bytes,
result,
retained,
) = match execution {
Ok((output, _manifest, result)) => {
let retained = retained_result_artifact(
self.args.project_root.as_deref(),
@ -306,20 +391,40 @@ impl CoordinatorWasmTaskHost {
output.status_code,
output.stdout,
output.stderr,
output.stdout_source_bytes,
output.stderr_source_bytes,
result,
retained,
),
Err(error) => ("failed", Some(1), String::new(), error, None, None),
Err(error) => (
"failed",
Some(1),
String::new(),
error.clone(),
output.stdout_source_bytes,
output
.stderr_source_bytes
.saturating_add(error.len() as u64),
None,
None,
),
}
}
Err(error) => (
"failed",
Some(1),
String::new(),
error.to_string(),
None,
None,
),
Err(error) => {
let (stdout_source_bytes, stderr_source_bytes) =
assignment_error_log_bytes(error.as_ref());
let error = error.to_string();
(
"failed",
Some(1),
String::new(),
error.clone(),
stdout_source_bytes,
stderr_source_bytes.saturating_add(error.len() as u64),
None,
None,
)
}
};
let artifact_path = retained
.as_ref()
@ -339,8 +444,8 @@ impl CoordinatorWasmTaskHost {
"task": runtime_task.task,
"terminal_state": terminal_state,
"status_code": status_code,
"stdout_bytes": stdout.len(),
"stderr_bytes": stderr.len(),
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": stdout,
"stderr_tail": stderr,
"stdout_truncated": false,

View file

@ -66,6 +66,8 @@ pub(super) struct CoordinatorControlledProcessRunner {
pub(super) node_private_key: String,
pub(super) debug_control: Arc<WasmDebugControl>,
pub(super) command_status: Arc<Mutex<Option<String>>>,
pub(super) stdout_source_bytes: Arc<AtomicU64>,
pub(super) stderr_source_bytes: Arc<AtomicU64>,
pub(super) timeout: Duration,
pub(super) configured_secrets: Vec<String>,
}
@ -85,6 +87,8 @@ impl CoordinatorControlledProcessRunner {
node_private_key: host.node_private_key.clone(),
debug_control: Arc::clone(&host.debug_control),
command_status: Arc::clone(&host.command_status),
stdout_source_bytes: Arc::clone(&host.command_stdout_source_bytes),
stderr_source_bytes: Arc::clone(&host.command_stderr_source_bytes),
timeout,
configured_secrets,
}
@ -269,12 +273,13 @@ impl CoordinatorControlledProcessRunner {
stream: &'static str,
sender: SyncSender<LiveLogChunk>,
configured_secrets: Vec<String>,
source_bytes_total: Arc<AtomicU64>,
) -> thread::JoinHandle<Result<Vec<u8>, String>> {
thread::spawn(move || {
let mut captured = Vec::new();
let mut buffer = [0_u8; 16 * 1024];
let mut source_offset = 0_u64;
let mut pending_offset = 0_u64;
let stream_base = source_bytes_total.load(Ordering::Relaxed);
let mut pending_offset = stream_base;
let mut pending = Vec::new();
let mut discarded = false;
loop {
@ -284,6 +289,11 @@ impl CoordinatorControlledProcessRunner {
if count == 0 {
break;
}
let _ = source_bytes_total.fetch_update(
Ordering::Relaxed,
Ordering::Relaxed,
|current| Some(current.saturating_add(count as u64)),
);
let remaining = maximum.saturating_sub(captured.len());
let retained = count.min(remaining);
if retained > 0 {
@ -306,7 +316,6 @@ impl CoordinatorControlledProcessRunner {
if retained < count {
discarded = true;
}
source_offset = source_offset.saturating_add(count as u64);
}
if let Some((consumed, text)) =
redact_safe_live_log_prefix(&pending, &configured_secrets, true)
@ -322,7 +331,7 @@ impl CoordinatorControlledProcessRunner {
if discarded {
let _ = sender.try_send(LiveLogChunk {
stream,
offset: maximum as u64,
offset: stream_base.saturating_add(maximum as u64),
source_bytes: 0,
bytes: b"[log output truncated at node capture limit]".to_vec(),
truncated: true,
@ -445,6 +454,7 @@ impl ProcessRunner for CoordinatorControlledProcessRunner {
"stdout",
live_log_sender.clone(),
self.configured_secrets.clone(),
Arc::clone(&self.stdout_source_bytes),
);
let stderr = Self::drain_bounded(
child
@ -455,6 +465,7 @@ impl ProcessRunner for CoordinatorControlledProcessRunner {
"stderr",
live_log_sender,
self.configured_secrets.clone(),
Arc::clone(&self.stderr_source_bytes),
);
let live_log_reporter = self.spawn_live_log_reporter(live_log_receiver);
let mut session = match CoordinatorSession::connect(&self.args.coordinator) {
@ -584,7 +595,10 @@ impl ProcessRunner for CoordinatorControlledProcessRunner {
#[cfg(test)]
mod tests {
use super::redact_safe_live_log_prefix;
use super::{redact_safe_live_log_prefix, CoordinatorControlledProcessRunner};
use std::io::Cursor;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::{mpsc, Arc};
#[test]
fn live_log_redaction_holds_boundaries_until_split_secrets_are_complete() {
@ -600,4 +614,30 @@ mod tests {
assert!(!combined.contains("correct-"));
assert!(!combined.contains("horse"));
}
#[test]
fn bounded_capture_retains_the_complete_source_byte_count() {
let source_bytes = Arc::new(AtomicU64::new(5));
let (sender, receiver) = mpsc::sync_channel(8);
let reader = CoordinatorControlledProcessRunner::drain_bounded(
Cursor::new(vec![b'x'; 32]),
8,
"stdout",
sender,
Vec::new(),
Arc::clone(&source_bytes),
);
let captured = reader.join().unwrap().unwrap();
let chunks = receiver.into_iter().collect::<Vec<_>>();
assert_eq!(captured, vec![b'x'; 8]);
assert_eq!(source_bytes.load(Ordering::Relaxed), 37);
assert_eq!(
chunks.iter().map(|chunk| chunk.source_bytes).sum::<u64>(),
8
);
assert_eq!(chunks[0].offset, 5);
assert_eq!(chunks.last().unwrap().offset, 13);
assert!(chunks.iter().any(|chunk| chunk.truncated));
}
}

View file

@ -48,6 +48,8 @@ fn test_controlled_runner(
),
debug_control: Arc::new(WasmDebugControl::default()),
command_status: Arc::new(Mutex::new(None)),
stdout_source_bytes: Arc::new(AtomicU64::new(0)),
stderr_source_bytes: Arc::new(AtomicU64::new(0)),
timeout,
configured_secrets: Vec::new(),
}
@ -90,6 +92,8 @@ fn controlled_process_runner_kills_running_group_when_abort_is_polled() {
),
debug_control: Arc::new(WasmDebugControl::default()),
command_status: Arc::new(Mutex::new(None)),
stdout_source_bytes: Arc::new(AtomicU64::new(0)),
stderr_source_bytes: Arc::new(AtomicU64::new(0)),
timeout: Duration::from_secs(30),
configured_secrets: Vec::new(),
};

View file

@ -42,6 +42,8 @@ pub struct CommandOutput {
pub status_code: Option<i32>,
pub stdout: String,
pub stderr: String,
pub stdout_source_bytes: u64,
pub stderr_source_bytes: u64,
pub stdout_truncated: bool,
pub stderr_truncated: bool,
pub log_backpressured: bool,
@ -83,6 +85,8 @@ impl LocalCommandExecutor {
&output.stderr,
max_log_bytes,
);
let stdout_source_bytes = output.stdout.len() as u64;
let stderr_source_bytes = output.stderr.len() as u64;
let staged_artifact = if let Some(path) = command.stage_stdout_as {
Some(overlay.write(
path,
@ -98,6 +102,8 @@ impl LocalCommandExecutor {
status_code: output.status.code(),
stdout: logs.stdout,
stderr: logs.stderr,
stdout_source_bytes,
stderr_source_bytes,
stdout_truncated: logs.stdout_truncated,
stderr_truncated: logs.stderr_truncated,
log_backpressured: logs.backpressured,

View file

@ -11,7 +11,7 @@ use clusterflux_core::{
};
use serde_json::{json, Value};
use crate::assignment_runner::run_verified_wasmtime_assignment;
use crate::assignment_runner::{assignment_error_log_bytes, run_verified_wasmtime_assignment};
#[cfg(test)]
use crate::coordinator_session::control_endpoint_identity;
use crate::coordinator_session::CoordinatorSession;
@ -464,6 +464,8 @@ fn run_runtime_task(
capability_report,
debug_command,
node_private_key,
0,
0,
);
}
@ -498,9 +500,13 @@ fn run_runtime_task(
debug_command,
node_private_key,
&error,
output.stdout_source_bytes,
output.stderr_source_bytes,
),
},
Err(error) => {
let (stdout_source_bytes, stderr_source_bytes) =
assignment_error_log_bytes(error.as_ref());
let error = error.to_string();
if error.contains("task execution cancelled:") {
record_cancelled_task(
@ -512,6 +518,8 @@ fn run_runtime_task(
capability_report,
debug_command,
node_private_key,
stdout_source_bytes,
stderr_source_bytes,
)
} else {
record_failed_task(
@ -524,6 +532,8 @@ fn run_runtime_task(
debug_command,
node_private_key,
&error,
stdout_source_bytes,
stderr_source_bytes,
)
}
}

View file

@ -47,8 +47,8 @@ pub(crate) fn record_completed_task(
"process": &task.process,
"node": &args.node,
"task": &task.task,
"stdout_bytes": output.stdout.len(),
"stderr_bytes": output.stderr.len(),
"stdout_bytes": output.stdout_source_bytes,
"stderr_bytes": output.stderr_source_bytes,
"stdout_tail": &output.stdout,
"stderr_tail": &output.stderr,
"stdout_truncated": output.stdout_truncated,
@ -85,8 +85,8 @@ pub(crate) fn record_completed_task(
"node": &args.node,
"task": &task.task,
"status_code": output.status_code,
"stdout_bytes": output.stdout.len(),
"stderr_bytes": output.stderr.len(),
"stdout_bytes": output.stdout_source_bytes,
"stderr_bytes": output.stderr_source_bytes,
"stdout_tail": &output.stdout,
"stderr_tail": &output.stderr,
"stdout_truncated": output.stdout_truncated,
@ -123,8 +123,11 @@ pub(crate) fn record_failed_task(
debug_command: Value,
node_private_key: &str,
error: &str,
stdout_source_bytes: u64,
command_stderr_source_bytes: u64,
) -> Result<Value, Box<dyn std::error::Error>> {
let error = bounded_runtime_error(error);
let stderr_source_bytes = command_stderr_source_bytes.saturating_add(error.len() as u64);
let log_event = session.request(signed_node_request_json(
args,
node_private_key,
@ -136,8 +139,8 @@ pub(crate) fn record_failed_task(
"process": &task.process,
"node": &args.node,
"task": &task.task,
"stdout_bytes": 0,
"stderr_bytes": error.len(),
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": "",
"stderr_tail": &error,
"stdout_truncated": false,
@ -175,8 +178,8 @@ pub(crate) fn record_failed_task(
"task": &task.task,
"terminal_state": "failed",
"status_code": -1,
"stdout_bytes": 0,
"stderr_bytes": error.len(),
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": "",
"stderr_tail": &error,
"stdout_truncated": false,
@ -189,6 +192,8 @@ pub(crate) fn record_failed_task(
Ok(failed_node_report(
task,
&error,
stdout_source_bytes,
stderr_source_bytes,
registration,
heartbeat,
capability_report,
@ -210,6 +215,8 @@ pub(crate) fn record_cancelled_task(
capability_report: Value,
debug_command: Value,
node_private_key: &str,
stdout_source_bytes: u64,
stderr_source_bytes: u64,
) -> Result<Value, Box<dyn std::error::Error>> {
let recorded = session.request(signed_node_request_json(
args,
@ -224,12 +231,12 @@ pub(crate) fn record_cancelled_task(
"task": &task.task,
"terminal_state": "cancelled",
"status_code": null,
"stdout_bytes": 0,
"stderr_bytes": 0,
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": "",
"stderr_tail": "",
"stdout_truncated": false,
"stderr_truncated": false,
"stdout_truncated": stdout_source_bytes > 0,
"stderr_truncated": stderr_source_bytes > 0,
"artifact_path": null,
"artifact_digest": null,
"artifact_size_bytes": null,
@ -238,6 +245,8 @@ pub(crate) fn record_cancelled_task(
)?)?;
Ok(cancelled_node_report(
task,
stdout_source_bytes,
stderr_source_bytes,
registration,
heartbeat,
capability_report,
@ -281,8 +290,8 @@ pub(crate) fn completed_node_report(
"virtual_thread": output.virtual_thread,
"terminal_state": if output.status_code == Some(0) { "completed" } else { "failed" },
"status_code": output.status_code,
"stdout_bytes": output.stdout.len(),
"stderr_bytes": output.stderr.len(),
"stdout_bytes": output.stdout_source_bytes,
"stderr_bytes": output.stderr_source_bytes,
"stdout_tail": &output.stdout,
"stderr_tail": &output.stderr,
"stdout_truncated": output.stdout_truncated,
@ -305,6 +314,8 @@ pub(crate) fn completed_node_report(
#[allow(clippy::too_many_arguments)]
pub(crate) fn cancelled_node_report(
task: &RuntimeTask,
stdout_source_bytes: u64,
stderr_source_bytes: u64,
registration_response: Value,
heartbeat_response: Value,
capability_response: Value,
@ -318,12 +329,12 @@ pub(crate) fn cancelled_node_report(
"virtual_thread": &task.task,
"terminal_state": "cancelled",
"status_code": null,
"stdout_bytes": 0,
"stderr_bytes": 0,
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": "",
"stderr_tail": "",
"stdout_truncated": false,
"stderr_truncated": false,
"stdout_truncated": stdout_source_bytes > 0,
"stderr_truncated": stderr_source_bytes > 0,
"log_backpressured": false,
"staged_artifact": null,
"large_bytes_uploaded": false,
@ -343,6 +354,8 @@ pub(crate) fn cancelled_node_report(
pub(crate) fn failed_node_report(
task: &RuntimeTask,
error: &str,
stdout_source_bytes: u64,
stderr_source_bytes: u64,
registration_response: Value,
heartbeat_response: Value,
capability_response: Value,
@ -357,8 +370,8 @@ pub(crate) fn failed_node_report(
"virtual_thread": &task.task,
"terminal_state": "failed",
"status_code": -1,
"stdout_bytes": 0,
"stderr_bytes": error.len(),
"stdout_bytes": stdout_source_bytes,
"stderr_bytes": stderr_source_bytes,
"stdout_tail": "",
"stderr_tail": error,
"stdout_truncated": false,
@ -377,3 +390,40 @@ pub(crate) fn failed_node_report(
"coordinator_response": coordinator_response,
})
}
#[cfg(test)]
mod tests {
use super::*;
use clusterflux_core::TaskInstanceId;
#[test]
fn completed_report_uses_source_counts_instead_of_bounded_tail_lengths() {
let report = completed_node_report(
CommandOutput {
virtual_thread: TaskInstanceId::from("task"),
status_code: Some(0),
stdout: "bounded tail".to_owned(),
stderr: String::new(),
stdout_source_bytes: 519,
stderr_source_bytes: 0,
stdout_truncated: true,
stderr_truncated: false,
log_backpressured: false,
staged_artifact: None,
},
false,
Value::Null,
Value::Null,
Value::Null,
Value::Null,
Value::Null,
Value::Null,
Value::Null,
Value::Null,
1,
);
assert_eq!(report["stdout_bytes"], 519);
assert_eq!(report["stdout_tail"], "bounded tail");
}
}