ScalaTest failing tests take ages to complete - any suggestions on how to diagnose what it's up to?

Hi,

We've got an odd problem when trying to execute ScalaTest's from within IntelliJ. When the tests are run and pass then everything works really well. But when the tests are run and something fails then we have to sit and wait about 5 minutes while IntelliJ becomes unresponsive and uses 100% CPU. Eventually it'll finish doing whatever it's doing and give the failing report.

Anyone able to give some clues as to what might be wrong? Or maybe a good approach to diagnosing what IntelliJ and/or the Scala plugin are up to in those extremely intensive 5 mins?

The only thing we can think of that's particularly weird about our project is its size. It's a huge project with a massive classpath. Would that cause issues?

This is a bit of a duplicate of Tong's post to the ScalaTest forum https://groups.google.com/forum/#!topic/scalatest-users/F4iLSb0PVoc but I'm pretty sure this is specific to the IntelliJ Scala plugin as it doesn't affect running ScalaTest from gradle or running ScalaTests in Eclipse.

Thanks,

Ralph.

6 comments
Comment actions Permalink

Let's take a look for threaddump of running tests process. It's hard to say what's going on without this information.

Best regards,
Alexander Podkhlayuzin.

0
Comment actions Permalink

Hi Alexander,

I've attached a dump for every minute. The timeline is as follows:

  • 00:00 start tests, test progress bar is red to indicate failure, IntelliJ takes max CPU and becomes unresponsive
  • 03:40 the CPU goes back to idle, IntelliJ stays unresponsive
  • 04:45 a stacktrace of the test failure is printed to the console, IntelliJ stays unresponsive, CPU goes back to the max
  • 07:10 CPU goes kind of back to normal, spiking occasionally, IntelliJ stays unresponsive
  • 08:55 DONE!!! :-)))))


It's worth noting that if the test passes everything is pretty quick and responsive, so it's something about having a failing test.

Thanks for any help,

Ralph.

P.S. Here's a redacted copy/paste of the console output after the IDE has become responsive again:

/[...]/jdk/1.7.0_45/MacOSX64/bin/java -Didea.launcher.port=7534 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA 13.app/bin" -Dfile.encoding=UTF-8 -classpath "[lots and lots and lots and lots and lots and lots of jar files - too many to count in fact]" com.intellij.rt.execution.application.AppMain org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner -s [...] -showProgressMessages true -C org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestReporter
Testing started at 16:51 ...

[...] was not null
org.scalatest.exceptions.TestFailedException: [...] was not null
    at org.scalatest.MatchersHelper$.newTestFailedException(MatchersHelper.scala:160)
    at org.scalatest.Matchers$ShouldMethodHelper$.shouldMatcher(Matchers.scala:5518)
    at org.scalatest.Matchers$AnyShouldWrapper.should(Matchers.scala:5552)
    at [...]
    at [...]
    at [...]
    at org.scalatest.Transformer$$anonfun$apply$1.apply(Transformer.scala:22)
    at org.scalatest.Transformer$$anonfun$apply$1.apply(Transformer.scala:22)
    at org.scalatest.OutcomeOf$class.outcomeOf(OutcomeOf.scala:86)
    at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:106)
    at org.scalatest.Transformer.apply(Transformer.scala:22)
    at org.scalatest.Transformer.apply(Transformer.scala:20)
    at org.scalatest.WordSpecLike$$anon$1.apply(WordSpecLike.scala:920)
    at org.scalatest.Suite$class.withFixture(Suite.scala:1105)
    at org.scalatest.WordSpec.withFixture(WordSpec.scala:1694)
    at org.scalatest.WordSpecLike$class.invokeWithFixture$1(WordSpecLike.scala:917)
    at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:929)
    at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:929)
    at org.scalatest.SuperEngine.runTestImpl(Engine.scala:234)
    at org.scalatest.WordSpecLike$class.runTest(WordSpecLike.scala:929)
    at [...]
    at [...]
    at [...]
    at org.scalatest.BeforeAndAfter$class.runTest(BeforeAndAfter.scala:200)
    at [...]
    at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:988)
    at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:988)
    at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:333)
    at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:321)
    at scala.collection.immutable.List.foreach(List.scala:318)
    at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:321)
    at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:310)
    at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:341)
    at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:321)
    at scala.collection.immutable.List.foreach(List.scala:318)
    at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:321)
    at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:316)
    at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:397)
    at org.scalatest.WordSpecLike$class.runTests(WordSpecLike.scala:988)
    at org.scalatest.WordSpec.runTests(WordSpec.scala:1694)
    at org.scalatest.Suite$class.run(Suite.scala:1419)
    at org.scalatest.WordSpec.org$scalatest$WordSpecLike$$super$run(WordSpec.scala:1694)
    at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1034)
    at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1034)
    at org.scalatest.SuperEngine.runImpl(Engine.scala:433)
    at org.scalatest.WordSpecLike$class.run(WordSpecLike.scala:1034)
    at [...]
    at [...]
    at [...]
    at org.scalatest.BeforeAndAfter$class.run(BeforeAndAfter.scala:241)
    at [...]
    at org.scalatest.tools.SuiteRunner.run(SuiteRunner.scala:55)
    at org.scalatest.tools.Runner$$anonfun$doRunRunRunDaDoRunRun$3.apply(Runner.scala:2445)
    at org.scalatest.tools.Runner$$anonfun$doRunRunRunDaDoRunRun$3.apply(Runner.scala:2439)
    at scala.collection.immutable.List.foreach(List.scala:318)
    at org.scalatest.tools.Runner$.doRunRunRunDaDoRunRun(Runner.scala:2439)
    at org.scalatest.tools.Runner$$anonfun$runOptionallyWithPassFailReporter$2.apply(Runner.scala:1007)
    at org.scalatest.tools.Runner$$anonfun$runOptionallyWithPassFailReporter$2.apply(Runner.scala:1006)
    at org.scalatest.tools.Runner$.withClassLoaderAndDispatchReporter(Runner.scala:2573)
    at org.scalatest.tools.Runner$.runOptionallyWithPassFailReporter(Runner.scala:1006)
    at org.scalatest.tools.Runner$.run(Runner.scala:839)
    at org.scalatest.tools.Runner.run(Runner.scala)
    at org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner.runScalaTest2(ScalaTestRunner.java:144)
    at org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner.main(ScalaTestRunner.java:35)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)

Given [...]
Then [...]

Process finished with exit code 0



Attachment(s):
dumps.tar.gz
0
Comment actions Permalink

I found problem and just fixed it: https://github.com/JetBrains/intellij-scala/commit/1a7ef03ea46045af5b718d3cf0f8328a1bf1dc16

As for older plugin versions there are workaround: add sources to all your dependencies if it's possible, otherwise search for them will be slow (and unsuccessful).

Best regards,
Alexander Podkhalyuzin.

0
Comment actions Permalink

Hi Alexander,

Thanks for the update, that's great! I'll build the latest snapshot and see if it sorts things out for us.

Ralph.

0
Comment actions Permalink

Hi Alexander,

A few of us have tried the latest plugin release. Things are much improved now, thanks loads for that!

However! ;-) - It still takes 10 seconds or so after a failing test has completed which feels a bit sluggish, especially when the passing tests are practically instant. I take it we can improve things further by fixing the source attachments as per your previous message?

Thanks,

Ralph.

0
Comment actions Permalink

Problem is to find related source, which is located in wrong directory (not according to packages). Problem is that we can't distinguish case for invalid sources and missing sources. Probably I can add special setting for this case (do not search invalid sources, until user will enable this setting). Ok, I'll do that, not so critical, so it will not be backported to 13.0.2 and will not be released soon.

Best regards,
Alexander Podkhalyuzin.

0

Please sign in to leave a comment.