chore(ckbtc): improve Bitcoin Checker metrics and tests (#3228)

* Add to metrics the rejection case that does not return http error
code.
* Remove check_address_count because query calls can't persist state,
even when called from an update call context.
* Add tests for specific metrics.

---------

Co-authored-by: IDX GitHub Automation <infra+github-automation@dfinity.org>

rs/bitcoin/checker/BUILD.bazel

@@ -73,7 +73,6 @@ rust_canister(
         "@crate_index//:ic-cdk",
         "@crate_index//:ic-metrics-encoder",
         "@crate_index//:ic-stable-structures",
-        "@crate_index//:num-traits",
         "@crate_index//:serde",
         "@crate_index//:serde_json",
         "@crate_index//:time",
@@ -107,5 +106,6 @@ rust_ic_test(
         "@crate_index//:candid",
         "@crate_index//:ic-btc-interface",
         "@crate_index//:ic-cdk",
+        "@crate_index//:regex",
     ],
 )

rs/bitcoin/checker/Cargo.toml

@@ -24,7 +24,6 @@ ic-canisters-http-types = { path = "../../rust_canisters/http_types" }
 ic-cdk = { workspace = true }
 ic-metrics-encoder = "1.1"
 ic-stable-structures = { workspace = true }
-num-traits = { workspace = true }
 serde = { workspace = true }
 serde_json = {workspace = true }
 time = { workspace = true }
@@ -39,4 +38,5 @@ ic-universal-canister = { path = "../../universal_canister/lib" }
 pocket-ic = { path = "../../../packages/pocket-ic" }
 proptest = { workspace = true }
 tokio = { workspace = true }
+regex = { workspace = true }
 scraper = "0.17.1"

rs/bitcoin/checker/src/main.rs

@@ -1,19 +1,20 @@
 use bitcoin::{consensus::Decodable, Address, Transaction};
+use candid::Nat;
 use ic_btc_checker::{
     blocklist::is_blocked, get_tx_cycle_cost, BtcNetwork, CheckAddressArgs, CheckAddressResponse,
     CheckArg, CheckMode, CheckTransactionArgs, CheckTransactionIrrecoverableError,
     CheckTransactionResponse, CheckTransactionRetriable, CheckTransactionStatus,
     CheckTransactionStrArgs, CHECK_TRANSACTION_CYCLES_REQUIRED,
-    CHECK_TRANSACTION_CYCLES_SERVICE_FEE,
+    CHECK_TRANSACTION_CYCLES_SERVICE_FEE, RETRY_MAX_RESPONSE_BYTES,
 };
 use ic_btc_interface::Txid;
 use ic_canister_log::{export as export_logs, log};
 use ic_canisters_http_types as http;
 use ic_cdk::api::call::RejectionCode;
 use ic_cdk::api::management_canister::http_request::{HttpResponse, TransformArgs};
-use num_traits::cast::ToPrimitive;
 use std::cell::RefCell;
 use std::collections::BTreeMap;
+use std::fmt;
 use std::str::FromStr;
 
 mod dashboard;
@@ -26,12 +27,28 @@ use fetch::{FetchEnv, FetchResult, TryFetchResult};
 use logs::{Log, LogEntry, Priority, DEBUG, WARN};
 use state::{get_config, set_config, Config, FetchGuardError, HttpGetTxError};
 
+#[derive(PartialOrd, Ord, PartialEq, Eq)]
+enum HttpsOutcallStatus {
+    ResponseTooLarge,
+    IcError(RejectionCode),
+    HttpStatusCode(Nat),
+}
+
+impl fmt::Display for HttpsOutcallStatus {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        match self {
+            Self::ResponseTooLarge => write!(f, "ResponseTooLarge"),
+            Self::IcError(rejection_code) => write!(f, "IcError({})", *rejection_code as i32),
+            Self::HttpStatusCode(status_code) => write!(f, "HttpStatusCode({})", status_code),
+        }
+    }
+}
+
 #[derive(Default)]
 struct Stats {
-    https_outcall_status: BTreeMap<(String, u16), u64>,
+    https_outcall_status: BTreeMap<(String, HttpsOutcallStatus), u64>,
     http_response_size: BTreeMap<u32, u64>,
     check_transaction_count: u64,
-    check_address_count: u64,
 }
 
 thread_local! {
@@ -57,7 +74,6 @@ fn check_address(args: CheckAddressArgs) -> CheckAddressResponse {
             ic_cdk::trap(&format!("Not a Bitcoin {} address: {}", btc_network, err))
         });
 
-    STATS.with(|s| s.borrow_mut().check_transaction_count += 1);
     match config.check_mode {
         CheckMode::AcceptAll => CheckAddressResponse::Passed,
         CheckMode::RejectAll => CheckAddressResponse::Failed,
@@ -232,7 +248,7 @@ fn http_request(req: http::HttpRequest) -> http::HttpResponse {
                     .value(
                         &[
                             ("provider", provider.as_str()),
-                            ("status", status.to_string().as_str()),
+                            ("status", status.to_string().as_ref()),
                         ],
                         *count as f64,
                     )
@@ -259,11 +275,6 @@ fn http_request(req: http::HttpRequest) -> http::HttpResponse {
                     &[("type", "check_transaction")],
                     stats.check_transaction_count as f64,
                 )
-                .unwrap()
-                .value(
-                    &[("type", "check_address")],
-                    stats.check_address_count as f64,
-                )
                 .unwrap();
         });
 
@@ -373,7 +384,10 @@ impl FetchEnv for BtcCheckerCanisterEnv {
                     let mut stat = s.borrow_mut();
                     *stat
                         .https_outcall_status
-                        .entry((provider.name(), response.status.0.to_u16().unwrap()))
+                        .entry((
+                            provider.name(),
+                            HttpsOutcallStatus::HttpStatusCode(response.status.clone()),
+                        ))
                         .or_default() += 1;
                     // Calculate size bucket as a series of power of 2s.
                     // Note that the max is bounded by `max_response_bytes`, which fits `u32`.
@@ -421,8 +435,26 @@ impl FetchEnv for BtcCheckerCanisterEnv {
                 }
                 Ok(tx)
             }
-            Err((r, m)) if is_response_too_large(&r, &m) => Err(HttpGetTxError::ResponseTooLarge),
+            Err((r, m)) if is_response_too_large(&r, &m) => {
+                if max_response_bytes >= RETRY_MAX_RESPONSE_BYTES {
+                    STATS.with(|s| {
+                        let mut stat = s.borrow_mut();
+                        *stat
+                            .https_outcall_status
+                            .entry((provider.name(), HttpsOutcallStatus::ResponseTooLarge))
+                            .or_default() += 1;
+                    });
+                }
+                Err(HttpGetTxError::ResponseTooLarge)
+            }
             Err((r, m)) => {
+                STATS.with(|s| {
+                    let mut stat = s.borrow_mut();
+                    *stat
+                        .https_outcall_status
+                        .entry((provider.name(), HttpsOutcallStatus::IcError(r)))
+                        .or_default() += 1;
+                });
                 log!(
                     DEBUG,
                     "The http_request resulted into error. RejectionCode: {r:?}, Error: {m}, Request: {request:?}"

rs/bitcoin/checker/tests/tests.rs

@@ -8,16 +8,18 @@ use ic_btc_checker::{
     INITIAL_MAX_RESPONSE_BYTES,
 };
 use ic_btc_interface::Txid;
+use ic_cdk::api::call::RejectionCode;
 use ic_test_utilities_load_wasm::load_wasm;
 use ic_types::Cycles;
 use ic_universal_canister::{call_args, wasm, UNIVERSAL_CANISTER_WASM};
 use pocket_ic::{
     common::rest::{
-        CanisterHttpHeader, CanisterHttpReply, CanisterHttpRequest, CanisterHttpResponse,
-        MockCanisterHttpResponse, RawMessageId,
+        CanisterHttpHeader, CanisterHttpReject, CanisterHttpReply, CanisterHttpRequest,
+        CanisterHttpResponse, MockCanisterHttpResponse, RawMessageId,
     },
     query_candid, PocketIc, PocketIcBuilder, UserError, WasmResult,
 };
+use regex::Regex;
 use std::str::FromStr;
 
 const MAX_TICKS: usize = 10;
@@ -374,6 +376,9 @@ fn test_check_transaction_passed() {
         let actual_cost = cycles_before - cycles_after;
         assert!(actual_cost > expected_cost);
         assert!(actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN);
+        MetricsAssert::from_querying_metrics(&setup).assert_contains_metric_matching(
+            r#"btc_check_requests_total\{type=\"check_transaction\"\} 1 \d+"#,
+        );
     };
 
     // With default installation
@@ -416,6 +421,9 @@ fn test_check_transaction_passed() {
     let actual_cost = cycles_before - cycles_after;
     assert!(actual_cost > expected_cost);
     assert!(actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN);
+    MetricsAssert::from_querying_metrics(&setup).assert_contains_metric_matching(
+        r#"btc_check_requests_total\{type=\"check_transaction\"\} 1 \d+"#,
+    );
 
     // Test CheckMode::AcceptAll
     env.tick();
@@ -457,6 +465,9 @@ fn test_check_transaction_passed() {
         actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN,
         "actual_cost: {actual_cost}, expected_cost: {expected_cost}"
     );
+    MetricsAssert::from_querying_metrics(&setup).assert_contains_metric_matching(
+        r#"btc_check_requests_total\{type=\"check_transaction\"\} 1 \d+"#,
+    );
 
     // Test CheckMode::Normal
     env.tick();
@@ -605,6 +616,45 @@ fn test_check_transaction_error() {
     assert!(actual_cost > expected_cost);
     assert!(actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN);
 
+    // Test for CanisterHttpReject error
+    let cycles_before = setup.env.cycle_balance(setup.caller);
+    let call_id = setup
+        .submit_btc_checker_call(
+            "check_transaction",
+            Encode!(&CheckTransactionArgs { txid: txid.clone() }).unwrap(),
+            CHECK_TRANSACTION_CYCLES_REQUIRED,
+        )
+        .expect("submit_call failed to return call id");
+    let canister_http_requests = tick_until_next_request(&setup.env);
+    setup
+        .env
+        .mock_canister_http_response(MockCanisterHttpResponse {
+            subnet_id: canister_http_requests[0].subnet_id,
+            request_id: canister_http_requests[0].request_id,
+            response: CanisterHttpResponse::CanisterHttpReject(CanisterHttpReject {
+                reject_code: RejectionCode::SysTransient as u64,
+                message: "Failed to directly connect".to_string(),
+            }),
+            additional_responses: vec![],
+        });
+    let result = setup
+        .env
+        .await_call(call_id)
+        .expect("the fetch request didn't finish");
+    // Reject error is retriable too
+    assert!(matches!(
+        decode::<CheckTransactionResponse>(&result),
+        CheckTransactionResponse::Unknown(CheckTransactionStatus::Retriable(
+            CheckTransactionRetriable::TransientInternalError(msg)
+        )) if msg.contains("Failed to directly connect")
+    ));
+    let cycles_after = setup.env.cycle_balance(setup.caller);
+    let expected_cost = CHECK_TRANSACTION_CYCLES_SERVICE_FEE
+        + get_tx_cycle_cost(INITIAL_MAX_RESPONSE_BYTES, TEST_SUBNET_NODES);
+    let actual_cost = cycles_before - cycles_after;
+    assert!(actual_cost > expected_cost);
+    assert!(actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN);
+
     // Test for malformatted transaction data
     let cycles_before = setup.env.cycle_balance(setup.caller);
     let call_id = setup
@@ -702,6 +752,23 @@ fn test_check_transaction_error() {
     let actual_cost = cycles_before - cycles_after;
     assert!(actual_cost > expected_cost);
     assert!(actual_cost - expected_cost < UNIVERSAL_CANISTER_CYCLE_MARGIN);
+
+    MetricsAssert::from_querying_metrics(&setup)
+        .assert_contains_metric_matching(
+            r#"btc_check_requests_total\{type=\"check_transaction\"\} 5 \d+"#,
+        )
+        .assert_contains_metric_matching(
+            r#"btc_checker_http_calls_total\{provider=\"[a-z.]*\",status=\"HttpStatusCode\(500\)\"\} 1 \d+"#,
+        )
+        .assert_contains_metric_matching(
+            r#"btc_checker_http_calls_total\{provider=\"[a-z.]*\",status=\"HttpStatusCode\(200\)\"\} 1 \d+"#,
+        )
+        .assert_contains_metric_matching(
+            r#"btc_checker_http_calls_total\{provider=\"[a-z.]*\",status=\"HttpStatusCode\(404\)\"\} 1 \d+"#,
+        )
+        .assert_contains_metric_matching(
+            r#"btc_checker_http_calls_total\{provider=\"[a-z.]*\",status=\"IcError\(2\)\"\} 1 \d+"#,
+        );
 }
 
 fn tick_until_next_request(env: &PocketIc) -> Vec<CanisterHttpRequest> {
@@ -723,38 +790,38 @@ fn tick_until_next_request(env: &PocketIc) -> Vec<CanisterHttpRequest> {
 
 #[test]
 fn should_query_logs_and_metrics() {
-    use candid::Decode;
-
     let setup = Setup::new(BtcNetwork::Mainnet);
-    test_http_query(&setup, "/metrics");
-    test_http_query(&setup, "/logs");
-
-    fn test_http_query<U: Into<String>>(setup: &Setup, url: U) {
-        let request = ic_canisters_http_types::HttpRequest {
-            method: "GET".to_string(),
-            url: url.into(),
-            headers: Default::default(),
-            body: Default::default(),
-        };
+    make_http_query(&setup, "/metrics");
+    make_http_query(&setup, "/logs");
+}
 
-        let response = Decode!(
-            &assert_reply(
-                setup
-                    .env
-                    .query_call(
-                        setup.btc_checker_canister,
-                        Principal::anonymous(),
-                        "http_request",
-                        Encode!(&request).expect("failed to encode HTTP request"),
-                    )
-                    .expect("failed to query get_transactions on the ledger")
-            ),
-            ic_canisters_http_types::HttpResponse
-        )
-        .unwrap();
+fn make_http_query<U: Into<String>>(setup: &Setup, url: U) -> Vec<u8> {
+    use candid::Decode;
+    let request = ic_canisters_http_types::HttpRequest {
+        method: "GET".to_string(),
+        url: url.into(),
+        headers: Default::default(),
+        body: Default::default(),
+    };
 
-        assert_eq!(response.status_code, 200_u16);
-    }
+    let response = Decode!(
+        &assert_reply(
+            setup
+                .env
+                .query_call(
+                    setup.btc_checker_canister,
+                    Principal::anonymous(),
+                    "http_request",
+                    Encode!(&request).expect("failed to encode HTTP request"),
+                )
+                .expect("failed to query get_transactions on the ledger")
+        ),
+        ic_canisters_http_types::HttpResponse
+    )
+    .unwrap();
+
+    assert_eq!(response.status_code, 200_u16);
+    response.body.into_vec()
 }
 
 fn assert_reply(result: WasmResult) -> Vec<u8> {
@@ -765,3 +832,38 @@ fn assert_reply(result: WasmResult) -> Vec<u8> {
         }
     }
 }
+
+pub struct MetricsAssert {
+    metrics: Vec<String>,
+}
+
+impl MetricsAssert {
+    fn from_querying_metrics(setup: &Setup) -> Self {
+        let response = make_http_query(setup, "/metrics");
+        let metrics = String::from_utf8_lossy(&response)
+            .trim()
+            .split('\n')
+            .map(|line| line.to_string())
+            .collect::<Vec<_>>();
+        Self { metrics }
+    }
+
+    fn assert_contains_metric_matching(self, pattern: &str) -> Self {
+        assert!(
+            !self.find_metrics_matching(pattern).is_empty(),
+            "Expected to find metric matching '{}', but none matched in:\n{:?}",
+            pattern,
+            self.metrics
+        );
+        self
+    }
+
+    fn find_metrics_matching(&self, pattern: &str) -> Vec<String> {
+        let regex = Regex::new(pattern).unwrap_or_else(|_| panic!("Invalid regex: {}", pattern));
+        self.metrics
+            .iter()
+            .filter(|line| regex.is_match(line))
+            .cloned()
+            .collect()
+    }
+}