Suspecting a bug in org.scalatest.concurrent.AsynchronousAssertions.Waiter. The code below fails pretty reliably. There seems to be a window of vulnerability in awaitImpl(): if the last (or last few) dismiss() calls happen after the dismissals count test at the top of the while() loop, but the associated notifyAll() invocations happen before the…

WaiterSpec.scala

package scratch

// scalatest 2.0.M8

import org.scalatest.WordSpec
import org.scalatest.matchers.ShouldMatchers
import org.scalatest.concurrent.AsyncAssertions
import org.scalatest.time.{ Span, Millis }

class WaiterSpec extends WordSpec with ShouldMatchers with AsyncAssertions {
  "A Waiter instance" should {
    "not break when beaten on" in {
      val n = 100000
      val w = new Waiter
      new Thread(new Runnable {
        override def run(): Unit = {
          var i = 0
          while (i < n) { w.dismiss(); i += 1 }
          println(s"i=$i")
        }
      }).start
      w.await(timeout(Span(2000, Millis)), dismissals(n))
    }
  }
}

Here's what I think is happening:

// from Waiter.awaitImpl

while (dismissedCount < dismissals && !timedOut && thrown.isEmpty) {

// -> other thread calls dismiss() for the last time here in this window:
// increments dismissedCount, acquires lock, invokes notifyAll()  and releases lock
  val timeLeft: Span = {
     val diff = endTime - System.nanoTime
     if (diff > 0) Span(diff, Nanoseconds) else Span.ZeroLength
   }
  // -> lock is acquired and wait() is entered, but notifyAll() signal from dismissedCount is missed.
  synchronized {
     wait(timeLeft.millisPart, timeLeft.nanosPart)
   }
}
dismissedCount = 0 // reset the dismissed count to support multiple await calls
if (thrown.isDefined)
  throw thrown.get
else if (timedOut)
  throw new TestFailedException(Resources("awaitTimedOut"), 2)

Since we have no more dismissals, the wait() condition times out. Now we loop back to the while condition, it evaluates false (because dismissedCount == dismissals), but when we fall through, first thing we do is zero out dismissedCount, and the rest of the condition checks come up with "timedOut" as the cause of failure.

I have a fix which involves moving the synchronized block to encompass the while condition, and more carefully checking the exit conditions on the way out. Seems to work but still testing it. Not a wizard at this github thing, bear with me.

Hi Nick,

Thanks for investigating. I'll take a look at this later tonight, on the train ride home.

Bill

Having some trouble building scalatest on my machine. I hacked up a version with the patches below and compiled it outside of scalatest in a different package, and it passes the WaiterSpec posted above, and works great for testing my code.

I pushed it to my fork of the scalatest repo in the waiter-race-fix2 branch, if you want to look at the whole file. Obviously won't do a pull request until I get scalatest building ok.

Reference: Java Concurrency in Practice, chapter 14, first few sections.

diff --git a/src/main/scala/org/scalatest/concurrent/AsyncAssertions.scala b/src/main/scala/org/scalatest/concurrent/AsyncAssertions.scala
index c2c420d..b2eedc2 100644
--- a/src/main/scala/org/scalatest/concurrent/AsyncAssertions.scala
+++ b/src/main/scala/org/scalatest/concurrent/AsyncAssertions.scala
@@ -303,11 +303,23 @@ trait AsyncAssertions extends PatienceConfiguration {

     private final val creatingThread = Thread.currentThread

-    @volatile private var dismissedCount = 0
-    @volatile private var thrown: Option[Throwable] = None
+    /*
+     * @volatile is not sufficient to ensure atomic compare and set, or increment.
+     * Given that the code which modifies these variables should be synchronized anyway
+     * (because these variables are used in the wait condition predicate), 
+     * the @volatile is superfluous. 
+     */
+    /* @volatile */ private var dismissedCount = 0
+    /* @volatile */ private var thrown: Option[Throwable] = None

     private def setThrownIfEmpty(t: Throwable) {
-      synchronized {      // Why is this synchronized?
+      /*
+       * synchronized to serialize access to `thrown` which is used in the wait condition, 
+       * and to ensure the compare and set is atomic.
+       * (Arguably, a race condition on setting `thrown` is harmless, but synchronization makes
+       * the class easier to reason about.)
+       */
+      synchronized {
         if (thrown.isEmpty) thrown = Some(t)
       }
     }
@@ -330,12 +342,12 @@ trait AsyncAssertions extends PatienceConfiguration {
     def apply(fun: => Unit) {
       try {
         fun
-      }
-      catch { // Exceptions after the first are swallowed (need to get to dismissals later)
-        case t: Throwable => setThrownIfEmpty(t)
-        synchronized {
-          notifyAll()
-        }
+      } catch { // Exceptions after the first are swallowed (need to get to dismissals later)
+        case t: Throwable =>
+          setThrownIfEmpty(t)
+          synchronized {
+            notifyAll()
+          }
       }
     }

@@ -362,25 +374,30 @@ trait AsyncAssertions extends PatienceConfiguration {
      */
     private def awaitImpl(timeout: Span, dismissals: Int = 1) {
       if (Thread.currentThread != creatingThread)
-        throw new NotAllowedException(Resources("awaitMustBeCalledOnCreatingThread"), 2)
+        throw new NotAllowedException(Resources("awaitMustBeCalledOnCreatingThread", 2)

       val startTime: Long = System.nanoTime
       val endTime: Long = startTime + timeout.totalNanos
       def timedOut: Boolean = endTime < System.nanoTime
-      while (dismissedCount < dismissals && !timedOut && thrown.isEmpty) {
-        val timeLeft: Span = {
-          val diff = endTime - System.nanoTime
-          if (diff > 0) Span(diff, Nanoseconds) else Span.ZeroLength
-        }
-        synchronized {
+      synchronized {
+        while (dismissedCount < dismissals && !timedOut && thrown.isEmpty) {
+          val timeLeft: Span = {
+            val diff = endTime - System.nanoTime
+            if (diff > 0) Span(diff, Nanoseconds) else Span.ZeroLength
+          }
           wait(timeLeft.millisPart, timeLeft.nanosPart)
         }
       }
-      dismissedCount = 0 // reset the dismissed count to support multiple await calls
+      // it should never be the case that we get all the expected dismissals and still throw 
+      // a timeout failure - clients trying to debug code would find that very surprising.
+      // Calls to timedOut subsequent to while loop exit constitute a kind of "double jepardy".
       if (thrown.isDefined)
         throw thrown.get
+      else if (dismissedCount == dismissals)
+        dismissedCount = 0 // reset the dismissed count to support multiple await calls        

Sorry it took me a while to get enough focused time to study this. I think your reasoning makes sense. Can you submit a pull request?

Also we have added instructions on building ScalaTest to the scalatest.org site and the github project. With the advent of Scala 2.10.3 it has become much easier (because of a memory-leak fix in the Scala compiler that affected ScalaTest badly). Previously I couldn't build it with sbt on my laptop with 8Gb (though I could with ant)! Now the sbt build works fine in much less memory, so I'd recommend using that instead of ant now. We also as of this morning made a tweak that enables ScalaTest to be built on JDK 7 as well as JDK6. The problem was that some Swing classes, which were raw in JDK6, were generified in JDK7. We had to use code gen to deal with that, but that was another thing that made ScalaTest hard to build.

Thanks.

Bill

Huzzah! Scalatest built and tests ran ok. Instructions were a big help. (Yeah I'd discovered the memory and JDK-7 issues.)

Now working on integrating my fix.

OK, pull request made. Happy to iterate if necessary.