Deadlock with ScalaCheck 1.13.x, scalaz-concurrent, and Scala 2.12.0-RC2 #290

Closed
larsrh opened this Issue Oct 29, 2016 · 30 comments

Projects

None yet

6 participants

@larsrh
larsrh commented Oct 29, 2016

After trying to port remotely to Scala 2.12.x, I found that some of the tests involving scala.concurrent.Future weren't terminating. The most likely cause is a deadlock. The issue doesn't appear in Scala 2.10.x or 2.11.x, and also not when running ScalaCheck properties through ScalaTest. It only manifests when using the plain ScalaCheck runner and 2.12.0-RC2.

A small reproduction project, including instructions, can be found here.

As of now I'm unsure whether this is a problem with scalaz.concurrent.Task, scala.concurrent.Future, or ScalaCheck (or a combination thereof). I'm opening this issue so that others who might have the same problem can find it.

@larsrh
larsrh commented Oct 29, 2016

Same result even with a different worker count:

> testOnly remotely.ResponseSpec -- -workers 2

deadlocks with w = 1 and 2

@viktorklang

Thread dump? (logical or actual deadlock?)

@mpilquist
Contributor

This throws after 10 second delay at object initialization time:

object ResponseSpec extends Properties("Response") {
  property("stack safety") = {
    import ExecutionContext.Implicits.global
    val f = Future(1)
    Await.result(f, 10.seconds) == 1
  }
}

Not sure if it's related or not but seems suspicious. JStack shows the same/similar stack trace as the hang in the original ResponseSpec:

"scala-execution-context-global-9" #9 daemon prio=5 os_prio=31 tid=0x00007fd89d435000 nid=0x4d03 in Object.wait() [0x0000700001149000]
   java.lang.Thread.State: RUNNABLE
        at remotely.ResponseSpec$$$Lambda$19/1836797772.apply$mcI$sp(Unknown Source)
        at scala.runtime.java8.JFunction0$mcI$sp.apply(JFunction0$mcI$sp.java:12)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:653)
        at scala.concurrent.Future$$$Lambda$21/1206883981.apply(Unknown Source)
        at scala.util.Success.$anonfun$map$1(Try.scala:251)
        at scala.util.Success.map(Try.scala:209)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:287)
        at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$22/1525037790.apply(Unknown Source)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:29)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
        at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$23/727001376.apply(Unknown Source)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
        at scala.concurrent.impl.ExecutionContextImpl$AdaptedForkJoinTask.exec(ExecutionContextImpl.scala:140)
        at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
        at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
        at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
        at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
@viktorklang

hmm, I don't understand. why is remotely in the stack trace if not in the
code?

Cheers,

On Oct 29, 2016 6:31 PM, "Michael Pilquist" notifications@github.com
wrote:

This throws after 10 second delay at object initialization time:

object ResponseSpec extends Properties("Response") {
property("stack safety") = {
import ExecutionContext.Implicits.global
val f = Future(1)
Await.result(f, 10.seconds) == 1
}
}

Not sure if it's related or not but seems suspicious. JStack shows the
same/similar stack trace as the hang in the original ResponseSpec:

"scala-execution-context-global-9" #9 daemon prio=5 os_prio=31 tid=0x00007fd89d435000 nid=0x4d03 in Object.wait() [0x0000700001149000]
java.lang.Thread.State: RUNNABLE
at remotely.ResponseSpec$$$Lambda$19/1836797772.apply$mcI$sp(Unknown Source)
at scala.runtime.java8.JFunction0$mcI$sp.apply(JFunction0$mcI$sp.java:12)
at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:653)
at scala.concurrent.Future$$$Lambda$21/1206883981.apply(Unknown Source)
at scala.util.Success.$anonfun$map$1(Try.scala:251)
at scala.util.Success.map(Try.scala:209)
at scala.concurrent.Future.$anonfun$map$1(Future.scala:287)
at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$22/1525037790.apply(Unknown Source)
at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:29)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$23/727001376.apply(Unknown Source)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at scala.concurrent.impl.ExecutionContextImpl$AdaptedForkJoinTask.exec(ExecutionContextImpl.scala:140)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)


You are receiving this because you commented.
Reply to this email directly, view it on GitHub
#290 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAqdwW_W-euLVJZ66nW2i4Mxh-sW-5Eks5q43S-gaJpZM4KkEq9
.

@mpilquist
Contributor

@viktorklang Only because the test class is in the "remotely" package.

Here's a further simplification which shows the same hang in jstack:

package remotely

import org.scalacheck._
import scala.concurrent.{Await,ExecutionContext,Future}
import scala.concurrent.duration._
import scala.util.{Success,Failure}
import java.util.concurrent.Executors

object ResponseSpec extends Properties("Response") {
  property("stack safety") = {
    implicit val ec = ExecutionContext.fromExecutor(Executors.newCachedThreadPool())
    Await.result(Future(1), 1000.seconds) == 1
  }
}

I think what's happening here is that when we run the tests via ScalaCheck, the properties are being instantiated as part of object initialization of ResponseSpec. However, we have a separate thread calling back in to ResponseSpec from the thread pool, and it looks like that thread spin-waits on ResponseSpec object initialization to complete (or otherwise blocks in a way that's not visible to JVM).

So overall, I don't think this is a bug, just an undesirable result of running futures from an object initializer.

@mpilquist
Contributor
mpilquist commented Oct 29, 2016 edited

One more simplification -- same hang here:

object Foo {
  import ExecutionContext.Implicits.global
  val x = Await.result(Future(1), 1000.seconds)
  def main(args: Array[String]) = println(x)
}

Dump:

2016-10-29 12:56:19
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.102-b14 mixed mode):

"Attach Listener" #10 daemon prio=9 os_prio=31 tid=0x00007fcc6c19b000 nid=0x360b waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"pool-1-thread-1" #9 prio=5 os_prio=31 tid=0x00007fcc6a58c000 nid=0x4d03 in Object.wait() [0x0000700001149000]
   java.lang.Thread.State: RUNNABLE
        at remotely.Foo$$$Lambda$12/60830820.apply$mcI$sp(Unknown Source)
        at scala.runtime.java8.JFunction0$mcI$sp.apply(JFunction0$mcI$sp.java:12)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:653)
        at scala.concurrent.Future$$$Lambda$13/1698156408.apply(Unknown Source)
        at scala.util.Success.$anonfun$map$1(Try.scala:251)
        at scala.util.Success.map(Try.scala:209)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:287)
        at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$14/913190639.apply(Unknown Source)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:29)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
        at scala.concurrent.impl.Promise$KeptPromise$Successful$$Lambda$15/922151033.apply(Unknown Source)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

"Service Thread" #8 daemon prio=9 os_prio=31 tid=0x00007fcc6a029800 nid=0x4903 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007fcc6b845800 nid=0x4703 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007fcc6b833800 nid=0x4503 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007fcc6b832000 nid=0x4303 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007fcc6b83c800 nid=0x320f runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007fcc6b814800 nid=0x3003 in Object.wait() [0x000070000092e000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x0000000795588e98> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
@adriaanm
Contributor
adriaanm commented Oct 29, 2016 edited

Yep, @mpilquist says it well. See also http://stackoverflow.com/questions/15176199/scala-parallel-collection-in-object-initializer-causes-a-program-to-hang/15176433#15176433. This was true before 2.12.

New in 2.12 is that locking behavior is now different when lambdas are involved, as the lambda body is lifted to a member of the enclosing class (and thus an invocation blocks on the object's initialization lock), instead of a method in a separate (anonymous) class.

@viktorklang

Adrian,

this new behavior sounds plenty risky.

Cheers,

On Oct 29, 2016 7:57 PM, "Adriaan Moors" notifications@github.com wrote:

Yep, @mpilquist https://github.com/mpilquist says it well. See also
http://stackoverflow.com/questions/15176199/scala-
parallel-collection-in-object-initializer-causes-a-program-
to-hang/15176433#15176433. This was true before 2.12.

New in 2.12 is that locking behavior is now different when lambdas are
involved, as the lambda body is lifted to a member of the enclosing class
(and thus an invocation locks on the class's monitor), instead of a method
in a separate (anonymous) class.


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#290 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAqd-BDK_Jd7g0E4xhWKJRmsKOpskozks5q44jNgaJpZM4KkEq9
.

@som-snytt

A sympathy comment: I hit the same issue looking at https://issues.scala-lang.org/browse/SI-10007 and you scratch your head looking at thread dumps.

@adriaanm
Contributor

Viktor, it's a consequence of the new lambda encoding, which is also how Java does it. I don't know how we could change this and still use invokedynamic. There's a SIP for less deadlock-prone object/lazy val initialization that will likely get into 2.13. /cc @retronym

@adriaanm
Contributor

To make this more concrete:

object O { 
  def f = (x: Int) => x
  f(1)
}

compiles to:

public final class O {
  public static Function1<Object, Object> f() {
    return O$.MODULE$.f();
  }
}

public final class O$ {
  public static O$ MODULE$;
  public static { new O$();  }
  private O$() {
    MODULE$ = this;
    this.f().apply$mcII$sp(1);
  }

  public scala.Function1<Object, Object> f() { return x -> x;  }
}
@viktorklang

I probably over-interpreted it.
Is the problem only manifesting because the logic is executed as the
object initializer?

(I am a contributor to the improved lazy init so I'd of course want it as
soon as possible. 😊)

Cheers,

On Oct 30, 2016 2:47 AM, "Adriaan Moors" notifications@github.com wrote:

Viktor, it's a consequence of the new lambda encoding, which is also how
Java does it. I don't know how we could change this and still use
invokedynamic. There's a SIP for less deadlock-prone object/lazy val
initialization that will likely get into 2.13. /cc @retronym
https://github.com/retronym


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#290 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAqd9b0HUHxvh2bCVoaINxaIzzb0D8cks5q4-kPgaJpZM4KkEq9
.

@larsrh
larsrh commented Oct 30, 2016

So, to summarize: It's not a problem in ScalaCheck per se, but it is exhibited by the fact that the ScalaCheck runner

  • uses objects instead of instantiating classes, and
  • if a property is constructed from a plain Boolean, this is not done lazily

Is that assessment correct?

@non
Contributor
non commented Oct 30, 2016 edited

The simplest change which would fix this issue (for the end-user, in this case @larsrh) is something like this:

-  property("stack safety") = {
+  property("stack safety") = P {
     import ExecutionContext.Implicits.global
     fromFuture(Future(1)).run == 1
   }
 }
+
+object P {
+  def apply(body: => Boolean): Prop =
+    Prop(_ => Prop.Result(if (body) Prop.True else Prop.False))
+}

@larsrh @rickynils Do you think ScalaCheck should support something like this? If P was instead some method on Prop it would make fixing these issues relatively straightforward (albeit still annoying).

@adriaanm
Contributor
adriaanm commented Oct 30, 2016 edited

Is the problem only manifesting because the logic is executed as the object initializer?

yep, as far as I understand -- all access indirects through the module field, which is locked during initialization, and re-entry (e.g., by invoking a lambda which is now implemented as a method defined in the module class, and is thus invoked through the module field) will lock (from another thread)

@viktorklang

I guess we'll see how much of a problem this will become—it's not going to
be easy or obvious to debug.

Are there any chances of getting the improved lazy val SIP retrofitted onto
2.12 somewhere down the line?

On Sun, Oct 30, 2016 at 8:30 PM, Adriaan Moors notifications@github.com
wrote:

Is the problem only manifesting because the logic is executed as the
object initializer?

yep, as far as I understand -- all access indirect through the module
field, which is locked during initialization, and re-entry (e.g., by
invoking a lambda which is now implemented as a method defined in the
module class, and is thus invoked through the module field) will lock


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#290 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAqdwL_VvJsK3gNUVBAfHgOapcwxfNsks5q5PBggaJpZM4KkEq9
.

Cheers,

@larsrh
larsrh commented Oct 31, 2016

@larsrh @rickynils Do you think ScalaCheck should support something like this? If P was instead some method on Prop it would make fixing these issues relatively straightforward (albeit still annoying).

IMHO this should be the default behaviour (lazy evaluation), because I assume quite a few people will hit this issue.

@mpilquist
Contributor

Note this works:

object ResponseSpec extends Properties("Response") {

  def fromFuture[A](f: Future[A])(implicit E: ExecutionContext): Task[A] =
    Task.async { cb => f.onComplete {
      case Success(a) => cb(\/.right(a))
      case Failure(e) => cb(\/.left(e))
    }}

  property("stack safety") = Ext.suspend {
    import ExecutionContext.Implicits.global
    fromFuture(Future(1)).run == 1
  }
}

object Ext {
  def suspend[P <% Prop](p: => P): Prop = Prop { prms => (p: Prop)(prms) }
}
@mpilquist
Contributor

I don't think there's any other way to solve it in ScalaCheck 1.13.x -- the main culprit is the propBoolean implicit conversion, which is defined strictly:

  implicit def propBoolean(b: Boolean): Prop = Prop(b)

Theoretically, we could change that (and maybe other conversions) to be by-name like:

  implicit def propBoolean(b: => Boolean): Prop = Prop(_ => b)
@non
Contributor
non commented Oct 31, 2016

@mpilquist We could keep that method but make it non-implicit, and add a new by-name implicit. That would maintain binary compatibility and fix the issue I think.

@mpilquist
Contributor

@non oooo good idea!

@non
Contributor
non commented Oct 31, 2016 edited

I'll try it out now, unless you want to?

@viktorklang

Cool, I hope it is fixable.

On Mon, Oct 31, 2016 at 5:21 PM, Erik Osheim notifications@github.com
wrote:

I'll try it out now.


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#290 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAqd9-VaQieyl19Xl1YNeF3vP50bF8oks5q5hV4gaJpZM4KkEq9
.

Cheers,

@non
Contributor
non commented Oct 31, 2016 edited

So, the simple fix did not work.

I tried creating implicit def propBooleanLazy(b: => Boolean): Prop and then making propBoolean non-implicit. This doesn't seem to work -- in at least some cases when a Boolean => Prop is asked for, a (=> Boolean) => Prop is not sufficient. I tried creating a lower-priority implicit of the old type, but then that gets preferentially used even in the case we care about.

If I could get propBooleanLazy to be chosen at the property definition site then things would be fine. But I haven't yet found a good way to do this (that doesn't break tons of existing ScalaCheck-using code).

@mpilquist
Contributor
mpilquist commented Oct 31, 2016 edited

@non How about this instead?

diff --git a/src/main/scala/org/scalacheck/Prop.scala b/src/main/scala/org/scalacheck/Prop.scala
index cc0e92d..ce04f6b 100644
--- a/src/main/scala/org/scalacheck/Prop.scala
+++ b/src/main/scala/org/scalacheck/Prop.scala
@@ -300,6 +300,8 @@ object Prop {
   /** Create a property from a boolean value */
   def apply(b: Boolean): Prop = if(b) proved else falsified

+  def suspend(p: => Prop): Prop = apply(prms => p(prms))
+

   // Implicits

diff --git a/src/main/scala/org/scalacheck/Properties.scala b/src/main/scala/org/scalacheck/Properties.scala
index 972bae2..5029ff1 100644
--- a/src/main/scala/org/scalacheck/Properties.scala
+++ b/src/main/scala/org/scalacheck/Properties.scala
@@ -93,7 +93,7 @@ class Properties(val name: String) {
    *  }}}
    */
   sealed class PropertySpecifier() {
-    def update(propName: String, p: Prop) = props += ((name+"."+propName, p))
+    def update(propName: String, p: => Prop) = props += ((name+"."+propName, Prop.suspend(p)))
   }

   lazy val property = new PropertySpecifier()
@non
Contributor
non commented Oct 31, 2016 edited

@mpilquist Oh, that looks great! Does that pass mimaReportBinaryIssues?

@mpilquist
Contributor

Yep, mima passes

@non
Contributor
non commented Oct 31, 2016

:shipit:

@mpilquist
Contributor

mimaPreviousArtifacts wasn't configured -- once I changed it to compare against 1.13.3, it fails of course. I have a fix that passes tests and mima by making the old update method protected. PR incoming shortly.

@mpilquist mpilquist added a commit to mpilquist/scalacheck that referenced this issue Oct 31, 2016
@mpilquist mpilquist Fixes #290 (deadlock under 2.12 during property initialization) 7b7f85a
@mpilquist mpilquist added a commit to mpilquist/scalacheck that referenced this issue Oct 31, 2016
@mpilquist mpilquist Fixes #290 (deadlock under 2.12 during property initialization) 4dd1a15
@rickynils rickynils added a commit that referenced this issue Nov 1, 2016
@mpilquist @rickynils mpilquist + Fixes #290 (deadlock under 2.12 during property initialization)
(cherry picked from commit 4dd1a15)
c80c840
@rickynils rickynils added a commit that closed this issue Nov 1, 2016
@mpilquist @rickynils mpilquist + Fixes #290 (deadlock under 2.12 during property initialization)
(cherry picked from commit 4dd1a15)
2874398
@rickynils rickynils closed this in 2874398 Nov 1, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment