From 709c9038b15ca33f688ac14e9907a520a7ac89d7 Mon Sep 17 00:00:00 2001 From: Piotr Chabelski Date: Fri, 31 Jan 2025 16:34:05 +0100 Subject: [PATCH] Add operation retries to prevent unnecessary failures when multiple Scala CLI instances are run on the same project in parallel --- .../src/main/scala/scala/build/Bloop.scala | 48 +++++++------ .../src/main/scala/scala/build/Build.scala | 10 +-- .../build/compiler/BloopCompilerMaker.scala | 31 +++++--- .../scala/build/internal/MainClass.scala | 71 +++++++++++++------ .../src/main/scala/scala/build/package.scala | 33 +++++++++ .../postprocessing/AsmPositionUpdater.scala | 45 ++++++++---- .../postprocessing/TastyPostProcessor.scala | 54 ++++++++------ .../src/main/scala/scala/build/Logger.scala | 2 + .../cli/integration/RunTestDefinitions.scala | 49 ++++++++++++- 9 files changed, 246 insertions(+), 97 deletions(-) create mode 100644 modules/build/src/main/scala/scala/build/package.scala diff --git a/modules/build/src/main/scala/scala/build/Bloop.scala b/modules/build/src/main/scala/scala/build/Bloop.scala index bd439fb39d..743acb10ed 100644 --- a/modules/build/src/main/scala/scala/build/Bloop.scala +++ b/modules/build/src/main/scala/scala/build/Bloop.scala @@ -12,9 +12,10 @@ import java.io.{File, IOException} import scala.annotation.tailrec import scala.build.EitherCps.{either, value} import scala.build.errors.{BuildException, ModuleFormatError} -import scala.build.internal.CsLoggerUtil._ +import scala.build.internal.CsLoggerUtil.* +import scala.concurrent.ExecutionException import scala.concurrent.duration.FiniteDuration -import scala.jdk.CollectionConverters._ +import scala.jdk.CollectionConverters.* object Bloop { @@ -35,32 +36,37 @@ object Bloop { logger: Logger, buildTargetsTimeout: FiniteDuration ): Either[Throwable, Boolean] = - try { - logger.debug("Listing BSP build targets") - val results = buildServer.workspaceBuildTargets() - .get(buildTargetsTimeout.length, buildTargetsTimeout.unit) - val buildTargetOpt = results.getTargets.asScala.find(_.getDisplayName == projectName) + try retry()(logger) { + logger.debug("Listing BSP build targets") + val results = buildServer.workspaceBuildTargets() + .get(buildTargetsTimeout.length, buildTargetsTimeout.unit) + val buildTargetOpt = results.getTargets.asScala.find(_.getDisplayName == projectName) - val buildTarget = buildTargetOpt.getOrElse { - throw new Exception( - s"Expected to find project '$projectName' in build targets (only got ${results.getTargets - .asScala.map("'" + _.getDisplayName + "'").mkString(", ")})" - ) - } + val buildTarget = buildTargetOpt.getOrElse { + throw new Exception( + s"Expected to find project '$projectName' in build targets (only got ${results.getTargets + .asScala.map("'" + _.getDisplayName + "'").mkString(", ")})" + ) + } - logger.debug(s"Compiling $projectName with Bloop") - val compileRes = buildServer.buildTargetCompile( - new bsp4j.CompileParams(List(buildTarget.getId).asJava) - ).get() + logger.debug(s"Compiling $projectName with Bloop") + val compileRes = buildServer.buildTargetCompile( + new bsp4j.CompileParams(List(buildTarget.getId).asJava) + ).get() - val success = compileRes.getStatusCode == bsp4j.StatusCode.OK - logger.debug(if (success) "Compilation succeeded" else "Compilation failed") - Right(success) - } + val success = compileRes.getStatusCode == bsp4j.StatusCode.OK + logger.debug(if (success) "Compilation succeeded" else "Compilation failed") + Right(success) + } catch { case ex @ BrokenPipeInCauses(e) => logger.debug(s"Caught $ex while exchanging with Bloop server, assuming Bloop server exited") Left(ex) + case ex: ExecutionException => + logger.debug( + s"Caught $ex while exchanging with Bloop server, you may consider restarting the build server" + ) + Left(ex) } def bloopClassPath( diff --git a/modules/build/src/main/scala/scala/build/Build.scala b/modules/build/src/main/scala/scala/build/Build.scala index 1d0482d5ef..ac72d747fb 100644 --- a/modules/build/src/main/scala/scala/build/Build.scala +++ b/modules/build/src/main/scala/scala/build/Build.scala @@ -50,16 +50,17 @@ object Build { output: os.Path, diagnostics: Option[Seq[(Either[String, os.Path], bsp4j.Diagnostic)]], generatedSources: Seq[GeneratedSource], - isPartial: Boolean + isPartial: Boolean, + logger: Logger ) extends Build { def success: Boolean = true def successfulOpt: Some[this.type] = Some(this) def outputOpt: Some[os.Path] = Some(output) def dependencyClassPath: Seq[os.Path] = sources.resourceDirs ++ artifacts.classPath def fullClassPath: Seq[os.Path] = Seq(output) ++ dependencyClassPath - private lazy val mainClassesFoundInProject: Seq[String] = MainClass.find(output).sorted + private lazy val mainClassesFoundInProject: Seq[String] = MainClass.find(output, logger).sorted private lazy val mainClassesFoundOnExtraClasspath: Seq[String] = - options.classPathOptions.extraClassPath.flatMap(MainClass.find).sorted + options.classPathOptions.extraClassPath.flatMap(MainClass.find(_, logger)).sorted private lazy val mainClassesFoundInUserExtraDependencies: Seq[String] = artifacts.jarsForUserExtraDependencies.flatMap(MainClass.findInDependency).sorted def foundMainClasses(): Seq[String] = { @@ -1184,7 +1185,8 @@ object Build { classesDir0, buildClient.diagnostics, generatedSources, - partial + partial, + logger ) else Failed( diff --git a/modules/build/src/main/scala/scala/build/compiler/BloopCompilerMaker.scala b/modules/build/src/main/scala/scala/build/compiler/BloopCompilerMaker.scala index 34eaa1d3c6..d142178417 100644 --- a/modules/build/src/main/scala/scala/build/compiler/BloopCompilerMaker.scala +++ b/modules/build/src/main/scala/scala/build/compiler/BloopCompilerMaker.scala @@ -3,11 +3,11 @@ package scala.build.compiler import bloop.rifle.{BloopRifleConfig, BloopServer, BloopThreads} import ch.epfl.scala.bsp4j.BuildClient -import scala.build.Logger import scala.build.errors.{BuildException, FetchingDependenciesError, Severity} import scala.build.internal.Constants import scala.build.internal.util.WarningMessages import scala.build.options.BuildOptions +import scala.build.{Logger, retry} import scala.concurrent.duration.DurationInt import scala.util.Try @@ -37,16 +37,25 @@ final class BloopCompilerMaker( case Right(config) => val createBuildServer = () => - BloopServer.buildServer( - config, - "scala-cli", - Constants.version, - workspace.toNIO, - classesDir.toNIO, - buildClient, - threads, - logger.bloopRifleLogger - ) + // retrying here in case a number of Scala CLI processes are started at the same time + // and they all try to connect to the server / spawn a new server + // otherwise, users may run into one of: + // - libdaemonjvm.client.ConnectError$ZombieFound + // - Caught java.lang.RuntimeException: Fatal error, could not spawn Bloop: not running + // - java.lang.RuntimeException: Bloop BSP connection in (...) was unexpectedly closed or bloop didn't start. + // if a sufficiently large number of processes was started, this may happen anyway, of course + retry(if offline then 1 else 3)(logger) { + BloopServer.buildServer( + config, + "scala-cli", + Constants.version, + workspace.toNIO, + classesDir.toNIO, + buildClient, + threads, + logger.bloopRifleLogger + ) + } val res = Try(new BloopCompiler(createBuildServer, 20.seconds, strictBloopJsonCheck)) .toEither diff --git a/modules/build/src/main/scala/scala/build/internal/MainClass.scala b/modules/build/src/main/scala/scala/build/internal/MainClass.scala index ed46bbd61e..6a05c776f7 100644 --- a/modules/build/src/main/scala/scala/build/internal/MainClass.scala +++ b/modules/build/src/main/scala/scala/build/internal/MainClass.scala @@ -4,11 +4,13 @@ import org.objectweb.asm import org.objectweb.asm.ClassReader import java.io.{ByteArrayInputStream, InputStream} +import java.nio.file.NoSuchFileException import java.util.jar.{Attributes, JarFile, JarInputStream, Manifest} import java.util.zip.ZipEntry import scala.build.input.Element import scala.build.internal.zip.WrappedZipInputStream +import scala.build.{Logger, retry} object MainClass { @@ -44,29 +46,54 @@ object MainClass { if (foundMainClass) nameOpt else None } - def findInClass(path: os.Path): Iterator[String] = - findInClass(os.read.inputStream(path)) - def findInClass(is: InputStream): Iterator[String] = + private def findInClass(path: os.Path, logger: Logger): Iterator[String] = try { - val reader = new ClassReader(is) - val checker = new MainMethodChecker - reader.accept(checker, 0) - checker.mainClassOpt.iterator + val is = retry()(logger)(os.read.inputStream(path)) + findInClass(is, logger) + } + catch { + case e: NoSuchFileException => + e.getStackTrace.foreach(ste => logger.debug(ste.toString)) + logger.log(s"Class file $path not found: $e") + logger.log("Are you trying to run too many builds at once? Trying to recover...") + Iterator.empty + } + private def findInClass(is: InputStream, logger: Logger): Iterator[String] = + try retry()(logger) { + val reader = new ClassReader(is) + val checker = new MainMethodChecker + reader.accept(checker, 0) + checker.mainClassOpt.iterator + } + catch { + case e: ArrayIndexOutOfBoundsException => + e.getStackTrace.foreach(ste => logger.debug(ste.toString)) + logger.log(s"Class input stream could not be created: $e") + logger.log("Are you trying to run too many builds at once? Trying to recover...") + Iterator.empty } finally is.close() - def findInJar(path: os.Path): Iterator[String] = { - val content = os.read.bytes(path) - val jarInputStream = WrappedZipInputStream.create(new ByteArrayInputStream(content)) - jarInputStream.entries().flatMap(ent => - if !ent.isDirectory && ent.getName.endsWith(".class") then { - val content = jarInputStream.readAllBytes() - val inputStream = new ByteArrayInputStream(content) - findInClass(inputStream) + private def findInJar(path: os.Path, logger: Logger): Iterator[String] = + try retry()(logger) { + val content = os.read.bytes(path) + val jarInputStream = WrappedZipInputStream.create(new ByteArrayInputStream(content)) + jarInputStream.entries().flatMap(ent => + if !ent.isDirectory && ent.getName.endsWith(".class") then { + val content = jarInputStream.readAllBytes() + val inputStream = new ByteArrayInputStream(content) + findInClass(inputStream, logger) + } + else Iterator.empty + ) } - else Iterator.empty - ) - } + catch { + case e: NoSuchFileException => + logger.debugStackTrace(e) + logger.log(s"JAR file $path not found: $e, trying to recover...") + logger.log("Are you trying to run too many builds at once? Trying to recover...") + Iterator.empty + } def findInDependency(jar: os.Path): Option[String] = jar match { @@ -79,19 +106,19 @@ object MainClass { case _ => None } - def find(output: os.Path): Seq[String] = + def find(output: os.Path, logger: Logger): Seq[String] = output match { case o if os.isFile(o) && o.last.endsWith(".class") => - findInClass(o).toVector + findInClass(o, logger).toVector case o if os.isFile(o) && o.last.endsWith(".jar") => - findInJar(o).toVector + findInJar(o, logger).toVector case o if os.isDir(o) => os.walk(o) .iterator .filter(os.isFile) .flatMap { case classFilePath if classFilePath.last.endsWith(".class") => - findInClass(classFilePath) + findInClass(classFilePath, logger) case _ => Iterator.empty } .toVector diff --git a/modules/build/src/main/scala/scala/build/package.scala b/modules/build/src/main/scala/scala/build/package.scala new file mode 100644 index 0000000000..2f082dca32 --- /dev/null +++ b/modules/build/src/main/scala/scala/build/package.scala @@ -0,0 +1,33 @@ +package scala + +import scala.annotation.tailrec +import scala.concurrent.duration.{DurationInt, FiniteDuration} +import scala.util.Random + +package object build { + def retry[T]( + maxAttempts: Int = 3, + waitDuration: FiniteDuration = 1.seconds, + variableWaitDelayInMs: Int = 500 + )(logger: Logger)( + run: => T + ): T = { + @tailrec + def helper(count: Int): T = + try run + catch { + case t: Throwable => + if count >= maxAttempts then throw t + else + logger.debugStackTrace(t) + val variableDelay = Random.between(0, variableWaitDelayInMs + 1).milliseconds + val currentWaitDuration = waitDuration + variableDelay + logger.log(s"Caught $t, trying again in $currentWaitDuration…") + Thread.sleep(currentWaitDuration.toMillis) + helper(count + 1) + } + + helper(1) + } + +} diff --git a/modules/build/src/main/scala/scala/build/postprocessing/AsmPositionUpdater.scala b/modules/build/src/main/scala/scala/build/postprocessing/AsmPositionUpdater.scala index a858d714a6..6bfce0c0de 100644 --- a/modules/build/src/main/scala/scala/build/postprocessing/AsmPositionUpdater.scala +++ b/modules/build/src/main/scala/scala/build/postprocessing/AsmPositionUpdater.scala @@ -2,7 +2,10 @@ package scala.build.postprocessing import org.objectweb.asm -import scala.build.{Logger, Os} +import java.io +import java.nio.file.{FileAlreadyExistsException, NoSuchFileException} + +import scala.build.{Logger, Os, retry} object AsmPositionUpdater { @@ -53,20 +56,34 @@ object AsmPositionUpdater { .filter(os.isFile(_)) .filter(_.last.endsWith(".class")) .foreach { path => - val is = os.read.inputStream(path) - val updateByteCodeOpt = - try { - val reader = new asm.ClassReader(is) - val writer = new asm.ClassWriter(reader, 0) - val checker = new LineNumberTableClassVisitor(mappings, writer) - reader.accept(checker, 0) - if (checker.mappedStuff) Some(writer.toByteArray) - else None + try retry()(logger) { + val is = os.read.inputStream(path) + val updateByteCodeOpt = + try retry()(logger) { + val reader = new asm.ClassReader(is) + val writer = new asm.ClassWriter(reader, 0) + val checker = new LineNumberTableClassVisitor(mappings, writer) + reader.accept(checker, 0) + if checker.mappedStuff then Some(writer.toByteArray) else None + } + catch { + case e: ArrayIndexOutOfBoundsException => + e.getStackTrace.foreach(ste => logger.debug(ste.toString)) + logger.log(s"Error while processing ${path.relativeTo(Os.pwd)}: $e.") + logger.log("Are you trying to run too many builds at once? Trying to recover...") + None + } + finally is.close() + for (b <- updateByteCodeOpt) { + logger.debug(s"Overwriting ${path.relativeTo(Os.pwd)}") + os.write.over(path, b) + } } - finally is.close() - for (b <- updateByteCodeOpt) { - logger.debug(s"Overwriting ${path.relativeTo(Os.pwd)}") - os.write.over(path, b) + catch { + case e: (NoSuchFileException | FileAlreadyExistsException | ArrayIndexOutOfBoundsException) => + logger.debugStackTrace(e) + logger.log(s"Error while processing ${path.relativeTo(Os.pwd)}: $e") + logger.log("Are you trying to run too many builds at once? Trying to recover...") } } } diff --git a/modules/build/src/main/scala/scala/build/postprocessing/TastyPostProcessor.scala b/modules/build/src/main/scala/scala/build/postprocessing/TastyPostProcessor.scala index d0023e70e7..c452dcc07a 100644 --- a/modules/build/src/main/scala/scala/build/postprocessing/TastyPostProcessor.scala +++ b/modules/build/src/main/scala/scala/build/postprocessing/TastyPostProcessor.scala @@ -1,9 +1,11 @@ package scala.build.postprocessing +import java.nio.file.{FileAlreadyExistsException, NoSuchFileException} + import scala.build.internal.Constants import scala.build.options.BuildOptions import scala.build.tastylib.{TastyData, TastyVersions} -import scala.build.{GeneratedSource, Logger} +import scala.build.{GeneratedSource, Logger, retry} case object TastyPostProcessor extends PostProcessor { @@ -51,28 +53,36 @@ case object TastyPostProcessor extends PostProcessor { updatedPaths: Map[String, String] )(f: os.Path): Unit = { logger.debug(s"Reading TASTy file $f") - val content = os.read.bytes(f) - TastyData.read(content) match { - case Left(ex) => logger.debug(s"Ignoring exception during TASty postprocessing: $ex") - case Right(data) => - logger.debug(s"Parsed TASTy file $f") - var updatedOne = false - val updatedData = data.mapNames { n => - updatedPaths.get(n) match { - case Some(newName) => - updatedOne = true - newName - case None => - n - } - } - if (updatedOne) { - logger.debug( - s"Overwriting ${if (f.startsWith(os.pwd)) f.relativeTo(os.pwd) else f}" - ) - val updatedContent = TastyData.write(updatedData) - os.write.over(f, updatedContent) + try retry()(logger) { + val content = os.read.bytes(f) + TastyData.read(content) match { + case Left(ex) => logger.debug(s"Ignoring exception during TASty postprocessing: $ex") + case Right(data) => + logger.debug(s"Parsed TASTy file $f") + var updatedOne = false + val updatedData = data.mapNames { n => + updatedPaths.get(n) match { + case Some(newName) => + updatedOne = true + newName + case None => + n + } + } + if updatedOne then { + logger.debug( + s"Overwriting ${if f.startsWith(os.pwd) then f.relativeTo(os.pwd) else f}" + ) + val updatedContent = TastyData.write(updatedData) + os.write.over(f, updatedContent) + } } + } + catch { + case e: (NoSuchFileException | FileAlreadyExistsException | ArrayIndexOutOfBoundsException) => + logger.debugStackTrace(e) + logger.log(s"Tasty file $f not found: $e. Are you trying to run too many builds at once") + logger.log("Are you trying to run too many builds at once? Trying to recover...") } } } diff --git a/modules/core/src/main/scala/scala/build/Logger.scala b/modules/core/src/main/scala/scala/build/Logger.scala index 35b863aaee..e63c48771b 100644 --- a/modules/core/src/main/scala/scala/build/Logger.scala +++ b/modules/core/src/main/scala/scala/build/Logger.scala @@ -17,6 +17,8 @@ trait Logger { def log(s: => String, debug: => String): Unit def debug(s: => String): Unit + def debugStackTrace(t: => Throwable): Unit = t.getStackTrace.foreach(ste => debug(ste.toString)) + def log(diagnostics: Seq[Diagnostic]): Unit def diagnostic( diff --git a/modules/integration/src/test/scala/scala/cli/integration/RunTestDefinitions.scala b/modules/integration/src/test/scala/scala/cli/integration/RunTestDefinitions.scala index 100391e613..b59c5e9174 100644 --- a/modules/integration/src/test/scala/scala/cli/integration/RunTestDefinitions.scala +++ b/modules/integration/src/test/scala/scala/cli/integration/RunTestDefinitions.scala @@ -2010,9 +2010,7 @@ abstract class RunTestDefinitions customExtraOptions, "--offline", "--cache", - cachePath.toString, - "-v", - "-v" + cachePath.toString ) .call(cwd = root, mergeErrIntoOut = true) expect(scalaAndJvmRes.exitCode == 0) @@ -2319,4 +2317,49 @@ abstract class RunTestDefinitions expect(err.contains(main2)) } } + + for { + (input, code) <- Seq( + os.rel / "script.sc" -> """println(args.mkString(" "))""", + os.rel / "raw.scala" -> """object Main { def main(args: Array[String]) = println(args.mkString(" ")) }""" + ) + testInputs = TestInputs(input -> code) + shouldRestartBloop <- Seq(true, false) + restartBloopString = if (shouldRestartBloop) "with" else "without" + parallelInstancesCount <- + TestUtil.isCI -> shouldRestartBloop match { + case (true, false) => Seq(2, 5) + case (true, true) => Seq(2) + case _ => Seq(5, 10, 20) + } + } + test( + s"run $parallelInstancesCount instances of $input in parallel ($restartBloopString restarting Bloop)" + ) { + TestUtil.retryOnCi() { + testInputs.fromRoot { + root => + if (shouldRestartBloop) + os.proc(TestUtil.cli, "bloop", "exit", "--power") + .call(cwd = root) + val processes: Seq[(os.SubProcess, Int)] = + (0 until parallelInstancesCount).map { i => + os.proc( + TestUtil.cli, + "run", + input.toString(), + extraOptions, + "--", + "iteration", + i.toString + ) + .spawn(cwd = root, env = Map("SCALA_CLI_EXTRA_TIMEOUT" -> "120 seconds")) + }.zipWithIndex + processes.foreach { case (p, _) => p.waitFor() } + processes.foreach { case (p, _) => expect(p.exitCode == 0) } + processes.foreach { case (p, i) => expect(p.stdout.trim() == s"iteration $i") } + } + } + + } }