fix(cli): reduce noise & better track progress within Harmony (#91)

Introduce a way to instrument what happens within Harmony and around Harmony (e.g. in the CLI or in Composer).

The goal is to provide visual feedback to the end users and inform them of the progress of their tasks (e.g. deployment) as clearly as possible. It is important to also let them know of the outcome of their tasks (what was created, where to access stuff, etc.).

<img src="https://media.discordapp.net/attachments/1295353830300713062/1400289618636574741/demo.gif?ex=688c18d5&is=688ac755&hm=2c70884aacb08f7bd15cbb65a7562a174846906718aa15294bbb238e64febbce&=" />

## Changes

### Instrumentation architecture
Extensibility and ease of use is key here, while preserving type safety as much as possible.

The proposed API is quite simple:
```rs
// Emit an event
instrumentation::instrument(
    HarmonyEvent::TopologyPrepared {
        topology: "k8s-anywhere",
        outcome: Outcome::success("yay")
    }
);

// Consume events
instrumentation::subscribe("Harmony CLI Logger", async |event| {
    match event {
        HarmonyEvent::TopologyPrepared { name, outcome } => todo!(),
    }
});
```

#### Current limitations
* this API is not very extensible, but it could be easily changed to allow end users to define custom events in addition to Harmony core events
* we use a tokio broadcast channel behind the scene so only in process communication can happen, but it could be easily changed to a more flexible communication mechanism as implementation details are hidden

### `harmony_composer` VS `harmony_cli`
As Harmony Composer launches commands from Harmony (CLI), they both live in different processes. And because of this, we cannot easily make all the logging happens in one place (Harmony Composer) and get rid of Harmony CLI. At least not without introducing additional complexity such as communication through a server, unix socket, etc.

So for the time being, it was decided to preserve both `harmony_composer` and `harmony_cli` and let them independently log their stuff and handle their own responsibilities:
* `harmony_composer`: takes care only of setting up & packaging a project, delegates everything else to `harmony_cli`
* `harmony_cli`: takes care of configuring & running Harmony

### Logging & prompts
* [indicatif](https://github.com/console-rs/indicatif) is used to create progress bars and track progress within Harmony, Harmony CLI, and Harmony Composer
* [inquire](https://github.com/mikaelmello/inquire) is preserved, but was removed from `harmony` (core) as UI concerns shouldn't go that deep
  * note: for now the only prompt we had was simply deleted, we'll have to find a better way to prompt stuff in the future

## Todos
* [ ] Update/Create ADRs
* [ ] Continue instrumentation for missing branches
* [ ] Allow instrumentation to emit and subscribe to custom events

Co-authored-by: Ian Letourneau <letourneau.ian@gmail.com>
Reviewed-on: #91
Reviewed-by: johnride <jg@nationtech.io>

harmony_composer/src/harmony_composer_logger.rs

@@ -0,0 +1,112 @@
+use indicatif::{MultiProgress, ProgressBar};
+use indicatif_log_bridge::LogWrapper;
+use log::error;
+use std::{
+    collections::HashMap,
+    sync::{Arc, Mutex},
+};
+
+use crate::instrumentation::{self, HarmonyComposerEvent};
+
+pub fn init() -> tokio::task::JoinHandle<()> {
+    configure_logger();
+    let handle = tokio::spawn(handle_events());
+
+    loop {
+        if instrumentation::instrument(HarmonyComposerEvent::HarmonyComposerStarted).is_ok() {
+            break;
+        }
+    }
+
+    handle
+}
+
+fn configure_logger() {
+    let logger =
+        env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).build();
+    let level = logger.filter();
+    let multi = MultiProgress::new();
+    LogWrapper::new(multi.clone(), logger).try_init().unwrap();
+    log::set_max_level(level);
+}
+
+pub async fn handle_events() {
+    const PROGRESS_SETUP: &str = "project-initialization";
+    const PROGRESS_DEPLOYMENT: &str = "deployment";
+
+    instrumentation::subscribe("Harmony Composer Logger", {
+        let progresses: Arc<Mutex<HashMap<String, MultiProgress>>> =
+            Arc::new(Mutex::new(HashMap::new()));
+        let compilation_progress = Arc::new(Mutex::new(None::<ProgressBar>));
+
+        move |event| {
+            let progresses_clone = Arc::clone(&progresses);
+            let compilation_progress_clone = Arc::clone(&compilation_progress);
+
+            async move {
+                let mut progresses_guard = progresses_clone.lock().unwrap();
+                let mut compilation_progress_guard = compilation_progress_clone.lock().unwrap();
+
+                match event {
+                    HarmonyComposerEvent::HarmonyComposerStarted => {}
+                    HarmonyComposerEvent::ProjectInitializationStarted => {
+                        let multi_progress = harmony_cli::progress::new_section(format!(
+                            "{} Initializing Harmony project...",
+                            harmony_cli::theme::EMOJI_HARMONY,
+                        ));
+                        (*progresses_guard).insert(PROGRESS_SETUP.to_string(), multi_progress);
+                    }
+                    HarmonyComposerEvent::ProjectInitialized => println!("\n"),
+                    HarmonyComposerEvent::ProjectCompilationStarted { details } => {
+                        let initialization_progress =
+                            (*progresses_guard).get(PROGRESS_SETUP).unwrap();
+                        let _ = initialization_progress.clear();
+
+                        let progress =
+                            harmony_cli::progress::add_spinner(initialization_progress, details);
+                        *compilation_progress_guard = Some(progress);
+                    }
+                    HarmonyComposerEvent::ProjectCompiled => {
+                        let initialization_progress =
+                            (*progresses_guard).get(PROGRESS_SETUP).unwrap();
+
+                        harmony_cli::progress::success(
+                            initialization_progress,
+                            (*compilation_progress_guard).take(),
+                            "project compiled".to_string(),
+                        );
+                    }
+                    HarmonyComposerEvent::ProjectCompilationFailed { details } => {
+                        let initialization_progress =
+                            (*progresses_guard).get(PROGRESS_SETUP).unwrap();
+
+                        harmony_cli::progress::error(
+                            initialization_progress,
+                            (*compilation_progress_guard).take(),
+                            "failed to compile project".to_string(),
+                        );
+
+                        error!("{details}");
+                    }
+                    HarmonyComposerEvent::DeploymentStarted { target } => {
+                        let multi_progress = harmony_cli::progress::new_section(format!(
+                            "{} Starting deployment to {target}...\n\n",
+                            harmony_cli::theme::EMOJI_DEPLOY
+                        ));
+                        (*progresses_guard).insert(PROGRESS_DEPLOYMENT.to_string(), multi_progress);
+                    }
+                    HarmonyComposerEvent::DeploymentCompleted { details } => println!("\n"),
+                    HarmonyComposerEvent::Shutdown => {
+                        for (_, progresses) in (*progresses_guard).iter() {
+                            progresses.clear().unwrap();
+                        }
+
+                        return false;
+                    }
+                }
+                true
+            }
+        }
+    })
+    .await
+}

harmony_composer/src/instrumentation.rs

@@ -0,0 +1,53 @@
+use log::debug;
+use once_cell::sync::Lazy;
+use tokio::sync::broadcast;
+
+#[derive(Debug, Clone)]
+pub enum HarmonyComposerEvent {
+    HarmonyComposerStarted,
+    ProjectInitializationStarted,
+    ProjectInitialized,
+    ProjectCompilationStarted { details: String },
+    ProjectCompiled,
+    ProjectCompilationFailed { details: String },
+    DeploymentStarted { target: String },
+    DeploymentCompleted { details: String },
+    Shutdown,
+}
+
+static HARMONY_COMPOSER_EVENT_BUS: Lazy<broadcast::Sender<HarmonyComposerEvent>> =
+    Lazy::new(|| {
+        // TODO: Adjust channel capacity
+        let (tx, _rx) = broadcast::channel(16);
+        tx
+    });
+
+pub fn instrument(event: HarmonyComposerEvent) -> Result<(), &'static str> {
+    match HARMONY_COMPOSER_EVENT_BUS.send(event) {
+        Ok(_) => Ok(()),
+        Err(_) => Err("send error: no subscribers"),
+    }
+}
+
+pub async fn subscribe<F, Fut>(name: &str, mut handler: F)
+where
+    F: FnMut(HarmonyComposerEvent) -> Fut + Send + 'static,
+    Fut: Future<Output = bool> + Send,
+{
+    let mut rx = HARMONY_COMPOSER_EVENT_BUS.subscribe();
+    debug!("[{name}] Service started. Listening for events...");
+    loop {
+        match rx.recv().await {
+            Ok(event) => {
+                if !handler(event).await {
+                    debug!("[{name}] Handler requested exit.");
+                    break;
+                }
+            }
+            Err(broadcast::error::RecvError::Lagged(n)) => {
+                debug!("[{name}] Lagged behind by {n} messages.");
+            }
+            Err(_) => break,
+        }
+    }
+}

harmony_composer/src/main.rs

@@ -7,12 +7,16 @@ use bollard::secret::HostConfig;
 use cargo_metadata::{Artifact, Message, MetadataCommand};
 use clap::{Args, Parser, Subcommand};
 use futures_util::StreamExt;
-use log::info;
+use instrumentation::HarmonyComposerEvent;
+use log::{debug, info, log_enabled};
 use std::collections::HashMap;
 use std::path::{Path, PathBuf};
 use std::process::{Command, Stdio};
 use tokio::fs;
 
+mod harmony_composer_logger;
+mod instrumentation;
+
 #[derive(Parser)]
 #[command(version, about, long_about = None, flatten_help = true, propagate_version = true)]
 struct GlobalArgs {
@@ -66,13 +70,15 @@ struct AllArgs {
 
 #[tokio::main]
 async fn main() {
-    env_logger::init();
+    let hc_logger_handle = harmony_composer_logger::init();
     let cli_args = GlobalArgs::parse();
 
     let harmony_path = Path::new(&cli_args.harmony_path)
         .try_exists()
         .expect("couldn't check if path exists");
 
+    instrumentation::instrument(HarmonyComposerEvent::ProjectInitializationStarted).unwrap();
+
     let harmony_bin_path: PathBuf = match harmony_path {
         true => {
             compile_harmony(
@@ -85,6 +91,8 @@ async fn main() {
         false => todo!("implement autodetect code"),
     };
 
+    instrumentation::instrument(HarmonyComposerEvent::ProjectInitialized).unwrap();
+
     match cli_args.command {
         Some(command) => match command {
             Commands::Check(args) => {
@@ -116,19 +124,31 @@ async fn main() {
             }
             Commands::Deploy(args) => {
                 let deploy = if args.staging {
+                    instrumentation::instrument(HarmonyComposerEvent::DeploymentStarted {
+                        target: "staging".to_string(),
+                    })
+                    .unwrap();
                     todo!("implement staging deployment")
                 } else if args.prod {
+                    instrumentation::instrument(HarmonyComposerEvent::DeploymentStarted {
+                        target: "prod".to_string(),
+                    })
+                    .unwrap();
                     todo!("implement prod deployment")
                 } else {
+                    instrumentation::instrument(HarmonyComposerEvent::DeploymentStarted {
+                        target: "dev".to_string(),
+                    })
+                    .unwrap();
                     Command::new(harmony_bin_path).arg("-y").arg("-a").spawn()
                 }
                 .expect("failed to run harmony deploy");
 
                 let deploy_output = deploy.wait_with_output().unwrap();
-                println!(
-                    "deploy output: {}",
-                    String::from_utf8(deploy_output.stdout).expect("couldn't parse from utf8")
-                );
+                instrumentation::instrument(HarmonyComposerEvent::DeploymentCompleted {
+                    details: String::from_utf8(deploy_output.stdout).unwrap(),
+                })
+                .unwrap();
             }
             Commands::All(_args) => todo!(
                 "take all previous match arms and turn them into separate functions, and call them all one after the other"
@@ -137,6 +157,10 @@ async fn main() {
         },
         None => todo!("run interactively, ask for info on CLI"),
     }
+
+    instrumentation::instrument(HarmonyComposerEvent::Shutdown).unwrap();
+
+    let _ = tokio::try_join!(hc_logger_handle);
 }
 
 #[derive(Clone, Debug, clap::ValueEnum)]
@@ -166,17 +190,32 @@ async fn compile_harmony(
         Some(m) => m,
         None => {
             if cargo_exists {
-                return compile_cargo(platform, harmony_location).await;
+                CompileMethod::LocalCargo
             } else {
-                return compile_docker(platform, harmony_location).await;
+                CompileMethod::Docker
             }
         }
     };
 
-    match method {
-        CompileMethod::LocalCargo => return compile_cargo(platform, harmony_location).await,
-        CompileMethod::Docker => return compile_docker(platform, harmony_location).await,
+    let path = match method {
+        CompileMethod::LocalCargo => {
+            instrumentation::instrument(HarmonyComposerEvent::ProjectCompilationStarted {
+                details: "compiling project with cargo".to_string(),
+            })
+            .unwrap();
+            compile_cargo(platform, harmony_location).await
+        }
+        CompileMethod::Docker => {
+            instrumentation::instrument(HarmonyComposerEvent::ProjectCompilationStarted {
+                details: "compiling project with docker".to_string(),
+            })
+            .unwrap();
+            compile_docker(platform, harmony_location).await
+        }
     };
+
+    instrumentation::instrument(HarmonyComposerEvent::ProjectCompiled).unwrap();
+    path
 }
 
 // TODO: make sure this works with cargo workspaces
@@ -186,6 +225,12 @@ async fn compile_cargo(platform: String, harmony_location: String) -> PathBuf {
         .exec()
         .unwrap();
 
+    let stderr = if log_enabled!(log::Level::Debug) {
+        Stdio::inherit()
+    } else {
+        Stdio::piped()
+    };
+
     let mut cargo_build = Command::new("cargo")
         .current_dir(&harmony_location)
         .args(vec![
@@ -195,6 +240,7 @@ async fn compile_cargo(platform: String, harmony_location: String) -> PathBuf {
             "--message-format=json-render-diagnostics",
         ])
         .stdout(Stdio::piped())
+        .stderr(stderr)
         .spawn()
         .expect("run cargo command failed");
 
@@ -210,18 +256,20 @@ async fn compile_cargo(platform: String, harmony_location: String) -> PathBuf {
                         .expect("failed to get root package")
                         .manifest_path
                 {
-                    println!("{:?}", artifact);
+                    debug!("{:?}", artifact);
                     artifacts.push(artifact);
                 }
             }
             Message::BuildScriptExecuted(_script) => (),
             Message::BuildFinished(finished) => {
-                println!("{:?}", finished);
+                debug!("{:?}", finished);
             }
             _ => (), // Unknown message
         }
     }
 
+    cargo_build.wait().expect("run cargo command failed");
+
     let bin = artifacts
         .last()
         .expect("no binaries built")
@@ -237,7 +285,8 @@ async fn compile_cargo(platform: String, harmony_location: String) -> PathBuf {
         bin_out = PathBuf::from(format!("{}/harmony", harmony_location));
         let _copy_res = fs::copy(&bin, &bin_out).await;
     }
-    return bin_out;
+
+    bin_out
 }
 
 async fn compile_docker(platform: String, harmony_location: String) -> PathBuf {