Additional info to debug AccessDenied problems (#10663)

Plain `Storage failure [AccessDenied].` was rather uninformative when it comes to debugging the underlying problem.
Added more detailed error messages and runners' failures should now sometimes print a detailed message.
References #10662.

build.sbt

@@ -335,6 +335,7 @@ lazy val enso = (project in file("."))
     `library-manager-test`,
     `connected-lock-manager`,
     `connected-lock-manager-server`,
+    `process-utils`,
     testkit,
     `test-utils`,
     `common-polyglot-core-utils`,
@@ -3137,6 +3138,7 @@ lazy val `library-manager-test` = project
     )
   )
   .dependsOn(`library-manager`)
+  .dependsOn(`process-utils`)
   .dependsOn(`logging-utils` % "test->test")
   .dependsOn(testkit)
   .dependsOn(`logging-service-logback` % "test->test")
@@ -3189,10 +3191,20 @@ lazy val `runtime-version-manager` = project
   .dependsOn(pkg)
   .dependsOn(downloader)
   .dependsOn(cli)
+  .dependsOn(`process-utils`)
   .dependsOn(`version-output`)
   .dependsOn(`edition-updater`)
   .dependsOn(`distribution-manager`)
 
+/** `process-utils` provides utilities for correctly managing process execution such as providing
+  *  handlers for its stdout/stderr.
+  */
+lazy val `process-utils` = project
+  .in(file("lib/scala/process-utils"))
+  .settings(
+    frgaalJavaCompilerSetting
+  )
+
 lazy val `runtime-version-manager-test` = project
   .in(file("lib/scala/runtime-version-manager-test"))
   .configs(Test)

engine/launcher/src/main/scala/org/enso/launcher/Launcher.scala

@@ -81,7 +81,7 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
       versionOverride.getOrElse(configurationManager.defaultVersion)
     val globalConfig = configurationManager.getConfig
 
-    val exitCode = runner
+    val (exitCode, output) = runner
       .withCommand(
         runner
           .newProject(
@@ -97,7 +97,7 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
           .get,
         JVMSettings(useSystemJVM, jvmOpts, extraOptions = Seq.empty)
       ) { command =>
-        command.run().get
+        command.runAndCaptureOutput().get
       }
 
     if (exitCode == 0) {
@@ -105,7 +105,7 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
         s"Project created in `$actualPath` using version $version."
       )
     } else {
-      logger.error("Project creation failed.")
+      logger.error(s"Project creation failed: $output")
     }
 
     exitCode
@@ -211,7 +211,7 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
     jvmOpts: Seq[(String, String)],
     additionalArguments: Seq[String]
   ): Int = {
-    val exitCode = runner
+    runner
       .withCommand(
         runner
           .repl(
@@ -226,7 +226,6 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
       ) { command =>
         command.run().get
       }
-    exitCode
   }
 
   /** Runs an Enso script or project.
@@ -412,12 +411,13 @@ case class Launcher(cliOptions: GlobalCLIOptions) {
       )
       .get
 
-    runner.withCommand(
-      settings,
-      JVMSettings(useSystemJVM, jvmOpts, extraOptions = Seq())
-    ) { command =>
-      command.run().get
-    }
+    runner
+      .withCommand(
+        settings,
+        JVMSettings(useSystemJVM, jvmOpts, extraOptions = Seq())
+      ) { command =>
+        command.run().get
+      }
   }
 
   /** Prints the value of `key` from the global configuration.

engine/launcher/src/test/scala/org/enso/launcher/NativeTest.scala

@@ -2,7 +2,7 @@ package org.enso.launcher
 
 import org.enso.cli.OS
 import org.enso.runtimeversionmanager.test.NativeTestHelper
-import org.enso.testkit.process.RunResult
+import org.enso.process.RunResult
 import org.scalatest.concurrent.{Signaler, TimeLimitedTests}
 import org.scalatest.matchers.should.Matchers
 import org.scalatest.matchers.{MatchResult, Matcher}

engine/launcher/src/test/scala/org/enso/launcher/upgrade/UpgradeSpec.scala

@@ -9,7 +9,7 @@ import FileSystem.PathSyntax
 import org.enso.cli.OS
 import org.enso.launcher._
 import org.enso.testkit.{FlakySpec, WithTemporaryDirectory}
-import org.enso.testkit.process.{RunResult, WrappedProcess}
+import org.enso.process.{RunResult, WrappedProcess}
 import org.scalatest.exceptions.TestFailedException
 import org.scalatest.{BeforeAndAfterAll, Ignore, OptionValues}
 

lib/scala/library-manager-test/src/main/scala/org/enso/librarymanager/published/repository/DummyRepository.scala

@@ -7,7 +7,7 @@ import org.enso.downloader.archive.TarGzWriter
 import org.enso.editions.Editions.RawEdition
 import org.enso.editions.{Editions, LibraryName}
 import org.enso.pkg.{Package, PackageManager}
-import org.enso.testkit.process.WrappedProcess
+import org.enso.process.WrappedProcess
 import org.enso.yaml.YamlHelper
 
 import java.io.File

lib/scala/process-utils/src/main/scala/org/enso/process/RunResult.scala

@@ -1,4 +1,4 @@
-package org.enso.testkit.process
+package org.enso.process
 
 /** A result of running a process.
   *

lib/scala/process-utils/src/main/scala/org/enso/process/WrappedProcess.scala

@@ -1,4 +1,4 @@
-package org.enso.testkit.process
+package org.enso.process
 
 import java.io._
 import java.util.concurrent.{Semaphore, TimeUnit}
@@ -87,6 +87,31 @@ class WrappedProcess(command: Seq[String], process: Process) {
     }
   }
 
+  /** Registers a handler for stdout/stderr that appends streams to the provided
+    * string builder.
+    */
+  def registerStringBuilderAppendTarget(
+    builder: StringBuilder
+  ): Unit = {
+    def handler(line: String, streamType: StreamType): Unit = {
+      streamType match {
+        case StdErr =>
+          builder.append(
+            s"stderr> $line${System.getProperty("line.separator")}"
+          )
+        case StdOut =>
+          builder.append(
+            s"stdout> $line${System.getProperty("line.separator")}"
+          )
+      }
+    }
+
+    this.synchronized {
+      ioHandlers ++= Seq(handler _)
+    }
+
+  }
+
   private lazy val inputWriter = new PrintWriter(process.getOutputStream)
 
   /** Prints a message to the standard input stream of the process.

lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/file/BlockingFileSystem.scala

@@ -123,12 +123,12 @@ class BlockingFileSystem[F[+_, +_]: Sync: ErrorChannel](
       .mapError(toFsFailure)
 
   private val toFsFailure: Throwable => FileSystemFailure = {
-    case _: FileNotFoundException => FileNotFound
-    case _: NotDirectoryException => NotDirectory
-    case _: NoSuchFileException   => FileNotFound
-    case _: FileExistsException   => FileExists
-    case _: AccessDeniedException => AccessDenied
-    case ex                       => GenericFileSystemFailure(ex.getMessage)
+    case _: FileNotFoundException  => FileNotFound
+    case _: NotDirectoryException  => NotDirectory
+    case _: NoSuchFileException    => FileNotFound
+    case _: FileExistsException    => FileExists
+    case ex: AccessDeniedException => AccessDenied(ex.getFile)
+    case ex                        => GenericFileSystemFailure(ex.getMessage)
   }
 
 }

lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/file/FileSystemFailure.scala

@@ -8,7 +8,9 @@ object FileSystemFailure {
 
   /** Signals that a user doesn't have access to a file.
     */
-  case object AccessDenied extends FileSystemFailure
+  case class AccessDenied(file: String) extends FileSystemFailure {
+    override def toString: String = s"AccessDenied[$file]"
+  }
 
   /** Signals that the file cannot be found.
     */

lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/repository/ProjectFileRepository.scala

@@ -66,7 +66,9 @@ class ProjectFileRepository[
       .recover { case FileNotFound | NotDirectory =>
         Nil
       }
-      .mapError(th => StorageFailure(th.toString))
+      .mapError(th =>
+        StorageFailure(s"Cannot find projects at $projectsPath: ${th.toString}")
+      )
       .flatMap { dirs =>
         Traverse[List].traverse(dirs)(tryLoadProject).map(_.flatten)
       }
@@ -172,14 +174,18 @@ class ProjectFileRepository[
   ): F[ProjectRepositoryFailure, Option[Package[File]]] =
     Sync[F]
       .blockingOp { PackageManager.Default.fromDirectory(projectPath) }
-      .mapError(th => StorageFailure(th.toString))
+      .mapError(th => StorageFailure(s"Cannot load package $projectPath: $th"))
 
   private def getDirectoryCreationTime(
     pkg: Package[File]
   ): F[ProjectRepositoryFailure, FileTime] =
     Sync[F]
       .blockingOp(pkg.fileSystem.getCreationTime(pkg.root))
-      .mapError(th => StorageFailure(th.toString))
+      .mapError(th =>
+        StorageFailure(
+          s"Cannot find creation time for package ${pkg.root}: $th"
+        )
+      )
 
   private def getPackage(
     projectPath: File
@@ -202,14 +208,20 @@ class ProjectFileRepository[
         Sync[F]
           .blockingOp { projectPackage.rename(newName) }
           .map(_ => ())
-          .mapError(th => StorageFailure(th.toString))
+          .mapError(th =>
+            StorageFailure(
+              s"Cannot rename package $newName at $projectPath: $th"
+            )
+          )
       }
 
   /** @inheritdoc */
   def update(project: Project): F[ProjectRepositoryFailure, Unit] =
     metadataStorage(project.path)
       .persist(ProjectMetadata(project))
-      .mapError(th => StorageFailure(th.toString))
+      .mapError(th =>
+        StorageFailure(s"Cannot update project at ${project.path}: $th")
+      )
 
   /** @inheritdoc */
   override def delete(projectId: UUID): F[ProjectRepositoryFailure, Unit] = {
@@ -218,7 +230,9 @@ class ProjectFileRepository[
         case Some(project) =>
           fileSystem
             .remove(project.path)
-            .mapError(th => StorageFailure(th.toString))
+            .mapError(th =>
+              StorageFailure(s"Cannot delete project at ${project.path}: $th")
+            )
         case None =>
           ErrorChannel[F].fail(ProjectNotFoundInIndex)
       }
@@ -257,7 +271,11 @@ class ProjectFileRepository[
       newProjectPath <- copy(project)
       _ <- metadataStorage(newProjectPath)
         .persist(newMetadata)
-        .mapError(th => StorageFailure(th.toString))
+        .mapError(th =>
+          StorageFailure(
+            s"Cannot persist new project name at $newProjectPath: $th"
+          )
+        )
       _          <- renamePackage(newProjectPath, newName)
       newProject <- getProject(newMetadata.id)
     } yield newProject
@@ -267,7 +285,9 @@ class ProjectFileRepository[
     fileSystem
       .move(projectPath, targetPath)
       .mapError[ProjectRepositoryFailure](failure =>
-        StorageFailure(failure.toString)
+        StorageFailure(
+          s"Cannot move project path from $projectPath to $targetPath: $failure"
+        )
       )
   }
 
@@ -275,7 +295,9 @@ class ProjectFileRepository[
     fileSystem
       .copy(projectPath, targetPath)
       .mapError[ProjectRepositoryFailure](failure =>
-        StorageFailure(failure.toString)
+        StorageFailure(
+          s"Cannot copy project directory $projectPath to $targetPath: $failure"
+        )
       )
   }
 
@@ -292,7 +314,7 @@ class ProjectFileRepository[
         fileSystem
           .exists(path)
           .mapError[ProjectRepositoryFailure](failure =>
-            StorageFailure(failure.toString)
+            StorageFailure(s"Cannot find path $path: $failure")
           )
           .flatMap { fileExists =>
             if (fileExists) {

lib/scala/project-manager/src/main/scala/org/enso/projectmanager/service/ProjectCreationService.scala

@@ -74,20 +74,20 @@ class ProjectCreationService[
           s"Running engine $engineVersion to create project $name at " +
           s"[${MaskedPath(path).applyMasking()}]."
         )
-        command.run().get
+        command.runAndCaptureOutput().get
       }
     }
     .mapRuntimeManagerErrors { other: Throwable =>
       ProjectCreateFailed(other.getMessage)
     }
-    .flatMap { exitCode =>
+    .flatMap { case (exitCode, output) =>
       if (exitCode == 0)
         CovariantFlatMap[F].pure(())
       else
         ErrorChannel[F].fail(
           ProjectCreateFailed(
-            s"The runner used to create the project returned exit code " +
-            s"$exitCode."
+            s"The runner used to create the project returned exit code $exitCode.${System
+              .getProperty("line.separator")}Runner's output: $output"
           )
         )
     }

lib/scala/runtime-version-manager-test/src/main/scala/org/enso/runtimeversionmanager/test/NativeTestHelper.scala

@@ -1,7 +1,7 @@
 package org.enso.runtimeversionmanager.test
 
 import org.enso.cli.OS
-import org.enso.testkit.process.{RunResult, WrappedProcess}
+import org.enso.process.{RunResult, WrappedProcess}
 
 import java.lang.{ProcessBuilder => JProcessBuilder}
 import scala.jdk.CollectionConverters._

lib/scala/runtime-version-manager/src/main/scala/org/enso/runtimeversionmanager/runner/Command.scala

@@ -1,6 +1,7 @@
 package org.enso.runtimeversionmanager.runner
 
 import com.typesafe.scalalogging.Logger
+import org.enso.process.WrappedProcess
 
 import scala.sys.process.Process
 import scala.util.{Failure, Try}
@@ -27,6 +28,31 @@ case class Command(command: Seq[String], extraEnv: Seq[(String, String)]) {
       process.waitFor()
     }
 
+  /** Runs the command and returns its exit code along with any output produced..
+    *
+    * May return an exception if it is impossible to run the command (for
+    * example due to insufficient permissions or nonexistent executable).
+    *
+    * @param timeoutInSeconds timeout specifying how long this thread will wait
+    *                         for the process to finish until it attempts to kill it
+    */
+  def runAndCaptureOutput(
+    timeoutInSeconds: Option[Long] = Some(300)
+  ): Try[(Int, String)] =
+    wrapError {
+      logger.debug("Executing {}", this)
+      val processBuilder = builder()
+      val process        = processBuilder.start()
+      val wrappedProcess = new WrappedProcess(command, process)
+      val stringBuilder  = new StringBuilder()
+      wrappedProcess.registerStringBuilderAppendTarget(stringBuilder)
+      val result = wrappedProcess.join(
+        waitForDescendants = true,
+        timeoutInSeconds.getOrElse(Long.MaxValue)
+      )
+      (result.exitCode, stringBuilder.toString())
+    }
+
   /** Runs the command and returns its standard output as [[String]].
     *
     * The standard error is printed to the console.