Interesting case of a Future block not being invoked, potential regression from 2.11

rmgn · February 7, 2019, 11:35pm

This is the minimized problem, consider this block of code:

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

def test(): Unit = {
  var continue = true
  Future {
    println(s"Future thread: ${Thread.currentThread().getName}")
    Thread.sleep(2000)
  }.onComplete { _ =>
    println(s"got here")
    continue = false
  }

  while(continue) {
    println("waiting...")
    Thread.sleep(400)
  }
}

test()

If I run a Scala repl (2.12.7), invoke :paste and paste that block, I never see the Future thread: println and the while loops forever.

But, if I paste everything except the last line (test()) and instead invoke it in the next repl prompt, everything works as expected.

This does not happen on a 2.11 repl.

I tried a few variations of this (all pasted in :paste mode):

I put that entire code block above inside an object, i.e. object Foo { .. block .. }
The behavior in the repl was interesting, it printed defined object Foo, then writing Foo in the prompt yielded the same behavior as before (loop forever)
Again I created an object Foo and put the test function in it, but did not invoke it, instead I put the invocation of test() inside a def main(args: Array[String]): Unit = test(). Then in the next repl prompt I wrote Foo.main(Array.empty) and everything worked as expected.

fwiw, this does not seem to be limited to the scala repl. I had this variation too:

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

object Foo {

  def test(): Unit = {
    var continue = true
    Future {
      println(s"Future thread: ${Thread.currentThread().getName}")
      Thread.sleep(2000)
    }.onComplete{ _ =>
      println(s"got here")
      continue = false
    }

    while(continue) {
      println("waiting...")
      Thread.sleep(400)
    }
  }

  test()
}

object Goo {
  def main(args: Array[String]): Unit = {
    println(s"in Goo")
    val f = Foo
    println(f)
  }
}

And I had Intellij run Goo.main to see the same behavior.

I would love to hear people’s thoughts on this, or to actually figure out what’s going on? It seems like some kind of regression, and definitely not expected behavior, but I’m aware there might be aspects I’m not familiar with.

Thanks

shawjef3 · February 8, 2019, 2:14am

Interesting find. My first thought is that it’s because you didn’t use @transient on your boolean, but that’s not it. AtomicBoolean doesn’t help either.
I found that it’s broken without sleep inside the Future.
Here’s a variation I came up with while playing with your code.

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

def test(): Unit = {
  @transient
  var continue = true

  Future {
    continue = false
  }

  while(continue) {
    println(java.time.Instant.now())
    Thread.sleep(400)
  }
  println("done")
}

test()

scottcarey · February 8, 2019, 3:03am

Did you mean @volatile?

scalway · February 8, 2019, 9:33am

I’ve made some tests on my machine:

ammonite version: Scala 2.12.7 Java 1.8.0_191 Repl 1.2.1-16-48ce533
scala version: 2.12.2 (old but it looks that it wasn’t fixed in never versions)

What i’ve found:

@volatile will not help.
another implicit ExecutionContext’ll not help

here are some cases that I’ve tested:

without wrapper Foo [scala:FAIL, amm:OK]:

def test(): Unit = {
    @volatile var continue = true
    Future { ... }.onComplete{ _ => ... }
    while(continue) {...}
}
test()

happens on scala 2.12.2 REPL with :paste mode ONLY!
pasting code directly to repl works as expected.
works as expected on ammonite 2.12.7 REPL

with wrapper Foo and call `test()` after `Foo` [scala,amm:OK]:

object Foo {
    def test() = {...}
}
Foo.test()

amm/scala works as expected.

with wrapper Foo and call `test()` inside `Foo` [scala,amm:FAIL]:

object Foo {
     def test() = {...}
     test()
}
Foo //force to create

amm/scala fails as described
on scastie worksheet it works fine: https://scastie.scala-lang.org/CrkQtRbwSTCGTZyQAVG97g

here is diff of :javap -c Foo of two Foo versions (working & failing one):
https://www.diffchecker.com/upLKT1EP

Case where while loop is in Future: [scala,amm:OK]

def test(): Unit = {
    @volatile var continue = true
    Future { ... }.onComplete{ _ => ... }
    Future { while(continue) {...} }
}
test()

work fine everywhere

eyalroth · February 8, 2019, 9:53am

I don’t see how the boolean continue has anything to do with this. The Future thread: line should be printed regardless of its value.

Perhaps this is a problem with streaming the output to the console / stdout? Try writing the text into a file instead of printing it and see if the file is still missing that line.

scalway · February 8, 2019, 10:43am

no Future isn’t fired at all. Tested using:

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future
import concurrent._
import java.util.concurrent.Executors
import java.io._

object Foo {
  def test(): Unit = {
    @volatile var continue = true
    Future.apply {
      new FileOutputStream(new File("/tmp/killmeplease.txt")).close();
      Thread.sleep(2000)
      new FileOutputStream(new File("/tmp/killmeplease2.txt")).close();      
    }.onComplete{ _ =>
      println(s"got here")
      continue = false
    }

        while(continue) {
          println("waiting...")
          Thread.sleep(400)
        }
  }
  test()
}
Foo

this script when pastad to REPL doesn’t produce any file in /tmp

scalway · February 8, 2019, 11:03am

smallest affected version:

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

def test(): Unit = {
  @volatile var continue = true
  Future {continue = false}
  while(continue) {
    println("waiting...")
    Thread.sleep(400)
  }
}

test()

seams that
Future { … } is never fired!

zygfryd · February 8, 2019, 11:39am

I only looked at desugared intermediate code and not the actual bytecode, but it seems to me like Foo’s instance is constructed while holding a lock. All the lambdas used inside Foo are lifted to methods on Foo’s instance and accessed by trying to acquire that lock again, in a different thread, so it deadlocks.

2.11 lambdas were top level classes instead and didn’t have this problem.

eyalroth · February 8, 2019, 1:23pm

A shorter version:

scala> :paste
// Entering paste mode (ctrl-D to finish)\

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

println("start")
Future {
  println("future")
}
while (true) {}

// Exiting paste mode, now interpreting.

start

Indeed the Future is never fired.

eyalroth · February 8, 2019, 1:41pm

Seems like this is not exclusive to the :paste mode:

scala> {
     | import scala.concurrent.ExecutionContext.Implicits.global
     | import scala.concurrent.Future
     |
     | println("start")
     | Future {
     |   println("future")
     | }
     | while (true) {}
     | }
start

And with ammonite:

@ {
  import scala.concurrent.ExecutionContext.Implicits.global
  import scala.concurrent.Future

  println("start")
  Future {
    println("future")
  }
  while (true) {}
  }
start

jducoeur · February 8, 2019, 2:09pm

Makes sense – it seemed like there had to be something like that going on, preventing the Future from firing.

So the larger question raised by this is, is this a bug, or something to be documented, or what? The implication is that blocking during object construction is Dangerous. That doesn’t totally surprise me (it actually had never occurred to me to try this), and my reaction to the Foo version is that that’s a weird edge case that might just deserve a “don’t do that”. (Although I’m concerned about whether there might be other ways to hit this deadlock with interdependent closures and vars, without even getting into Futures and blocking.)

The REPL version is arguably a hair more serious – while it’s slightly weird code, there’s nothing obviously broken about it – and I assume is failing because it turns into something like the Foo version when you :paste it.

It feels like there’s a bug to be opened here, but offhand I’m not sure on what…

smarter · February 8, 2019, 2:18pm

This is a known issue (and fixed in Dotty): https://github.com/scala/scala-dev/issues/195

rmgn · February 8, 2019, 5:45pm

The bug seems to be specifically for the REPL? This is not limited to the repl.
I created Foo.scala:

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

object Foo {

  def test(): Unit = {
    var continue = true
    Future {
      println(s"Future thread: ${Thread.currentThread().getName}")
      continue = false
    }

    while(continue) {
      println("waiting...")
      Thread.sleep(400)
    }
  }

  test()
}

object Goo {
  def main(args: Array[String]): Unit = {
    val f = Foo
    println(f)
  }
}

Then ran:

> scalac Foo.scala
> scala Goo
waiting...
waiting...
waiting...
waiting...
waiting...
...

^C

mpilquist · February 8, 2019, 6:11pm

It’s not just limited to the REPL, though that’s where folks most frequently run in to it. The original issue came up in the context of ScalaCheck - https://github.com/rickynils/scalacheck/issues/290.

Interesting case of a Future block not being invoked, potential regression from 2.11

without wrapper Foo [scala:FAIL, amm:OK]:

with wrapper Foo and call test() after Foo [scala,amm:OK]:

with wrapper Foo and call test() inside Foo [scala,amm:FAIL]:

Case where while loop is in Future: [scala,amm:OK]

with wrapper Foo and call `test()` after `Foo` [scala,amm:OK]:

with wrapper Foo and call `test()` inside `Foo` [scala,amm:FAIL]: