chore: Fix log filters and refactor code to use log macros (#426)

* Fix the log layer in normal mode

* switch to info messages

* Update tests

* taplo config

* verbose output to stderr too

* fix cli docs script

* tweaks

* snapshot upload should be info

* Revert "snapshot upload should be info"

This reverts commit e43af4f.

Author: adamspofford-dfinity

Cargo.lock

@@ -32,7 +32,6 @@ candid = "0.10.19"
 candid_parser = "0.3.0"
 clap = { version = "4.5.3", features = ["derive", "env"] }
 clap-markdown = "0.1.5"
-console = "0.16.0"
 cryptoki = "0.12.0"
 dialoguer = "0.12.0"
 directories = "6.0.0"
@@ -61,12 +60,7 @@ indoc = "2.0.6"
 itertools = "0.14.0"
 jsonschema = "0.45.0"
 k256 = { version = "0.13.4", features = ["pem", "pkcs8", "std"] }
-keyring = { version = "3.6.3", features = [
-  "apple-native",
-  "windows-native",
-  "sync-secret-service",
-  "crypto-rust",
-] }
+keyring = { version = "3.6.3", features = ["apple-native", "windows-native", "sync-secret-service", "crypto-rust"] }
 lazy_static = "1.5.0"
 mockall = "0.14.0"
 nix = { version = "0.31.2", features = ["process", "signal"] }
@@ -82,11 +76,7 @@ phf = { version = "0.13.1", features = ["macros"] }
 pkcs8 = { version = "0.10.2", features = ["encryption", "std"] }
 rand = "0.10.0"
 regex = "1.12.2"
-reqwest = { version = "0.13.2", default-features = false, features = [
-  "rustls",
-  "json",
-  "stream",
-] }
+reqwest = { version = "0.13.2", default-features = false, features = ["rustls", "json", "stream"] }
 schemars = { version = "1.0.4", features = ["derive", "url2"] }
 scrypt = "0.11.0"
 sec1 = { version = "0.7.3", features = ["pkcs8"] }

Cargo.toml

@@ -24,7 +24,6 @@ candid.workspace = true
 cargo-generate.workspace = true
 clap-markdown.workspace = true
 clap.workspace = true
-console.workspace = true
 dialoguer.workspace = true
 dunce.workspace = true
 elliptic-curve.workspace = true

crates/icp-cli/Cargo.toml

@@ -1,9 +1,9 @@
-use std::sync::Arc;
-
 use clap::Args;
 use futures::future::try_join_all;
 use icp::context::{Context, EnvironmentSelection};
 
+use tracing::info;
+
 use crate::{operations::build::build_many_with_progress_bar, options::EnvironmentOpt};
 
 /// Build canisters
@@ -44,19 +44,18 @@ pub(crate) async fn exec(ctx: &Context, args: &BuildArgs) -> Result<(), anyhow::
     )
     .await?;
     // Build the selected canisters
-    let _ = ctx.term.write_line("Building canisters:");
+    info!("Building canisters:");
 
     build_many_with_progress_bar(
         canisters_to_build,
         ctx.builder.clone(),
         ctx.artifacts.clone(),
         &ctx.dirs.package_cache()?,
-        Arc::new(ctx.term.clone()),
         ctx.debug,
     )
     .await?;
 
-    let _ = ctx.term.write_line("\nCanisters built successfully");
+    info!("Canisters built successfully");
 
     Ok(())
 }

crates/icp-cli/src/commands/build.rs

@@ -5,6 +5,7 @@ use icp::context::Context;
 use icp::parsers::{CyclesAmount, DurationAmount, MemoryAmount};
 use icp::{Canister, context::CanisterSelection, prelude::*};
 use icp_canister_interfaces::management_canister::CanisterSettingsArg;
+use tracing::info;
 
 use crate::{commands::args, operations::create::CreateOperation};
 
@@ -191,11 +192,9 @@ async fn create_canister(ctx: &Context, args: &CreateArgs) -> Result<(), anyhow:
     let id = create_operation.create(&canister_settings).await?;
 
     if args.quiet {
-        let _ = ctx.term.write_line(&format!("{id}"));
+        println!("{id}");
     } else {
-        let _ = ctx
-            .term
-            .write_line(&format!("Created canister with ID {id}"));
+        println!("Created canister with ID {id}");
     }
 
     Ok(())
@@ -224,9 +223,7 @@ async fn create_project_canister(ctx: &Context, args: &CreateArgs) -> Result<(),
         .await
         .is_ok()
     {
-        let _ = ctx
-            .term
-            .write_line(&format!("Canister {canister} already exists"));
+        info!("Canister {canister} already exists");
         return Ok(());
     }
 
@@ -251,11 +248,9 @@ async fn create_project_canister(ctx: &Context, args: &CreateArgs) -> Result<(),
     ctx.update_custom_domains(&selections.environment).await;
 
     if args.quiet {
-        let _ = ctx.term.write_line(&format!("{id}"));
+        println!("{id}");
     } else {
-        let _ = ctx
-            .term
-            .write_line(&format!("Created canister {canister} with ID {id}"));
+        println!("Created canister {canister} with ID {id}");
     }
 
     Ok(())

crates/icp-cli/src/commands/canister/create.rs

@@ -8,6 +8,7 @@ use icp::context::{CanisterSelection, Context};
 use icp::manifest::InitArgsFormat;
 use icp::prelude::*;
 use icp::{InitArgs, fs};
+use tracing::{info, warn};
 
 use crate::{
     commands::args,
@@ -138,7 +139,7 @@ pub(crate) async fn exec(ctx: &Context, args: &InstallArgs) -> Result<(), anyhow
                 );
 
                 if std::io::stdin().is_terminal() {
-                    let _ = ctx.term.write_line(&warning);
+                    warn!("{warning}");
                     let confirmed = Confirm::new()
                         .with_prompt("Do you want to proceed anyway?")
                         .default(false)
@@ -164,9 +165,7 @@ pub(crate) async fn exec(ctx: &Context, args: &InstallArgs) -> Result<(), anyhow
     )
     .await?;
 
-    let _ = ctx.term.write_line(&format!(
-        "Canister {canister_display} installed successfully"
-    ));
+    info!("Canister {canister_display} installed successfully");
 
     Ok(())
 }

crates/icp-cli/src/commands/canister/install.rs

@@ -15,7 +15,7 @@ pub(crate) async fn exec(ctx: &Context, args: &ListArgs) -> Result<(), anyhow::E
     let env = ctx.get_environment(&environment_selection).await?;
 
     for c in env.canisters.keys() {
-        ctx.term.write_line(c)?;
+        println!("{c}");
     }
 
     Ok(())

crates/icp-cli/src/commands/canister/list.rs

@@ -99,10 +99,10 @@ pub(crate) async fn exec(ctx: &Context, args: &LogsArgs) -> Result<(), anyhow::E
 
     if args.follow {
         // Follow mode: continuously fetch and display new logs
-        follow_logs(ctx, &mgmt, &canister_id, args.interval).await
+        follow_logs(&mgmt, &canister_id, args.interval).await
     } else {
         // Single fetch mode: fetch all logs once
-        fetch_and_display_logs(ctx, &mgmt, &canister_id, build_filter(args)?).await
+        fetch_and_display_logs(&mgmt, &canister_id, build_filter(args)?).await
     }
 }
 
@@ -141,7 +141,6 @@ fn build_filter(args: &LogsArgs) -> Result<Option<CanisterLogFilter>, anyhow::Er
 }
 
 async fn fetch_and_display_logs(
-    ctx: &Context,
     mgmt: &ManagementCanister<'_>,
     canister_id: &candid::Principal,
     filter: Option<CanisterLogFilter>,
@@ -157,7 +156,7 @@ async fn fetch_and_display_logs(
 
     for log in result.canister_log_records {
         let formatted = format_log(&log);
-        let _ = ctx.term.write_line(&formatted);
+        println!("{formatted}");
     }
 
     Ok(())
@@ -166,7 +165,6 @@ async fn fetch_and_display_logs(
 const FOLLOW_LOOKBACK_NANOS: u64 = 60 * 60 * 1_000_000_000; // 1 hour
 
 async fn follow_logs(
-    ctx: &Context,
     mgmt: &ManagementCanister<'_>,
     canister_id: &candid::Principal,
     interval_seconds: u64,
@@ -207,7 +205,7 @@ async fn follow_logs(
         if !new_logs.is_empty() {
             for log in &new_logs {
                 let formatted = format_log(log);
-                let _ = ctx.term.write_line(&formatted);
+                println!("{formatted}");
             }
             // Update last_idx to the highest idx we've displayed
             if let Some(last_log) = new_logs.last() {

crates/icp-cli/src/commands/canister/logs.rs

@@ -40,7 +40,7 @@ pub(crate) async fn exec(ctx: &Context, args: &MetadataArgs) -> Result<(), anyho
 
     match metadata {
         Some(value) => {
-            ctx.term.write_line(&value)?;
+            println!("{value}");
             Ok(())
         }
         None => bail!(

crates/icp-cli/src/commands/canister/metadata.rs

@@ -10,6 +10,7 @@ use icp::context::Context;
 use icp_canister_interfaces::nns_migration::{MigrationStatus, NNS_MIGRATION_PRINCIPAL};
 use indicatif::{ProgressBar, ProgressStyle};
 use num_traits::ToPrimitive;
+use tracing::{info, warn};
 
 use crate::commands::args::{self, Canister};
 use crate::operations::canister_migration::{
@@ -87,12 +88,12 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
     if !args.resume_watch {
         let can_confirm = stdin().is_terminal();
         if !args.yes && can_confirm {
-            ctx.term.write_line(&format!(
+            info!(
                 "This will migrate canister '{source_name}' ({source_cid}) to replace '{target_name}' ({target_cid})."
-            ))?;
-            ctx.term.write_line(
-                "The target canister will be deleted and the source canister will take over its ID.",
-            )?;
+            );
+            info!(
+                "The target canister will be deleted and the source canister will take over its ID."
+            );
 
             let confirmed = Confirm::new()
                 .with_prompt("Do you want to proceed?")
@@ -136,11 +137,8 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
 
         if !args.yes && cycles > WARN_CYCLES_THRESHOLD {
             if can_confirm {
-                ctx.term.write_line(&format!(
-                    "Warning: Canister '{source_name}' has more than 15T cycles ({cycles} cycles)."
-                ))?;
-                ctx.term
-                    .write_line("The extra cycles will get burned during the migration.")?;
+                warn!("Canister '{source_name}' has more than 15T cycles ({cycles} cycles).");
+                warn!("The extra cycles will get burned during the migration.");
 
                 let confirmed = Confirm::new()
                     .with_prompt("Do you want to proceed?")
@@ -178,20 +176,16 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
             );
         }
 
-        ctx.term.write_line(&format!(
+        info!(
             "Migrating canister '{source_name}' ({source_cid}) to replace '{target_name}' ({target_cid})"
-        ))?;
-        ctx.term
-            .write_line(&format!("  Source subnet: {source_subnet}"))?;
-        ctx.term
-            .write_line(&format!("  Target subnet: {target_subnet}"))?;
+        );
+        info!("  Source subnet: {source_subnet}");
+        info!("  Target subnet: {target_subnet}");
 
         // Add NNS migration canister as controller to both canisters if not already
         let source_controllers = source_status.settings.controllers;
         if !source_controllers.contains(&NNS_MIGRATION_PRINCIPAL) {
-            ctx.term.write_line(&format!(
-                "Adding NNS migration canister as controller of '{source_name}'..."
-            ))?;
+            info!("Adding NNS migration canister as controller of '{source_name}'...");
             let mut new_controllers = source_controllers;
             new_controllers.push(NNS_MIGRATION_PRINCIPAL);
             let mut builder = mgmt.update_settings(&source_cid);
@@ -203,9 +197,7 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
 
         let target_controllers = target_status.settings.controllers;
         if !target_controllers.contains(&NNS_MIGRATION_PRINCIPAL) {
-            ctx.term.write_line(&format!(
-                "Adding NNS migration canister as controller of '{target_name}'..."
-            ))?;
+            info!("Adding NNS migration canister as controller of '{target_name}'...");
             let mut new_controllers = target_controllers;
             new_controllers.push(NNS_MIGRATION_PRINCIPAL);
             let mut builder = mgmt.update_settings(&target_cid);
@@ -216,12 +208,12 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
         }
 
         // Initiate migration
-        ctx.term.write_line("Initiating canister ID migration...")?;
+        info!("Initiating canister ID migration...");
         migrate_canister(&agent, source_cid, target_cid).await?;
     } else {
-        ctx.term.write_line(&format!(
+        info!(
             "Resuming watch for migration of '{source_name}' ({source_cid}) to '{target_name}' ({target_cid})"
-        ))?;
+        );
     }
 
     // Create spinner for polling
@@ -246,12 +238,12 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
                     spinner.finish_with_message(format!(
                         "Migration in progress: {status} (exiting early due to --skip-watch)"
                     ));
-                    ctx.term.write_line(&format!(
+                    info!(
                         "The source canister '{source_name}' has been deleted. Migration will continue in the background."
-                    ))?;
-                    ctx.term.write_line(&format!(
+                    );
+                    info!(
                         "Use `icp canister migrate-id {source_name} --replace {target_name} --resume-watch` to monitor completion."
-                    ))?;
+                    );
                     return Ok(());
                 }
             }
@@ -286,9 +278,9 @@ pub(crate) async fn exec(ctx: &Context, args: &MigrateIdArgs) -> Result<(), anyh
         }
     }
 
-    ctx.term.write_line(&format!(
+    info!(
         "Canister '{source_name}' ({source_cid}) has been successfully migrated to the new subnet, replacing {target_cid}"
-    ))?;
+    );
 
     Ok(())
 }