Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

run/streams.scala intermittently fails on Windows #11412

Open
SethTisue opened this Issue Jan 8, 2019 · 7 comments

Comments

Projects
None yet
4 participants
@SethTisue
Copy link
Member

SethTisue commented Jan 8, 2019

seen at e.g. https://scala-ci.typesafe.com/view/scala-2.13.x/job/scala-2.13.x-integrate-windows/839/consoleText

!!  740 - run/streams.scala                         [output differs]
% diff Y:\jenkins\workspace\scala-2.13.x-integrate-windows\test\files\run\streams.check Y:\jenkins\workspace\scala-2.13.x-integrate-windows\test\files\run\streams-run.log--- streams.check
+++ streams-run.log
@@ -37,3 +37,48 @@
 705082704
-
-true
+java.lang.NullPointerException
+	at java.lang.reflect.Array.getLength(Native Method)
+	at scala.collection.IterableOnceOps.copyToArray(IterableOnce.scala:813)
+	at scala.collection.IterableOnceOps.copyToArray$(IterableOnce.scala:812)
+	at Test$.delayedEndpoint$Test$1(streams.scala:59)
+	at Test$delayedInit$body.apply(streams.scala:3)
+	at scala.Function0.apply$mcV$sp(Function0.scala:39)
+	at scala.Function0.apply$mcV$sp$(Function0.scala:39)
+	at scala.runtime.AbstractFunction0.apply$mcV$sp(AbstractFunction0.scala:17)
+	at scala.App.$anonfun$main$1(App.scala:76)
+	at scala.App.$anonfun$main$1$adapted(App.scala:76)
+	at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:518)
+	at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:516)
+	at scala.collection.AbstractIterable.foreach(Iterable.scala:916)
+	at scala.App.main(App.scala:76)
+	at scala.App.main$(App.scala:74)
+	at Test$.main(streams.scala:3)
+	at Test.main(streams.scala)
+	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
+	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
+	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
+	at java.lang.reflect.Method.invoke(Method.java:498)
+	at scala.tools.partest.nest.Runner.$anonfun$execTestInProcess$2(Runner.scala:249)
+	at scala.util.DynamicVariable.withValue(DynamicVariable.scala:62)
+	at scala.Console$.withOut(Console.scala:167)
+	at scala.tools.partest.nest.StreamCapture$.$anonfun$capturingOutErr$2(StreamCapture.scala:40)
+	at scala.util.DynamicVariable.withValue(DynamicVariable.scala:62)
+	at scala.Console$.withErr(Console.scala:196)
+	at scala.tools.partest.nest.Runner.$anonfun$execTestInProcess$1(Runner.scala:245)
+	at scala.tools.partest.nest.Runner.run$2(Runner.scala:241)
+	at scala.tools.partest.nest.Runner.$anonfun$execTestInProcess$3(Runner.scala:268)
+	at scala.tools.partest.nest.Runner.execTestInProcess(Runner.scala:268)
+	at scala.tools.partest.nest.Runner.exec$1(Runner.scala:649)
+	at scala.tools.partest.nest.Runner.$anonfun$runRunTest$1(Runner.scala:651)
+	at scala.tools.partest.nest.Runner.$anonfun$runTestCommon$1(Runner.scala:551)
+	at scala.tools.partest.nest.Runner.runInContext(Runner.scala:435)
+	at scala.tools.partest.nest.Runner.runTestCommon(Runner.scala:548)
+	at scala.tools.partest.nest.Runner.runRunTest(Runner.scala:651)
+	at scala.tools.partest.nest.Runner.run(Runner.scala:640)
+	at scala.tools.partest.nest.AbstractRunner.liftedTree1$1(AbstractRunner.scala:313)
+	at scala.tools.partest.nest.AbstractRunner.runTest(AbstractRunner.scala:313)
+	at scala.tools.partest.nest.AbstractRunner.$anonfun$runTestsForFiles$2(AbstractRunner.scala:338)
+	at scala.tools.partest.package$$anon$2.call(package.scala:139)
+	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
+	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)

@NthPortal what do you make of this, could this be a real bug?

note that I'm not completely certain it never fails except on Windows, if anyone else has seen this on a non-Windows system, let us know

@SethTisue

This comment has been minimized.

Copy link
Member Author

SethTisue commented Jan 24, 2019

ping @NthPortal

@Jasper-M

This comment has been minimized.

Copy link
Member

Jasper-M commented Jan 24, 2019

Some sort of Java Memory Model intricacy or bug?
Seems to me that the problem boils down to this:

object Test {
  private[this] var _arr: Array[Int] = null
  def arr() = _arr

  def main(args: Array[String]): Unit = {
    _arr = new Array[Int](100000)
    assert(arr() ne null) //fails
  }
}

Except with a whole bunch of extra indirection via DelayedInit. And the way it gets run by the test framework might also be relevant...

@som-snytt

This comment has been minimized.

Copy link

som-snytt commented Jan 25, 2019

Also ScalaRunTime.array_length is inlined, which invokes java.lang.reflect.Array.getLength. Though on M5 :javap doesn't show it inlined. Maybe it was only recently made inline?

:javap -pv scala.collection.IterableOnceOps#copyToArray

In fact, git blame shows it was inlined in September.

@NthPortal

This comment has been minimized.

Copy link

NthPortal commented Jan 25, 2019

@SethTisue oops, I missed this. Sorry!

For reference, the NPE appears to be thrown by this line.

// copies of the relevant lines
  val size = 100000
  val arr = new Array[Int](size)
  LazyList.from(1).take(size).copyToArray(arr, 0) // throws NPE sometimes?

@Jasper-M you think arr is somehow null in the call to copyToArray, despite being initialized? that would certainly be a fun thing to work around. Does the test code you pasted actually fail sometimes?

@Jasper-M

This comment has been minimized.

Copy link
Member

Jasper-M commented Jan 25, 2019

@som-snytt you think arr is somehow null in the call to copyToArray, despite being initialized? that would certainly be a fun thing to work around. Does the test code you pasted actually fail sometimes?

I guess I'm supposed to come up with some kind of pun now...
Based on the stacktrace I would say that xs in xs.length in copyToArray is somehow null. So I assume that's because arr is null in the call to copyToArray. I don't think that test code would ever fail when you would run it as-is, or I would certainly hope so. But based on the evidence presented it appears that when you run something very similar through partest on Windows it does fail sometimes. But it's strange that it doesn't happen in other places or other tests where App is used.

Perhaps some cosmic ray hit the CPU of the CI machine at just the right spot...

edit: I see that it failed multiple times in exactly the same spot so we can probably rule out the cosmic rays.

@NthPortal

This comment has been minimized.

Copy link

NthPortal commented Jan 25, 2019

do we just give up on App for this test, and have an explicit main?

@som-snytt

This comment has been minimized.

Copy link

som-snytt commented Jan 25, 2019

I'll never use App in a test again...

It would be nice to know if it started to fail at a certain point and check JDK too, in case it's a JDK bug.

@SethTisue SethTisue transferred this issue from scala/scala-dev Feb 22, 2019

@SethTisue SethTisue added this to the Backlog milestone Feb 22, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.
You signed in with another tab or window. Reload to refresh your session. You signed out in another tab or window. Reload to refresh your session.