Cleanup: Fix documentation, improve logs

This moves some spammier logs to `trace` level, removes a few redundant
spans, and provides some general cleanup.

ghcid-ng/src/ghci/mod.rs

@@ -8,6 +8,7 @@ use std::sync::atomic::AtomicUsize;
 use std::time::Instant;
 
 use aho_corasick::AhoCorasick;
+use camino::Utf8Path;
 use camino::Utf8PathBuf;
 use itertools::Itertools;
 use miette::IntoDiagnostic;
@@ -109,8 +110,9 @@ pub struct Ghci {
     process: Child,
     /// The handle for the stderr reader task.
     stderr_handle: JoinHandle<miette::Result<()>>,
-    /// The handle for the stdin interaction task.
+    /// The stdin writer.
     stdin: GhciStdin,
+    /// The stdout reader.
     stdout: GhciStdout,
     /// Channel for communicating with the stderr reader task.
     stderr: mpsc::Sender<StderrEvent>,
@@ -237,29 +239,18 @@ impl Ghci {
         };
 
         // Wait for the stdout job to start up.
-        {
-            let span = tracing::debug_span!("Stdout startup");
-            let _enter = span.enter();
-            ret.stdout.initialize().await?;
-        }
+        let messages = ret.stdout.initialize().await?;
+        ret.process_ghc_messages(messages).await?;
 
         // Perform start-of-session initialization.
-        {
-            let span = tracing::debug_span!("Start-of-session initialization");
-            let _enter = span.enter();
-            ret.stdin
-                .initialize(&mut ret.stdout, &ret.opts.after_startup_ghci)
-                .await?;
-        }
+        ret.stdin
+            .initialize(&mut ret.stdout, &ret.opts.after_startup_ghci)
+            .await?;
 
-        {
-            let span = tracing::debug_span!("Start-of-session sync");
-            let _enter = span.enter();
-            // Sync up for any prompts.
-            ret.sync().await?;
-            // Get the initial list of loaded modules.
-            ret.refresh_modules().await?;
-        }
+        // Sync up for any prompts.
+        ret.sync().await?;
+        // Get the initial list of loaded modules.
+        ret.refresh_modules().await?;
 
         tracing::info!("ghci started in {:.2?}", start_instant.elapsed());
 
@@ -325,7 +316,6 @@ impl Ghci {
                 "Restarting ghci due to deleted/moved modules:\n{}",
                 format_bulleted_list(&actions.needs_restart)
             );
-            // TODO: Probably also need a restart hook / `.cabal` hook / similar.
             self.stop().await?;
             let new = Self::new(self.opts.clone()).await?;
             let _ = std::mem::replace(self, new);
@@ -339,7 +329,7 @@ impl Ghci {
                 format_bulleted_list(&actions.needs_add)
             );
             for path in &actions.needs_add {
-                let add_result = self.add_module(path.into()).await?;
+                let add_result = self.add_module(path).await?;
                 if let Some(CompilationResult::Err) = add_result {
                     compilation_failed = true;
                 }
@@ -408,7 +398,7 @@ impl Ghci {
     #[instrument(skip(self), level = "debug")]
     pub async fn add_module(
         &mut self,
-        path: Utf8PathBuf,
+        path: &Utf8Path,
     ) -> miette::Result<Option<CompilationResult>> {
         let messages = self.stdin.add_module(&mut self.stdout, &path).await?;
 
@@ -423,6 +413,7 @@ impl Ghci {
                 // the module to the module set.
             }
         }
+
         Ok(result)
     }
 

ghcid-ng/src/ghci/stderr.rs

@@ -119,7 +119,7 @@ impl GhciStderr {
         Ok(())
     }
 
-    #[instrument(skip(self), level = "debug")]
+    #[instrument(skip(self), level = "trace")]
     async fn ingest_line(&mut self, line: String) {
         // We might not have a buffer for some modes, e.g. `Internal`.
         if let Some(buffer) = self.buffers.get_mut(&self.mode) {
@@ -145,7 +145,7 @@ impl GhciStderr {
             let mut writer = BufWriter::new(file);
 
             if !self.compilation_summary.is_empty() {
-                tracing::debug!(?path, "Writing error log headline");
+                tracing::debug!(%path, "Writing error log headline");
                 writer
                     .write_all(self.compilation_summary.as_bytes())
                     .await
@@ -154,7 +154,7 @@ impl GhciStderr {
             }
 
             for (mode, buffer) in &self.buffers {
-                tracing::debug!(?path, %mode, bytes = buffer.len(), "Writing error log");
+                tracing::debug!(%path, %mode, bytes = buffer.len(), "Writing error log");
                 writer
                     .write_all(&strip_ansi_escapes::strip(buffer.as_bytes()))
                     .await
@@ -171,7 +171,7 @@ impl GhciStderr {
         Ok(())
     }
 
-    #[instrument(skip(self, sender), level = "debug")]
+    #[instrument(skip(self, sender), level = "trace")]
     async fn set_mode(&mut self, sender: oneshot::Sender<()>, mode: Mode) {
         self.mode = mode;
 

ghcid-ng/src/ghci/stdin.rs

@@ -44,7 +44,7 @@ impl GhciStdin {
         stdout.prompt(None).await
     }
 
-    #[instrument(skip(self, stdout), level = "debug")]
+    #[instrument(skip(self, stdout), name = "stdin_initialize", level = "debug")]
     pub async fn initialize(
         &mut self,
         stdout: &mut GhciStdout,
@@ -62,7 +62,7 @@ impl GhciStdin {
         .await?;
 
         for command in setup_commands {
-            tracing::debug!(?command, "Running user intialization command");
+            tracing::debug!(command, "Running user intialization command");
             self.write_line(stdout, &format!("{command}\n")).await?;
         }
 
@@ -83,7 +83,7 @@ impl GhciStdin {
     ) -> miette::Result<()> {
         if let Some(test_command) = test_command {
             self.set_mode(stdout, Mode::Testing).await?;
-            tracing::debug!(command = ?test_command, "Running user test command");
+            tracing::debug!(command = test_command, "Running user test command");
             tracing::info!("Running tests");
             let start_time = Instant::now();
             self.write_line(stdout, &format!("{test_command}\n"))
@@ -114,7 +114,7 @@ impl GhciStdin {
         self.write_line(stdout, &format!(":add {path}\n")).await
     }
 
-    #[instrument(skip(self, stdout), level = "debug")]
+    #[instrument(skip(self, stdout), level = "trace")]
     pub async fn sync(
         &mut self,
         stdout: &mut GhciStdout,
@@ -146,7 +146,7 @@ impl GhciStdin {
         stdout.show_modules().await
     }
 
-    #[instrument(skip(self, stdout), level = "debug")]
+    #[instrument(skip(self, stdout), level = "trace")]
     pub async fn set_mode(&mut self, stdout: &mut GhciStdout, mode: Mode) -> miette::Result<()> {
         let mut set = JoinSet::<Result<(), oneshot::error::RecvError>>::new();
 

ghcid-ng/src/ghci/stdout.rs

@@ -111,7 +111,7 @@ impl GhciStdout {
         Ok(result)
     }
 
-    #[instrument(skip_all, level = "debug")]
+    #[instrument(skip_all, level = "trace")]
     pub async fn sync(&mut self, sentinel: SyncSentinel) -> miette::Result<()> {
         // Read until the sync marker...
         let sync_pattern = AhoCorasick::from_anchored_patterns([sentinel.to_string()]);

ghcid-ng/src/incremental_reader.rs

@@ -249,7 +249,7 @@ where
         }
 
         let line = std::mem::replace(&mut self.line, String::with_capacity(LINE_BUFFER_CAPACITY));
-        tracing::debug!(line, "Read line");
+        tracing::trace!(line, "Read line");
         self.lines.push_str(&line);
         self.lines.push('\n');
 

test-harness/src/internal.rs

@@ -119,7 +119,7 @@ async fn cleanup() {
                         .expect("Failed to kill `ghcid-ng` after test completion");
                 }
                 Ok(Ok(status)) => {
-                    tracing::info!(?status, "ghcid-ng exited");
+                    tracing::info!(%status, "ghcid-ng exited");
                 }
                 Ok(Err(err)) => {
                     tracing::error!("Waiting for ghcid-ng to exit failed: {err}");

test-harness/src/tracing_reader.rs

@@ -48,7 +48,9 @@ impl TracingReader {
 
         while let Some(duration) = backoff.next_backoff() {
             if let Some(line) = self.lines.next_line().await.into_diagnostic()? {
-                let event = serde_json::from_str(&line).into_diagnostic()?;
+                let event = serde_json::from_str(&line)
+                    .into_diagnostic()
+                    .wrap_err_with(|| format!("Failed to deserialize JSON: {line}"))?;
                 return Ok(event);
             }
             tokio::time::sleep(duration).await;