chore: Add some HTTP outcalls metrics

rs/consensus/src/consensus/metrics.rs

@@ -190,7 +190,7 @@ pub(crate) struct FinalizerMetrics {
     pub canister_http_out_of_cycles_delivered: IntCounter,
     pub canister_http_async_receipts_delivered: IntCounter,
     pub canister_http_flexible_candid_failures: IntCounter,
-    pub canister_http_flexible_errors_delivered: IntCounter,
+    pub canister_http_flexible_errors_delivered: IntCounterVec,
     pub canister_http_payload_bytes_delivered: Histogram,
 }
 
@@ -313,9 +313,10 @@ impl FinalizerMetrics {
                 "canister_http_flexible_candid_failures",
                 "Total number of flexible canister http responses skipped due to candid encoding/decoding failures",
             ),
-            canister_http_flexible_errors_delivered: metrics_registry.int_counter(
+            canister_http_flexible_errors_delivered: metrics_registry.int_counter_vec(
                 "canister_http_flexible_errors_delivered",
-                "Total number of flexible canister http errors delivered",
+                "Total number of flexible canister http errors delivered, by kind of error",
+                &["type"],
             ),
             canister_http_payload_bytes_delivered: metrics_registry.histogram(
                 "canister_http_payload_bytes_delivered",
@@ -387,8 +388,11 @@ impl FinalizerMetrics {
         self.canister_http_flexible_candid_failures
             .inc_by(flexible_ok_candid_failures + flexible_error_candid_failures);
 
-        self.canister_http_flexible_errors_delivered
-            .inc_by(batch_stats.canister_http.flexible_errors as u64);
+        for (kind, count) in &batch_stats.canister_http.flexible_errors {
+            self.canister_http_flexible_errors_delivered
+                .with_label_values(&[kind])
+                .inc_by(*count as u64);
+        }
         self.canister_http_payload_bytes_delivered
             .observe(batch_stats.canister_http.payload_bytes as f64);
 

rs/https_outcalls/consensus/BUILD.bazel

@@ -74,6 +74,7 @@ rust_test(
         "//rs/test_utilities",
         "//rs/test_utilities/consensus",
         "//rs/test_utilities/logger",
+        "//rs/test_utilities/metrics",
         "//rs/test_utilities/registry",
         "//rs/test_utilities/state",
         "//rs/test_utilities/time",

rs/https_outcalls/consensus/Cargo.toml

@@ -41,6 +41,7 @@ ic-registry-subnet-features = { path = "../../registry/subnet_features" }
 ic-test-utilities = { path = "../../test_utilities" }
 ic-test-utilities-consensus = { path = "../../test_utilities/consensus" }
 ic-test-utilities-logger = { path = "../../test_utilities/logger" }
+ic-test-utilities-metrics = { path = "../../test_utilities/metrics" }
 ic-test-utilities-registry = { path = "../../test_utilities/registry" }
 ic-test-utilities-state = { path = "../../test_utilities/state" }
 ic-test-utilities-time = { path = "../../test_utilities/time" }

rs/https_outcalls/consensus/src/metrics.rs

@@ -1,7 +1,10 @@
 //! This module contains metric structs for components of the canister http feature
 
 use ic_metrics::{MetricsRegistry, buckets::decimal_buckets};
-use prometheus::{HistogramVec, IntCounter, IntGauge};
+use prometheus::{HistogramVec, IntCounter, IntCounterVec, IntGauge};
+
+/// The label whose value names the kind of event or error that was counted.
+const LABEL_TYPE: &str = "type";
 
 pub struct CanisterHttpPoolManagerMetrics {
     /// Records the time it took to perform an operation
@@ -17,6 +20,10 @@ pub struct CanisterHttpPoolManagerMetrics {
     pub shares_validated: IntCounter,
     /// A count of the total number of shares marked invalid.
     pub shares_marked_invalid: IntCounter,
+    /// Notable, but expected events observed by the pool manager, by kind.
+    pool_manager_events: IntCounterVec,
+    /// Operations the pool manager failed to perform, by kind.
+    pool_manager_errors: IntCounterVec,
 }
 
 impl CanisterHttpPoolManagerMetrics {
@@ -43,9 +50,29 @@ impl CanisterHttpPoolManagerMetrics {
             ),
             shares_marked_invalid: metrics_registry.int_counter(
                 "canister_http_shares_marked_invalid", "A count of the total number of shares marked invalid."
-            )
+            ),
+            pool_manager_events: metrics_registry.int_counter_vec(
+                "canister_http_pool_manager_events",
+                "Notable, but expected events observed by the pool manager, by kind.",
+                &[LABEL_TYPE],
+            ),
+            pool_manager_errors: metrics_registry.int_counter_vec(
+                "canister_http_pool_manager_errors",
+                "Canister http pool manager related errors, by kind.",
+                &[LABEL_TYPE],
+            ),
         }
     }
+
+    /// Records a notable, but expected event of the given kind.
+    pub(crate) fn observe_pool_manager_event(&self, label: &str) {
+        self.pool_manager_events.with_label_values(&[label]).inc();
+    }
+
+    /// Records a failed operation of the given kind.
+    pub(crate) fn observe_pool_manager_error(&self, label: &str) {
+        self.pool_manager_errors.with_label_values(&[label]).inc();
+    }
 }
 
 pub struct CanisterHttpPayloadBuilderMetrics {
@@ -60,6 +87,8 @@ pub struct CanisterHttpPayloadBuilderMetrics {
     /// The number of times the initial spent exceeds the limit under
     /// legacy pricing.
     pub initial_spent_exceeds_limit: IntCounter,
+    /// The number of payloads that hit the max response limit.
+    pub max_responses_per_block_reached: IntCounter,
 }
 
 impl CanisterHttpPayloadBuilderMetrics {
@@ -83,7 +112,11 @@ impl CanisterHttpPayloadBuilderMetrics {
             initial_spent_exceeds_limit: metrics_registry.int_counter(
                 "canister_http_initial_spent_exceeds_limit",
                 "The number of times the initial spent exceeds the limit under legacy pricing."
-            )
+            ),
+            max_responses_per_block_reached: metrics_registry.int_counter(
+                "canister_http_max_responses_per_block_reached",
+                "The number of payloads that hit the per-block limit on canister http responses."
+            ),
         }
     }
 }

rs/https_outcalls/consensus/src/payload_builder.rs

@@ -87,7 +87,7 @@ pub struct CanisterHttpBatchStats {
     pub single_signature_responses: usize,
     pub flexible_ok_responses: usize,
     pub flexible_ok_responses_candid_failures: usize,
-    pub flexible_errors: usize,
+    pub flexible_errors: BTreeMap<&'static str, usize>,
     pub flexible_errors_candid_failures: usize,
     pub payload_bytes: usize,
 }
@@ -239,6 +239,27 @@ impl CanisterHttpPayloadBuilderImpl {
                             accumulated_size += candidate_size;
                         }
                     }
+                    let groups = shares_by_callback_id.get(callback_id);
+                    let (groups, success, reject) = groups.map_or((0, 0, 0), |groups| {
+                        let (mut success, mut reject) = (0, 0);
+                        for share in groups.values().flatten() {
+                            if share.content.is_reject() {
+                                reject += 1;
+                            } else {
+                                success += 1;
+                            }
+                        }
+                        (groups.len(), success, reject)
+                    });
+                    warn!(
+                        self.log,
+                        "CanisterHttpPayloadBuilder: timeout for callback_id {callback_id} \
+                        with {groups} groups ({success} success, {reject} reject), pricing {:?}, \
+                        replication {:?}, refund status {:?}",
+                        request.pricing_version,
+                        request.replication,
+                        request.refund_status
+                    );
                     continue;
                 }
                 if responses_included >= CANISTER_HTTP_MAX_RESPONSES_PER_BLOCK {
@@ -425,6 +446,16 @@ impl CanisterHttpPayloadBuilderImpl {
             }
         }
 
+        if responses_included >= CANISTER_HTTP_MAX_RESPONSES_PER_BLOCK {
+            warn!(
+                every_n_seconds => 15,
+                self.log,
+                "CanisterHttpPayloadBuilder: reached max responses per block ({})",
+                CANISTER_HTTP_MAX_RESPONSES_PER_BLOCK
+            );
+            self.metrics.max_responses_per_block_reached.inc();
+        }
+
         CanisterHttpPayload {
             responses,
             timeouts,
@@ -1496,9 +1527,10 @@ impl
                 // Timeouts carry no shares and produce no spend report.
                 FlexibleCanisterHttpError::Timeout { .. } => None,
             };
+            let kind = error.kind();
             match flexible_error_into_consensus_response(error) {
                 Some(consensus_response) => {
-                    stats.flexible_errors += 1;
+                    *stats.flexible_errors.entry(kind).or_default() += 1;
                     consensus_responses.push(consensus_response);
                     if let Some(report) = report {
                         spent.initial.push(report);

rs/https_outcalls/consensus/src/payload_builder/tests.rs

@@ -3577,7 +3577,7 @@ fn flexible_error_into_messages_timeout() {
 
     assert_eq!(responses.len(), 1);
     assert_eq!(responses[0].callback, callback_id);
-    assert_eq!(stats.flexible_errors, 1);
+    assert_eq!(stats.flexible_errors, BTreeMap::from([("timeout", 1)]));
     assert_eq!(stats.flexible_errors_candid_failures, 0);
     // A flexible timeout carries no full response body, hence reports no spend.
     assert!(spent.initial.is_empty());
@@ -3621,7 +3621,10 @@ fn flexible_error_into_messages_too_many_rejects() {
 
     assert_eq!(responses.len(), 1);
     assert_eq!(responses[0].callback, callback_id);
-    assert_eq!(stats.flexible_errors, 1);
+    assert_eq!(
+        stats.flexible_errors,
+        BTreeMap::from([("too_many_rejects", 1)])
+    );
     assert_eq!(stats.flexible_errors_candid_failures, 0);
 
     let Payload::Data(ref data) = responses[0].payload else {
@@ -3676,7 +3679,10 @@ fn flexible_error_into_messages_responses_too_large() {
 
     assert_eq!(responses.len(), 1);
     assert_eq!(responses[0].callback, callback_id);
-    assert_eq!(stats.flexible_errors, 1);
+    assert_eq!(
+        stats.flexible_errors,
+        BTreeMap::from([("responses_too_large", 1)])
+    );
     assert_eq!(stats.flexible_errors_candid_failures, 0);
     // A responses-too-large error delivers no body (consensus cost zero), so it
     // reports the sum of its seen shares' per-replica spend. Here every share
@@ -6509,7 +6515,10 @@ fn flexible_outcall_is_out_of_cycles_when_allowances_are_exhausted() {
             let (responses, spent, stats) = CanisterHttpPayloadBuilderImpl::into_messages(
                 &payload_to_bytes_max_4mb(payload.clone()),
             );
-            assert_eq!(stats.flexible_errors, 1);
+            assert_eq!(
+                stats.flexible_errors,
+                BTreeMap::from([("out_of_cycles", 1)])
+            );
             assert_eq!(responses.len(), 1);
             let Payload::Data(ref data) = responses[0].payload else {
                 panic!("Expected Payload::Data, got {:?}", responses[0].payload);