From 20749c622b5634d478f3a27722a84b9ed86f907f Mon Sep 17 00:00:00 2001 From: rob thijssen Date: Thu, 3 Sep 2026 14:23:37 +0300 Subject: [PATCH] metrics: stale work is the batch in flight at cancellation, not the whole search miner_stale_hashes_total was recorded in the QUIC loop for every result whose job id no longer matched, which is every cancelled search: 74% of all hashes on benjy flagged as stale on the first hour of data. That is the loop's notion of a stale *result*, not wasted work; the hashes were done while the job was current. The wasted work is the batch that completes after the job was superseded. Record that in the engine at the cancellation check, per device and kernel, and drop the loop-level accounting. Expect one batch per job switch. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01CBgs2nSi4H2mdh8kD8vMX5 --- crates/engine-gpu/src/lib.rs | 5 +++++ crates/metrics/src/lair.rs | 34 ++++++++++++++++++-------------- crates/miner-service/src/quic.rs | 7 ------- 3 files changed, 24 insertions(+), 22 deletions(-) diff --git a/crates/engine-gpu/src/lib.rs b/crates/engine-gpu/src/lib.rs index 3973750..1ff788d 100644 --- a/crates/engine-gpu/src/lib.rs +++ b/crates/engine-gpu/src/lib.rs @@ -618,6 +618,9 @@ impl MinerEngine for GpuEngine { let mut total_hashes: u64 = 0; let mut current_start = range.start; let mut batch_num = 0u64; + // lair: hashes of the most recent batch; if the job turns out to have + // been superseded while it ran, that batch was wasted work. + let mut last_batch_hashes: u64 = 0; log::info!( target: "gpu_engine", @@ -632,6 +635,7 @@ impl MinerEngine for GpuEngine { while current_start <= range.end { // Check for cancellation at host level BEFORE starting each batch if cancel.is_cancelled() { + gpu_ctx.metrics.record_stale_hashes(last_batch_hashes); // lair let elapsed = search_start.elapsed(); let hash_rate = total_hashes as f64 / elapsed.as_secs_f64(); log::info!( @@ -699,6 +703,7 @@ impl MinerEngine for GpuEngine { } BatchResult::NotFound { hash_count } => { total_hashes += hash_count; + last_batch_hashes = hash_count; // lair } BatchResult::DeviceLost => { gpu_ctx.metrics.record_device_lost(); // lair diff --git a/crates/metrics/src/lair.rs b/crates/metrics/src/lair.rs index 790fb72..a5dd942 100644 --- a/crates/metrics/src/lair.rs +++ b/crates/metrics/src/lair.rs @@ -116,6 +116,18 @@ static DEVICE_LOST: Lazy = Lazy::new(|| { .expect("miner_device_lost_total")) }); +static DEVICE_STALE_HASHES: Lazy = Lazy::new(|| { + reg(IntCounterVec::new( + Opts::new( + "miner_stale_hashes_total", + "Hashes computed after the job they were for had been superseded: the batch in \ + flight when a new job arrived. The wasted-work cost of batch size.", + ), + &["device", "kernel"], + ) + .expect("miner_stale_hashes_total")) +}); + static GPU_BATCH_SECONDS: Lazy = Lazy::new(|| { reg(HistogramVec::new( HistogramOpts::new( @@ -138,6 +150,7 @@ pub struct DeviceMetrics { hashes: IntCounter, solutions: IntCounter, lost: IntCounter, + stale: IntCounter, batch_gpu: Histogram, batch_host: Histogram, } @@ -149,6 +162,7 @@ impl DeviceMetrics { hashes: DEVICE_HASHES.with_label_values(&[&d, kernel]), solutions: DEVICE_SOLUTIONS.with_label_values(&[&d, kernel]), lost: DEVICE_LOST.with_label_values(&[&d, kernel]), + stale: DEVICE_STALE_HASHES.with_label_values(&[&d, kernel]), batch_gpu: GPU_BATCH_SECONDS.with_label_values(&[&d, kernel, "gpu"]), batch_host: GPU_BATCH_SECONDS.with_label_values(&[&d, kernel, "host"]), } @@ -166,6 +180,11 @@ impl DeviceMetrics { self.lost.inc(); } + /// The batch that completed after its job was superseded. + pub fn record_stale_hashes(&self, n: u64) { + self.stale.inc_by(n); + } + /// `gpu` is submit-to-completion on the device; `host` is everything else /// in the batch (buffer writes, encoding, readback, bookkeeping). pub fn observe_batch(&self, gpu: Duration, host: Duration) { @@ -185,17 +204,6 @@ static JOBS_RECEIVED: Lazy = Lazy::new(|| { ) }); -static STALE_HASHES: Lazy = Lazy::new(|| { - reg(IntCounterVec::new( - Opts::new( - "miner_stale_hashes_total", - "Hashes reported for a job after a newer job had been issued (wasted work)", - ), - &["engine"], - ) - .expect("miner_stale_hashes_total")) -}); - static JOB_PICKUP_SECONDS: Lazy = Lazy::new(|| { reg(HistogramVec::new( HistogramOpts::new( @@ -252,10 +260,6 @@ pub fn record_job_received() { JOBS_RECEIVED.inc(); } -pub fn record_stale_hashes(engine: &str, n: u64) { - STALE_HASHES.with_label_values(&[engine]).inc_by(n); -} - pub fn observe_job_pickup(engine: &str, d: Duration) { JOB_PICKUP_SECONDS .with_label_values(&[engine]) diff --git a/crates/miner-service/src/quic.rs b/crates/miner-service/src/quic.rs index e477e39..b714e93 100644 --- a/crates/miner-service/src/quic.rs +++ b/crates/miner-service/src/quic.rs @@ -186,13 +186,6 @@ async fn handle_connection( // Check if this result is for the current job (not stale) if worker_result.job_id != internal_job_id { - metrics::record_stale_hashes( - match worker_result.engine_type { - EngineType::Cpu => "CPU", - EngineType::Gpu => "GPU", - }, - worker_result.hash_count, - ); // lair log::debug!( "⏰ Discarding stale result from worker {} (result job_id {} != current {})", worker_result.thread_id, -- 2.52.0