diff --git a/Cargo.lock b/Cargo.lock index d437173187..a6419024f4 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2597,6 +2597,7 @@ dependencies = [ "carbide-api-db", "carbide-api-model", "carbide-firmware", + "carbide-instrument", "carbide-redfish", "carbide-secrets", "carbide-ssh", diff --git a/crates/preingestion-manager/Cargo.toml b/crates/preingestion-manager/Cargo.toml index 1f4dccd397..9eef8fa1f6 100644 --- a/crates/preingestion-manager/Cargo.toml +++ b/crates/preingestion-manager/Cargo.toml @@ -18,6 +18,7 @@ bmc-vendor = { path = "../bmc-vendor" } carbide-api-db = { path = "../api-db" } carbide-api-model = { path = "../api-model" } carbide-firmware = { path = "../firmware" } +carbide-instrument = { path = "../instrument" } carbide-redfish = { path = "../redfish" } carbide-secrets = { path = "../secrets" } carbide-ssh = { path = "../ssh" } @@ -38,6 +39,7 @@ version-compare = { workspace = true } [dev-dependencies] carbide-firmware = { path = "../firmware", features = ["test-support"] } +carbide-instrument = { path = "../instrument", features = ["test-support"] } carbide-test-harness = { path = "../test-harness" } carbide-test-support = { path = "../test-support" } carbide-uuid = { path = "../uuid" } diff --git a/crates/preingestion-manager/src/lib.rs b/crates/preingestion-manager/src/lib.rs index 9c732cdf9f..5f5bb25278 100644 --- a/crates/preingestion-manager/src/lib.rs +++ b/crates/preingestion-manager/src/lib.rs @@ -32,6 +32,7 @@ use carbide_firmware::{ FirmwareConfigSnapshot, FirmwareDownloader, ResolvedFirmwareArtifactSource, resolve_files_firmware_artifact, }; +use carbide_instrument::{Outcome, emit}; use carbide_redfish::libredfish::conv::IntoLibredfish; use carbide_redfish::libredfish::{RedfishClientCreationError, RedfishClientPool}; use carbide_secrets::credentials::{ @@ -61,7 +62,11 @@ use tokio_util::sync::CancellationToken; use crate::bfb_rshim_copier::BfbRshimCopier; use crate::errors::{PreingestionManagerError, PreingestionManagerResult}; -use crate::metrics::PreingestionMetrics; +use crate::metrics::{ + BfbCopyFinished, BfbCopyOutcome, FirmwareComponentLabel, FirmwareUpgradeTaskFinished, + FirmwareUploadFinished, FirmwareUploadMethod, PowerOperation, PreingestionMetrics, + UpgradeTaskFinalState, count_power_op, +}; const NOT_FOUND: u16 = 404; const LEGACY_NO_URL_SENTINEL: &str = "file://dev/null"; @@ -767,6 +772,12 @@ impl PreingestionManagerStatic { } Some(TaskState::Completed) => { // Task has completed, update is done and we can clean up. Site explorer will ingest this next time it runs on this endpoint. + // + // The completion event fires only once the state moves + // on (the next chain task is stored, or the transition + // commits): this same Completed task is re-observed on + // every pass until then, and a rolled-back transition + // never happened. // If we have multiple firmware files to be uploaded, do the next one. if let Some(fw_info) = self.find_fw_info_for_host(db, endpoint).await? @@ -788,14 +799,24 @@ impl PreingestionManagerStatic { endpoint.address ); - self.initiate_update( - endpoint, - selected_firmware, - upgrade_type, - firmware_number, - db, - ) - .await?; + if self + .initiate_update( + endpoint, + selected_firmware, + upgrade_type, + firmware_number, + db, + ) + .await? + { + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(*upgrade_type), + final_state: UpgradeTaskFinalState::Completed, + outcome: Outcome::Ok, + address: endpoint.address, + error: String::new(), + }); + } return Ok(()); } } @@ -816,6 +837,13 @@ impl PreingestionManagerStatic { .boxed() }) .await??; + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(*upgrade_type), + final_state: UpgradeTaskFinalState::Completed, + outcome: Outcome::Ok, + address: endpoint.address, + error: String::new(), + }); // Can immediately process as that new state return self .in_reset_for_new_firmware( @@ -831,25 +859,24 @@ impl PreingestionManagerStatic { ) .await; } - Some(TaskState::Exception) - | Some(TaskState::Interrupted) - | Some(TaskState::Killed) - | Some(TaskState::Cancelled) => { + Some( + state @ (TaskState::Exception + | TaskState::Interrupted + | TaskState::Killed + | TaskState::Cancelled), + ) => { + let task_message = task_info + .messages + .last() + .map_or(String::new(), |m| m.message.clone()); let msg = format!( "Failure in firmware upgrade for {}: {} {:?}", - &endpoint.address, - task_info.task_state.unwrap_or(TaskState::Killed), - task_info - .messages - .last() - .map_or(String::new(), |m| m.message.clone()) + &endpoint.address, state, task_message, ); - tracing::warn!(msg); db.with_txn(|txn| { async move { // Wait for site explorer to refresh it then try again after that. - // Someday, we should generate metrics for visiblity if something fails multiple times. db::explored_endpoints::set_preingestion_recheck_versions_reason( endpoint.address, msg, @@ -874,6 +901,18 @@ impl PreingestionManagerStatic { .boxed() }) .await??; + // The event owns the historical WARN line and counts the + // failure, so an endpoint failing repeatedly is visible + // as a moving error series. It fires only after the + // transition commits -- a rolled-back pass re-observes + // this task and retries. + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(*upgrade_type), + final_state: UpgradeTaskFinalState::from_failed_task_state(state), + outcome: Outcome::Error, + address: endpoint.address, + error: task_message, + }); } _ => { // Unexpected state @@ -906,6 +945,16 @@ impl PreingestionManagerStatic { .boxed() }) .await??; + // The BMC dropped the task record after finishing; + // the confirmed new version is the completion + // evidence, so this task still counts as completed. + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(*upgrade_type), + final_state: UpgradeTaskFinalState::Completed, + outcome: Outcome::Ok, + address: endpoint.address, + error: String::new(), + }); } } } @@ -991,7 +1040,12 @@ impl PreingestionManagerStatic { &endpoint.address, *power_drains_needed ); - if let Err(e) = redfish_client.power(SystemPowerControl::ForceOff).await { + if let Err(e) = count_power_op( + PowerOperation::ForceOff, + redfish_client.power(SystemPowerControl::ForceOff), + ) + .await + { tracing::error!("Failed to power off {}: {e}", &endpoint.address); return Ok(()); } @@ -1028,8 +1082,11 @@ impl PreingestionManagerStatic { %power_state, "ACPowercycle requires chassis to be Off, forcing off first" ); - if let Err(e) = - redfish_client.power(SystemPowerControl::ForceOff).await + if let Err(e) = count_power_op( + PowerOperation::ForceOff, + redfish_client.power(SystemPowerControl::ForceOff), + ) + .await { tracing::error!( "Failed to force off {}: {e}", @@ -1066,7 +1123,11 @@ impl PreingestionManagerStatic { return Ok(()); } } - if let Err(e) = redfish_client.power(SystemPowerControl::ACPowercycle).await + if let Err(e) = count_power_op( + PowerOperation::AcPowercycle, + redfish_client.power(SystemPowerControl::ACPowercycle), + ) + .await { tracing::error!("Failed to power cycle {}: {e}", &endpoint.address); return Ok(()); @@ -1094,7 +1155,12 @@ impl PreingestionManagerStatic { } Some(PowerDrainState::Powercycle) => { tracing::info!("Turning back on {}", &endpoint.address); - if let Err(e) = redfish_client.power(SystemPowerControl::On).await { + if let Err(e) = count_power_op( + PowerOperation::On, + redfish_client.power(SystemPowerControl::On), + ) + .await + { tracing::error!("Failed to power on {}: {e}", &endpoint.address); return Ok(()); } @@ -1124,7 +1190,12 @@ impl PreingestionManagerStatic { "Upgrade task has completed for {} but needs reboot, initiating one", &endpoint.address ); - if let Err(e) = redfish_client.power(SystemPowerControl::ForceRestart).await { + if let Err(e) = count_power_op( + PowerOperation::ForceRestart, + redfish_client.power(SystemPowerControl::ForceRestart), + ) + .await + { tracing::error!("Failed to reboot {}: {e}", &endpoint.address); return Ok(()); } @@ -1151,7 +1222,9 @@ impl PreingestionManagerStatic { "Upgrade task has completed for {} but needs BMC reboot, initiating one", &endpoint.address ); - if let Err(e) = redfish_client.bmc_reset().await { + if let Err(e) = + count_power_op(PowerOperation::BmcReset, redfish_client.bmc_reset()).await + { tracing::error!("Failed to reboot {}: {e}", &endpoint.address); return Ok(()); } @@ -1178,12 +1251,19 @@ impl PreingestionManagerStatic { } else { SystemPowerControl::ForceOff }; - if let Err(e) = redfish_client.power(poweroff_style).await { + if let Err(e) = + count_power_op(poweroff_style.into(), redfish_client.power(poweroff_style)).await + { tracing::error!("Failed to power off {}: {e}", &endpoint.address); return Ok(()); } tokio::time::sleep(self.config.hgx_bmc_gpu_reboot_delay).await; - if let Err(e) = redfish_client.power(SystemPowerControl::On).await { + if let Err(e) = count_power_op( + PowerOperation::On, + redfish_client.power(SystemPowerControl::On), + ) + .await + { tracing::error!("Failed to power on {}: {e}", &endpoint.address); return Ok(()); } @@ -1198,9 +1278,11 @@ impl PreingestionManagerStatic { .await??; return Ok(()); } else if *upgrade_type == FirmwareComponentType::Cec { - match redfish_client - .chassis_reset("Bluefield_ERoT", SystemPowerControl::GracefulRestart) - .await + match count_power_op( + PowerOperation::ChassisReset, + redfish_client.chassis_reset("Bluefield_ERoT", SystemPowerControl::GracefulRestart), + ) + .await { Ok(()) => {} Err(e) if e.to_string().contains("is not supported") => { @@ -1402,7 +1484,9 @@ impl PreingestionManagerStatic { return Ok(false); } }; - if let Err(e) = redfish_client.bmc_reset().await { + if let Err(e) = + count_power_op(PowerOperation::BmcReset, redfish_client.bmc_reset()).await + { let next = attempts + 1; if next >= INITIAL_BMC_RESET_MAX_ATTEMPTS { tracing::warn!( @@ -1666,7 +1750,12 @@ impl PreingestionManagerStatic { redfish_client: &dyn libredfish::Redfish, endpoint: &ExploredEndpoint, ) -> bool { - match redfish_client.power(SystemPowerControl::ForceOff).await { + match count_power_op( + PowerOperation::ForceOff, + redfish_client.power(SystemPowerControl::ForceOff), + ) + .await + { Ok(()) => {} Err(e) if matches!(e, RedfishError::UnnecessaryOperation) => { // ignore because it is already off @@ -1689,7 +1778,7 @@ impl PreingestionManagerStatic { tracing::warn!("Host {} did not turn off when requested", endpoint.address); return false; } - if let Err(e) = redfish_client.bmc_reset().await { + if let Err(e) = count_power_op(PowerOperation::BmcReset, redfish_client.bmc_reset()).await { tracing::warn!("Could not reset BMC on {}: {e}", endpoint.address); return false; } @@ -1711,7 +1800,12 @@ impl PreingestionManagerStatic { return false; } - match redfish_client.power(SystemPowerControl::On).await { + match count_power_op( + PowerOperation::On, + redfish_client.power(SystemPowerControl::On), + ) + .await + { Ok(()) => {} Err(e) if matches!(e, RedfishError::UnnecessaryOperation) => { // ignore because it is already on @@ -2299,7 +2393,12 @@ impl PreingestionManagerStatic { }; tracing::info!(%address, host_ip=%host_bmc_ip, "{label}: powering off host"); - if let Err(e) = redfish_client.power(SystemPowerControl::ForceOff).await { + if let Err(e) = count_power_op( + PowerOperation::ForceOff, + redfish_client.power(SystemPowerControl::ForceOff), + ) + .await + { tracing::error!(%address, host_ip=%host_bmc_ip, error=%e, "{label}: failed to power off host, will retry"); return Ok(()); } @@ -2330,7 +2429,12 @@ impl PreingestionManagerStatic { }; tracing::info!(%address, host_ip=%host_bmc_ip, "{label}: powering on host"); - if let Err(e) = redfish_client.power(SystemPowerControl::On).await { + if let Err(e) = count_power_op( + PowerOperation::On, + redfish_client.power(SystemPowerControl::On), + ) + .await + { tracing::error!(%address, host_ip=%host_bmc_ip, error=%e, "{label}: failed to power on host, will retry"); return Ok(()); } @@ -2444,20 +2548,37 @@ impl PreingestionManagerStatic { let _permit = permit; tracing::info!(%address, "starting BFB copy to DPU rshim"); + let started = std::time::Instant::now(); let result = bfb_rshim_copier .copy_bfb_to_dpu_rshim(bmc_addr, &bmc_credential_key) .await; + // A result the poll loop no longer tracks was preempted by its + // timeout: the Timeout observation already counted this copy, so + // the late result is dropped without a second emit. match result { Ok(()) => { - tracing::info!(%address, "BFB copy completed successfully"); - bfb_copy_state.completed(address.to_string(), BfbCopyResult::Success); + if bfb_copy_state.completed(&address.to_string(), BfbCopyResult::Success) { + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Ok, + took: started.elapsed(), + address, + error: String::new(), + }); + } } Err(e) => { - tracing::error!(%address, error=%e, "BFB copy failed"); - bfb_copy_state - .completed(address.to_string(), BfbCopyResult::Failed(e.to_string())); + if bfb_copy_state + .completed(&address.to_string(), BfbCopyResult::Failed(e.to_string())) + { + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Error, + took: started.elapsed(), + address, + error: e.to_string(), + }); + } } } }); @@ -2475,49 +2596,18 @@ impl PreingestionManagerStatic { let address = endpoint.address.to_string(); let timeout_mins = BFB_COPY_TIMEOUT_MINS; - - let elapsed_mins = Utc::now().signed_duration_since(*started_at).num_minutes(); - if elapsed_mins > timeout_mins { - self.bfb_copy_state.clear(&address); - tracing::error!(%address, elapsed_mins, timeout_mins, "BFB copy timed out"); - db.with_txn(|txn| { - db::explored_endpoints::set_preingestion_failed( - endpoint.address, - format!( - "BFB copy timed out after {elapsed_mins} minutes. \ - Re-run `site-explorer copy-bfb-to-dpu-rshim` to retry.", - ), - txn, - ) - .boxed() - }) - .await??; - return Ok(()); - } - - if !self.bfb_copy_state.is_tracked(&address) { - tracing::warn!(%address, "detected orphaned BFB copy state, restarting copy"); - db.with_txn(|txn| { - db::explored_endpoints::set_preingestion_bfb_recovery_needed( - endpoint.address, - "Restarting after orphaned copy state detected".to_string(), - *host_bmc_ip, - false, - txn, - ) - .boxed() - }) - .await??; - return Ok(()); - } - - match self.bfb_copy_state.state(&address) { - None => { - tracing::debug!(%address, "BFB copy still in progress"); - Ok(()) - } - Some(BfbCopyResult::Success) => { - self.bfb_copy_state.clear(&address); + let elapsed = Utc::now().signed_duration_since(*started_at); + let elapsed_mins = elapsed.num_minutes(); + + // One lock-held step decides this pass: a ready result always wins + // over the deadline (the spawned task already counted it), and a + // timeout removes the tracker entry under that same lock, so a + // racing `completed()` finds nothing and drops its late result. + match self + .bfb_copy_state + .resolve_or_timeout(&address, elapsed_mins > timeout_mins) + { + BfbResolution::Ready(BfbCopyResult::Success) => { tracing::info!(%address, "BFB copy completed, waiting for installation"); db.with_txn(|txn| { db::explored_endpoints::set_preingestion_bfb_installation_wait( @@ -2530,8 +2620,7 @@ impl PreingestionManagerStatic { .await??; Ok(()) } - Some(BfbCopyResult::Failed(error)) => { - self.bfb_copy_state.clear(&address); + BfbResolution::Ready(BfbCopyResult::Failed(error)) => { tracing::error!(%address, error=%error, "BFB copy failed"); db.with_txn(|txn| { db::explored_endpoints::set_preingestion_failed( @@ -2547,6 +2636,52 @@ impl PreingestionManagerStatic { .await??; Ok(()) } + BfbResolution::TimedOut => { + // No result inside the deadline: the task died without + // reporting, or the copy is still dragging. The entry is + // already gone (removed under the resolution's lock), so + // this Timeout stays the copy's only record. + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Timeout, + took: elapsed.to_std().unwrap_or_default(), + address: endpoint.address, + error: format!( + "BFB copy timed out after {elapsed_mins} minutes (limit {timeout_mins} minutes)" + ), + }); + db.with_txn(|txn| { + db::explored_endpoints::set_preingestion_failed( + endpoint.address, + format!( + "BFB copy timed out after {elapsed_mins} minutes. \ + Re-run `site-explorer copy-bfb-to-dpu-rshim` to retry.", + ), + txn, + ) + .boxed() + }) + .await??; + Ok(()) + } + BfbResolution::Untracked => { + tracing::warn!(%address, "detected orphaned BFB copy state, restarting copy"); + db.with_txn(|txn| { + db::explored_endpoints::set_preingestion_bfb_recovery_needed( + endpoint.address, + "Restarting after orphaned copy state detected".to_string(), + *host_bmc_ip, + false, + txn, + ) + .boxed() + }) + .await??; + Ok(()) + } + BfbResolution::Pending => { + tracing::debug!(%address, "BFB copy still in progress"); + Ok(()) + } } } @@ -2662,6 +2797,22 @@ pub enum BfbCopyResult { Failed(String), } +/// The poll loop's single-lock view of one copy, from +/// [`BfbCopyManager::resolve_or_timeout`]. +#[derive(Debug)] +enum BfbResolution { + /// A recorded result was taken; the entry is gone. + Ready(BfbCopyResult), + /// No result inside the deadline; the entry (if any) was removed under + /// the same lock, so a racing `completed()` finds nothing and its late + /// result is dropped. + TimedOut, + /// Tracked with no result yet, inside the deadline. + Pending, + /// Not tracked at all (inside the deadline): an orphaned copy state. + Untracked, +} + #[derive(Debug, Default)] struct BfbCopyManager { active: std::sync::Mutex>>, @@ -2673,9 +2824,19 @@ impl BfbCopyManager { hashmap.insert(address, None); } - fn completed(&self, address: String, result: BfbCopyResult) { + /// Records the copy's result, but only while the address is still + /// tracked. Returns false when the poll loop already gave up on the copy + /// (timeout) and removed it -- the late result is dropped so the caller + /// doesn't count it a second time. + fn completed(&self, address: &str, result: BfbCopyResult) -> bool { let mut hashmap = self.active.lock().expect("lock poisoned"); - hashmap.insert(address, Some(result)); + match hashmap.get_mut(address) { + Some(entry) => { + *entry = Some(result); + true + } + None => false, + } } fn clear(&self, address: &str) { @@ -2683,14 +2844,30 @@ impl BfbCopyManager { hashmap.remove(address); } - fn state(&self, address: &str) -> Option { - let hashmap = self.active.lock().expect("lock poisoned"); - hashmap.get(address).and_then(|r| r.clone()) - } - - fn is_tracked(&self, address: &str) -> bool { - let hashmap = self.active.lock().expect("lock poisoned"); - hashmap.contains_key(address) + /// Resolves one poll pass under a single lock, so a `completed()` racing + /// in between cannot be both consumed and timed out. A present result is + /// taken (and always wins, deadline or not); otherwise, past the deadline + /// the entry is removed and the copy reported [`BfbResolution::TimedOut`]. + /// An address that was never tracked also times out past the deadline, + /// preserving the state machine's `started_at` SLA across restarts. + fn resolve_or_timeout(&self, address: &str, timed_out: bool) -> BfbResolution { + let mut hashmap = self.active.lock().expect("lock poisoned"); + let Some(entry) = hashmap.get_mut(address) else { + return if timed_out { + BfbResolution::TimedOut + } else { + BfbResolution::Untracked + }; + }; + if let Some(result) = entry.take() { + hashmap.remove(address); + return BfbResolution::Ready(result); + } + if timed_out { + hashmap.remove(address); + return BfbResolution::TimedOut; + } + BfbResolution::Pending } } @@ -2779,10 +2956,11 @@ fn need_upgrade( impl PreingestionManagerStatic { /// initiate_update will start a Redfish connection to the given address and start an update - /// by doing an upload. It may be unable to start it if the firmware has not been previously - /// downloaded; if that happens it also returns success, but has not modified the state. On Redfish - /// errors, we return Ok but leave the state as it was, with the intention that we will retry - /// on the next go. + /// by doing an upload. Returns true once the upload's Redfish task has been stored as the + /// new wait state. It may be unable to start the update if the firmware has not been + /// previously downloaded; if that happens it returns Ok(false), but has not modified the + /// state. On Redfish errors, we also return Ok(false) and leave the state as it was, with + /// the intention that we will retry on the next go. async fn initiate_update( &self, endpoint_clone: &ExploredEndpoint, @@ -2790,7 +2968,7 @@ impl PreingestionManagerStatic { firmware_type: &FirmwareComponentType, firmware_number: u32, db_pool: &PgPool, - ) -> Result<(), DatabaseError> { + ) -> Result { let artifact = match resolve_preingestion_firmware_artifact( &self.config.firmware_download_cache_directory, to_install, @@ -2799,7 +2977,7 @@ impl PreingestionManagerStatic { Ok(artifact) => artifact, Err(error) => { tracing::error!("Failed to resolve firmware artifact: {error}"); - return Ok(()); + return Ok(false); } }; @@ -2813,7 +2991,7 @@ impl PreingestionManagerStatic { url ); - return Ok(()); + return Ok(false); } } ResolvedFirmwareArtifactSource::Local => { @@ -2822,7 +3000,7 @@ impl PreingestionManagerStatic { "Firmware artifact {} is not present", artifact.local_path.display() ); - return Ok(()); + return Ok(false); } } } @@ -2840,7 +3018,7 @@ impl PreingestionManagerStatic { "Failed to open redfish to {}: {e}", endpoint_clone.address.to_string() ); - return Ok(()); + return Ok(false); } }; @@ -2871,13 +3049,23 @@ impl PreingestionManagerStatic { ) .await { - Ok(task) => task.id, + Ok(task) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::SimpleUpdate, + outcome: Outcome::Ok, + }); + task.id + } Err(e) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::SimpleUpdate, + outcome: Outcome::Error, + }); tracing::error!( "initiate_update: Failed to call update_firmware_simple_update {}: {e}", endpoint_clone.address ); - return Ok(()); + return Ok(false); } } } else { @@ -2890,8 +3078,18 @@ impl PreingestionManagerStatic { ) .await { - Ok(task) => task, + Ok(task) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::Multipart, + outcome: Outcome::Ok, + }); + task + } Err(RedfishError::NotSupported(err)) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::Multipart, + outcome: Outcome::Error, + }); tracing::warn!( "Multipart update is not supported: {err}. Trying to use HttpPushUri" ); @@ -2899,26 +3097,40 @@ impl PreingestionManagerStatic { Ok(f) => f, Err(e) => { tracing::error!("Failed to open a file: {e}"); - return Ok(()); + return Ok(false); } }; match redfish_client.update_firmware(file).await { - Ok(task) => task.id, + Ok(task) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::HttpPush, + outcome: Outcome::Ok, + }); + task.id + } Err(e) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::HttpPush, + outcome: Outcome::Error, + }); tracing::error!( "initiate_update: Failed uploading firmware to {}: {e}", endpoint_clone.address ); - return Ok(()); + return Ok(false); } } } Err(e) => { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::Multipart, + outcome: Outcome::Error, + }); tracing::warn!( "initiate_update: Failed uploading firmware to {}: {e}", endpoint_clone.address ); - return Ok(()); + return Ok(false); } } }; @@ -2942,7 +3154,7 @@ impl PreingestionManagerStatic { }) .await??; - Ok(()) + Ok(true) } } @@ -3099,6 +3311,61 @@ mod tests { } } + /// The poll's single-lock resolution: a ready result always wins over + /// the deadline, and a timeout removes the entry under that same lock, + /// so a racing `completed()` finds nothing and reports the late result + /// dropped. + #[test] + fn bfb_copy_manager_resolves_or_times_out_atomically() { + let manager = BfbCopyManager::default(); + + // A recorded result is taken even past the deadline, and taking it + // untracks the copy. + manager.started("a".to_string()); + assert!(manager.completed("a", BfbCopyResult::Success)); + assert!(matches!( + manager.resolve_or_timeout("a", true), + BfbResolution::Ready(BfbCopyResult::Success) + )); + assert!(matches!( + manager.resolve_or_timeout("a", false), + BfbResolution::Untracked + )); + + // A failure result resolves the same way. + manager.started("b".to_string()); + assert!(manager.completed("b", BfbCopyResult::Failed("ssh died".to_string()))); + assert!(matches!( + manager.resolve_or_timeout("b", false), + BfbResolution::Ready(BfbCopyResult::Failed(_)) + )); + + // No result inside the deadline stays tracked and pending; past the + // deadline the entry is removed, and the task's racing `completed()` + // finds nothing -- its late result is dropped. + manager.started("c".to_string()); + assert!(matches!( + manager.resolve_or_timeout("c", false), + BfbResolution::Pending + )); + assert!(matches!( + manager.resolve_or_timeout("c", true), + BfbResolution::TimedOut + )); + assert!(!manager.completed("c", BfbCopyResult::Success)); + + // A never-tracked address is an orphan inside the deadline and a + // timeout past it (the started_at SLA holds across restarts). + assert!(matches!( + manager.resolve_or_timeout("d", false), + BfbResolution::Untracked + )); + assert!(matches!( + manager.resolve_or_timeout("d", true), + BfbResolution::TimedOut + )); + } + #[test] fn select_firmware_for_artifact_continuation_selects_requested_or_default() { value_scenarios!(run = |requested_version| { diff --git a/crates/preingestion-manager/src/metrics.rs b/crates/preingestion-manager/src/metrics.rs index eac83f9fc8..7b8b17a34c 100644 --- a/crates/preingestion-manager/src/metrics.rs +++ b/crates/preingestion-manager/src/metrics.rs @@ -15,7 +15,15 @@ * limitations under the License. */ +use std::net::IpAddr; +use std::time::Duration; + use ::carbide_utils::metrics::SharedMetricsHolder; +use carbide_instrument::{DynamicLog, Event, LabelValue, LogAt, Outcome, emit}; +use libredfish::model::task::TaskState; +use libredfish::{RedfishError, SystemPowerControl}; +use model::firmware::FirmwareComponentType; +use opentelemetry::StringValue; use opentelemetry::metrics::Meter; #[derive(Clone, Debug)] @@ -99,11 +107,273 @@ impl MetricHolder { } } +// --------------------------------------------------------------------------- +// Occurrence events (the instrumentation framework). These land on the global +// meter -- carbide-api's meter provider exposes them on /metrics -- and are +// separate from the point-in-time gauges above, which stay on the +// `SharedMetricsHolder` pattern and the `Meter` passed into `MetricHolder`. +// --------------------------------------------------------------------------- + +/// How a BFB copy ended, as a bounded metric label. `Ok` and `Error` are the +/// spawned copy task's own result; `Timeout` is the state machine giving up +/// on a copy whose task died without ever reporting. +#[derive(Debug, Clone, Copy, PartialEq, Eq, LabelValue)] +pub(crate) enum BfbCopyOutcome { + Ok, + Error, + Timeout, +} + +/// A BFB copy to a DPU rshim ran to completion, or timed out. The event owns +/// the completion log line (INFO on success, ERROR otherwise) and records the +/// copy's duration -- a roughly 30-minute operation whose duration previously +/// existed only as log timestamps. +#[derive(Event)] +#[event( + name = "carbide_preingestion_bfb_copy_duration_seconds", + component = "preingestion-manager", + log = dynamic, + metric = histogram, + message = "BFB copy finished", + describe = "Duration of preingestion BFB copies to a DPU rshim, by outcome; the _count \ + series, split by outcome, is the copy and failure rate." +)] +pub(crate) struct BfbCopyFinished { + #[label] + pub outcome: BfbCopyOutcome, + #[observation] + pub took: Duration, + #[context] + pub address: IpAddr, + /// The copy failure, when there was one; empty on success. + #[context] + pub error: String, +} + +impl DynamicLog for BfbCopyFinished { + fn log_at(&self) -> LogAt { + match self.outcome { + BfbCopyOutcome::Ok => LogAt::Level(tracing::Level::INFO), + BfbCopyOutcome::Error | BfbCopyOutcome::Timeout => LogAt::Level(tracing::Level::ERROR), + } + } +} + +/// The Redfish route a preingestion firmware upload went through, as a +/// bounded metric label: `SimpleUpdate` is the BFB image-URI path, +/// `Multipart` the standard file push, and `HttpPush` the fallback when a +/// BMC does not support multipart. +#[derive(Debug, Clone, Copy, PartialEq, Eq, LabelValue)] +pub(crate) enum FirmwareUploadMethod { + SimpleUpdate, + Multipart, + HttpPush, +} + +/// A preingestion firmware upload to a BMC finished. Metric-only: each upload +/// site in `initiate_update` keeps its own log line untouched (their messages +/// differ per route), and this counter is the shared rate beside them. A +/// multipart attempt a BMC rejects as unsupported counts as a `multipart` +/// error followed by the `http_push` fallback's own outcome. +#[derive(Event)] +#[event( + name = "carbide_preingestion_firmware_upload_total", + component = "preingestion-manager", + log = off, + metric = counter, + describe = "Number of preingestion firmware uploads to a BMC, by upload method and outcome." +)] +pub(crate) struct FirmwareUploadFinished { + #[label] + pub method: FirmwareUploadMethod, + #[label] + pub outcome: Outcome, +} + +/// `FirmwareComponentType` as a bounded metric label. The manual impl is the +/// framework's reviewed escape hatch: the type is a fieldless enum in +/// `model::firmware` (bounded by construction), and the orphan rule keeps the +/// derive out of reach from here. The rendering mirrors what +/// `#[derive(LabelValue)]` would produce. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub(crate) struct FirmwareComponentLabel(pub FirmwareComponentType); + +impl LabelValue for FirmwareComponentLabel { + fn label_value(&self) -> StringValue { + StringValue::from(match self.0 { + FirmwareComponentType::Bmc => "bmc", + FirmwareComponentType::Cec => "cec", + FirmwareComponentType::Uefi => "uefi", + FirmwareComponentType::Nic => "nic", + FirmwareComponentType::CpldMb => "cpld_mb", + FirmwareComponentType::CpldPdb => "cpld_pdb", + FirmwareComponentType::HGXBmc => "hgx_bmc", + FirmwareComponentType::CombinedBmcUefi => "combined_bmc_uefi", + FirmwareComponentType::Gpu => "gpu", + FirmwareComponentType::Cx7 => "cx7", + FirmwareComponentType::Unknown => "unknown", + }) + } +} + +/// The terminal state a firmware upgrade's Redfish task reported, as a +/// bounded metric label. +#[derive(Debug, Clone, Copy, PartialEq, Eq, LabelValue)] +pub(crate) enum UpgradeTaskFinalState { + Completed, + Exception, + Interrupted, + Killed, + Cancelled, +} + +impl UpgradeTaskFinalState { + /// Maps a failed Redfish task state onto the label. `Killed` doubles as + /// the fallback for anything outside the failure states the caller + /// matches -- the same fallback the site's failure text has always used + /// for an absent state. + pub(crate) fn from_failed_task_state(state: TaskState) -> Self { + match state { + TaskState::Exception => Self::Exception, + TaskState::Interrupted => Self::Interrupted, + TaskState::Cancelled => Self::Cancelled, + _ => Self::Killed, + } + } +} + +/// A preingestion firmware upgrade's Redfish task reached a terminal state. +/// Successes are counted silently (the surrounding INFO lines already narrate +/// them); a failure owns the WARN line, so an endpoint failing over and over +/// shows up as a moving error series. +#[derive(Event)] +#[event( + name = "carbide_preingestion_firmware_upgrade_tasks_total", + component = "preingestion-manager", + log = dynamic, + metric = counter, + message = "Firmware upgrade task finished", + describe = "Number of preingestion firmware upgrade Redfish tasks reaching a terminal \ + state, by firmware component, final task state, and outcome." +)] +pub(crate) struct FirmwareUpgradeTaskFinished { + #[label] + pub firmware: FirmwareComponentLabel, + #[label] + pub final_state: UpgradeTaskFinalState, + #[label] + pub outcome: Outcome, + #[context] + pub address: IpAddr, + /// The task's last reported message, when it failed; empty on success. + #[context] + pub error: String, +} + +impl DynamicLog for FirmwareUpgradeTaskFinished { + fn log_at(&self) -> LogAt { + match self.outcome { + Outcome::Ok => LogAt::Off, + Outcome::Error => LogAt::Level(tracing::Level::WARN), + } + } +} + +/// The Redfish power operation performed, as a bounded metric label. Host +/// power controls mirror `SystemPowerControl` variant for variant; the BMC +/// and chassis resets are the two reset calls preingestion also issues. +#[derive(Debug, Clone, Copy, PartialEq, Eq, LabelValue)] +pub(crate) enum PowerOperation { + On, + GracefulShutdown, + ForceOff, + GracefulRestart, + ForceRestart, + AcPowercycle, + PowerCycle, + BmcReset, + ChassisReset, +} + +impl From for PowerOperation { + fn from(control: SystemPowerControl) -> Self { + match control { + SystemPowerControl::On => Self::On, + SystemPowerControl::GracefulShutdown => Self::GracefulShutdown, + SystemPowerControl::ForceOff => Self::ForceOff, + SystemPowerControl::GracefulRestart => Self::GracefulRestart, + SystemPowerControl::ForceRestart => Self::ForceRestart, + SystemPowerControl::ACPowercycle => Self::AcPowercycle, + SystemPowerControl::PowerCycle => Self::PowerCycle, + } + } +} + +impl PowerOperation { + /// Whether `RedfishError::UnnecessaryOperation` means this operation's + /// goal already held. libredfish maps every HTTP 409 onto that error: for + /// an operation that targets a power state a 409 means "already in the + /// requested state", which is success in all but name. Restarts and + /// powercycles are transitions with no requested state to already be in + /// -- a 409 is the BMC refusing the operation (a powercycle on a chassis + /// that must first be off, a restart of a host that is not running) -- + /// and the BMC and chassis resets likewise, so for all of those it stays + /// an error. + fn treats_unnecessary_as_ok(self) -> bool { + matches!(self, Self::On | Self::GracefulShutdown | Self::ForceOff) + } +} + +/// A preingestion Redfish power operation completed. Metric-only: every call +/// site keeps its own log line (each already reports the endpoint and error +/// at its own level), and this counter is the shared failure-rate signal +/// beside them. +#[derive(Event)] +#[event( + name = "carbide_preingestion_power_control_total", + component = "preingestion-manager", + log = off, + metric = counter, + describe = "Number of preingestion Redfish power operations (host power control, BMC and \ + chassis resets), by operation and outcome." +)] +pub(crate) struct PowerControlFinished { + #[label] + pub operation: PowerOperation, + #[label] + pub outcome: Outcome, +} + +/// Wraps one preingestion Redfish power operation: the result is returned +/// untouched, and its outcome ticks `carbide_preingestion_power_control_total`. +/// For operations that target a power state (`On`, `GracefulShutdown`, +/// `ForceOff`), `RedfishError::UnnecessaryOperation` counts as `ok` (the +/// requested state already held); for restarts, powercycles, and the BMC and +/// chassis resets it counts as `error` -- there is no state to already be in, +/// so a 409 is a refusal (see [`PowerOperation::treats_unnecessary_as_ok`]). +pub(crate) async fn count_power_op( + operation: PowerOperation, + call: impl Future>, +) -> Result { + let result = call.await; + let outcome = match &result { + Ok(_) => Outcome::Ok, + Err(RedfishError::UnnecessaryOperation) if operation.treats_unnecessary_as_ok() => { + Outcome::Ok + } + Err(_) => Outcome::Error, + }; + emit(PowerControlFinished { operation, outcome }); + result +} + #[cfg(test)] mod tests { use std::sync::Arc; use std::time::Duration; + use carbide_instrument::testing::{MetricsCapture, capture_logs}; + use carbide_test_support::{Check, check_values}; use carbide_utils::test_support::test_meter::TestMeter; use prometheus_text_parser::ParsedPrometheusMetrics; @@ -130,4 +400,425 @@ mod tests { .unwrap() ); } + + /// The label vocabularies are the dashboard contract: every power + /// operation renders as its snake_case name, and the `From` mapping + /// covers `SystemPowerControl` variant for variant. + #[test] + fn power_operation_label_covers_every_system_power_control() { + check_values( + [ + Check { + scenario: "power on", + input: PowerOperation::from(SystemPowerControl::On), + expect: "on".to_string(), + }, + Check { + scenario: "graceful shutdown", + input: PowerOperation::from(SystemPowerControl::GracefulShutdown), + expect: "graceful_shutdown".to_string(), + }, + Check { + scenario: "force off", + input: PowerOperation::from(SystemPowerControl::ForceOff), + expect: "force_off".to_string(), + }, + Check { + scenario: "graceful restart", + input: PowerOperation::from(SystemPowerControl::GracefulRestart), + expect: "graceful_restart".to_string(), + }, + Check { + scenario: "force restart", + input: PowerOperation::from(SystemPowerControl::ForceRestart), + expect: "force_restart".to_string(), + }, + Check { + scenario: "AC powercycle", + input: PowerOperation::from(SystemPowerControl::ACPowercycle), + expect: "ac_powercycle".to_string(), + }, + Check { + scenario: "powercycle", + input: PowerOperation::from(SystemPowerControl::PowerCycle), + expect: "power_cycle".to_string(), + }, + Check { + scenario: "BMC reset", + input: PowerOperation::BmcReset, + expect: "bmc_reset".to_string(), + }, + Check { + scenario: "chassis reset", + input: PowerOperation::ChassisReset, + expect: "chassis_reset".to_string(), + }, + ], + |operation| operation.label_value().to_string(), + ); + } + + /// The manual `LabelValue` impl must render exactly what the derive + /// would: the variant's snake_case name, for every component type. + #[test] + fn firmware_component_label_renders_snake_case() { + check_values( + [ + Check { + scenario: "BMC", + input: FirmwareComponentType::Bmc, + expect: "bmc".to_string(), + }, + Check { + scenario: "CEC", + input: FirmwareComponentType::Cec, + expect: "cec".to_string(), + }, + Check { + scenario: "UEFI", + input: FirmwareComponentType::Uefi, + expect: "uefi".to_string(), + }, + Check { + scenario: "NIC", + input: FirmwareComponentType::Nic, + expect: "nic".to_string(), + }, + Check { + scenario: "CPLD MB", + input: FirmwareComponentType::CpldMb, + expect: "cpld_mb".to_string(), + }, + Check { + scenario: "CPLD PDB", + input: FirmwareComponentType::CpldPdb, + expect: "cpld_pdb".to_string(), + }, + Check { + scenario: "HGX BMC", + input: FirmwareComponentType::HGXBmc, + expect: "hgx_bmc".to_string(), + }, + Check { + scenario: "combined BMC+UEFI", + input: FirmwareComponentType::CombinedBmcUefi, + expect: "combined_bmc_uefi".to_string(), + }, + Check { + scenario: "GPU", + input: FirmwareComponentType::Gpu, + expect: "gpu".to_string(), + }, + Check { + scenario: "CX7", + input: FirmwareComponentType::Cx7, + expect: "cx7".to_string(), + }, + Check { + scenario: "unknown", + input: FirmwareComponentType::Unknown, + expect: "unknown".to_string(), + }, + ], + |component| FirmwareComponentLabel(component).label_value().to_string(), + ); + } + + /// `from_failed_task_state` maps each terminal failure to its own label + /// value, and anything outside the failure set falls back to `killed`. + #[test] + fn upgrade_task_final_state_maps_failure_states() { + check_values( + [ + Check { + scenario: "exception", + input: TaskState::Exception, + expect: "exception".to_string(), + }, + Check { + scenario: "interrupted", + input: TaskState::Interrupted, + expect: "interrupted".to_string(), + }, + Check { + scenario: "cancelled", + input: TaskState::Cancelled, + expect: "cancelled".to_string(), + }, + Check { + scenario: "killed", + input: TaskState::Killed, + expect: "killed".to_string(), + }, + Check { + scenario: "fallback outside the failure set", + input: TaskState::Running, + expect: "killed".to_string(), + }, + ], + |state| { + UpgradeTaskFinalState::from_failed_task_state(state) + .label_value() + .to_string() + }, + ); + } + + /// One emit per copy: the histogram records the duration under the copy's + /// outcome, and the event owns the completion line -- INFO for a success, + /// ERROR for a failure or timeout. + #[test] + fn bfb_copy_finished_records_duration_and_owns_the_completion_line() { + let metrics = MetricsCapture::start(); + let logs = capture_logs(|| { + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Ok, + took: Duration::from_secs(90), + address: IpAddr::from([10, 0, 0, 5]), + error: String::new(), + }); + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Error, + took: Duration::from_secs(30), + address: IpAddr::from([10, 0, 0, 6]), + error: "ssh connection reset".to_string(), + }); + emit(BfbCopyFinished { + outcome: BfbCopyOutcome::Timeout, + took: Duration::from_secs(2100), + address: IpAddr::from([10, 0, 0, 7]), + error: "BFB copy timed out after 35 minutes".to_string(), + }); + }); + + assert_eq!(logs.len(), 3, "every outcome writes its line: {logs:?}"); + assert_eq!(logs[0].level, tracing::Level::INFO); + assert_eq!(logs[1].level, tracing::Level::ERROR); + assert_eq!(logs[2].level, tracing::Level::ERROR); + + for (outcome, seconds) in [("ok", 90.0), ("error", 30.0), ("timeout", 2100.0)] { + assert_eq!( + metrics.histogram_count_delta( + "carbide_preingestion_bfb_copy_duration_seconds", + &[("outcome", outcome)], + ), + 1, + "one observation under outcome={outcome}", + ); + let sum = metrics.histogram_sum_delta( + "carbide_preingestion_bfb_copy_duration_seconds", + &[("outcome", outcome)], + ); + assert!( + (sum - seconds).abs() < 1e-9, + "outcome={outcome} records {seconds}s, got {sum}" + ); + } + } + + /// Upload outcomes count per method without constructing any log line; + /// the `initiate_update` sites keep their own messages. + #[test] + fn firmware_upload_counts_by_method_without_logging() { + let metrics = MetricsCapture::start(); + let logs = capture_logs(|| { + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::SimpleUpdate, + outcome: Outcome::Ok, + }); + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::Multipart, + outcome: Outcome::Error, + }); + emit(FirmwareUploadFinished { + method: FirmwareUploadMethod::HttpPush, + outcome: Outcome::Ok, + }); + }); + + assert!( + logs.is_empty(), + "log = off must not construct any log line, got {logs:?}" + ); + for (method, outcome, expect) in [ + ("simple_update", "ok", 1.0), + ("multipart", "error", 1.0), + ("http_push", "ok", 1.0), + ("multipart", "ok", 0.0), + ] { + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_firmware_upload_total", + &[("method", method), ("outcome", outcome)], + ), + expect, + "series method={method} outcome={outcome}", + ); + } + } + + /// Successes are counted silently; a failure owns the WARN line with the + /// endpoint and the task's message as context. + #[test] + fn firmware_upgrade_task_failures_own_the_warn_line() { + let metrics = MetricsCapture::start(); + let logs = capture_logs(|| { + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(FirmwareComponentType::Bmc), + final_state: UpgradeTaskFinalState::Completed, + outcome: Outcome::Ok, + address: IpAddr::from([10, 0, 0, 5]), + error: String::new(), + }); + emit(FirmwareUpgradeTaskFinished { + firmware: FirmwareComponentLabel(FirmwareComponentType::Uefi), + final_state: UpgradeTaskFinalState::Exception, + outcome: Outcome::Error, + address: IpAddr::from([10, 0, 0, 6]), + error: "flash verification failed".to_string(), + }); + }); + + assert_eq!(logs.len(), 1, "only the failure logs: {logs:?}"); + assert_eq!(logs[0].level, tracing::Level::WARN); + + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_firmware_upgrade_tasks_total", + &[ + ("firmware", "bmc"), + ("final_state", "completed"), + ("outcome", "ok"), + ], + ), + 1.0, + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_firmware_upgrade_tasks_total", + &[ + ("firmware", "uefi"), + ("final_state", "exception"), + ("outcome", "error"), + ], + ), + 1.0, + ); + } + + /// The wrapper returns the call's result untouched and splits + /// `UnnecessaryOperation` (libredfish's mapping of every HTTP 409) by + /// operation: `ok` for operations that target a power state, where it + /// means "already in the requested state", and `error` for restarts, + /// powercycles, and the BMC and chassis resets, where a 409 is the BMC + /// refusing the operation. Every other error counts as `error`. No log + /// line: the call sites own their own. + #[test] + fn count_power_op_splits_unnecessary_operation_by_operation() { + use futures_util::FutureExt as _; + + let metrics = MetricsCapture::start(); + let logs = capture_logs(|| { + count_power_op(PowerOperation::ForceOff, std::future::ready(Ok(()))) + .now_or_never() + .expect("ready future") + .expect("ok result passes through"); + count_power_op( + PowerOperation::ForceOff, + std::future::ready(Err::<(), _>(RedfishError::UnnecessaryOperation)), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + count_power_op( + PowerOperation::AcPowercycle, + std::future::ready(Err::<(), _>(RedfishError::UnnecessaryOperation)), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + count_power_op( + PowerOperation::ForceRestart, + std::future::ready(Err::<(), _>(RedfishError::UnnecessaryOperation)), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + count_power_op( + PowerOperation::BmcReset, + std::future::ready(Err::<(), _>(RedfishError::UnnecessaryOperation)), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + count_power_op( + PowerOperation::ChassisReset, + std::future::ready(Err::<(), _>(RedfishError::UnnecessaryOperation)), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + count_power_op( + PowerOperation::BmcReset, + std::future::ready(Err::<(), _>(RedfishError::NotSupported( + "no such reset".to_string(), + ))), + ) + .now_or_never() + .expect("ready future") + .expect_err("the error itself still propagates"); + }); + + assert!( + logs.is_empty(), + "log = off must not construct any log line, got {logs:?}" + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "force_off"), ("outcome", "ok")], + ), + 2.0, + "a real success and an already-in-state 409 both count as ok", + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "bmc_reset"), ("outcome", "error")], + ), + 2.0, + "for a BMC reset a 409 is a refusal, not an outcome that already held", + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "chassis_reset"), ("outcome", "error")], + ), + 1.0, + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "ac_powercycle"), ("outcome", "error")], + ), + 1.0, + "a powercycle has no state to already be in; its 409 is a refusal", + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "force_restart"), ("outcome", "error")], + ), + 1.0, + "a restart has no state to already be in; its 409 is a refusal", + ); + assert_eq!( + metrics.counter_delta( + "carbide_preingestion_power_control_total", + &[("operation", "bmc_reset"), ("outcome", "ok")], + ), + 0.0, + "an untouched label pair must not move", + ); + } } diff --git a/docs/observability/core_metrics.md b/docs/observability/core_metrics.md index e1dafc327d..45335cd0dc 100644 --- a/docs/observability/core_metrics.md +++ b/docs/observability/core_metrics.md @@ -119,6 +119,10 @@ This file contains a list of metrics exported by NVIDIA Infra Controller (NICo). carbide_power_shelves_iteration_latency_millisecondshistogramThe elapsed time in the last state processor iteration to handle objects of type carbide_power_shelves carbide_power_shelves_object_tasks_enqueued_totalcounterThe amount of types that object handling tasks that have been freshly enqueued for objects of type carbide_power_shelves carbide_power_shelves_totalgaugeThe total number of carbide_power_shelves in the system +carbide_preingestion_bfb_copy_duration_secondshistogramDuration of preingestion BFB copies to a DPU rshim, by outcome; the _count series, split by outcome, is the copy and failure rate. +carbide_preingestion_firmware_upgrade_tasks_totalcounterNumber of preingestion firmware upgrade Redfish tasks reaching a terminal state, by firmware component, final task state, and outcome. +carbide_preingestion_firmware_upload_totalcounterNumber of preingestion firmware uploads to a BMC, by upload method and outcome. +carbide_preingestion_power_control_totalcounterNumber of preingestion Redfish power operations (host power control, BMC and chassis resets), by operation and outcome. carbide_preingestion_totalgaugeThe amount of known machines currently being evaluated prior to ingestion carbide_preingestion_waiting_downloadgaugeThe amount of machines that are waiting for firmware downloads on other machines to complete before doing their own carbide_preingestion_waiting_installationgaugeThe amount of machines which have had firmware uploaded to them and are currently in the process of installing that firmware