feat: debug graal install (#1663)

Log GraalVM installation progress

lib/scala/runtime-version-manager/src/main/scala/org/enso/runtimeversionmanager/components/GraalVMComponentUpdater.scala

@@ -2,6 +2,7 @@ package org.enso.runtimeversionmanager.components
 
 import java.nio.file.Path
 
+import com.typesafe.scalalogging.Logger
 import org.enso.runtimeversionmanager.OS
 
 import scala.sys.process._
@@ -17,22 +18,30 @@ class GraalVMComponentUpdater(runtime: GraalRuntime, os: OS)
 
   import GraalVMComponentUpdater._
 
+  private val logger = Logger[GraalVMComponentUpdater]
+
   /** List the installed GraalVM components.
     *
     * @return the list of installed GraalVM components
     */
   override def list: Try[Seq[GraalVMComponent]] = {
-    val suppressStderr = ProcessLogger(_ => ())
+    val command: Seq[String] = Seq(Paths.gu, "list", "-v")
     val process = Process(
-      Seq[String](Paths.gu, "list", "-v"),
+      command,
       Some(runtime.path.toFile),
       ("JAVA_HOME", runtime.path),
       ("GRAALVM_HOME", runtime.path)
     )
 
+    logger.trace(
+      s"command=${command.mkString(" ")}; " +
+      s"JAVA_HOME=${Properties(runtime.path)}" +
+      s"gu=${Properties(Paths.gu)}"
+    )
     for {
-      lines <- Try(process.lazyLines(suppressStderr))
-    } yield ListOut.parse(lines)
+      stdout <- Try(process.lazyLines(stderrLogger))
+      _ = logger.trace(stdout.mkString(System.lineSeparator()))
+    } yield ListOut.parse(stdout)
   }
 
   /** Install the provided GraalVM components.
@@ -41,19 +50,31 @@ class GraalVMComponentUpdater(runtime: GraalRuntime, os: OS)
     */
   override def install(components: Seq[GraalVMComponent]): Try[Unit] = {
     if (components.nonEmpty) {
-      val componentsList = components.map(_.id)
+      val command: Seq[String] =
+        Seq[String](Paths.gu, "install") ++ components.map(_.id)
       val process = Process(
-        Seq[String](Paths.gu, "install") ++ componentsList,
+        command,
         Some(runtime.path.toFile),
         ("JAVA_HOME", runtime.path),
         ("GRAALVM_HOME", runtime.path)
       )
-      Try(process.!!)
+      logger.trace(
+        s"command=${command.mkString(" ")}; " +
+        s"JAVA_HOME=${Properties(runtime.path)}" +
+        s"gu=${Properties(Paths.gu)}"
+      )
+      for {
+        stdout <- Try(process.lazyLines(stderrLogger))
+        _ = logger.trace(stdout.mkString(System.lineSeparator()))
+      } yield ()
     } else {
       Success(())
     }
   }
 
+  private def stderrLogger =
+    ProcessLogger(err => logger.trace(s"[stderr] $err"))
+
   private object Paths {
 
     /** Path to `gu` executable. */
@@ -74,6 +95,18 @@ object GraalVMComponentUpdater {
     def /(child: String): Path = path.resolve(child)
   }
 
+  /** Debug file properties. */
+  private case class Properties(path: Path) {
+
+    private val file = path.toFile
+
+    override def toString: String =
+      s"${path.toAbsolutePath} { " +
+      s"exists=${file.exists()}; " +
+      s"executable=${file.canExecute}; " +
+      "}"
+  }
+
   /** Parser for the `gu list -v` command output. */
   object ListOut {
 

lib/scala/runtime-version-manager/src/main/scala/org/enso/runtimeversionmanager/components/RuntimeVersionManager.scala

@@ -578,6 +578,7 @@ class RuntimeVersionManager(
   /** Loads the GraalVM runtime definition.
     */
   private def loadGraalRuntime(path: Path): Try[GraalRuntime] = {
+    logger.debug(s"Loading Graal runtime ${path.toAbsolutePath}.")
     val name = path.getFileName.toString
     for {
       version <- parseGraalRuntimeVersionString(name)
@@ -666,10 +667,12 @@ class RuntimeVersionManager(
     runtimeVersion: GraalVMVersion
   ): GraalRuntime =
     FileSystem.withTemporaryDirectory("enso-install-runtime") { directory =>
+      logger.debug(s"Installing runtime $runtimeVersion.")
       val runtimePackage =
         directory / runtimeReleaseProvider.packageFileName(runtimeVersion)
       val downloadTask =
         runtimeReleaseProvider.downloadPackage(runtimeVersion, runtimePackage)
+      logger.debug(s"Downloading ${runtimePackage.getFileName}.")
       userInterface.trackProgress(
         s"Downloading ${runtimePackage.getFileName}.",
         downloadTask
@@ -683,6 +686,7 @@ class RuntimeVersionManager(
         temporaryDirectoryManager.accessTemporaryDirectory(),
         Some(runtimeDirectoryName)
       )
+      logger.debug(s"Extracting ${runtimePackage.toAbsolutePath}.")
       userInterface.trackProgress("Extracting the runtime.", extractionTask)
       extractionTask.force()
 
@@ -697,6 +701,9 @@ class RuntimeVersionManager(
       }
 
       try {
+        logger.debug(
+          s"Loading temporary runtime ${runtimeTemporaryPath.toAbsolutePath}."
+        )
         val temporaryRuntime =
           loadGraalRuntime(runtimeTemporaryPath).getOrElse {
             throw InstallationError(
@@ -704,6 +711,7 @@ class RuntimeVersionManager(
               "corrupted. Reverting installation."
             )
           }
+        logger.debug(s"Installing GraalVM components to $temporaryRuntime.")
         installRequiredRuntimeComponents(temporaryRuntime, os).getOrElse {
           throw InstallationError(
             "fatal: Cannot install the required runtime components."
@@ -712,6 +720,9 @@ class RuntimeVersionManager(
 
         val runtimePath =
           distributionManager.paths.runtimes / runtimeDirectoryName
+        logger.debug(
+          s"Moving ${runtimeTemporaryPath.toAbsolutePath} to ${runtimePath.toAbsolutePath}."
+        )
         FileSystem.atomicMove(runtimeTemporaryPath, runtimePath)
         val runtime = loadGraalRuntime(runtimePath).getOrElse {
           FileSystem.removeDirectory(runtimePath)
@@ -719,6 +730,7 @@ class RuntimeVersionManager(
             "fatal: Cannot load the installed runtime."
           )
         }
+        logger.debug(s"Installed $runtime.")
         userInterface.logInfo(s"Installed $runtime.")
 
         runtime
@@ -738,12 +750,14 @@ class RuntimeVersionManager(
     runtime: GraalRuntime,
     os: OS
   ): Try[Unit] = {
+    logger.debug(s"Installing GraalVM components $runtime on $os.")
     val cu = componentUpdaterFactory.build(runtime, os)
     val requiredComponents =
       componentConfig.getRequiredComponents(runtime.version, os)
 
     for {
       installedComponents <- cu.list
+      _                 = logger.debug(s"Available GraalVM components: $installedComponents.")
       missingComponents = requiredComponents.diff(installedComponents)
       _ <- cu.install(missingComponents)
     } yield ()