Add a mode to reuse JVM for test execution #99

retronym · 2018-03-07T12:32:06Z

The cost of VM startup and JIT is the predominant reason that
partest --run is slow. We're much better of using one thread
on the main JVM to execute these tests.

This commit uses such a mode under a non-default option.

Unforked test execution requires some care:

we need to check the main JVM is started with the mandated
immutable System properties (e.g. file.encoding)
other test-specific system properties (e.g. partest.output)
need to be patched into the system property map before
each test is executed.
sys.exit calls need to be intercepted with a security manager
stdout / stderr need to be intercepted, both in the Java and
Scala console printing APIs.

Some tests need to be adapted, in particular those that assume
that java.class.path will contain the test classes.

Tests can also force usage of the legacy forked mode by adding
a .javaopts file with a dummy JVM option.

Also improve recording of test durations and flag slow tests in
console output.

The cost of VM startup and JIT is the predominant reason that `partest --run` is slow. We're much better of using one thread on the main JVM to execute these tests. This commit uses such a mode under a non-default option. Unforked test execution requires some care: - we need to check the main JVM is started with the mandated immutable System properties (e.g. file.encoding) - other test-specific system properties (e.g. partest.output) need to be patched into the system property map before each test is executed. - sys.exit calls need to be intercepted with a security manager - stdout / stderr need to be intercepted, both in the Java and Scala console printing APIs. Some tests need to be adapted, in particular those that assume that java.class.path will contain the test classes. Tests can also force usage of the legacy forked mode by adding a .javaopts file with a dummy JVM option. Also improve recording of test durations and flag slow tests in console output.

retronym · 2018-03-07T12:35:46Z

My branch of adapted/deleted tests is over in https://github.com/retronym/scala/tree/topic/partest-apace

With this version of partest, that now completes in 11.5 minutes.

retronym · 2018-03-07T12:37:43Z

Seems like JVM reuse is the main win. I've also been experimenting with "Global reuse" which I haven't got working yet, but only seems to offer another 1-2m speedup. I've parked that effort in my topic/global-reuse branch.

adriaanm

Just some small questions/nitpicks. Won't hold up the PR over those.

adriaanm · 2018-03-07T13:22:56Z

src/main/scala/scala/tools/partest/nest/StreamCapture.scala

+  def withExtraProperties[A](extra: Map[String, String])(action: => A): A = {
+    val saved = System.getProperties()
+    val modified = new java.util.Properties()
+    saved.stringPropertyNames().forEach((k) => modified.setProperty(k, saved.getProperty(k)))


val modified = saved.clone.asInstanceOf[java.util.Properties] modified.putAll(extra.asJava)

?

I've settled on modified.putAll(saved) to avoid the cast after cloning.

adriaanm · 2018-03-07T13:31:28Z

src/main/scala/scala/tools/partest/nest/StreamCapture.scala

+    val savedOut = System.out
+    val savedErr = System.err
+    try {
+      val charset = Charset.defaultCharset()


(Just wondering: how do we know System.out was set to a stream with the encoding returned by Charset.defaultCharset()? Does it matter? It doesn't look like we can recover the info anyway.)

At this point System.out will be the default, as the rest of partest hasn't messed with it.

But looking back at this code, I now realise that one other place in the partest is mutating System.{out,err}:

pushTranscript(args mkString " ") val captured = StreamCapture(runCommand(args, logFile)) if (captured.result) genPass() else { logFile appendAll captured.stderr genFail("java compilation failed") }

So we have a potential race condition if a Java compilation step happens concurrently with a non-forked test execution step.

That wrapping of Javac looks to be a no-op, we fork a process to start javac, so we should just rely on the ProcessLogger to redirect its output to a file. I'll add an assertion to that effect and test things out, and hopefully I'll be able to remove that use of StreamCapture.

Yep, we still get Javac compilation errors under --verbose without that StreamCapture. Pushed that change.

adriaanm · 2018-03-07T13:35:26Z

src/main/scala/scala/tools/partest/nest/Stopwatch.scala

+    base = Some(System.nanoTime())
+  }
+
+  def stop(): Long = {


let's add a quick comment to document the unit

dwijnand · 2018-03-07T14:01:38Z

nice!

supposedly installing a SecurityManager incurs "substantial filesystem performance penalty" (https://github.com/sbt/sbt/blob/v1.1.1/run/src/main/scala/sbt/TrapExit.scala#L425-L432). did you try either using those overrides? alternatively maybe trapping exit can be opt-in by the (I presume) few partests that use sys.exit?

(edit: more details in the associated PR sbt/sbt#1153)

- Comment for Stopwatch - Delete commented out debug code - Refactor properties save/restore - DRY up console scraping

retronym · 2018-03-07T23:18:18Z

supposedly installing a SecurityManager incurs "substantial filesystem performance penalty"

I'm not using the default implementations of checkRead etc, but rather using:

class DelegatingSecurityManager(delegate: SecurityManager) extends SecurityManager {
  ...
  override def checkExec(cmd: String): Unit = if (delegate ne null) delegate.checkExec(cmd)
  override def checkWrite(file: String): Unit = if (delegate ne null) delegate.checkWrite(file)
  override def checkDelete(file: String): Unit = if (delegate ne null) delegate.checkDelete(file)
  override def checkRead(file: String): Unit = if (delegate ne null) delegate.checkRead(file)
  override def checkRead(file: String, context: scala.Any): Unit = if (delegate ne null) delegate.checkRead(file, context)

delegate is null in our case, so we don't have the performance penalty of SecurityMangager.{checkRead, ... } creating Permissions and computing canonical file paths.

We fork a process with a process logger that redirects stdout and stderr to a log file, so I can't see why this was ever needed. Tested: ``` Note: test execution will be non-parallel under -Dpartest.exec.in.process % scalac t1459/InheritingPrinter.scala t1459/JavaPrinter.java t1459/ScalaPrinter.scala t1459/Test.java t1459/VarArg.java !! 1 - run/t1459 [compilation failed] % scalac t1459/InheritingPrinter.scala t1459/JavaPrinter.java t1459/ScalaPrinter.scala t1459/Test.java t1459/VarArg.java JavaPrinter.java:1: error: illegal start of type declaration public cla ss JavaPrinter implements VarArg { ^ one error found partest --update-check \ /Users/jz/code/scala/test/files/run/t1459 ```

Add a mode to reuse JVM for test execution

som-snytt · 2018-05-31T22:45:42Z

src/main/scala/scala/tools/partest/nest/Runner.scala

-    val captured = StreamCapture(runCommand(args, logFile))
-    if (captured.result) genPass() else {
-      logFile appendAll captured.stderr
+    if (runCommand(args, logFile)) genPass() else {


To answer the question in the commit message: there were two tickets, on the first someone comments that process #> doesn't do stderr. So StreamCapture came first. The proper fix using process logger came second.

That was exactly five years ago this past US Memorial Day weekend.

I said: In about five years, paulp will levy a commit, "Remove commented code from 2013." I still can't believe it's 2013. It is 2013, right?

You said: I don't recall having to enter 2-0-1-3 on a form this year. Usually I write down the previous year the first few times; after that my brain comes to grips with the annus novus.

It turns out there is no coming to grips.

scala/bug#6289
scala/bug#7003
scala/scala#2591 (comment)

Thanks for the nostalgia trip :)

retronym requested a review from SethTisue March 7, 2018 12:33

retronym mentioned this pull request Mar 7, 2018

Speed up partest scala/scala#6391

Closed

adriaanm approved these changes Mar 7, 2018

View reviewed changes

Address review feedback

0e63ce5

- Comment for Stopwatch - Delete commented out debug code - Refactor properties save/restore - DRY up console scraping

retronym merged commit fbeb205 into scala:1.1.x Mar 7, 2018

SethTisue removed their request for review March 13, 2018 20:24

lrytz pushed a commit to lrytz/scala-partest that referenced this pull request May 9, 2018

Merge pull request scala#99 from retronym/ticket/75

2f0a510

Add a mode to reuse JVM for test execution

lrytz pushed a commit to lrytz/scala-partest that referenced this pull request May 9, 2018

Merge pull request scala#99 from retronym/ticket/75

f2ca192

Add a mode to reuse JVM for test execution

som-snytt reviewed May 31, 2018

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add a mode to reuse JVM for test execution #99

Add a mode to reuse JVM for test execution #99

retronym commented Mar 7, 2018

retronym commented Mar 7, 2018

retronym commented Mar 7, 2018

adriaanm left a comment

adriaanm Mar 7, 2018

retronym Mar 7, 2018

adriaanm Mar 7, 2018

retronym Mar 7, 2018

retronym Mar 7, 2018

adriaanm Mar 7, 2018

dwijnand commented Mar 7, 2018 •

edited

Loading

retronym commented Mar 7, 2018

som-snytt May 31, 2018

retronym Jun 1, 2018

Add a mode to reuse JVM for test execution #99

Add a mode to reuse JVM for test execution #99

Conversation

retronym commented Mar 7, 2018

retronym commented Mar 7, 2018

retronym commented Mar 7, 2018

adriaanm left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwijnand commented Mar 7, 2018 • edited Loading

retronym commented Mar 7, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwijnand commented Mar 7, 2018 •

edited

Loading