From 3addbe39b068b7639512a7c2b1e76b0cbc4351bb Mon Sep 17 00:00:00 2001 From: Bruno Bieth Date: Fri, 8 Nov 2013 15:44:42 +0100 Subject: [PATCH] Multi VM forked test & test output segregation Currently SBT is unable to run tests in parallel while providing a meaningful trace: test outputs are interleaved. This is especially annoying when a test pass on your machine but breaks on a continuous integration server. This commit allows running forked tests in multiple VM, enabling test output segregation. In order to report test outputs a refactoring of `TestReportListener` was necessary, breaking compatibility with 0.13. In addition SBT provides now a reference implementation of the new `TestReportListener`, formatting test reports in JUnit XML. Those features are disabled by default and are activated with the following settings: * `testNumberForkedJvm` : controls how many VM are used to run the tests Note: this is reduced if there are fewer tests than vm Note: forking must be enabled (`fork in test := true`) * `testHideSuccessfulOutput` : when set to true, do not print tests output on the console Note: this does not work in non-forked mode * `testReportJUnitXml` : when set to true produce reports in the JUnit XML format Note: in non-forked mode test outputs are not captured Meaningful (debug level) logs are produced for each of these features. --- .../src/main/scala/sbt/ForkTests.scala | 480 +++++++++++++++--- main/actions/src/main/scala/sbt/Tests.scala | 7 +- main/src/main/scala/sbt/Defaults.scala | 25 +- main/src/main/scala/sbt/Keys.scala | 3 + .../project/ForkMultiVmTest.scala | 25 + .../tests/fork-multi-vm/project/machete.sbt | 3 + .../fork-multi-vm/src/test/scala/tests.scala | 40 ++ sbt/src/sbt-test/tests/fork-multi-vm/test | 15 + .../project/HideSuccessfulOutputBuild.scala | 26 + .../project/machete.sbt | 3 + .../src/test/scala/tests.scala | 42 ++ .../tests/hide-successful-output/test | 15 + .../project/JUnitXmlReportTest.scala | 95 ++++ .../junit-xml-report/project/matchete.sbt | 3 + .../src/test/scala/tests.scala | 65 +++ sbt/src/sbt-test/tests/junit-xml-report/test | 43 ++ .../tests/t543/project/Ticket543Test.scala | 8 +- .../src/main/scala/sbt/test/SbtHandler.scala | 28 +- testing/agent/src/main/java/sbt/ForkMain.java | 134 +++-- .../agent/src/main/java/sbt/ForkSuites.java | 29 ++ testing/agent/src/main/java/sbt/ForkTags.java | 2 +- .../src/main/java/sbt/FrameworkLoader.java | 35 ++ .../scala/sbt/JUnitXmlTestsListener.scala | 101 ++++ .../src/main/scala/sbt/TestFramework.scala | 28 +- .../main/scala/sbt/TestReportListener.scala | 130 +++-- .../main/scala/sbt/TestStatusReporter.scala | 12 +- 26 files changed, 1190 insertions(+), 207 deletions(-) create mode 100644 sbt/src/sbt-test/tests/fork-multi-vm/project/ForkMultiVmTest.scala create mode 100644 sbt/src/sbt-test/tests/fork-multi-vm/project/machete.sbt create mode 100644 sbt/src/sbt-test/tests/fork-multi-vm/src/test/scala/tests.scala create mode 100644 sbt/src/sbt-test/tests/fork-multi-vm/test create mode 100644 sbt/src/sbt-test/tests/hide-successful-output/project/HideSuccessfulOutputBuild.scala create mode 100644 sbt/src/sbt-test/tests/hide-successful-output/project/machete.sbt create mode 100644 sbt/src/sbt-test/tests/hide-successful-output/src/test/scala/tests.scala create mode 100644 sbt/src/sbt-test/tests/hide-successful-output/test create mode 100644 sbt/src/sbt-test/tests/junit-xml-report/project/JUnitXmlReportTest.scala create mode 100644 sbt/src/sbt-test/tests/junit-xml-report/project/matchete.sbt create mode 100644 sbt/src/sbt-test/tests/junit-xml-report/src/test/scala/tests.scala create mode 100644 sbt/src/sbt-test/tests/junit-xml-report/test create mode 100644 testing/agent/src/main/java/sbt/ForkSuites.java create mode 100644 testing/agent/src/main/java/sbt/FrameworkLoader.java create mode 100644 testing/src/main/scala/sbt/JUnitXmlTestsListener.scala diff --git a/main/actions/src/main/scala/sbt/ForkTests.scala b/main/actions/src/main/scala/sbt/ForkTests.scala index 63b8da1d4..19e008270 100755 --- a/main/actions/src/main/scala/sbt/ForkTests.scala +++ b/main/actions/src/main/scala/sbt/ForkTests.scala @@ -8,11 +8,18 @@ import testing._ import java.net.ServerSocket import java.io._ import Tests.{Output => TestOutput, _} -import ForkMain._ +import scala.util.control.NonFatal +import java.util.concurrent.ConcurrentLinkedQueue +import scala.annotation.tailrec +import java.util.concurrent.atomic.AtomicReference private[sbt] object ForkTests { - def apply(runners: Map[TestFramework, Runner], tests: List[TestDefinition], config: Execution, classpath: Seq[File], fork: ForkOptions, log: Logger): Task[TestOutput] = { + /** + * @param hideSuccessfulOutput only available in forked mode + * @param noForkedVm only available in forked mode; if > 1 will disable intra-vm parallel execution + */ + def apply(frameworks: Map[TestFramework,Framework], runners: Map[TestFramework, Runner], tests: List[TestDefinition], config: Execution, classpath: Seq[File], fork: ForkOptions, log: Logger, hideSuccessfulOutput: Boolean, noForkedVm: Int): Task[TestOutput] = { val opts = processOptions(config, tests, log) import std.TaskExtra._ @@ -23,111 +30,418 @@ private[sbt] object ForkTests if(opts.tests.isEmpty) constant( TestOutput(TestResult.Passed, Map.empty[String, SuiteResult], Iterable.empty) ) else - mainTestTask(runners, opts, classpath, fork, log, config.parallel).tagw(config.tags: _*) + mainTestTask(frameworks, runners, opts, classpath, fork, log, config.parallel, hideSuccessfulOutput, noForkedVm).tagw(config.tags: _*) main.dependsOn( all(opts.setup) : _*) flatMap { results => all(opts.cleanup).join.map( _ => results) } } - private[this] def mainTestTask(runners: Map[TestFramework, Runner], opts: ProcessedOptions, classpath: Seq[File], fork: ForkOptions, log: Logger, parallel: Boolean): Task[TestOutput] = - std.TaskExtra.task - { - val server = new ServerSocket(0) - val testListeners = opts.testListeners flatMap { - case tl: TestsListener => Some(tl) - case _ => None + // Note: these log-related utilities could be made more visible, somewhere else? + + private sealed trait LoggerEvent + private case class TraceEvent(error: Throwable) extends LoggerEvent + private case class SuccessEvent(message: String) extends LoggerEvent + private case class LogEvent(level: Level.Value, message: String) extends LoggerEvent + + private class RecordingLogger extends Logger { + private val events = new AtomicReference[List[LoggerEvent]](Nil) + + @tailrec private def addEvent(e: LoggerEvent) { + val previous = events.get + if( !events.compareAndSet(previous, e :: previous) ) { + addEvent(e) } + } - object Acceptor extends Runnable { - val resultsAcc = mutable.Map.empty[String, SuiteResult] - lazy val result = TestOutput(overall(resultsAcc.values.map(_.result)), resultsAcc.toMap, Iterable.empty) + def getEventsAndReset : List[LoggerEvent] = events.getAndSet(Nil).reverse - def run() { - val socket = - try { - server.accept() - } catch { - case e: java.net.SocketException => - log.error("Could not accept connection from test agent: " + e.getClass + ": " + e.getMessage) - log.trace(e) - server.close() - return - } - val os = new ObjectOutputStream(socket.getOutputStream) - // Must flush the header that the constructor writes, otherwise the ObjectInputStream on the other end may block indefinitely - os.flush() - val is = new ObjectInputStream(socket.getInputStream) + def trace(t: => Throwable) { addEvent(new TraceEvent(t))} + def success(message: => String) { addEvent(new SuccessEvent(message))} + def log(level: Level.Value, message: => String) { addEvent(new LogEvent(level, message))} + } - try { - val config = new ForkConfiguration(log.ansiCodesSupported, parallel) - os.writeObject(config) + /** + * A test runner in a forked VM. + * + * Picks tasks from `suiteQueue` and send them to the forked VM for execution. Once the queue is empty, shuts down the VM. + * If an unexpected failure happen (i.e not a test failure), the VM will be terminated. Terminated VMs (could be a test calling `System.exit`) + * are not restarted. + * + * @param parallel whether tests should run in parallel in the forked VM - usePipedProcessOutput will be disabled if this is enabled + */ + class ForkedTestRunner(runners: Map[TestFramework, Runner], + classpath: Seq[File], + forkOptions: ForkOptions, + log: Logger, + listeners: Seq[TestReportListener], + parallel: Boolean, + hideSuccessfulOutput: Boolean, + suiteQueue: ConcurrentLinkedQueue[ForkSuites]) extends Runnable { - val taskdefs = opts.tests.map(t => new TaskDef(t.name, forkFingerprint(t.fingerprint), t.explicitlySpecified, t.selectors)) - os.writeObject(taskdefs.toArray) + private val server = new ServerSocket(0) + private var process : Process = _ + private var vmArgs : Seq[String] = Nil + private val thread = new Thread(this) - os.writeInt(runners.size) - for ((testFramework, mainRunner) <- runners) { - os.writeObject(testFramework.implClassNames.toArray) - os.writeObject(mainRunner.args) - os.writeObject(mainRunner.remoteArgs) - } - os.flush() + private val usePipedProcessOutput = !parallel - new React(is, os, log, opts.testListeners, resultsAcc).react() - } finally { - is.close(); os.close(); socket.close() + /** a map of [SuiteName, SuiteReport] */ + val results = mutable.Map.empty[String, SuiteReport] + + private val outputBuffer = new RecordingLogger + + def getLocalPort : Int = server.getLocalPort + + private def closeSocketQuietly() { + try { + server.close() + } catch { + case _ : Throwable => + } + } + + /** + * Start the forked VM and start sending tests to it from the `suiteQueue`, through the socket. + * A call to start should be followed by a call to `join`. + * Upon failure the associated resources will be released (thread & socket). + * This method does not block and should only be called once. + */ + def start() { + try { + thread.start() + + val fullCp = classpath ++: Seq(IO.classLocationFile[ForkMain], IO.classLocationFile[Framework]) + vmArgs = Seq("-classpath", fullCp mkString File.pathSeparator, classOf[ForkMain].getCanonicalName, getLocalPort.toString) + + val newOptions = if( usePipedProcessOutput ) { + val outputStrategy = if( hideSuccessfulOutput ) { + BufferedOutput(outputBuffer) + } else { + LoggedOutput(new MultiLogger(List(FullLogger(log), FullLogger(outputBuffer)))) } + forkOptions.copy(outputStrategy = Some(outputStrategy)) + } else { + forkOptions + } + + log.debug( + s"""Creating a forked test runner: + | - fork-options=$newOptions + | - vm-args=$vmArgs, + | - parallel=$parallel""".stripMargin) + + process = new Fork("java", None).fork(newOptions, vmArgs) + } catch { + case err : Throwable => + // if the process has not been created, then the thread will be released + // when closing the socket + closeSocketQuietly() + throw err + } + } + + private def getPipedProcessOutputAndReset() : String = { + val events = outputBuffer.getEventsAndReset + events.flatMap { + case LogEvent(Level.Info, msg) => Some(msg) + case _ => None + }.mkString("\n") + } + + /** Wait until the VM dies */ + def join() { + try { + thread.join() + if( process != null ) { + val exitCode = process.exitValue() + if( exitCode != 0 ) { + throw new RuntimeException("Running java with options " + vmArgs.mkString(" ") + " failed with exit code " + exitCode) + } + } + } finally { + closeSocketQuietly() + } + } + + def run() { + val socket = + try { + server.accept() + } catch { + case e: java.net.SocketException => + log.error("Could not accept connection from test agent: " + e.getClass + ": " + e.getMessage) + log.trace(e) + closeSocketQuietly() + return + } + + val os = new ObjectOutputStream(socket.getOutputStream) + // Must flush the header that the constructor writes, otherwise the ObjectInputStream on the other end may block indefinitely + os.flush() + val is = new ObjectInputStream(socket.getInputStream) + + try { + writeConfig(os) + writeTestFrameworks(os) + writeTestSuite(os, is) + + } finally { + try { + is.close(); os.close(); socket.close() + } catch { + case NonFatal(e) => // swallow, we don't want to hide potential exceptions from above. + } + } + } + + private def writeConfig(os: ObjectOutputStream) { + val config = new ForkConfiguration( + log.ansiCodesSupported, + parallel) + + os.writeObject(config) + } + + private def writeTestFrameworks(os: ObjectOutputStream) { + os.writeInt(runners.size) + for ((testFramework, mainRunner) <- runners) { + os.writeObject(testFramework.implClassNames.toArray) + os.writeObject(mainRunner.args) + os.writeObject(mainRunner.remoteArgs) + } + os.flush() + } + + @tailrec + private def writeTestSuite(os: ObjectOutputStream, is: ObjectInputStream) { + val test = suiteQueue.poll() + if( test == null ) { + terminateVm(os, is) + } else { + os.writeObject(test) + react(is) + writeTestSuite(os,is) + } + } + + private def terminateVm(os: ObjectOutputStream, is: ObjectInputStream) { + log.debug("Terminating VM, sending `Done`") + os.writeObject(ForkTags.Done) + os.flush() + + // `Done` will be acknoledged by another `Done` + react(is) + } + + /** @return the existing or newly created suite with name `name` */ + private def getOrInitSuite(name: String) : SuiteReport = { + results.get(name) match { + case Some(existing) => existing + case None => + val newSuite = SuiteReport.empty + results += name -> newSuite + newSuite + } + } + + private def updateSuite(name: String, update: SuiteReport => SuiteReport) { + val existing = getOrInitSuite(name) + val updated = update(existing) + results += name -> updated + } + + /** read messages sent by the forked VM until `Done` is received. */ + private def react(is: ObjectInputStream) { + + import ForkTags._ + + @tailrec + def react() { + is.readObject match { + case `Done` => + + case Array(`Error`, s: String) => log.error(s); react() + case Array(`Warn`, s: String) => log.warn(s); react() + case Array(`Info`, s: String) => log.info(s); react() + case Array(`Debug`, s: String) => log.debug(s); react() + + case Array(`StartSuite`, name: String) => + getOrInitSuite(name) + listeners.foreach( _.startSuite(name) ) + react() + + case Array(`EndTest`, suiteName: String, event: Event) => + val out = if( usePipedProcessOutput ) { + getPipedProcessOutputAndReset() + } else { + "" + } + val shortStdOut = if( out.length > 33 ) out.substring(0, 30) + "[...]" else out + log.debug("Received EndTest event with stdout: >" + shortStdOut + "<") + if( usePipedProcessOutput && hideSuccessfulOutput && (event.status() == Status.Failure || event.status() == Status.Error) ) { + log.error(out) + } + val testReport = TestReport(out,event) + updateSuite(suiteName, _.addTest(testReport)) + listeners.foreach(_.endTest(testReport)) + react() + + case Array(`EndSuite`, name: String) => + val suite = getOrInitSuite(name) + listeners.foreach(_.endSuite(name, suite)) + react() + + case Array(`EndSuiteError`, name: String, error: Throwable) => + updateSuite(name, _.error(error) ) + val suite = getOrInitSuite(name) + listeners.foreach(_.endSuite(name, suite)) + react() + + case t: Throwable => + log.trace(t) + react() } } - try { - testListeners.foreach(_.doInit()) - val acceptorThread = new Thread(Acceptor) - acceptorThread.start() + react() + } + } - val fullCp = classpath ++: Seq(IO.classLocationFile[ForkMain], IO.classLocationFile[Framework]) - val options = Seq("-classpath", fullCp mkString File.pathSeparator, classOf[ForkMain].getCanonicalName, server.getLocalPort.toString) - val ec = Fork.java(fork, options) - val result = - if (ec != 0) - TestOutput(TestResult.Error, Map("Running java with options " + options.mkString(" ") + " failed with exit code " + ec -> SuiteResult.Error), Iterable.empty) - else { - // Need to wait acceptor thread to finish its business - acceptorThread.join() - Acceptor.result - } + private def enqueueSuites(frameworks: Map[TestFramework,Framework], opts: ProcessedOptions, oneItemPerSuites: Boolean) : ConcurrentLinkedQueue[ForkSuites] = { + val queue = new ConcurrentLinkedQueue[ForkSuites]() - testListeners.foreach(_.doComplete(result.overall)) - result - } finally { - server.close() + val taskdefs = opts.tests.map(t => new TaskDef(t.name, forkFingerprint(t.fingerprint), t.explicitlySpecified, t.selectors)) + + for { + (_,framework) <- frameworks + frameworkFingerprint <- framework.fingerprints() + } { + val filteredTaskDefs = taskdefs.filter( t => TestFramework.matches(t.fingerprint(), frameworkFingerprint) ) + if( oneItemPerSuites ) { + for( taskdef <- filteredTaskDefs ) { + queue.add(new ForkSuites(framework.name(), taskdef)) + } + } else { + queue.add(new ForkSuites(framework.name(), filteredTaskDefs.toArray)) } } + queue + } + private[this] def forkFingerprint(f: Fingerprint): Fingerprint with Serializable = f match { case s: SubclassFingerprint => new ForkMain.SubclassFingerscan(s) case a: AnnotatedFingerprint => new ForkMain.AnnotatedFingerscan(a) - case _ => error("Unknown fingerprint type: " + f.getClass) + case _ => sys.error("Unknown fingerprint type: " + f.getClass) + } + + /** + * @param forkOptions options used to create the forked VMs - the output strategy will be overridden if noForkedVm is > 1 + * @param parallel whether tests should run in parallel in the forked VM - this will be overridden and set to false if noForkedVm is > 1 + * @param hideSuccessfulOutput whether to hide the output of successful tests + */ + private[this] def mainTestTask(frameworks: Map[TestFramework,Framework], + runners: Map[TestFramework, Runner], + opts: ProcessedOptions, + classpath: Seq[File], + forkOptions: ForkOptions, + log: Logger, + parallel: Boolean, + hideSuccessfulOutput: Boolean, + noForkedVm: Int): Task[TestOutput] = { + + /** + * Create a forked process that will execute test suites from `suiteQueue` until the queue becomes empty. + * @note if the standard output is not captured, it will not be hidden (no matter `hideSuccessfulOutput`) + * @throws RuntimeException if the forked runner cannot be created + */ + def fork(suiteQueue: ConcurrentLinkedQueue[ForkSuites]) : ForkedTestRunner = { + val forkedTestRunner = new ForkedTestRunner(runners, classpath, forkOptions, log, opts.testListeners, parallel, hideSuccessfulOutput, suiteQueue) + forkedTestRunner.start() + forkedTestRunner + } + + def failedTestOutput(message: String) : TestOutput = { + TestOutput( + TestResult.Error, + Map(message -> SuiteResult.Error), + Iterable.empty) + } + + std.TaskExtra.task + { + val testListeners = opts.testListeners flatMap { + case tl: TestsListener => Some(tl) + case _ => None + } + + def onTestsCompletion(output: TestOutput) : TestOutput = { + testListeners.foreach( _.doComplete(output.overall)) + output + } + + def awaitForkedVms(vms: Seq[ForkedTestRunner]) : TestOutput = { + for( vm <- vms ) { + try { vm.join() } catch { case _ : Throwable => } + } + val result = try { + val results = if( !vms.isEmpty ) { + vms.map( _.results ).reduce( _ ++ _ ) + } else { + Map.empty[String,SuiteReport] + } + + TestOutput( + TestResult.overall(results.values.map(_.result.result)), + results.mapValues(_.result).toMap, + Iterable.empty) + } catch { + case NonFatal(e) => + failedTestOutput(e.getMessage) + } + onTestsCompletion(result) + } + + def createForkedVms() : Seq[ForkedTestRunner] = { + if( noForkedVm > 1 ) { + val noTests = opts.tests.size + val adjustedNoForkedVm = if( noTests < noForkedVm ) { + // note: if a test spawns new tests then this might be of a problem + // we should ask the testing framework if it supports spawning of new tests + // and disable this feature if it does + log.debug(s"Reducing the number of forked vm ($noForkedVm) as it exceeds the number of tests ($noTests)") + noTests + } else { + noForkedVm + } + log.debug(s"Creating $adjustedNoForkedVm forked test runners") + val suiteQueue = enqueueSuites(frameworks, opts, oneItemPerSuites = true) + var forkedVms : List[ForkedTestRunner] = Nil + var noVm = 0 + try { + while( noVm < adjustedNoForkedVm ) { + forkedVms ::= fork(suiteQueue) + noVm += 1 + } + forkedVms + } catch { + case _ : Throwable if noVm > 0 => forkedVms + } + } else { + log.debug(s"Creating a forked test runner") + val suiteQueue = enqueueSuites(frameworks, opts, oneItemPerSuites = false) + Seq(fork(suiteQueue)) + } + } + + testListeners.foreach(_.doInit()) + + try { + awaitForkedVms(createForkedVms()) + } catch { + case err : Throwable => onTestsCompletion(failedTestOutput(err.getMessage)) + } } -} -private final class React(is: ObjectInputStream, os: ObjectOutputStream, log: Logger, listeners: Seq[TestReportListener], results: mutable.Map[String, SuiteResult]) -{ - import ForkTags._ - @annotation.tailrec def react(): Unit = is.readObject match { - case `Done` => os.writeObject(Done); os.flush() - case Array(`Error`, s: String) => log.error(s); react() - case Array(`Warn`, s: String) => log.warn(s); react() - case Array(`Info`, s: String) => log.info(s); react() - case Array(`Debug`, s: String) => log.debug(s); react() - case t: Throwable => log.trace(t); react() - case Array(group: String, tEvents: Array[Event]) => - listeners.foreach(_ startGroup group) - val event = TestEvent(tEvents) - listeners.foreach(_ testEvent event) - val suiteResult = SuiteResult(tEvents) - results += group -> suiteResult - listeners.foreach(_ endGroup (group, suiteResult.result)) - react() } -} +} \ No newline at end of file diff --git a/main/actions/src/main/scala/sbt/Tests.scala b/main/actions/src/main/scala/sbt/Tests.scala index d2276cf24..67e46906a 100644 --- a/main/actions/src/main/scala/sbt/Tests.scala +++ b/main/actions/src/main/scala/sbt/Tests.scala @@ -218,7 +218,7 @@ object Tests } def processResults(results: Iterable[(String, SuiteResult)]): Output = - Output(overall(results.map(_._2.result)), results.toMap, Iterable.empty) + Output(TestResult.overall(results.map(_._2.result)), results.toMap, Iterable.empty) def foldTasks(results: Seq[Task[Output]], parallel: Boolean): Task[Output] = if (parallel) reduced(results.toIndexedSeq, { @@ -231,11 +231,10 @@ object Tests } sequence(results.toList, List()) map { ress => val (rs, ms) = ress.unzip { e => (e.overall, e.events) } - Output(overall(rs), ms reduce (_ ++ _), Iterable.empty) + Output(TestResult.overall(rs), ms reduce (_ ++ _), Iterable.empty) } } - def overall(results: Iterable[TestResult.Value]): TestResult.Value = - (TestResult.Passed /: results) { (acc, result) => if(acc.id < result.id) result else acc } + def discover(frameworks: Seq[Framework], analysis: Analysis, log: Logger): (Seq[TestDefinition], Set[String]) = discover(frameworks flatMap TestFramework.getFingerprints, allDefs(analysis), log) diff --git a/main/src/main/scala/sbt/Defaults.scala b/main/src/main/scala/sbt/Defaults.scala index 465578606..2f3a2ddfe 100755 --- a/main/src/main/scala/sbt/Defaults.scala +++ b/main/src/main/scala/sbt/Defaults.scala @@ -106,6 +106,8 @@ object Defaults extends BuildCommon exportJars :== false, fork :== false, testForkedParallel :== false, + testHideSuccessfulOutput :== false, + testNumberForkedJvm :== 1, javaOptions :== Nil, sbtPlugin :== false, crossPaths :== true, @@ -352,6 +354,7 @@ object Defaults extends BuildCommon Seq(ScalaCheck, Specs2, Specs, ScalaTest, JUnit) }, testListeners :== Nil, + testReportJUnitXml :== false, testOptions :== Nil, testFilter in testOnly :== (selectedFilter _) )) @@ -361,13 +364,14 @@ object Defaults extends BuildCommon definedTests <<= detectTests, definedTestNames <<= definedTests map ( _.map(_.name).distinct) storeAs definedTestNames triggeredBy compile, testFilter in testQuick <<= testQuickFilter, - executeTests <<= (streams in test, loadedTestFrameworks, testLoader, testGrouping in test, testExecution in test, fullClasspath in test, javaHome in test, testForkedParallel) flatMap allTestGroupsTask, + executeTests <<= (streams in test, loadedTestFrameworks, testLoader, testGrouping in test, testExecution in test, fullClasspath in test, javaHome in test, testForkedParallel, testHideSuccessfulOutput, testNumberForkedJvm) flatMap allTestGroupsTask, test := { implicit val display = Project.showContextKey(state.value) Tests.showResults(streams.value.log, executeTests.value, noTestsMessage(resolvedScoped.value)) }, testOnly <<= inputTests(testOnly), - testQuick <<= inputTests(testQuick) + testQuick <<= inputTests(testQuick), + testListeners ++= (if( testReportJUnitXml.value ) Seq(new JUnitXmlTestsListener(target.value.getAbsolutePath, streams.value.log)) else Nil) ) private[this] def noTestsMessage(scoped: ScopedKey[_])(implicit display: Show[ScopedKey[_]]): String = "No tests to run for " + display(scoped) @@ -469,7 +473,7 @@ object Defaults extends BuildCommon implicit val display = Project.showContextKey(state.value) val modifiedOpts = Tests.Filters(filter(selected)) +: Tests.Argument(frameworkOptions : _*) +: config.options val newConfig = config.copy(options = modifiedOpts) - val output = allTestGroupsTask(s, loadedTestFrameworks.value, testLoader.value, testGrouping.value, newConfig, fullClasspath.value, javaHome.value, testForkedParallel.value) + val output = allTestGroupsTask(s, loadedTestFrameworks.value, testLoader.value, testGrouping.value, newConfig, fullClasspath.value, javaHome.value, testForkedParallel.value, testHideSuccessfulOutput.value, testNumberForkedJvm.value) val processed = for(out <- output) yield Tests.showResults(s.log, out, noTestsMessage(resolvedScoped.value)) @@ -491,19 +495,26 @@ object Defaults extends BuildCommon } def allTestGroupsTask(s: TaskStreams, frameworks: Map[TestFramework,Framework], loader: ClassLoader, groups: Seq[Tests.Group], config: Tests.Execution, cp: Classpath, javaHome: Option[File]): Task[Tests.Output] = { - allTestGroupsTask(s,frameworks,loader, groups, config, cp, javaHome, forkedParallelExecution = false) + allTestGroupsTask(s,frameworks,loader, groups, config, cp, javaHome, forkedParallelExecution = false, hideSuccessfulOutput = false, noForkedVm = 1) } - def allTestGroupsTask(s: TaskStreams, frameworks: Map[TestFramework,Framework], loader: ClassLoader, groups: Seq[Tests.Group], config: Tests.Execution, cp: Classpath, javaHome: Option[File], forkedParallelExecution: Boolean): Task[Tests.Output] = { + def allTestGroupsTask(s: TaskStreams, frameworks: Map[TestFramework,Framework], loader: ClassLoader, groups: Seq[Tests.Group], config: Tests.Execution, cp: Classpath, javaHome: Option[File], forkedParallelExecution: Boolean, hideSuccessfulOutput: Boolean, noForkedVm: Int): Task[Tests.Output] = { val runners = createTestRunners(frameworks, loader, config) val groupTasks = groups map { case Tests.Group(name, tests, runPolicy) => runPolicy match { case Tests.SubProcess(opts) => val forkedConfig = config.copy(parallel = config.parallel && forkedParallelExecution) - s.log.debug(s"Forking tests - parallelism = ${forkedConfig.parallel}") - ForkTests(runners, tests.toList, forkedConfig, cp.files, opts, s.log) tag Tags.ForkedTestGroup + + s.log.debug( + s"""Forking tests + | - parallel=${forkedConfig.parallel} + | - hiding-successful-output=$hideSuccessfulOutput + | - noForkedVm=$noForkedVm""".stripMargin) + + ForkTests(frameworks, runners, tests.toList, forkedConfig, cp.files, opts, s.log, hideSuccessfulOutput, noForkedVm) tag Tags.ForkedTestGroup case Tests.InProcess => + s.log.debug("Not forking tests") Tests(frameworks, loader, runners, tests, config, s.log) } } diff --git a/main/src/main/scala/sbt/Keys.scala b/main/src/main/scala/sbt/Keys.scala index 17f64e0b3..77b99d69f 100644 --- a/main/src/main/scala/sbt/Keys.scala +++ b/main/src/main/scala/sbt/Keys.scala @@ -194,6 +194,9 @@ object Keys val testFrameworks = SettingKey[Seq[TestFramework]]("test-frameworks", "Registered, although not necessarily present, test frameworks.", CTask) val testListeners = TaskKey[Seq[TestReportListener]]("test-listeners", "Defines test listeners.", DTask) val testForkedParallel = SettingKey[Boolean]("test-forked-parallel", "Whether forked tests should be executed in parallel", CTask) + val testReportJUnitXml = SettingKey[Boolean]("test-report-junit-xml", "Produce JUnit XML test reports", BPlusTask) + val testHideSuccessfulOutput = SettingKey[Boolean]("test-hide-successful-output","Do not show standard output of successful tests - this works only in serial forked tests") + val testNumberForkedJvm = SettingKey[Int]("test-number-forked-jvm", "How many forked JVM will be used for executing the tests - this only applies in forked tests") val testExecution = TaskKey[Tests.Execution]("test-execution", "Settings controlling test execution", DTask) val testFilter = TaskKey[Seq[String] => Seq[String => Boolean]]("test-filter", "Filter controlling whether the test is executed", DTask) val testGrouping = TaskKey[Seq[Tests.Group]]("test-grouping", "Collects discovered tests into groups. Whether to fork and the options for forking are configurable on a per-group basis.", BMinusTask) diff --git a/sbt/src/sbt-test/tests/fork-multi-vm/project/ForkMultiVmTest.scala b/sbt/src/sbt-test/tests/fork-multi-vm/project/ForkMultiVmTest.scala new file mode 100644 index 000000000..90f7522e8 --- /dev/null +++ b/sbt/src/sbt-test/tests/fork-multi-vm/project/ForkMultiVmTest.scala @@ -0,0 +1,25 @@ +import sbt._ +import Keys._ +import Tests._ +import Defaults._ +import org.backuity.matchete.{FileMatchers,AssertionMatchers} + +object ForkMultiVmTest extends Build with AssertionMatchers with FileMatchers { + + val check = taskKey[Unit]("Check that tests are executed in multiple vms") + val checkClean = taskKey[Unit]("Check that clean left no test results") + + lazy val root = project.in(file(".")).settings( + scalaVersion := "2.9.2", + libraryDependencies += "com.novocode" % "junit-interface" % "0.10" % "test", + checkClean := { + for(i <- 1 to 4) file("target/" + i) must not(exist) + }, + check := { + file("target/1") must exist + for(i <- 4 to 2 by -1) { + file("target/" + i) must not(exist) + } + } + ) +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/fork-multi-vm/project/machete.sbt b/sbt/src/sbt-test/tests/fork-multi-vm/project/machete.sbt new file mode 100644 index 000000000..aa02bbe17 --- /dev/null +++ b/sbt/src/sbt-test/tests/fork-multi-vm/project/machete.sbt @@ -0,0 +1,3 @@ +resolvers += Resolver.sonatypeRepo("releases") + +libraryDependencies += "org.backuity" %% "matchete" % "1.1" \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/fork-multi-vm/src/test/scala/tests.scala b/sbt/src/sbt-test/tests/fork-multi-vm/src/test/scala/tests.scala new file mode 100644 index 000000000..db9246054 --- /dev/null +++ b/sbt/src/sbt-test/tests/fork-multi-vm/src/test/scala/tests.scala @@ -0,0 +1,40 @@ + +import org.junit.Test + +package a.pkg { + + import java.io.File + import java.util.concurrent.atomic.AtomicInteger + + object Tests { + // if tests are executed within the same vm, then _noExecutedTests + // should end up 4 + private val _noExecutedTests = new AtomicInteger(0) + + def execute() { + val noExecutedTests = _noExecutedTests.incrementAndGet() + new File("target/" + noExecutedTests).createNewFile() + + // make sure each test is executed in a different vm. + // If a test was running too fast its vm could pick another test from the test suite queue + // before the queue gets emptied by the remaining vms. + Thread.sleep(5000) + } + } + + class Test1 { + @Test def test1() { Tests.execute() } + } + + class Test2 { + @Test def test2() { Tests.execute() } + } + + class Test3 { + @Test def test3() { Tests.execute() } + } + + class Test4 { + @Test def test4() { Tests.execute() } + } +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/fork-multi-vm/test b/sbt/src/sbt-test/tests/fork-multi-vm/test new file mode 100644 index 000000000..14d49e228 --- /dev/null +++ b/sbt/src/sbt-test/tests/fork-multi-vm/test @@ -0,0 +1,15 @@ +# with a single vm at most one file will be created +> test +-> check +> clean +> checkClean + +> set fork in Test := true +> test +-> check +> clean +> checkClean + +> set testNumberForkedJvm := 4 +> test +> check \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/hide-successful-output/project/HideSuccessfulOutputBuild.scala b/sbt/src/sbt-test/tests/hide-successful-output/project/HideSuccessfulOutputBuild.scala new file mode 100644 index 000000000..cd558e924 --- /dev/null +++ b/sbt/src/sbt-test/tests/hide-successful-output/project/HideSuccessfulOutputBuild.scala @@ -0,0 +1,26 @@ +import sbt._ +import Keys._ +import scala.xml.XML +import Tests._ +import Defaults._ +import org.backuity.matchete.AssertionMatchers + +object HideSuccessfulOutputBuild extends Build with AssertionMatchers { + + val check = taskKey[Unit]("make sure successful test output isn't present in the dumped stdout") + + val main = project.in(file(".")).settings( + + libraryDependencies += "com.novocode" % "junit-interface" % "0.10" % "test", + + // hiding successful output only works in forked mode + fork in Test := true, + + check := { + val content = IO.read(file("stdout.dump")).trim + val ansiFreeContent = content.replaceAll("\\p{C}", "") + ansiFreeContent must not(contain("shouldn't show up")) + ansiFreeContent must contain("must show up") + } + ) +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/hide-successful-output/project/machete.sbt b/sbt/src/sbt-test/tests/hide-successful-output/project/machete.sbt new file mode 100644 index 000000000..aa02bbe17 --- /dev/null +++ b/sbt/src/sbt-test/tests/hide-successful-output/project/machete.sbt @@ -0,0 +1,3 @@ +resolvers += Resolver.sonatypeRepo("releases") + +libraryDependencies += "org.backuity" %% "matchete" % "1.1" \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/hide-successful-output/src/test/scala/tests.scala b/sbt/src/sbt-test/tests/hide-successful-output/src/test/scala/tests.scala new file mode 100644 index 000000000..f2586825f --- /dev/null +++ b/sbt/src/sbt-test/tests/hide-successful-output/src/test/scala/tests.scala @@ -0,0 +1,42 @@ +import org.junit.Test + +package a.failing.pkg { + + class FailingTest { + @Test + def fail() { + for( i <- 1 to 10 ) { + println("This must show up") + Thread.sleep(10) + } + sys.error("fail") + } + } + + class SuccessfulTest { + @Test + def success1() { + for( i <- 1 to 10 ) { + println("This shouldn't show up 1") + Thread.sleep(10) + } + } + + @Test + def success2() { + new Thread() { + override def run() { + for( i <- 1 to 10 ) { + println("This shouldn't show up (from thread)") + Thread.sleep(10) + } + } + }.start() + + for( i <- 1 to 10 ) { + println("This shouldn't show up 2") + Thread.sleep(10) + } + } + } +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/hide-successful-output/test b/sbt/src/sbt-test/tests/hide-successful-output/test new file mode 100644 index 000000000..99a2ea9b9 --- /dev/null +++ b/sbt/src/sbt-test/tests/hide-successful-output/test @@ -0,0 +1,15 @@ +> set testHideSuccessfulOutput := true + +# parallel tests are more likely to fail at hiding the standard output +> set testForkedParallel := true +-> test +> check + +> set testNumberForkedJvm := 4 +-> test +> check + +> set testForkedParallel := false +-> test +> check + diff --git a/sbt/src/sbt-test/tests/junit-xml-report/project/JUnitXmlReportTest.scala b/sbt/src/sbt-test/tests/junit-xml-report/project/JUnitXmlReportTest.scala new file mode 100644 index 000000000..54a415004 --- /dev/null +++ b/sbt/src/sbt-test/tests/junit-xml-report/project/JUnitXmlReportTest.scala @@ -0,0 +1,95 @@ +import sbt._ +import Keys._ +import scala.xml.XML +import Tests._ +import Defaults._ +import org.backuity.matchete.{Matcher, AssertionMatchers, XmlMatchers, FileMatchers} + +object JUnitXmlReportTest extends Build with AssertionMatchers with XmlMatchers with FileMatchers { + val checkReport = taskKey[Unit]("Check the test reports") + val checkReportNoStdOut = taskKey[Unit]("Check the test reports (not checking stdout)") + val checkNoReport = taskKey[Unit]("Check that no reports are present") + + private val oneSecondReportFile = "target/test-reports/a.pkg.OneSecondTest.xml" + private val failingReportFile = "target/test-reports/another.pkg.FailingTest.xml" + private val failUponConstructionReportFile = "target/test-reports/another.pkg.FailUponConstructionTest.xml" + private val consoleReportFile = "target/test-reports/console.test.pkg.ConsoleTests.xml" + + def greaterThan(float: Float) : Matcher[String] = be("greater than " + float) { + case attr => attr.toFloat must be_>=(float) + } + + lazy val root = Project("root", file("."), settings = defaultSettings ++ Seq( + scalaVersion := "2.9.2", + libraryDependencies ++= Seq( + "com.novocode" % "junit-interface" % "0.10" % "test", + "org.scalatest" % "scalatest_2.9.2" % "2.0.M3" % "test" intransitive()), + + testReportJUnitXml := true, + + checkReport := { + doCheckReport(checkStdOut = true) + }, + + checkReportNoStdOut := { + doCheckReport(checkStdOut = false) + }, + + checkNoReport := { + file(oneSecondReportFile) must not(exist) + file(failingReportFile) must not(exist) + file(failUponConstructionReportFile) must not(exist) + file(consoleReportFile) must not(exist) + } + )) + + private def doCheckReport(checkStdOut: Boolean) { + val oneSecondReport = XML.loadFile(oneSecondReportFile) + oneSecondReport must haveLabel("testsuite") + oneSecondReport must haveAttribute("name", equalTo("a.pkg.OneSecondTest")) + + // junit-interface does not report time yet... + // oneSecondReport must haveAttribute("time", greaterThan(1f)) + + oneSecondReport \ "testcase" must containExactly( + a("one-second testcase") { case tc => + tc must haveAttribute("name", equalTo("oneSecond")) + tc must haveAttribute("classname", equalTo("a.pkg.OneSecondTest")) + // tc must haveAttribute("time", greaterThan(1f)) + }) + + val failingReport = XML.loadFile(failingReportFile) + failingReport must haveLabel("testsuite") + failingReport must haveAttribute("failures", equalTo("2")) + // failingReport must haveAttribute("time", greaterThan(1.5f)) // time is sumed-up in the testsuite element + failingReport must haveAttribute("name", equalTo("another.pkg.FailingTest")) + // TODO more checks -> the two test cases with time etc.. + + val failUponConstructionReport = XML.loadFile(failUponConstructionReportFile) + failUponConstructionReport must haveLabel("testsuite") + failUponConstructionReport must haveAttribute("errors", equalTo("1")) + (failUponConstructionReport \ "system-err").text must (contain("failed upon construction") and contain("RuntimeException")) + failUponConstructionReport \ "testcase" must haveSize(0) + + val consoleReport = XML.loadFile(consoleReportFile) + consoleReport must haveLabel("testsuite") + consoleReport must haveAttribute("tests", equalTo("2")) + consoleReport must haveAttribute("name", equalTo("console.test.pkg.ConsoleTests")) + consoleReport must haveAttribute("failures", equalTo("0")) + consoleReport \ "testcase" must containExactly( + a("sayHello test-case") { case tc => + tc must haveAttribute("name", equalTo("sayHello")) + tc must haveAttribute("classname", equalTo("console.test.pkg.ConsoleTests")) + if( checkStdOut ) { + tc \ "system-out" must haveTrimmedText("Hello\nWorld!") + }}, + + a("multiThreadedHello test-case") { case tc => + tc must haveAttribute("name", equalTo("multiThreadedHello")) + tc must haveAttribute("classname", equalTo("console.test.pkg.ConsoleTests")) + if( checkStdOut ) { + (tc \ "system-out").text.trim.split("\n").toList must containElements( (for( i <- 1 to 15) yield s"Hello from thread $i") : _*) + }}) + + } +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/junit-xml-report/project/matchete.sbt b/sbt/src/sbt-test/tests/junit-xml-report/project/matchete.sbt new file mode 100644 index 000000000..fc5eba8cb --- /dev/null +++ b/sbt/src/sbt-test/tests/junit-xml-report/project/matchete.sbt @@ -0,0 +1,3 @@ +resolvers += Resolver.sonatypeRepo("releases") + +libraryDependencies += "org.backuity" %% "matchete" % "1.2" \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/junit-xml-report/src/test/scala/tests.scala b/sbt/src/sbt-test/tests/junit-xml-report/src/test/scala/tests.scala new file mode 100644 index 000000000..d9a193a56 --- /dev/null +++ b/sbt/src/sbt-test/tests/junit-xml-report/src/test/scala/tests.scala @@ -0,0 +1,65 @@ +import org.junit.Test + +package a.pkg { + class OneSecondTest { + @Test + def oneSecond() { + Thread.sleep(1000) + } + } +} + +package another.pkg { + class FailingTest { + @Test + def failure1_OneSecond() { + Thread.sleep(1000) + sys.error("fail1") + } + + @Test + def failure2_HalfSecond() { + Thread.sleep(500) + sys.error("fail2") + } + } + + // junit doesn't blow up when a class fails during construction + // we'll use scalatest (which does blow up) to make sure + // the report contains that kind of error + import org.scalatest.{FunSpec, ShouldMatchers} + class FailUponConstructionTest extends FunSpec with ShouldMatchers { + sys.error("failed upon construction") + + describe("5 should") { + it("always be 5") { + 5 should equal (5) + } + } + } +} + +package console.test.pkg { + // we won't check console output in the report + // until SBT supports that + class ConsoleTests { + @Test + def sayHello() { + println("Hello") + System.out.println("World!") + } + + @Test + def multiThreadedHello() { + val threads = for( i <- 1 to 15 ) yield { + new Thread("t-" + i) { + override def run() { + println("Hello from thread " + i) + } + } + } + threads.foreach( _.start() ) + threads.foreach( _.join() ) + } + } +} \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/junit-xml-report/test b/sbt/src/sbt-test/tests/junit-xml-report/test new file mode 100644 index 000000000..678382689 --- /dev/null +++ b/sbt/src/sbt-test/tests/junit-xml-report/test @@ -0,0 +1,43 @@ +# This test is twofold: +# . +# - it checks the junit xml report format (provided by `JUnitXmlTestsListener`) +# . +# - it checks the segregation of test output. When tests run concurrently things printed on the standard output +# get mixed up. SBT can tell the test output appart so that each test is reported with its own standard output. +# . +# ------------------------------------------------------------------------------------------------------------ +# . +# for now test output segregation works only in fork mode +> set fork in Test := true + +# try parallel first (as it is more likely to fail than its serial counterpart) +> set testForkedParallel := true +-> test +# when parallel, stdout cannot be captured properly and is just printed on the console +> checkReportNoStdOut + +> clean +> checkNoReport + +> set testForkedParallel := false +> set testNumberForkedJvm := 3 +-> test +> checkReport + +> clean +> checkNoReport + +> set testNumberForkedJvm := 1 +-> test +> checkReport + +# there might be discrepancies between the 'normal' and the 'forked' mode + +> clean +> checkNoReport + +> set fork in Test := false +-> test +> checkReportNoStdOut + +## TODO serial non-forked should be able to capture output? \ No newline at end of file diff --git a/sbt/src/sbt-test/tests/t543/project/Ticket543Test.scala b/sbt/src/sbt-test/tests/t543/project/Ticket543Test.scala index cda602f1a..1a0d69132 100755 --- a/sbt/src/sbt-test/tests/t543/project/Ticket543Test.scala +++ b/sbt/src/sbt-test/tests/t543/project/Ticket543Test.scala @@ -13,7 +13,7 @@ object Ticket543Test extends Build { scalaVersion := "2.9.2", fork := true, testListeners += new TestReportListener { - def testEvent(event: TestEvent) { + def testEvent(event: SuiteReport) { for (e <- event.detail.filter(_.status == sbt.testing.Status.Failure)) { if (e.throwable != null && e.throwable.isDefined) { val caw = new CharArrayWriter @@ -23,9 +23,9 @@ object Ticket543Test extends Build { } } } - def startGroup(name: String) {} - def endGroup(name: String, t: Throwable) {} - def endGroup(name: String, result: TestResult.Value) {} + def startSuite(name: String) {} + def endSuite(name: String, t: Throwable) {} + def endSuite(name: String, result: TestResult.Value) {} }, check := { val exists = marker.exists diff --git a/scripted/sbt/src/main/scala/sbt/test/SbtHandler.scala b/scripted/sbt/src/main/scala/sbt/test/SbtHandler.scala index 4956b1b9f..b29969818 100644 --- a/scripted/sbt/src/main/scala/sbt/test/SbtHandler.scala +++ b/scripted/sbt/src/main/scala/sbt/test/SbtHandler.scala @@ -4,7 +4,7 @@ package sbt package test - import java.io.{File, IOException} + import java.io.{File, IOException,FileWriter} import xsbt.IPC import xsbt.test.{StatementHandler, TestFailed} @@ -64,7 +64,8 @@ final class SbtHandler(directory: File, launcher: File, log: Logger, launchOpts: val launcherJar = launcher.getAbsolutePath val globalBase = "-Dsbt.global.base=" + (new File(directory, "global")).getAbsolutePath val args = "java" :: (launchOpts.toList ++ (globalBase :: "-jar" :: launcherJar :: ( "<" + server.port) :: Nil)) - val io = BasicIO(log, false).withInput(_.close()) + val dumpLogger = new DumpLogger( new File(directory, "stdout.dump"), log) + val io = BasicIO(dumpLogger, false).withInput(_.close()) val p = Process(args, directory) run( io ) Spawn { p.exitValue(); server.close() } try { receive("Remote sbt initialization failed", server) } @@ -76,3 +77,26 @@ final class SbtHandler(directory: File, launcher: File, log: Logger, launchOpts: def escape(argument: String) = if(argument.contains(" ")) "\"" + argument.replaceAll(q("""\"""), """\\""").replaceAll(q("\""), "\\\"") + "\"" else argument } + +final class DumpLogger(dumpFile: File, delegate: ProcessLogger) extends ProcessLogger { + private val fileWriter = new FileWriter(dumpFile, false) + + private def writeFile(msg: String) { + fileWriter.write(msg) + fileWriter.flush() + } + + def info(s: => String): Unit = { + val msg = s + writeFile(msg) + delegate.info(msg) + } + + def error(s: => String): Unit = { + val msg = s + writeFile(msg) + delegate.error(msg) + } + + def buffer[T](f: => T): T = delegate.buffer(f) +} \ No newline at end of file diff --git a/testing/agent/src/main/java/sbt/ForkMain.java b/testing/agent/src/main/java/sbt/ForkMain.java index a56783fcd..7082c4db6 100755 --- a/testing/agent/src/main/java/sbt/ForkMain.java +++ b/testing/agent/src/main/java/sbt/ForkMain.java @@ -9,12 +9,16 @@ import java.io.IOException; import java.io.ObjectInputStream; import java.io.ObjectOutputStream; import java.io.Serializable; -import java.net.Socket; import java.net.InetAddress; +import java.net.Socket; import java.util.ArrayList; import java.util.Arrays; +import java.util.HashMap; import java.util.List; -import java.util.concurrent.*; +import java.util.concurrent.Callable; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; public class ForkMain { @@ -118,6 +122,8 @@ public class ForkMain { try { new Run().run(is, os); + } catch( Throwable t ) { + t.printStackTrace(); } finally { try { is.close(); @@ -162,7 +168,7 @@ public class ForkMain { } class RunAborted extends RuntimeException { - RunAborted(Exception e) { super(e); } + RunAborted(String message, Throwable cause) { super(message, cause); } } synchronized void write(ObjectOutputStream os, Object obj) { @@ -170,12 +176,16 @@ public class ForkMain { os.writeObject(obj); os.flush(); } catch (IOException e) { - throw new RunAborted(e); + throw new RunAborted("While writing " + obj, e); } } void log(ObjectOutputStream os, String message, ForkTags level) { - write(os, new Object[]{level, message}); + try { + write(os, new Object[]{level, message}); + } catch( RunAborted e ) { + throw new RunAborted("While logging " + level + " level message >" + message + "<", e.getCause()); + } } void logDebug(ObjectOutputStream os, String message) { log(os, message, ForkTags.Debug); } @@ -194,8 +204,20 @@ public class ForkMain { }; } - void writeEvents(ObjectOutputStream os, TaskDef taskDef, ForkEvent[] events) { - write(os, new Object[]{taskDef.fullyQualifiedName(), events}); + void writeEndTest(ObjectOutputStream os, String suiteName, ForkEvent event) { + write(os, new Object[]{ForkTags.EndTest, suiteName, event}); + } + + void writeStartSuite(ObjectOutputStream os, String suiteName) { + write(os, new Object[]{ForkTags.StartSuite, suiteName}); + } + + void writeEndSuite(ObjectOutputStream os, String suiteName) { + write(os, new Object[]{ForkTags.EndSuite, suiteName}); + } + + void writeEndSuiteError(ObjectOutputStream os, String suiteName, Throwable t) { + write(os, new Object[]{ForkTags.EndSuiteError, suiteName, t}); } ExecutorService executorService(ForkConfiguration config, ObjectOutputStream os) { @@ -211,53 +233,58 @@ public class ForkMain { } } + void runTests(ObjectInputStream is, final ObjectOutputStream os) throws Exception { final ForkConfiguration config = (ForkConfiguration) is.readObject(); + ExecutorService executor = executorService(config, os); - final TaskDef[] tests = (TaskDef[]) is.readObject(); + int nFrameworks = is.readInt(); Logger[] loggers = { remoteLogger(config.isAnsiCodesSupported(), os) }; + FrameworkLoader loader = new FrameworkLoader() { + @Override + protected void logDebug(String message) { + Run.this.logDebug(os, message); + } + }; + + HashMap runners = new HashMap(); + for (int i = 0; i < nFrameworks; i++) { final String[] implClassNames = (String[]) is.readObject(); final String[] frameworkArgs = (String[]) is.readObject(); final String[] remoteFrameworkArgs = (String[]) is.readObject(); - Framework framework = null; - for (String implClassName : implClassNames) { - try { - Object rawFramework = Class.forName(implClassName).newInstance(); - if (rawFramework instanceof Framework) - framework = (Framework) rawFramework; - else - framework = new FrameworkWrapper((org.scalatools.testing.Framework) rawFramework); - break; - } catch (ClassNotFoundException e) { - logDebug(os, "Framework implementation '" + implClassName + "' not present."); - } - } - + Framework framework = loader.loadFramework(implClassNames); if (framework == null) continue; - ArrayList filteredTests = new ArrayList(); - for (Fingerprint testFingerprint : framework.fingerprints()) { - for (TaskDef test : tests) { - // TODO: To pass in correct explicitlySpecified and selectors - if (matches(testFingerprint, test.fingerprint())) - filteredTests.add(new TaskDef(test.fullyQualifiedName(), test.fingerprint(), test.explicitlySpecified(), test.selectors())); - } - } - final Runner runner = framework.runner(frameworkArgs, remoteFrameworkArgs, getClass().getClassLoader()); - Task[] tasks = runner.tasks(filteredTests.toArray(new TaskDef[filteredTests.size()])); - logDebug(os, "Runner for " + framework.getClass().getName() + " produced " + tasks.length + " initial tasks for " + filteredTests.size() + " tests."); - - runTestTasks(executor, tasks, loggers, os); - - runner.done(); + Runner runner = framework.runner(frameworkArgs, remoteFrameworkArgs, getClass().getClassLoader()); + runners.put(framework.name(), runner); + } + + while(true) { + Object item = is.readObject(); + if( item instanceof ForkSuites ) { + ForkSuites suites = (ForkSuites)item; + Runner runner = runners.get(suites.getFrameworkName()); + if( runner == null ) { + logWarn(os, "Couldn't find a runner for framework " + suites.getFrameworkName()); + } else { + Task[] tasks = runner.tasks(suites.getTaskDefs()); + runTestTasks(executor, tasks, loggers, os); + } + write(os, ForkTags.Done); + } else { + logDebug(os, "Received " + item + " terminating forked runner."); + for (Runner runner : runners.values()) { + runner.done(); + } + write(os, ForkTags.Done); + break; + } } - write(os, ForkTags.Done); - is.readObject(); } void runTestTasks(ExecutorService executor, Task[] tasks, Logger[] loggers, ObjectOutputStream os) { @@ -274,7 +301,7 @@ public class ForkMain { try { nestedTasks.addAll( Arrays.asList(futureNestedTask.get())); } catch (Exception e) { - logError(os, "Failed to execute task " + futureNestedTask); + logError(os, "Failed to execute task " + futureNestedTask + ": " + e.getMessage()); } } runTestTasks(executor, nestedTasks.toArray(new Task[nestedTasks.size()]), loggers, os); @@ -282,33 +309,40 @@ public class ForkMain { } Future runTest(ExecutorService executor, final Task task, final Logger[] loggers, final ObjectOutputStream os) { + // one thread per suite return executor.submit(new Callable() { @Override public Task[] call() { - ForkEvent[] events; Task[] nestedTasks; - TaskDef taskDef = task.taskDef(); + final TaskDef taskDef = task.taskDef(); + final String suiteName = taskDef.fullyQualifiedName(); + writeStartSuite(os, suiteName); + try { - final List eventList = new ArrayList(); - EventHandler handler = new EventHandler() { public void handle(Event e){ eventList.add(new ForkEvent(e)); } }; + EventHandler handler = new EventHandler() { + public void handle(Event e){ + ForkEvent event = new ForkEvent(e); + writeEndTest(os, suiteName, event); + } + }; logDebug(os, " Running " + taskDef); nestedTasks = task.execute(handler, loggers); - if(nestedTasks.length > 0 || eventList.size() > 0) - logDebug(os, " Produced " + nestedTasks.length + " nested tasks and " + eventList.size() + " events."); - events = eventList.toArray(new ForkEvent[eventList.size()]); + if(nestedTasks.length > 0) + logDebug(os, " Produced " + nestedTasks.length + " nested tasks"); + writeEndSuite(os, suiteName); } catch (Throwable t) { nestedTasks = new Task[0]; - events = new ForkEvent[] { testError(os, taskDef, "Uncaught exception when running " + taskDef.fullyQualifiedName() + ": " + t.toString(), t) }; + writeEndSuiteError(os, suiteName, t); } - writeEvents(os, taskDef, events); return nestedTasks; } }); } void internalError(Throwable t) { - System.err.println("Internal error when running tests: " + t.toString()); + System.err.println("Internal error when running tests:"); + t.printStackTrace(System.err); } ForkEvent testEvent(final String fullyQualifiedName, final Fingerprint fingerprint, final Selector selector, final Status r, final ForkError err, final long duration) { diff --git a/testing/agent/src/main/java/sbt/ForkSuites.java b/testing/agent/src/main/java/sbt/ForkSuites.java new file mode 100644 index 000000000..afb609d9a --- /dev/null +++ b/testing/agent/src/main/java/sbt/ForkSuites.java @@ -0,0 +1,29 @@ +package sbt; + +import sbt.testing.TaskDef; + +import java.io.Serializable; + +public class ForkSuites implements Serializable { + + private String frameworkName; + private TaskDef[] taskDefs; + + public ForkSuites(String frameworkName, TaskDef taskDef) { + this.frameworkName = frameworkName; + this.taskDefs = new TaskDef[] { taskDef }; + } + + public ForkSuites(String frameworkName, TaskDef[] taskDefs) { + this.frameworkName = frameworkName; + this.taskDefs = taskDefs; + } + + public String getFrameworkName() { + return frameworkName; + } + + public TaskDef[] getTaskDefs() { + return taskDefs; + } +} diff --git a/testing/agent/src/main/java/sbt/ForkTags.java b/testing/agent/src/main/java/sbt/ForkTags.java index 31ee70223..3cb3e83fc 100644 --- a/testing/agent/src/main/java/sbt/ForkTags.java +++ b/testing/agent/src/main/java/sbt/ForkTags.java @@ -4,6 +4,6 @@ package sbt; public enum ForkTags { - Error, Warn, Info, Debug, Done; + Error, Warn, Info, Debug, Done, StartSuite, EndTest, EndSuite, EndSuiteError; } diff --git a/testing/agent/src/main/java/sbt/FrameworkLoader.java b/testing/agent/src/main/java/sbt/FrameworkLoader.java new file mode 100644 index 000000000..029aeef9d --- /dev/null +++ b/testing/agent/src/main/java/sbt/FrameworkLoader.java @@ -0,0 +1,35 @@ +package sbt; + +import sbt.testing.Framework; + +public abstract class FrameworkLoader { + + protected abstract void logDebug(String message); + + /** + * @return null if no {@link Framework} could be loaded out of `names` + */ + public Framework loadFramework(String[] names) { + for (String implClassName : names) { + try { + Object rawFramework = Class.forName(implClassName).newInstance(); + if (rawFramework instanceof Framework) + return (Framework) rawFramework; + else { + try { + return new FrameworkWrapper((org.scalatools.testing.Framework) rawFramework); + } catch (ClassCastException e) { + logDebug("Framework " + rawFramework + " is neither an sbt.testing.Framework nor an org.scalatools.testing.Framework"); + } + } + } catch (ClassNotFoundException e) { + logDebug("Framework implementation '" + implClassName + "' not present."); + } catch (InstantiationException e) { + logDebug("Framework implementation '" + implClassName + "' cannot be instiated: " + e.getMessage()); + } catch (IllegalAccessException e) { + logDebug("Framework implementation '" + implClassName + "' cannot be accessed: " + e.getMessage()); + } + } + return null; + } +} diff --git a/testing/src/main/scala/sbt/JUnitXmlTestsListener.scala b/testing/src/main/scala/sbt/JUnitXmlTestsListener.scala new file mode 100644 index 000000000..f66ae0b73 --- /dev/null +++ b/testing/src/main/scala/sbt/JUnitXmlTestsListener.scala @@ -0,0 +1,101 @@ +package sbt + +import java.io.{StringWriter, PrintWriter, File} +import java.net.InetAddress +import scala.collection.mutable.ListBuffer +import scala.util.DynamicVariable +import scala.xml.{Elem, Node, XML} +import testing.{Event => TEvent, Status => TStatus, OptionalThrowable, TestSelector} + +/** + * A tests listener that outputs the results it receives in junit xml + * report format. XSD can be found here: http://windyroad.com.au/dl/Open%20Source/JUnit.xsd (note: we might want to download this into the project?) + * @param outputDir path to the dir in which a folder with results is generated + */ +class JUnitXmlTestsListener(val outputDir:String, logger: Logger) extends TestsListener +{ + /**Current hostname so we know which machine executed the tests*/ + val hostname = InetAddress.getLocalHost.getHostName + /**The dir in which we put all result files. Is equal to the given dir + "/test-reports"*/ + val targetDir = new File(outputDir + "/test-reports/") + + /**all system properties as XML*/ + def properties = + { + val iter = System.getProperties.entrySet.iterator + val props:ListBuffer[Node] = new ListBuffer() + while (iter.hasNext) { + val next = iter.next + props += + } + props + } + + + private def cdata(content: String) = scala.xml.Unparsed("".format(content)) + + private def stackTraceToString(t: Throwable) : String = { + val stringWriter = new StringWriter() + val writer = new PrintWriter(stringWriter) + t.printStackTrace(writer) + writer.flush() + stringWriter.toString + } + + def toXml(name:String, suite: SuiteReport) : Elem = { + val errors = if( suite.result.errorCount == 0 && suite.errorCause.isDefined) 1 else suite.result.errorCount + + + {properties} + { + for (e <- suite.detail) yield + selector.testName.split('.').last + case _ => "(It is not a test)" + } + } + time={(e.detail.duration() / 1000.0).toString}> { + val trace: String = if (e.detail.throwable.isDefined) { + stackTraceToString(e.detail.throwable.get) + } + else { + "" + } + e.detail.status match { + case TStatus.Error if (e.detail.throwable.isDefined) => {trace} + case TStatus.Error => + case TStatus.Failure if (e.detail.throwable.isDefined) => {trace} + case TStatus.Failure => + case TStatus.Skipped => + case _ => {} + } + } + {cdata(e.stdout)} + + + } + + {cdata(suite.errorCause.map(stackTraceToString).getOrElse(""))} + + + } + + override def doInit() = {targetDir.mkdirs()} + + /** Ends the current suite, wraps up the result and writes it to an XML file + * in the output folder that is named after the suite. + */ + override def endSuite(name: String, suite: SuiteReport) = { + writeSuite(name, suite) + } + + private def writeSuite(name: String, suite: SuiteReport) = { + val file = new File(targetDir, name + ".xml").getAbsolutePath + logger.debug("Writing JUnit XML test report: " + file) + XML.save (file, toXml(name, suite), "UTF-8", true, null) + } +} diff --git a/testing/src/main/scala/sbt/TestFramework.scala b/testing/src/main/scala/sbt/TestFramework.scala index 47b1d69e3..cdafa7c14 100644 --- a/testing/src/main/scala/sbt/TestFramework.scala +++ b/testing/src/main/scala/sbt/TestFramework.scala @@ -13,6 +13,10 @@ package sbt object TestResult extends Enumeration { val Passed, Failed, Error = Value + + /** `Passed` when empty */ + def overall(results: Iterable[TestResult.Value]): TestResult.Value = + results.foldLeft(Passed) { (acc, result) => if(acc.id < result.id) result else acc } } object TestFrameworks @@ -77,28 +81,32 @@ final class TestRunner(delegate: Runner, listeners: Seq[TestReportListener], log def runTest() = { // here we get the results! here is where we'd pass in the event listener - val results = new scala.collection.mutable.ListBuffer[Event] - val handler = new EventHandler { def handle(e:Event){ results += e } } + val testReports = new scala.collection.mutable.ListBuffer[TestReport] + val handler = new EventHandler { + def handle(e:Event) { + val testReport = TestReport("", e) // TODO output capture + safeListenersCall( _.endTest(testReport) ) + testReports += testReport + } + } val loggers = listeners.flatMap(_.contentLogger(testDefinition)) val nestedTasks = try testTask.execute(handler, loggers.map(_.log).toArray) finally loggers.foreach( _.flush() ) - val event = TestEvent(results) - safeListenersCall(_.testEvent( event )) - (SuiteResult(results), nestedTasks.toSeq) + (SuiteReport(testReports), nestedTasks.toSeq) } - safeListenersCall(_.startGroup(name)) + safeListenersCall(_.startSuite(name)) try { - val (suiteResult, nestedTasks) = runTest() - safeListenersCall(_.endGroup(name, suiteResult.result)) - (suiteResult, nestedTasks) + val (suiteReport, nestedTasks) = runTest() + safeListenersCall(_.endSuite(name, suiteReport)) + (suiteReport.result, nestedTasks) } catch { case e: Throwable => - safeListenersCall(_.endGroup(name, e)) + safeListenersCall(_.endSuite(name, SuiteReport(e))) (SuiteResult.Error, Seq.empty[TestTask]) } } diff --git a/testing/src/main/scala/sbt/TestReportListener.scala b/testing/src/main/scala/sbt/TestReportListener.scala index 7484a6d37..219b7827e 100644 --- a/testing/src/main/scala/sbt/TestReportListener.scala +++ b/testing/src/main/scala/sbt/TestReportListener.scala @@ -9,66 +9,122 @@ package sbt trait TestReportListener { /** called for each class or equivalent grouping */ - def startGroup(name: String) + def startSuite(name: String) {} + /** called for each test method or equivalent */ - def testEvent(event: TestEvent) - /** called if there was an error during test */ - def endGroup(name: String, t: Throwable) + def endTest(report: TestReport) {} + /** called if test completed */ - def endGroup(name: String, result: TestResult.Value) - /** Used by the test framework for logging test results*/ + def endSuite(name: String, report: SuiteReport) {} + + /** Used by the test framework for logging test results*/ def contentLogger(test: TestDefinition): Option[ContentLogger] = None } trait TestsListener extends TestReportListener { /** called once, at beginning. */ - def doInit() + def doInit() {} /** called once, at end. */ - def doComplete(finalResult: TestResult.Value) + def doComplete(finalResult: TestResult.Value) {} } /** Provides the overall `result` of a group of tests (a suite) and test counts for each result type. */ final class SuiteResult( val result: TestResult.Value, val passedCount: Int, val failureCount: Int, val errorCount: Int, - val skippedCount: Int, val ignoredCount: Int, val canceledCount: Int, val pendingCount: Int) + val skippedCount: Int, val ignoredCount: Int, val canceledCount: Int, val pendingCount: Int) { + + def error : SuiteResult = new SuiteResult( + TestResult.Error, passedCount, failureCount, errorCount, + skippedCount, ignoredCount, canceledCount, pendingCount) +} object SuiteResult { /** Computes the overall result and counts for a suite with individual test results in `events`. */ - def apply(events: Seq[TEvent]): SuiteResult = + def apply(events: Seq[TestReport]): SuiteResult = { - def count(status: TStatus) = events.count(_.status == status) - new SuiteResult(TestEvent.overallResult(events), count(TStatus.Success), count(TStatus.Failure), count(TStatus.Error), + def count(status: TStatus) = events.count(_.detail.status == status) + val result = TestResult.overall(events.view.map(_.result)) + new SuiteResult(result, count(TStatus.Success), count(TStatus.Failure), count(TStatus.Error), count(TStatus.Skipped), count(TStatus.Ignored), count(TStatus.Canceled), count(TStatus.Pending)) } + val Error: SuiteResult = new SuiteResult(TestResult.Error, 0, 0, 0, 0, 0, 0, 0) val Empty: SuiteResult = new SuiteResult(TestResult.Passed, 0, 0, 0, 0, 0, 0, 0) } -abstract class TestEvent -{ - def result: Option[TestResult.Value] - def detail: Seq[TEvent] = Nil -} -object TestEvent -{ - def apply(events: Seq[TEvent]): TestEvent = - new TestEvent { - val result = Some(overallResult(events)) - override val detail = events - } +abstract class SuiteReport +{ outer => + def result: SuiteResult - private[sbt] def overallResult(events: Seq[TEvent]): TestResult.Value = - (TestResult.Passed /: events) { (sum, event) => - val status = event.status - if(sum == TestResult.Error || status == TStatus.Error) TestResult.Error - else if(sum == TestResult.Failed || status == TStatus.Failure) TestResult.Failed - else TestResult.Passed + /** + * @note it might happen that a class is flagged as a test suite but contains no tests, therefore + * producing a suite report with no test report. The test suite might also fail while + * being constructed. + * @return the test reports of this suite - can be empty + */ + def detail: Seq[TestReport] + + /** defined if an error has interrupted the suite execution */ + def errorCause: Option[Throwable] + + def addTest(test: TestReport) : SuiteReport = { + SuiteReport(detail :+ test) + } + + /** @return a copy of this suite report with result `Error` (result counts and details are preserved) */ + def error(err: Throwable) : SuiteReport = new SuiteReport { + val result = outer.result.error + val errorCause = Some(err) + def detail = outer.detail + } + + /** Duration of the Suite in milliseconds. + * @see [[sbt.testing.Event.duration()]] + */ + lazy val duration : Long = detail.view.map( _.detail.duration() ).sum +} +object SuiteReport +{ + val empty : SuiteReport = apply(Nil) + + def apply(err: Throwable) : SuiteReport = { + empty.error(err) + } + + def apply(events: Seq[TestReport]): SuiteReport = + new SuiteReport { + val result = SuiteResult(events) + val detail = events + val errorCause = None } } +abstract class TestReport { + def stdout : String + def detail : TEvent + def result : TestResult.Value +} +object TestReport { + + def apply(out: String, event: TEvent) : TestReport = + new TestReport { + val stdout = out + val detail = event + val result = toTestResult(event) + } + + private[sbt] def toTestResult(event: TEvent) : TestResult.Value = { + event.status() match { + case TStatus.Error => TestResult.Error + case TStatus.Failure => TestResult.Failed + case _ => TestResult.Passed + } + } +} + object TestLogger { @deprecated("Doesn't provide for underlying resources to be released.", "0.13.1") @@ -117,16 +173,12 @@ class TestLogger(val logging: TestLogging) extends TestsListener { import logging.{global => log, logTest} - def startGroup(name: String) {} - def testEvent(event: TestEvent): Unit = {} - def endGroup(name: String, t: Throwable) + override def endSuite(name: String, suite: SuiteReport) { - log.trace(t) - log.error("Could not run test " + name + ": " + t.toString) + for( error <- suite.errorCause ) { + log.trace(error) + log.error("Could not run test " + name + ": " + error.toString) + } } - def endGroup(name: String, result: TestResult.Value) {} - def doInit {} - /** called once, at end of test group. */ - def doComplete(finalResult: TestResult.Value): Unit = {} override def contentLogger(test: TestDefinition): Option[ContentLogger] = Some(logTest(test)) } diff --git a/testing/src/main/scala/sbt/TestStatusReporter.scala b/testing/src/main/scala/sbt/TestStatusReporter.scala index bab1d4b71..72567b850 100644 --- a/testing/src/main/scala/sbt/TestStatusReporter.scala +++ b/testing/src/main/scala/sbt/TestStatusReporter.scala @@ -12,15 +12,13 @@ private[sbt] class TestStatusReporter(f: File) extends TestsListener { private lazy val succeeded = TestStatus.read(f) - def doInit {} - def startGroup(name: String) { succeeded remove name } - def testEvent(event: TestEvent) {} - def endGroup(name: String, t: Throwable) {} - def endGroup(name: String, result: TestResult.Value) { - if(result == TestResult.Passed) + override def startSuite(name: String) { succeeded remove name } + override def endSuite(name: String, suite: SuiteReport) { + if(suite.result.result == TestResult.Passed) succeeded(name) = System.currentTimeMillis } - def doComplete(finalResult: TestResult.Value) { + + override def doComplete(finalResult: TestResult.Value) { TestStatus.write(succeeded, "Successful Tests", f) } }