Publish release-5edbadb22804 filtered source

Private source: 5edbadb2280419cf2cb42b5237835304ad7040e0

Public tree identity: sha256:e0d4d5e1c8693959e69448684a71582edfc13e9b18d7f1e733034fea5ce62cda

crates/clusterflux-coordinator/src/service.rs

@@ -304,6 +304,13 @@ pub struct CoordinatorService {
         clusterflux_core::TaskInstanceId,
         String,
     )>,
+    recent_log_quota_truncated_streams: BTreeSet<(
+        TenantId,
+        ProjectId,
+        ProcessId,
+        clusterflux_core::TaskInstanceId,
+        String,
+    )>,
     next_recent_log_sequence: u64,
     debug_audit_events: VecDeque<DebugAuditEvent>,
     debug_epochs: BTreeMap<ProcessControlKey, u64>,
@@ -579,6 +586,7 @@ impl CoordinatorService {
             recent_log_dropped_through: BTreeMap::new(),
             recent_log_accounted_bytes: BTreeMap::new(),
             recent_log_truncated_streams: BTreeSet::new(),
+            recent_log_quota_truncated_streams: BTreeSet::new(),
             next_recent_log_sequence: 1,
             debug_audit_events: VecDeque::new(),
             debug_epochs: BTreeMap::new(),

crates/clusterflux-coordinator/src/service/logs.rs

@@ -40,19 +40,7 @@ impl CoordinatorService {
         validate_task_log_tail("stdout_tail", &stdout_tail)?;
         validate_task_log_tail("stderr_tail", &stderr_tail)?;
         let now_epoch_seconds = self.current_epoch_seconds()?;
-        let unaccounted_bytes = self.unaccounted_final_log_bytes(
-            &tenant,
-            &project,
-            &process,
-            &task,
-            stdout_bytes,
-            stderr_bytes,
-        )?;
-        self.quota
-            .can_charge_log_bytes(&tenant, &project, unaccounted_bytes, now_epoch_seconds)?;
-        self.quota
-            .charge_log_bytes(&tenant, &project, unaccounted_bytes, now_epoch_seconds)?;
-        self.reconcile_final_log_stream(
+        let stdout_retained = self.accept_final_log_stream(
             &tenant,
             &project,
             &process,
@@ -62,8 +50,8 @@ impl CoordinatorService {
             &stdout_tail,
             stdout_truncated,
             now_epoch_seconds,
-        );
-        self.reconcile_final_log_stream(
+        )?;
+        let stderr_retained = self.accept_final_log_stream(
             &tenant,
             &project,
             &process,
@@ -73,18 +61,22 @@ impl CoordinatorService {
             &stderr_tail,
             stderr_truncated,
             now_epoch_seconds,
-        );
+        )?;
         Ok(CoordinatorResponse::TaskLogRecorded {
             process,
             task,
             stdout_bytes,
             stderr_bytes,
-            stdout_tail: if stdout_truncated {
+            stdout_tail: if !stdout_retained {
+                "[log output truncated at project log quota]".to_owned()
+            } else if stdout_truncated {
                 format!("{stdout_tail}\n... truncated")
             } else {
                 stdout_tail
             },
-            stderr_tail: if stderr_truncated {
+            stderr_tail: if !stderr_retained {
+                "[log output truncated at project log quota]".to_owned()
+            } else if stderr_truncated {
                 format!("{stderr_tail}\n... truncated")
             } else {
                 stderr_tail
@@ -150,11 +142,41 @@ impl CoordinatorService {
             });
         }
         let now_epoch_seconds = self.current_epoch_seconds()?;
+        if self.recent_log_quota_truncated_streams.contains(&key) {
+            if end > expected {
+                self.recent_log_accounted_bytes.insert(key, end);
+            }
+            return Ok(CoordinatorResponse::TaskLogChunkRecorded {
+                process,
+                task,
+                sequence: None,
+                next_offset: end.max(expected),
+            });
+        }
         let newly_accounted = end.saturating_sub(expected);
-        self.quota
-            .can_charge_log_bytes(&tenant, &project, newly_accounted, now_epoch_seconds)?;
-        self.quota
-            .charge_log_bytes(&tenant, &project, newly_accounted, now_epoch_seconds)?;
+        if self
+            .quota
+            .charge_log_bytes(&tenant, &project, newly_accounted, now_epoch_seconds)
+            .is_err()
+        {
+            if end > expected {
+                self.recent_log_accounted_bytes.insert(key.clone(), end);
+            }
+            let sequence = self.mark_log_quota_truncated(
+                &tenant,
+                &project,
+                &process,
+                &task,
+                &stream,
+                now_epoch_seconds,
+            );
+            return Ok(CoordinatorResponse::TaskLogChunkRecorded {
+                process,
+                task,
+                sequence,
+                next_offset: end.max(expected),
+            });
+        }
         if offset > expected {
             self.record_recent_log(
                 tenant.clone(),
@@ -334,27 +356,7 @@ impl CoordinatorService {
             result,
         };
         let now_epoch_seconds = self.current_epoch_seconds()?;
-        let unaccounted_bytes = self.unaccounted_final_log_bytes(
-            &event.tenant,
-            &event.project,
-            &event.process,
-            &event.task,
-            event.stdout_bytes,
-            event.stderr_bytes,
-        )?;
-        self.quota.can_charge_log_bytes(
-            &event.tenant,
-            &event.project,
-            unaccounted_bytes,
-            now_epoch_seconds,
-        )?;
-        self.quota.charge_log_bytes(
-            &event.tenant,
-            &event.project,
-            unaccounted_bytes,
-            now_epoch_seconds,
-        )?;
-        self.reconcile_final_log_stream(
+        let stdout_retained = self.accept_final_log_stream(
             &event.tenant,
             &event.project,
             &event.process,
@@ -364,8 +366,8 @@ impl CoordinatorService {
             &event.stdout_tail,
             event.stdout_truncated,
             now_epoch_seconds,
-        );
-        self.reconcile_final_log_stream(
+        )?;
+        let stderr_retained = self.accept_final_log_stream(
             &event.tenant,
             &event.project,
             &event.process,
@@ -375,7 +377,15 @@ impl CoordinatorService {
             &event.stderr_tail,
             event.stderr_truncated,
             now_epoch_seconds,
-        );
+        )?;
+        if !stdout_retained {
+            event.stdout_tail = "[log output truncated at project log quota]".to_owned();
+            event.stdout_truncated = true;
+        }
+        if !stderr_retained {
+            event.stderr_tail = "[log output truncated at project log quota]".to_owned();
+            event.stderr_truncated = true;
+        }
         let task_key = task_control_key(
             &event.tenant,
             &event.project,
@@ -833,48 +843,94 @@ impl CoordinatorService {
     }
 
     #[allow(clippy::too_many_arguments)]
-    fn unaccounted_final_log_bytes(
-        &self,
+    fn accept_final_log_stream(
+        &mut self,
         tenant: &TenantId,
         project: &ProjectId,
         process: &ProcessId,
         task: &TaskInstanceId,
-        stdout_bytes: u64,
-        stderr_bytes: u64,
-    ) -> Result<u64, CoordinatorServiceError> {
-        let stdout_accounted = self
+        stream: TaskLogStream,
+        total_source_bytes: u64,
+        final_tail: &str,
+        source_truncated: bool,
+        now_epoch_seconds: u64,
+    ) -> Result<bool, CoordinatorServiceError> {
+        let key = recent_log_offset_key(tenant, project, process, task, &stream);
+        let accounted = self
             .recent_log_accounted_bytes
-            .get(&recent_log_offset_key(
+            .get(&key)
+            .copied()
+            .unwrap_or(0);
+        let remaining = total_source_bytes.checked_sub(accounted).ok_or_else(|| {
+            let stream_name = match stream {
+                TaskLogStream::Stdout => "stdout",
+                TaskLogStream::Stderr => "stderr",
+            };
+            CoordinatorServiceError::Protocol(format!(
+                "final {stream_name} byte count {total_source_bytes} is below the {accounted} live bytes already accounted"
+            ))
+        })?;
+        if self.recent_log_quota_truncated_streams.contains(&key) {
+            self.recent_log_accounted_bytes
+                .insert(key, total_source_bytes);
+            return Ok(false);
+        }
+        if self
+            .quota
+            .charge_log_bytes(tenant, project, remaining, now_epoch_seconds)
+            .is_err()
+        {
+            self.recent_log_accounted_bytes
+                .insert(key, total_source_bytes);
+            self.mark_log_quota_truncated(
                 tenant,
                 project,
                 process,
                 task,
-                &TaskLogStream::Stdout,
-            ))
-            .copied()
-            .unwrap_or(0);
-        let stderr_accounted = self
-            .recent_log_accounted_bytes
-            .get(&recent_log_offset_key(
-                tenant,
-                project,
-                process,
-                task,
-                &TaskLogStream::Stderr,
-            ))
-            .copied()
-            .unwrap_or(0);
-        let stdout_remaining = stdout_bytes.checked_sub(stdout_accounted).ok_or_else(|| {
-            CoordinatorServiceError::Protocol(format!(
-                "final stdout byte count {stdout_bytes} is below the {stdout_accounted} live bytes already accounted"
-            ))
-        })?;
-        let stderr_remaining = stderr_bytes.checked_sub(stderr_accounted).ok_or_else(|| {
-            CoordinatorServiceError::Protocol(format!(
-                "final stderr byte count {stderr_bytes} is below the {stderr_accounted} live bytes already accounted"
-            ))
-        })?;
-        checked_reported_log_bytes(stdout_remaining, stderr_remaining)
+                &stream,
+                now_epoch_seconds,
+            );
+            return Ok(false);
+        }
+        self.reconcile_final_log_stream(
+            tenant,
+            project,
+            process,
+            task,
+            stream,
+            total_source_bytes,
+            final_tail,
+            source_truncated,
+            now_epoch_seconds,
+        );
+        Ok(true)
+    }
+
+    #[allow(clippy::too_many_arguments)]
+    fn mark_log_quota_truncated(
+        &mut self,
+        tenant: &TenantId,
+        project: &ProjectId,
+        process: &ProcessId,
+        task: &TaskInstanceId,
+        stream: &TaskLogStream,
+        now_epoch_seconds: u64,
+    ) -> Option<u64> {
+        let key = recent_log_offset_key(tenant, project, process, task, stream);
+        if !self.recent_log_quota_truncated_streams.insert(key.clone()) {
+            return None;
+        }
+        self.recent_log_truncated_streams.insert(key);
+        Some(self.record_recent_log(
+            tenant.clone(),
+            project.clone(),
+            process.clone(),
+            task.clone(),
+            stream.clone(),
+            "[log output truncated at project log quota]".to_owned(),
+            true,
+            now_epoch_seconds,
+        ))
     }
 
     #[allow(clippy::too_many_arguments)]
@@ -1020,6 +1076,14 @@ impl CoordinatorService {
                     || entry_task != task
             },
         );
+        self.recent_log_quota_truncated_streams.retain(
+            |(entry_tenant, entry_project, entry_process, entry_task, _)| {
+                entry_tenant != tenant
+                    || entry_project != project
+                    || entry_process != process
+                    || entry_task != task
+            },
+        );
     }
 
     fn finish_task_attempt(&mut self, event: &mut TaskCompletionEvent) -> bool {
@@ -1260,17 +1324,6 @@ impl CoordinatorService {
     }
 }
 
-fn checked_reported_log_bytes(
-    stdout_bytes: u64,
-    stderr_bytes: u64,
-) -> Result<u64, CoordinatorServiceError> {
-    stdout_bytes.checked_add(stderr_bytes).ok_or_else(|| {
-        CoordinatorServiceError::Protocol(
-            "reported task log byte counts exceed the supported range".to_owned(),
-        )
-    })
-}
-
 fn recent_log_offset_key(
     tenant: &TenantId,
     project: &ProjectId,
@@ -1305,11 +1358,11 @@ fn bounded_log_tail(mut value: String, truncated: &mut bool) -> String {
     if value.len() <= MAX_TASK_LOG_TAIL_BYTES {
         return value;
     }
-    let mut boundary = MAX_TASK_LOG_TAIL_BYTES;
-    while !value.is_char_boundary(boundary) {
-        boundary -= 1;
+    let mut boundary = value.len() - MAX_TASK_LOG_TAIL_BYTES;
+    while boundary < value.len() && !value.is_char_boundary(boundary) {
+        boundary += 1;
     }
-    value.truncate(boundary);
+    value.drain(..boundary);
     *truncated = true;
     value
 }

crates/clusterflux-coordinator/src/service/quota.rs

@@ -260,22 +260,6 @@ impl CoordinatorQuota {
         self.charge(tenant, project, LimitKind::ApiCall, 1, now_epoch_seconds)
     }
 
-    pub(super) fn can_charge_log_bytes(
-        &self,
-        tenant: &TenantId,
-        project: &ProjectId,
-        bytes: u64,
-        now_epoch_seconds: u64,
-    ) -> Result<(), LimitError> {
-        self.can_charge(
-            tenant,
-            project,
-            LimitKind::LogBytes,
-            bytes,
-            now_epoch_seconds,
-        )
-    }
-
     pub(super) fn charge_log_bytes(
         &mut self,
         tenant: &TenantId,

crates/clusterflux-coordinator/src/service/summaries.rs

@@ -98,6 +98,11 @@ impl CoordinatorService {
                 entry_tenant != tenant || entry_project != project || entry_process != process
             },
         );
+        self.recent_log_quota_truncated_streams.retain(
+            |(entry_tenant, entry_project, entry_process, _, _)| {
+                entry_tenant != tenant || entry_project != project || entry_process != process
+            },
+        );
         self.process_summary_order
             .retain(|retained| retained != &key);
         self.evict_process_summaries_for_project(tenant, project);
@@ -525,6 +530,10 @@ impl CoordinatorService {
             .retain(|(tenant, project, process, _, _)| {
                 tenant != &key.0 || project != &key.1 || process != &key.2
             });
+        self.recent_log_quota_truncated_streams
+            .retain(|(tenant, project, process, _, _)| {
+                tenant != &key.0 || project != &key.1 || process != &key.2
+            });
         self.process_summary_order
             .retain(|retained| retained != key);
     }

crates/clusterflux-coordinator/src/service/tests.rs

@@ -2435,7 +2435,7 @@ fn authenticated_api_calls_are_metered_per_tenant_and_project_before_dispatch()
 }
 
 #[test]
-fn signed_node_log_ingestion_checks_scoped_quota_before_accepting_bytes() {
+fn signed_node_log_ingestion_truncates_at_scoped_quota_without_failing_reports() {
     let mut limits = ResourceLimits::unlimited();
     limits.limits.insert(LimitKind::LogBytes, 4);
     let quota = CoordinatorQuotaConfiguration::new(limits, [(LimitKind::LogBytes, 60)]).unwrap();
@@ -2494,7 +2494,7 @@ fn signed_node_log_ingestion_checks_scoped_quota_before_accepting_bytes() {
             backpressured: false,
         })
         .unwrap();
-    let denied = service
+    let truncated = service
         .handle_signed_node_request_auto(CoordinatorRequest::ReportTaskLog {
             tenant: "tenant".to_owned(),
             project: "project".to_owned(),
@@ -2509,8 +2509,22 @@ fn signed_node_log_ingestion_checks_scoped_quota_before_accepting_bytes() {
             stderr_truncated: false,
             backpressured: true,
         })
-        .unwrap_err();
-    assert!(denied.to_string().contains("LogBytes"));
+        .unwrap();
+    let CoordinatorResponse::TaskLogRecorded {
+        stdout_tail,
+        stdout_bytes: 4,
+        ..
+    } = truncated
+    else {
+        panic!("expected a successful truncated task-log report");
+    };
+    assert_eq!(stdout_tail, "[log output truncated at project log quota]");
+    assert!(service
+        .recent_logs
+        .get(&(TenantId::from("tenant"), ProjectId::from("project")))
+        .unwrap()
+        .iter()
+        .any(|entry| entry.text.contains("project log quota") && entry.truncated));
     assert_eq!(
         service
             .quota
@@ -2519,6 +2533,140 @@ fn signed_node_log_ingestion_checks_scoped_quota_before_accepting_bytes() {
     );
 }
 
+#[test]
+fn log_quota_exhaustion_cannot_strand_task_completion_or_artifact_publication() {
+    let mut limits = ResourceLimits::unlimited();
+    limits.limits.insert(LimitKind::LogBytes, 4);
+    let quota = CoordinatorQuotaConfiguration::new(limits, [(LimitKind::LogBytes, 60)]).unwrap();
+    let mut service = CoordinatorService::new_with_admin_token_database_url_and_quota(
+        7,
+        "test-admin-token",
+        None,
+        quota,
+    )
+    .unwrap();
+    service.set_server_time(30);
+    service
+        .handle_request(CoordinatorRequest::AttachNode {
+            tenant: "tenant".to_owned(),
+            project: "project".to_owned(),
+            node: "node".to_owned(),
+            public_key: test_node_public_key("node"),
+        })
+        .unwrap();
+    service
+        .handle_request(CoordinatorRequest::StartProcess {
+            launch_attempt: None,
+            tenant: "tenant".to_owned(),
+            project: "project".to_owned(),
+            actor_user: None,
+            actor_agent: None,
+            agent_public_key_fingerprint: None,
+            agent_signature: None,
+            process: "process".to_owned(),
+            restart: false,
+        })
+        .unwrap();
+    service
+        .handle_signed_node_request_auto(CoordinatorRequest::ReconnectNode {
+            tenant: "tenant".to_owned(),
+            project: "project".to_owned(),
+            node: "node".to_owned(),
+            process: "process".to_owned(),
+            epoch: 7,
+        })
+        .unwrap();
+    register_test_task_assignment(
+        &mut service,
+        "tenant",
+        "project",
+        "process",
+        "node",
+        "compile",
+        "compile-one",
+        7,
+    );
+    service.record_task_completion_event(TaskCompletionEvent {
+        tenant: TenantId::from("tenant"),
+        project: ProjectId::from("project"),
+        process: ProcessId::from("process"),
+        node: NodeId::from("coordinator-main"),
+        executor: TaskExecutor::CoordinatorMain,
+        task_definition: TaskDefinitionId::from("build"),
+        task: TaskInstanceId::from("main"),
+        attempt_id: None,
+        placement: None,
+        terminal_state: TaskTerminalState::Completed,
+        status_code: Some(0),
+        stdout_bytes: 0,
+        stderr_bytes: 0,
+        stdout_tail: String::new(),
+        stderr_tail: String::new(),
+        stdout_truncated: false,
+        stderr_truncated: false,
+        artifact_path: None,
+        artifact_digest: None,
+        artifact_size_bytes: None,
+        result: None,
+    });
+
+    service
+        .handle_signed_node_request_auto(CoordinatorRequest::TaskCompleted {
+            tenant: "tenant".to_owned(),
+            project: "project".to_owned(),
+            process: "process".to_owned(),
+            node: "node".to_owned(),
+            task: "compile-one".to_owned(),
+            terminal_state: Some(TaskTerminalState::Completed),
+            status_code: Some(0),
+            stdout_bytes: 64,
+            stderr_bytes: 0,
+            stdout_tail: "the-real-final-tail".to_owned(),
+            stderr_tail: String::new(),
+            stdout_truncated: true,
+            stderr_truncated: false,
+            artifact_path: Some("/vfs/artifacts/result.bin".to_owned()),
+            artifact_digest: Some(Digest::sha256("artifact bytes")),
+            artifact_size_bytes: Some(14),
+            result: None,
+        })
+        .unwrap();
+
+    let event = service
+        .task_events
+        .iter()
+        .find(|event| event.task == TaskInstanceId::from("compile-one"))
+        .unwrap();
+    assert_eq!(
+        event.stdout_tail,
+        "[log output truncated at project log quota]"
+    );
+    assert!(event.stdout_truncated);
+    assert!(!service
+        .active_tasks
+        .iter()
+        .any(|key| key.4 == TaskInstanceId::from("compile-one")));
+    assert!(service
+        .coordinator
+        .active_process(
+            &TenantId::from("tenant"),
+            &ProjectId::from("project"),
+            &ProcessId::from("process"),
+        )
+        .is_none());
+    assert!(matches!(
+        service
+            .handle_request(CoordinatorRequest::GetArtifact {
+                tenant: "tenant".to_owned(),
+                project: "project".to_owned(),
+                actor_user: "user".to_owned(),
+                artifact: "result.bin".to_owned(),
+            })
+            .unwrap(),
+        CoordinatorResponse::Artifact { .. }
+    ));
+}
+
 #[test]
 fn service_attaches_node_starts_process_and_records_scoped_task_event() {
     let mut service = CoordinatorService::new(7);