scalatest / scalatest

A testing tool for Scala and Java developers
Apache License 2.0
1.15k stars 336 forks source link

"Reporter completed abruptly with exception after receiving event" #556

Open alexeyr opened 9 years ago

alexeyr commented 9 years ago

Sometimes I get a lot of exceptions from ScalaTest which look like this:

Reporter completed abruptly with an exception after receiving event: SuiteCompleted(Ordinal(0, 292),
CxxShptrLmsMmmItTests,scalan.compilation.lms.cxx.sharedptr.CxxShptrLmsMmmItTests,Some(scalan.compila
tion.lms.cxx.sharedptr.CxxShptrLmsMmmItTests),Some(230),Some(MotionToSuppress),Some(TopOfClass(scala
n.compilation.lms.cxx.sharedptr.CxxShptrLmsMmmItTests)),None,None,pool-1-thread-1,1429601879789).
java.net.SocketException: Software caused connection abort: socket write error
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
        at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1876)
        at java.io.ObjectOutputStream$BlockDataOutputStream.writeByte(ObjectOutputStream.java:1914)
        at java.io.ObjectOutputStream.writeFatalException(ObjectOutputStream.java:1575)
        at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:350)
        at org.scalatest.tools.SocketReporter.apply(SocketReporter.scala:31)
        at org.scalatest.DispatchReporter$Propagator$$anonfun$run$1.apply(DispatchReporter.scala:240
)
        at org.scalatest.DispatchReporter$Propagator$$anonfun$run$1.apply(DispatchReporter.scala:239
)
        at scala.collection.immutable.List.foreach(List.scala:318)
        at org.scalatest.DispatchReporter$Propagator.run(DispatchReporter.scala:239)
        at java.lang.Thread.run(Thread.java:745)

with events including TestSucceeded, SuiteStarting, etc. Unfortunately, I don't have a simple way to reproduce it.

jawshooah commented 9 years ago

:+1: Having the same issue with ScalaTest+Play.

ScalaTest+Play 1.2.0 Play 2.3.7 Scala 2.11.4 SBT 0.13.5.

margussipria commented 8 years ago

Having the same issue with ScalaTest+Play.

Scala Test 2.2.5 ScalaTest + Play 1.4.0-M3 Play 2.4.3 Scala 2.11.7 SBT 0.13.9

This starts happening for every test after first failure in test... errors do not have impact on results of tests.

alexeyr commented 8 years ago

For us, Play isn't involved.

margussipria commented 8 years ago

I managed to reproduce this bug with 21 line of code.

Code that can be run to reproduce it can be found here: https://github.com/margussipria/scalatest-bug-556

At least ScalaTest + Play 1.4.0-M3 was not needed, but when I added .enablePlugins(PlayScala) to build.sbt configuration and moved test file to test/TestSpec.scala bug triggers. Removing plugin and and moving test class to src/test/scala "Fixes" bug.

Maybe some other sbt configuration option also affects ScalaTest.

margussipria commented 8 years ago

I could not leave this alone, and managed to get this bug reproduced without Play Framework, throwing certain kind of exception when using fork in Test := true, exception isn't handled correctly? Next it would help to throw that exception without play-json

(new commit in example)

margussipria commented 8 years ago

When test throws exception that following signature case class TestException(value: Seq[JsPath]) extends Throwable exception isn't catched correctly. JsPath can be some case class. When I tried without Seq, just JsPath or with Seq[String], exception was thrown and catched correctly.

peterbecich commented 8 years ago

@margussipria , I have a similar problem caused by fork mode.

Was able to fix it with the advice here, disable forked mode: https://groups.google.com/forum/#!topic/scalatest-users/rMyTDxVL9Gc

Forked mode is necessary though for the Http4s Blaze server running in this subproject. The Blaze server does not shut down gracefully with a Control-C if forked mode is disabled.

Next I will try to enable forked mode for the run SBT task and disable forked mode for the test SBT task.

Reporter completed abruptly with an exception after receiving event: TestStarting(Ordinal(0, 21),SimpleUserCommandsSpec, ... ,None,pool-1-thread-1-ScalaTest-running-SimpleUserCommandsSpec,1454378551225).
java.net.SocketException: Broken pipe
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
    at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1877)
    at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1786)
    at java.io.ObjectOutputStream.writeNonProxyDesc(ObjectOutputStream.java:1286)
    at java.io.ObjectOutputStream.writeClassDesc(ObjectOutputStream.java:1231)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1427)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1178)
    at java.io.ObjectOutputStream.writeFatalException(ObjectOutputStream.java:1577)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:351)
    at org.scalatest.tools.SocketReporter.apply(SocketReporter.scala:31)
    at org.scalatest.DispatchReporter$Propagator$$anonfun$run$1.apply(DispatchReporter.scala:240)
    at org.scalatest.DispatchReporter$Propagator$$anonfun$run$1.apply(DispatchReporter.scala:239)
    at scala.collection.immutable.List.foreach(List.scala:381)
    at org.scalatest.DispatchReporter$Propagator.run(DispatchReporter.scala:239)
    at java.lang.Thread.run(Thread.java:745)
LuboVarga commented 8 years ago

I have encountered this problem, but only when running tests in parallel (-P parameter). I have about 60 tests in few suites with very different run times (one test runs for 40 seconds, other just a millisecond). I suspect finishing suites out of order is problem.

LuboVarga commented 8 years ago

Ehm, I probably see issue, in case that suites are runed in parallel: html reporter, around line 1000:

case SuiteCompleted(ordinal, suiteName, suiteId, suiteClassName, duration, formatter, location, rerunner, payload, threadName, timeStamp) =>
        val (suiteEvents, otherEvents) = extractSuiteEvents(suiteId)
        eventList = otherEvents //overwriting possible events from other suites!

While extractSuiteEvents extracts things from eventList, which is than replaced in SuiteCompleted, potentionaly replacing events from other suites.

Solution would be imho to store eventList in hashmap with suite name as a key and original eventListinstance as a list. Also there should be proper thread safe implementation of that collections.

dzhagr commented 8 years ago

In our case the issue was that the exception thrown from the test was non de-serializable. Basically, at the line

https://github.com/scalatest/scalatest/blob/3.1.x/scalatest/src/main/scala/org/scalatest/tools/Framework.scala#L798

the server part of the framework fails and closes later the server socket. That's why the client side of the test framework runs into the "java.net.SocketException: Broken pipe". In my opinion, it would be good either not to fail in a way the whole framework is broken or at least notify the client side of the application that it can't handle the requests anymore before closing the socket here:

https://github.com/scalatest/scalatest/blob/3.1.x/scalatest/src/main/scala/org/scalatest/tools/Framework.scala#L790.

softinio commented 7 years ago

I got this error with scalatest 3.0.1 when I switched to 3.0.0 i no longer get the error.

Reeebuuk commented 7 years ago

This fixed my issues: .settings(parallelExecution in Test := false) .settings(fork in Test := false)

margussipria commented 7 years ago

For my test case above, upgrading from 2.2.5 to 2.2.6, exception still happened, but using ScalaTest 3.0.[0, 1, 2, 3] exception was gone. There isn't also any issue if I toggle with fork or parallelExecution values.

virusdave commented 6 years ago

Any update on this? Happens a LOT when we parallelize tests, and is really annoying.

LuboVarga commented 6 years ago

There is simple problem, which I have solved by simply introducing abstract "parallel reporter". This one:

package sk.nike.tests.scalatest

import org.scalatest.ResourcefulReporter
import org.scalatest.events.{Event, RunCompleted}

import scala.collection.mutable

/**
  * ScalaTest reporter which will take events generated from parallel test run and apply them through #applySequentially
  * method to real implementation of this abstract class.
  */
abstract class ParallelReporter extends ResourcefulReporter {
  val events: mutable.MutableList[Event] = mutable.MutableList()

  override def apply(event: Event): Unit = {
    events += event
    event match {
      case _: RunCompleted =>
        events.sortBy(_.ordinal).foreach(
          e => {
            applySequentially(e)
          }
        )
        events.clear()
      case _ => {}
    }
  }

  def applySequentially(event: Event): Unit

  override def dispose(): Unit = {} //f.close()
}

And than make original reporter use it...

Problem cause is simple. Given reporter HtmlReporter is not able to receive event out of order. It needs to get events one by one, sequentially from one test after another one.

folex commented 6 years ago

@LuboVarga Hi! Can you please elaborate on make original reporter use it? I'm using default reporter, how do I apply your solution without modifying ScalaTest? Thanks in advance

cheeseng commented 6 years ago

I think we can see there are 2 causes of the problem at least:

  1. Non-serializable payload being carried in the Event's payload field.
  2. Out of order events being sent to HtmlReporter.

We talked about 1. before to make the payload field in Event Serializable, which is breaking change so it probably won't go into 3.0.x branch. If the cause is 1. the workaround for 3.0.x currently would be to make sure the payload you're attaching in your event is Serializable.

As for 2., we actually made Framework to use SuiteSortingReporter some time back (https://github.com/scalatest/scalatest/commit/5d646f242df9fadec9a1a48dd385d8b51c116c65#diff-5bb0da5e4d090e5e4d4dfbc9f216279d) to make the events are sent in order, but the problem is that the default timeout is 2 seconds, in which when the timeout occurs SuiteSortingReporter will just sending out the events out of order. If this is the cause of your problem, you can try -T [seconds] to increase the timeout.

Hope it helps.

@bvenners perhaps we shall consider to increase the default 2 seconds timeout too? The theoritical reason is that in the parallel execution and/or fork execution the cpu can get too busy to be responsive within 2 seconds, and in CI environment also it is common to have slower execution also.

virusdave commented 6 years ago

you can try -T [seconds] to increase the timeout.

I'm afraid i don't understand this suggestion.

In our case the cause is almost certainly (2), because it happens when we massively increase the parallelism of tests.

I'm happy to dramatically increase the timeout (and 2 seconds is almost certainly WAY too short for this in our case) but i don't understand what you mean here.

LuboVarga commented 6 years ago

What does SuiteSortingReporter do? From @cheeseng comment it seems that it waits 2 seconds (by default) and reorders messages from reporter. If so, it is way too short also for our case. Some of our test suites does have "timeout" as part of their names and they can run for tens of seconds. There is great chance to finish some other (tests are run in parallel) tests while some of "timeout" test is being run. HtmlReporter is not able to handle two test starts (or two test end; I do not remember the case) events one after one.

@folex this part should explain how we use it: We have copied HtmlReporter sources to NikeHtmlReporter and make it extends ParallelReporter (source code in comment a bit above). It now does wait till RunCompleted event and just after it passes things to reporter itself. There is some lag introduced to generate report, but it is just a fraction of test run time.

If someone wants, just add ParallelReporter to scalatest sources and make HtmlReporter extends it. It should fix given problem.

cheeseng commented 6 years ago

@virusdave The -T I meant was argument that you can pass to ScalaTest (through testOptions in sbt), but unfortunately, I just checked the source of Framework.scala and it seems that it is currently not supported in sbt:

https://github.com/scalatest/scalatest/blob/3.0.x/scalatest/src/main/scala/org/scalatest/tools/Framework.scala#L956

imho that's wrong, I'll try to discuss with @bvenners to see if we can fix it in the upcoming 3.0.7 release.

folex commented 6 years ago

@cheeseng it would also be very nice to have an option to override System.err as an output for all errors in ScalaTest, so I could just disable all internal error logging. Currently afaik it is strongly hardcoded in several places.

olafurpg commented 6 years ago

I'm encountering this exception as well and the stack trace points to

Caused by: java.io.NotSerializableException: org.scalatest.Engine

Could this error be fixed by adding extends Serializable to org.scalatest.SuperEngine? https://github.com/scalatest/scalatest/blob/57151f83937a4adb23d402efecfe76d4c96c73ac/scalatest/src/main/scala/org/scalatest/Engine.scala#L40

DavidPerezIngeniero commented 3 years ago

I got this error with scalatest 3.0.1 when I switched to 3.0.0 i no longer get the error.

In my case with forking and ScalaTest 3.2.2 it fails.

DavidPerezIngeniero commented 3 years ago

Since I'm using Docker to run SBT, I'm experiencing this problem with Java 11, ScalaTest 3.2.2, SBT 1.4.6. I need a forked JVM. Any workaround?

DavidPerezIngeniero commented 3 years ago

Upgraded to ScalaTest 3.2.5 (the latest one) and the problem isn't solved. :-(

bvenners commented 3 years ago

@DavidPerezIngeniero I wonder if you can share more details about the error, such as the stack trace or portions thereof that are not proprietary.

DavidPerezIngeniero commented 3 years ago

I've found the cause:

testForkedParallel = true

So, the only way of getting parallelism is not to use fork.

bvenners commented 3 years ago

@DavidPerezIngeniero That helps. We will try and reproduce it using that.

DavidPerezIngeniero commented 3 years ago

It starts ok, but after a few minutes, the stacktrace of "Reporter completed abruptly with...." appears continually.

DavidPerezIngeniero commented 3 years ago

Sorry for the delay. Here you have a more complete stack trace.

Reporter completed abruptly with an exception after receiving event: TestFailed(Ordinal(0, 2194),No se ha encontrado la consulta List() para la entidad 601031 en el área ma_prc_test,EntityDataQueriesTypesSpec,fcc.vision.modelo.entitydata.EntityDataQueriesTypesSpec,Some(fcc.vision.modelo.entitydata.EntityDataQueriesTypesSpec),TipoBooleano lee un campo TipoBooleano de una columna de tipo BOOLEAN (true),lee un campo TipoBooleano de una columna de tipo BOOLEAN (true),Vector(),Vector(),Some(fcc.vision.errores.QueryNotFound: No se ha encontrado la consulta List() para la entidad 601031 en el área ma_prc_test),Some(6351),Some(IndentedText(- lee un campo TipoBooleano de una columna de tipo BOOLEAN (true),lee un campo TipoBooleano de una columna de tipo BOOLEAN (true),1)),Some(SeeStackDepthException),Some(fcc.vision.modelo.entitydata.EntityDataQueriesTypesSpec),None,pool-1-thread-8-ScalaTest-running-EntityDataQueriesTypesSpec,1613404420078).
java.net.SocketException: Broken pipe (Write failed)
    at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
    at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
    at java.base/java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1883)
    at java.base/java.io.ObjectOutputStream$BlockDataOutputStream.writeByte(ObjectOutputStream.java:1921)
    at java.base/java.io.ObjectOutputStream.writeFatalException(ObjectOutputStream.java:1582)
    at java.base/java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:352)
    at org.scalatest.tools.SocketReporter.apply(SocketReporter.scala:31)
    at org.scalatest.DispatchReporter$Propagator.$anonfun$run$10(DispatchReporter.scala:249)
    at org.scalatest.DispatchReporter$Propagator.$anonfun$run$10$adapted(DispatchReporter.scala:248)
    at scala.collection.immutable.List.foreach(List.scala:392)
    at org.scalatest.DispatchReporter$Propagator.run(DispatchReporter.scala:248)
    at java.base/java.lang.Thread.run(Thread.java:834)
gmarti commented 3 years ago

Same issue here.

If i disable the fork... i get no output at all (green/red message from the tests are gone)

only the resume at the end that says my test has failed

DavidPerezIngeniero commented 3 years ago

Confirmed, when ScalaTest receives a non-serializable Exception, this error happens. One solution is to edit all the tests we have (a lot of work, because we have thousands). Is there any hook that can conver a non-serializable exception into a serializable one?

hsn10 commented 3 years ago

Still problem in 3.1.4

hsn10 commented 3 years ago

@DavidPerezIngeniero This looks like some internal event generated by framework. What should be serializable in my own code and is not?

Reporter completed abruptly with an exception after receiving event: RunCompleted(Ordinal(0, 143),Some(30508),Some(Summary(44,1,0,0,0,10,0,0)),None,None,None,main,1619691923993).
java.net.SocketException: Software caused connection abort: socket write error
        at java.net.SocketOutputStream.socketWrite0(Native Method)
DavidPerezIngeniero commented 2 years ago

After more than 6 years, any plan on solving this?

cheeseng commented 2 years ago

@DavidPerezIngeniero @hsn10 I am relooking this to see if there's anything I can improve, we didn't find a good solution for this last time, but perhaps this time we may find one. The issue I can see so far coming from ScalaTest events carrying non-serializable Exception or payload, perhaps when that happen we can try to wrap the Exception or the payload and make it clear to the user the class name of the Exception/payload that has serialization issue.

DavidPerezIngeniero commented 2 years ago

Your idea seems good to me. If an exception isn't serializable, the important data that should be preserved is the class name, the message and the stack trace. In the case of PyException (Jython), the toString() method contains clue information.

DavidPerezIngeniero commented 1 year ago

Any workaround to this nasty bug?

hsn10 commented 1 year ago

@cheeseng I don't use scala anymore, you don't have to fix anything for me.

DavidPerezIngeniero commented 1 year ago

Let's see if the SBT folks can do anything: https://github.com/sbt/sbt/issues/7216