diff --git a/scala/scala-impl/src/org/jetbrains/sbt/project/SbtProjectResolver.scala b/scala/scala-impl/src/org/jetbrains/sbt/project/SbtProjectResolver.scala index 96b2dc34102..95c124c7031 100644 --- a/scala/scala-impl/src/org/jetbrains/sbt/project/SbtProjectResolver.scala +++ b/scala/scala-impl/src/org/jetbrains/sbt/project/SbtProjectResolver.scala @@ -1,9 +1,6 @@ package org.jetbrains.sbt package project -import java.io.{File, FileNotFoundException} -import java.util.{Locale, UUID} - import com.intellij.notification.NotificationType import com.intellij.openapi.diagnostic.Logger import com.intellij.openapi.externalSystem.model.project.{ProjectData => ESProjectData, _} @@ -33,9 +30,11 @@ import org.jetbrains.sbt.structure.XmlSerializer._ import org.jetbrains.sbt.structure.{BuildData, ConfigurationData, DependencyData, DirectoryData, JavaData, ProjectData} import org.jetbrains.sbt.{structure => sbtStructure} -import scala.jdk.CollectionConverters._ +import java.io.{File, FileNotFoundException} +import java.util.{Locale, UUID} import scala.concurrent.Await import scala.concurrent.duration.Duration +import scala.jdk.CollectionConverters._ import scala.util.{Failure, Random, Success, Try} import scala.xml.{Elem, XML} @@ -182,13 +181,22 @@ class SbtProjectResolver extends ExternalSystemProjectResolver[SbtExecutionSetti } activeProcessDumper = None - messageResult.flatMap { messages => - val tried = if (messages.status != BuildMessages.OK || !structureFile.isFile || structureFile.length <= 0) { - val message = SbtBundle.message("sbt.import.extracting.structure.failed") - Failure(new Exception(message)) - } else Try { - val elem = XML.load(structureFile.toURI.toURL) - (elem, messages) + val result: Try[(Elem, BuildMessages)] = messageResult.flatMap { messages => + val tried = { + def failure(reason: String): Failure[(Elem, BuildMessages)] = { + val message = SbtBundle.message("sbt.import.extracting.structure.failed") + s", reason: ${reason}" + Failure(new Exception(message)) + } + if (messages.status != BuildMessages.OK) + failure(s"not ok build status: ${messages.status} (${messages})") + else if (!structureFile.isFile) + failure(s"structure file is not a file") + else if (structureFile.length <= 0) + failure(s"structure file is empty") + else Try { + val elem = XML.load(structureFile.toURI.toURL) + (elem, messages) + } } tried.recoverWith { case error => @@ -200,6 +208,12 @@ class SbtProjectResolver extends ExternalSystemProjectResolver[SbtExecutionSetti Failure(new Exception(message, error.getCause)) } } + if (result.isFailure) { + val processOutput = dumper.processOutput.mkString + // exception is logged in other places + log.debug(s"failed to dump sbt structure, sbt process output:\n$processOutput") + } + result } } diff --git a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/ListenerAdapter.scala b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/ListenerAdapter.scala index 7aeda020ff6..3283209e80b 100644 --- a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/ListenerAdapter.scala +++ b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/ListenerAdapter.scala @@ -12,7 +12,8 @@ class ListenerAdapter(listener: (OutputType, String) => Unit) extends ProcessAda val textType = outputType match { case ProcessOutputTypes.STDOUT => Some(OutputType.StdOut) case ProcessOutputTypes.STDERR => Some(OutputType.StdErr) - case _ => None + case ProcessOutputTypes.SYSTEM => Some(OutputType.MySystem) + case other => Some(OutputType.Other(other)) } textType.foreach(t => listener(t, event.getText)) } diff --git a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/OutputType.scala b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/OutputType.scala index 1ecc8898cd3..da29d320f97 100644 --- a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/OutputType.scala +++ b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/OutputType.scala @@ -1,6 +1,8 @@ package org.jetbrains.sbt package project.structure +import com.intellij.openapi.util.Key + /** * @author Pavel Fatin */ @@ -9,4 +11,6 @@ sealed abstract class OutputType object OutputType { object StdOut extends OutputType object StdErr extends OutputType + object MySystem extends OutputType + final case class Other(key: Key[_]) extends OutputType } diff --git a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/SbtStructureDump.scala b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/SbtStructureDump.scala index 6b48ae02cd6..5e0efe4a724 100644 --- a/scala/scala-impl/src/org/jetbrains/sbt/project/structure/SbtStructureDump.scala +++ b/scala/scala-impl/src/org/jetbrains/sbt/project/structure/SbtStructureDump.scala @@ -1,34 +1,47 @@ package org.jetbrains.sbt.project.structure -import java.io.{BufferedWriter, File, OutputStreamWriter, PrintWriter} -import java.nio.charset.Charset -import java.util.UUID -import java.util.concurrent.atomic.AtomicBoolean - import com.intellij.build.events.impl.{FailureResultImpl, SkippedResultImpl, SuccessResultImpl} import com.intellij.execution.process.OSProcessHandler +import com.intellij.openapi.application.ApplicationManager +import com.intellij.openapi.diagnostic.Logger import com.intellij.openapi.externalSystem.model.ExternalSystemException import com.intellij.openapi.project.Project +import com.intellij.openapi.util.SystemInfo import org.jetbrains.annotations.{Nls, NonNls} import org.jetbrains.plugins.scala.build.BuildMessages.EventId import org.jetbrains.plugins.scala.build.{BuildMessages, BuildReporter, ExternalSystemNotificationReporter} +import org.jetbrains.plugins.scala.extensions.LoggerExt import org.jetbrains.plugins.scala.findUsages.compilerReferences.compilation.SbtCompilationSupervisor import org.jetbrains.plugins.scala.findUsages.compilerReferences.settings.CompilerIndicesSettings +import org.jetbrains.sbt.SbtBundle import org.jetbrains.sbt.SbtUtil._ import org.jetbrains.sbt.project.SbtProjectResolver.ImportCancelledException import org.jetbrains.sbt.project.structure.SbtStructureDump._ import org.jetbrains.sbt.shell.SbtShellCommunication import org.jetbrains.sbt.shell.SbtShellCommunication._ -import org.jetbrains.sbt.SbtBundle -import scala.jdk.CollectionConverters._ +import java.io.{BufferedWriter, File, OutputStreamWriter, PrintWriter} +import java.nio.charset.Charset +import java.util.UUID +import java.util.concurrent.TimeoutException +import java.util.concurrent.atomic.AtomicBoolean import scala.concurrent.Future +import scala.concurrent.duration.{DurationInt, FiniteDuration} +import scala.jdk.CollectionConverters._ import scala.util.{Failure, Success, Try, Using} class SbtStructureDump { private val cancellationFlag: AtomicBoolean = new AtomicBoolean(false) + // NOTE: if this is a first run of sbt with a particular version on current machine + // sbt import will take some time because it will have to download quite a lot of dependencies + private val MaxImportDurationInUnitTests: FiniteDuration = 10.minutes + + // in failed tests we would like to see sbt process output + private val processOutputBuilder = new StringBuilder + def processOutput: String = processOutputBuilder.mkString + def cancel(): Unit = cancellationFlag.set(true) def dumpFromShell(project: Project, @@ -93,11 +106,46 @@ class SbtStructureDump { ) } + /** + * This is a workaround for [[https://github.com/sbt/sbt/issues/5128]] (tested for sbt 1.4.9) + * + * The bug is reproduced on Teamcity, on Windows agents: + * ProjectImportingTest is stuck indefinitely when the test is run from sbt.
+ * It's also reproduces locally when running the test from sbt.
+ * But for some reason is not reproduced when running from IDEA test runners
+ * + * Environment variables which have to be mocked are inferred from methods in + * `lmcoursier.internal.shaded.coursier.paths.CoursierPaths` (version 2.0.6) + * + * @see [[https://github.com/sbt/sbt/issues/5128]] + * @see [[https://github.com/dirs-dev/directories-jvm/issues/49]] + * @see [[https://github.com/ScoopInstaller/Main/pull/878/files]] + */ + private def defaultCoursierDirectoriesAsEnvVariables(): Seq[(String, String)] = { + val LocalAppData = System.getenv("LOCALAPPDATA") + val AppData = System.getenv("APPDATA") + + val CoursierLocalAppDataHome = LocalAppData + "/Coursier" + val CoursierAppDataHome = AppData + "/Coursier" + + Seq( + // these 2 variables seems to be enough for the workaround + ("COURSIER_CACHE", CoursierLocalAppDataHome + "/cache/v1"), + ("COURSIER_CONFIG_DIR", CoursierAppDataHome + "/config"), + // these 2 variables seems to be optional, but we set them just in cause + // they might be accessed in some unpredictable cases + ("COURSIER_JVM_CACHE", CoursierLocalAppDataHome + "/cache/jvm"), + ("COURSIER_DATA_DIR", CoursierLocalAppDataHome + "/data"), + // this also looks like an optional in 1.4.9, but setting it just in case + ("COURSIER_HOME", CoursierLocalAppDataHome), + ) + } + /** Run sbt with some sbt commands. */ def runSbt(directory: File, vmExecutable: File, vmOptions: Seq[String], - environment: Map[String, String], + environment0: Map[String, String], sbtLauncher: File, sbtCommandLineArgs: List[String], @NonNls sbtCommands: String, @@ -106,6 +154,24 @@ class SbtStructureDump { (implicit reporter: BuildReporter) : Try[BuildMessages] = { + val environment = if (ApplicationManager.getApplication.isUnitTestMode && SystemInfo.isWindows) { + val extraEnvs = defaultCoursierDirectoriesAsEnvVariables() + environment0 ++ extraEnvs + } + else environment0 + + Log.debugSafe( + s"""runSbt + | directory: $directory, + | vmExecutable: $vmExecutable, + | vmOptions: $vmOptions, + | environment: $environment, + | sbtLauncher: $sbtLauncher, + | sbtCommandLineArgs: $sbtCommandLineArgs, + | sbtCommands: $sbtCommands, + | reportMessage: $reportMessage""".stripMargin + ) + val startTime = System.currentTimeMillis() // assuming here that this method might still be called without valid project @@ -119,7 +185,7 @@ class SbtStructureDump { "-Dfile.encoding=UTF-8") ++ jvmOptions ++ List("-jar", normalizePath(sbtLauncher)) ++ - sbtCommandLineArgs + sbtCommandLineArgs // :+ "--debug" val processCommands = processCommandsRaw.filterNot(_.isEmpty) @@ -133,6 +199,10 @@ class SbtStructureDump { val procString = processBuilder.command().asScala.mkString(" ") reporter.log(procString) + Log.debugSafe( + s"""processBuilder.start() + | command line: ${processBuilder.command().asScala.mkString(" ")}""".stripMargin + ) processBuilder.start() } .flatMap { process => @@ -192,44 +262,74 @@ class SbtStructureDump { } } - val processListener: (OutputType, String) => Unit = { - case (typ@OutputType.StdOut, text) => - if (text.contains("(q)uit")) { - val writer = new PrintWriter(process.getOutputStream) - writer.println("q") - writer.close() - } else { - update(typ, text) + val isUnitTest = ApplicationManager.getApplication.isUnitTestMode + processOutputBuilder.clear() + + val processListener: (OutputType, String) => Unit = (typ, line) => { + if (isUnitTest) { + processOutputBuilder.append(s"[${typ.getClass.getSimpleName}] $line") + if (!line.endsWith("\n")) { + processOutputBuilder.append('\n') } - case (typ@OutputType.StdErr, text) => - update(typ, text) + } + (typ, line) match { + case (typ@OutputType.StdOut, text) => + if (text.contains("(q)uit")) { + val writer = new PrintWriter(process.getOutputStream) + writer.println("q") + writer.close() + } else { + update(typ, text) + } + case (typ@OutputType.StdErr, text) => + update(typ, text) + case _ => // ignore + } } - Try { - val handler = new OSProcessHandler(process, "sbt import", Charset.forName("UTF-8")) + val handler = new OSProcessHandler(process, "sbt import", Charset.forName("UTF-8")) + // TODO: rewrite this code, do not use try, throw + val result = Try { handler.addProcessListener(new ListenerAdapter(processListener)) + Log.debug("handler.startNotify()") handler.startNotify() + val start = System.currentTimeMillis() + var processEnded = false - while (!processEnded && !cancellationFlag.get()) + while (!processEnded && !cancellationFlag.get()) { processEnded = handler.waitFor(SBT_PROCESS_CHECK_TIMEOUT_MSEC) - if (!processEnded) { - // task was cancelled - handler.setShouldDestroyProcessRecursively(false) - handler.destroyProcess() + val importIsTooLong = isUnitTest && System.currentTimeMillis() - start > MaxImportDurationInUnitTests.toMillis + if (importIsTooLong) { + throw new TimeoutException(s"sbt process hasn't finished in $MaxImportDurationInUnitTests") + } + } + + val exitCode = handler.getExitCode + Log.debug(s"processEnded: $processEnded, exitCode: $exitCode") + if (!processEnded) throw ImportCancelledException(new Exception(SbtBundle.message("sbt.task.canceled"))) - } else if (handler.getExitCode != 0) - messages.status(BuildMessages.Error) + else if (exitCode != 0) + messages.status(BuildMessages.Error) else if (messages.status == BuildMessages.Indeterminate) messages.status(BuildMessages.OK) - else messages + else + messages } + if (!handler.isProcessTerminated) { + Log.debug(s"sbt process has not terminated, destroying the process...") + handler.setShouldDestroyProcessRecursively(false) // TODO: why not `true`? + handler.destroyProcess() + } + result } } object SbtStructureDump { + private val Log = Logger.getInstance(classOf[SbtStructureDump]) + private val SBT_PROCESS_CHECK_TIMEOUT_MSEC = 100 private def reportEvent(messages: BuildMessages,