Fix install bottlenecks from logging (#659)

Some users have reported elongated install times. I believe the changes put forth in this PR will alleviate that issue. Before: Decompiler/Compiler would finish but the next step wouldn't initiate for x amount of time. Now: It's almost instant.
open-goal · Jan 7, 2025 · a43c98d · a43c98d
1 parent e89d5a2
commit a43c98d
Show file tree

Hide file tree

Showing 5 changed files with 47 additions and 101 deletions.
diff --git a/src-tauri/src/commands/binaries.rs b/src-tauri/src/commands/binaries.rs
@@ -291,14 +291,7 @@ pub async fn extract_and_validate_iso(
 
   let process_status = watch_process(&mut log_file, &mut child, &app_handle).await?;
   log_file.flush().await?;
-  if process_status.is_none() {
-    log::error!("extraction and validation was not successful. No status code");
-    return Ok(InstallStepOutput {
-      success: false,
-      msg: Some("Unexpected error occurred".to_owned()),
-    });
-  }
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("extraction and validation was successful");
@@ -440,14 +433,7 @@ pub async fn run_decompiler(
 
   // Ensure all remaining data is flushed to the file
   log_file.flush().await?;
-  if process_status.is_none() {
-    log::error!("decompilation was not successful. No status code");
-    return Ok(InstallStepOutput {
-      success: false,
-      msg: Some("Unexpected error occurred".to_owned()),
-    });
-  }
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("decompilation was successful");
@@ -547,7 +533,7 @@ pub async fn run_compiler(
 
   let process_status = watch_process(&mut log_file, &mut child, &app_handle).await?;
   log_file.flush().await?;
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("compilation was successful");

diff --git a/src-tauri/src/commands/features/mods.rs b/src-tauri/src/commands/features/mods.rs
@@ -298,14 +298,7 @@ pub async fn extract_iso_for_mod_install(
   .await?;
 
   let process_status = watch_process(&mut log_file, &mut child, &app_handle).await?;
-  if process_status.is_none() {
-    log::error!("extraction and validation was not successful. No status code");
-    return Ok(InstallStepOutput {
-      success: false,
-      msg: Some("Unexpected error occurred".to_owned()),
-    });
-  }
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("extraction and validation was successful");
@@ -404,14 +397,7 @@ pub async fn decompile_for_mod_install(
 
   // Ensure all remaining data is flushed to the file
   log_file.flush().await?;
-  if process_status.is_none() {
-    log::error!("decompilation was not successful. No status code");
-    return Ok(InstallStepOutput {
-      success: false,
-      msg: Some("Unexpected error occurred".to_owned()),
-    });
-  }
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("decompilation was successful");
@@ -508,14 +494,7 @@ pub async fn compile_for_mod_install(
 
   let process_status = watch_process(&mut log_file, &mut child, &app_handle).await?;
   log_file.flush().await?;
-  if process_status.is_none() {
-    log::error!("compilation was not successful. No status code");
-    return Ok(InstallStepOutput {
-      success: false,
-      msg: Some("Unexpected error occurred".to_owned()),
-    });
-  }
-  match process_status.unwrap().code() {
+  match process_status.code() {
     Some(code) => {
       if code == 0 {
         log::info!("compilation was successful");

diff --git a/src-tauri/src/util/process.rs b/src-tauri/src/util/process.rs
@@ -1,8 +1,8 @@
-use std::{process::ExitStatus, sync::Arc, time::Duration};
+use std::process::ExitStatus;
 
 use tokio::{
   io::{AsyncBufReadExt, AsyncWriteExt},
-  sync::Mutex,
+  sync::mpsc,
 };
 
 use crate::commands::CommandError;
@@ -45,55 +45,49 @@ pub async fn watch_process(
   log_file: &mut tokio::fs::File,
   child: &mut tokio::process::Child,
   app_handle: &tauri::AppHandle,
-) -> Result<Option<ExitStatus>, CommandError> {
+) -> Result<ExitStatus, CommandError> {
   let stdout = child.stdout.take().unwrap();
   let stderr = child.stderr.take().unwrap();
 
   let mut stdout_reader = tokio::io::BufReader::new(stdout).lines();
   let mut stderr_reader = tokio::io::BufReader::new(stderr).lines();
-  let combined_buffer = Arc::new(Mutex::new(String::new()));
+  let (log_sender, mut log_receiver) = mpsc::channel::<String>(200);
+  let app_handle_clone = app_handle.clone();
 
-  let mut interval = tokio::time::interval(Duration::from_millis(25));
+  tokio::spawn(async move {
+    while let Some(log) = log_receiver.recv().await {
+      let _ = app_handle_clone.emit_all("log_update", LogPayload { logs: log });
+    }
+  });
+
+  let mut process_status: ExitStatus;
 
-  let mut process_status = None;
   loop {
-    let buffer_clone = Arc::clone(&combined_buffer);
     tokio::select! {
         Ok(Some(line)) = stdout_reader.next_line() => {
-          let formatted_line = format!("{line}\n");
-          log_file.write_all(formatted_line.as_bytes()).await?;
+          let formatted_line = format!("{line}\n").trim().to_string();
           if formatted_line != "\n" {
-            let mut buf = buffer_clone.lock().await;
-            buf.push_str(&formatted_line);
+            log_sender.try_send(formatted_line.clone()).ok();
+            log_file.write_all(formatted_line.as_bytes()).await?;
+            log_file.flush().await?;
           }
         },
         Ok(Some(line)) = stderr_reader.next_line() => {
-          let formatted_line = format!("{line}\n");
-          log_file.write_all(formatted_line.as_bytes()).await?;
+          let formatted_line = format!("{line}\n").trim().to_string();
           if formatted_line != "\n" {
-            let mut buf = buffer_clone.lock().await;
-            buf.push_str(&formatted_line);
-          }
-        },
-        _ = interval.tick() => {
-          log_file.flush().await?;
-          {
-            let mut buf = buffer_clone.lock().await;
-            let _ = app_handle.emit_all("log_update", LogPayload { logs: buf.clone() });
-            buf.clear();
+            log_sender.try_send(formatted_line.clone()).ok();
+            log_file.write_all(formatted_line.as_bytes()).await?;
+            log_file.flush().await?;
           }
         },
-        // Wait for the child process to finish
         status = child.wait() => {
-          let mut buf = buffer_clone.lock().await;
-          let _ = app_handle.emit_all("log_update", LogPayload { logs: buf.clone() });
-          buf.clear();
-          process_status = Some(status?);
+          process_status = status?;
+          drop(log_sender);
           break;
         }
     }
   }
-  return Ok(process_status);
+  Ok(process_status)
 }
 
 pub fn create_std_log_file(

diff --git a/src/components/games/setup/LogViewer.svelte b/src/components/games/setup/LogViewer.svelte
@@ -6,35 +6,25 @@
   import { onDestroy, onMount } from "svelte";
   import { _ } from "svelte-i18n";
 
-  let logListener: any = undefined;
-  let logElement;
-
-  const scrollToBottom = async (node) => {
-    node.scroll({ top: node.scrollHeight, behavior: "instant" });
-  };
+  let unlisten;
 
   onMount(async () => {
-    logListener = await listen("log_update", (event) => {
-      progressTracker.appendLogs(event.payload.logs);
-      if (logElement) {
-        scrollToBottom(logElement);
-      }
+    unlisten = await listen("log_update", (event) => {
+      const newLogs = event.payload.logs
+        .split("\n")
+        .map((log) => ansiSpan(escapeHtml(log)).replaceAll("\n", "<br/>"))
+        .filter((log) => log.length > 0);
+      progressTracker.appendLogs(newLogs);
     });
   });
 
-  onDestroy(() => {
-    if (logListener !== undefined) {
-      logListener();
-    }
-  });
-
-  function convertLogColors(text) {
-    return ansiSpan(escapeHtml(text)).replaceAll("\n", "<br/>");
-  }
+  onDestroy(() => unlisten());
 </script>
 
-{#if $progressTracker.logs}
+{#if $progressTracker.logs.length > 0}
   <pre
-    class="rounded p-2 bg-[#141414] text-[11px] max-h-[300px] overflow-auto text-pretty font-mono"
-    bind:this={logElement}>{@html convertLogColors($progressTracker.logs)}</pre>
+    class="rounded bg-[#141414] text-[11px] max-h-[300px] overflow-auto font-mono">{#each $progressTracker.logs as log}
+      {@html log}
+    {/each}
+</pre>
 {/if}
diff --git a/src/lib/stores/ProgressStore.ts b/src/lib/stores/ProgressStore.ts
@@ -16,14 +16,14 @@ interface ProgressTracker {
   currentStep: number;
   overallStatus: ProgressStatus;
   steps: ProgressStep[];
-  logs: string | undefined;
+  logs: string[];
 }
 
 const storeValue: ProgressTracker = {
   currentStep: 0,
   overallStatus: "inactive",
   steps: [],
-  logs: undefined,
+  logs: [],
 };
 
 function createProgressTracker() {
@@ -36,7 +36,7 @@ function createProgressTracker() {
         val.currentStep = 0;
         val.overallStatus = "inactive";
         val.steps = steps;
-        val.logs = undefined;
+        val.logs = [];
         return val;
       }),
     start: () =>
@@ -66,12 +66,9 @@ function createProgressTracker() {
         val.steps[val.currentStep].status = "failed";
         return val;
       }),
-    appendLogs: (logs: string) =>
+    appendLogs: (logs: string[]) =>
       update((val) => {
-        if (val.logs === undefined) {
-          val.logs = "";
-        }
-        val.logs += logs;
+        val.logs = [...val.logs, ...logs];
         return val;
       }),
   };