search

sbt / io

IO module for sbt
Apache License 2.0
41 stars 50 forks source link

Tests hang #152

Open OlegYch opened 6 years ago

OlegYch commented 6 years ago

On windows at 49e8c80991488e35b067b4d85f2f08189749f19a tests hang somewhere in native code:

"pool-7-thread-1-ScalaTest-running-IOSpec@21259" prio=5 tid=0x69 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at com.sun.jna.Native.initIDs(Native.java:-1)
      at com.sun.jna.Native.<clinit>(Native.java:216)
      at com.sun.jna.platform.win32.Kernel32.<clinit>(Kernel32.java:42)
      at sbt.internal.io.WinMilli$.getHandle(Milli.scala:275)
      at sbt.internal.io.WinMilli$.getModifiedTimeNative(Milli.scala:293)
      at sbt.internal.io.WinMilli$.getModifiedTimeNative(Milli.scala:271)
      at sbt.internal.io.MilliNative.getModifiedTime(Milli.scala:64)
      at sbt.internal.io.Milli$.getModifiedTime(Milli.scala:356)
      at sbt.io.IO$.getModifiedTime(IO.scala:1143)
      at sbt.io.IO$.getModifiedTimeOrZero(IO.scala:1212)
      at sbt.io.IOSpec.$anonfun$new$9(IOSpec.scala:67)
      at sbt.io.IOSpec$$Lambda$7104.1049495234.apply(Unknown Source:-1)
      at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
      at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
      at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
      at org.scalatest.Transformer.apply(Transformer.scala:22)
      at org.scalatest.Transformer.apply(Transformer.scala:20)
      at org.scalatest.FlatSpecLike$$anon$1.apply(FlatSpecLike.scala:1682)
      at org.scalatest.TestSuite.withFixture(TestSuite.scala:196)
      at org.scalatest.TestSuite.withFixture$(TestSuite.scala:195)
      at org.scalatest.FlatSpec.withFixture(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.invokeWithFixture$1(FlatSpecLike.scala:1680)
      at org.scalatest.FlatSpecLike.$anonfun$runTest$1(FlatSpecLike.scala:1692)
      at org.scalatest.FlatSpecLike$$Lambda$7237.1406170445.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
      at org.scalatest.FlatSpecLike.runTest(FlatSpecLike.scala:1692)
      at org.scalatest.FlatSpecLike.runTest$(FlatSpecLike.scala:1674)
      at org.scalatest.FlatSpec.runTest(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.$anonfun$runTests$1(FlatSpecLike.scala:1750)
      at org.scalatest.FlatSpecLike$$Lambda$7198.1432112447.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:396)
      at org.scalatest.SuperEngine$$Lambda$7200.2049402740.apply(Unknown Source:-1)
      at scala.collection.immutable.List.foreach(List.scala:389)
      at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
      at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:373)
      at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:410)
      at org.scalatest.SuperEngine$$Lambda$7200.2049402740.apply(Unknown Source:-1)
      at scala.collection.immutable.List.foreach(List.scala:389)
      at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
      at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:379)
      at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
      at org.scalatest.FlatSpecLike.runTests(FlatSpecLike.scala:1750)
      at org.scalatest.FlatSpecLike.runTests$(FlatSpecLike.scala:1749)
      at org.scalatest.FlatSpec.runTests(FlatSpec.scala:1685)
      at org.scalatest.Suite.run(Suite.scala:1147)
      at org.scalatest.Suite.run$(Suite.scala:1129)
      at org.scalatest.FlatSpec.org$scalatest$FlatSpecLike$$super$run(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.$anonfun$run$1(FlatSpecLike.scala:1795)
      at org.scalatest.FlatSpecLike$$Lambda$7166.166441666.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
      at org.scalatest.FlatSpecLike.run(FlatSpecLike.scala:1795)
      at org.scalatest.FlatSpecLike.run$(FlatSpecLike.scala:1793)
      at org.scalatest.FlatSpec.run(FlatSpec.scala:1685)
      at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
      at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:507)
      at sbt.TestRunner.runTest$1(TestFramework.scala:106)
      at sbt.TestRunner.run(TestFramework.scala:117)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.$anonfun$apply$1(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1$$Lambda$7016.1297959693.apply(Unknown Source:-1)
      at sbt.TestFramework$.sbt$TestFramework$$withContextLoader(TestFramework.scala:233)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFunction.apply(TestFramework.scala:271)
      at sbt.Tests$.$anonfun$toTask$1(Tests.scala:281)
      at sbt.Tests$$$Lambda$7005.1199965852.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$3.$anonfun$apply$2(System.scala:46)
      at sbt.std.Transform$$anon$3$$Lambda$2477.1508276760.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$4.work(System.scala:66)
      at sbt.Execute.$anonfun$submit$2(Execute.scala:262)
      at sbt.Execute$$Lambda$2488.311479461.apply(Unknown Source:-1)
      at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
      at sbt.Execute.work(Execute.scala:271)
      at sbt.Execute.$anonfun$submit$1(Execute.scala:262)
      at sbt.Execute$$Lambda$2479.1078426962.apply(Unknown Source:-1)
      at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:174)
      at sbt.ConcurrentRestrictions$$anon$4$$Lambda$2486.1027347651.apply(Unknown Source:-1)
      at sbt.CompletionService$$anon$2.call(CompletionService.scala:36)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
"pool-7-thread-4-ScalaTest-running-PathMapperSpec@21257" prio=5 tid=0x6c nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at com.sun.jna.Pointer.<clinit>(Pointer.java:54)
      at com.sun.jna.Structure.<clinit>(Structure.java:2130)
      at sbt.internal.io.WinMilli$.toNative(Milli.scala:322)
      at sbt.internal.io.WinMilli$.toNative(Milli.scala:271)
      at sbt.internal.io.MilliNative.setModifiedTime(Milli.scala:66)
      at sbt.internal.io.Milli$.setModifiedTime(Milli.scala:358)
      at sbt.io.IO$.setModifiedTime(IO.scala:1170)
      at sbt.io.IO$.touch(IO.scala:209)
      at sbt.io.PathMapperSpec.$anonfun$new$2(PathMapperSpec.scala:37)
      at sbt.io.PathMapperSpec$$Lambda$7082.1143690134.apply(Unknown Source:-1)
      at org.scalatest.fixture.TestSuite$TestFunAndConfigMap.$anonfun$apply$1(TestSuite.scala:132)
      at org.scalatest.fixture.TestSuite$TestFunAndConfigMap$$Lambda$7275.1288325399.apply(Unknown Source:-1)
      at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
      at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
      at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
      at org.scalatest.fixture.TestSuite$TestFunAndConfigMap.apply(TestSuite.scala:132)
      at org.scalatest.fixture.TestSuite$OneArgTest$$anon$1.apply(TestSuite.scala:80)
      at org.scalatest.TestSuite.withFixture(TestSuite.scala:196)
      at org.scalatest.TestSuite.withFixture$(TestSuite.scala:195)
      at org.scalatest.fixture.FlatSpec.withFixture(FlatSpec.scala:226)
      at sbt.io.PathMapperSpec.withFixture(PathMapperSpec.scala:122)
      at org.scalatest.fixture.FlatSpecLike.invokeWithFixture$1(FlatSpecLike.scala:2131)
      at org.scalatest.fixture.FlatSpecLike.$anonfun$runTest$1(FlatSpecLike.scala:2142)
      at org.scalatest.fixture.FlatSpecLike$$Lambda$7240.249633112.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
      at org.scalatest.fixture.FlatSpecLike.runTest(FlatSpecLike.scala:2142)
      at org.scalatest.fixture.FlatSpecLike.runTest$(FlatSpecLike.scala:2123)
      at org.scalatest.fixture.FlatSpec.runTest(FlatSpec.scala:226)
      at org.scalatest.fixture.FlatSpecLike.$anonfun$runTests$1(FlatSpecLike.scala:2185)
      at org.scalatest.fixture.FlatSpecLike$$Lambda$7197.753592513.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:396)
      at org.scalatest.SuperEngine$$Lambda$7200.2049402740.apply(Unknown Source:-1)
      at scala.collection.immutable.List.foreach(List.scala:389)
      at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
      at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:373)
      at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:410)
      at org.scalatest.SuperEngine$$Lambda$7200.2049402740.apply(Unknown Source:-1)
      at scala.collection.immutable.List.foreach(List.scala:389)
      at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
      at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:379)
      at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
      at org.scalatest.fixture.FlatSpecLike.runTests(FlatSpecLike.scala:2185)
      at org.scalatest.fixture.FlatSpecLike.runTests$(FlatSpecLike.scala:2184)
      at org.scalatest.fixture.FlatSpec.runTests(FlatSpec.scala:226)
      at org.scalatest.Suite.run(Suite.scala:1147)
      at org.scalatest.Suite.run$(Suite.scala:1129)
      at org.scalatest.fixture.FlatSpec.org$scalatest$fixture$FlatSpecLike$$super$run(FlatSpec.scala:226)
      at org.scalatest.fixture.FlatSpecLike.$anonfun$run$1(FlatSpecLike.scala:2206)
      at org.scalatest.fixture.FlatSpecLike$$Lambda$7165.1169641412.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
      at org.scalatest.fixture.FlatSpecLike.run(FlatSpecLike.scala:2206)
      at org.scalatest.fixture.FlatSpecLike.run$(FlatSpecLike.scala:2205)
      at org.scalatest.fixture.FlatSpec.run(FlatSpec.scala:226)
      at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
      at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:507)
      at sbt.TestRunner.runTest$1(TestFramework.scala:106)
      at sbt.TestRunner.run(TestFramework.scala:117)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.$anonfun$apply$1(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1$$Lambda$7016.1297959693.apply(Unknown Source:-1)
      at sbt.TestFramework$.sbt$TestFramework$$withContextLoader(TestFramework.scala:233)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFunction.apply(TestFramework.scala:271)
      at sbt.Tests$.$anonfun$toTask$1(Tests.scala:281)
      at sbt.Tests$$$Lambda$7005.1199965852.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$3.$anonfun$apply$2(System.scala:46)
      at sbt.std.Transform$$anon$3$$Lambda$2477.1508276760.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$4.work(System.scala:66)
      at sbt.Execute.$anonfun$submit$2(Execute.scala:262)
      at sbt.Execute$$Lambda$2488.311479461.apply(Unknown Source:-1)
      at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
      at sbt.Execute.work(Execute.scala:271)
      at sbt.Execute.$anonfun$submit$1(Execute.scala:262)
      at sbt.Execute$$Lambda$2479.1078426962.apply(Unknown Source:-1)
      at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:174)
      at sbt.ConcurrentRestrictions$$anon$4$$Lambda$2486.1027347651.apply(Unknown Source:-1)
      at sbt.CompletionService$$anon$2.call(CompletionService.scala:36)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
"pool-7-thread-10-ScalaTest-running-PollingWatchServiceSpec@21251" prio=5 tid=0x72 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at sbt.internal.io.WinMilli$.toNative(Milli.scala:322)
      at sbt.internal.io.WinMilli$.toNative(Milli.scala:271)
      at sbt.internal.io.MilliNative.setModifiedTime(Milli.scala:66)
      at sbt.internal.io.Milli$.setModifiedTime(Milli.scala:358)
      at sbt.io.IO$.setModifiedTimeOrFalse(IO.scala:1234)
      at sbt.internal.io.SourceModificationWatchSpec.writeNewFile(SourceModificationWatchSpec.scala:435)
      at sbt.internal.io.SourceModificationWatchSpec.$anonfun$new$2(SourceModificationWatchSpec.scala:23)
      at sbt.internal.io.SourceModificationWatchSpec$$Lambda$7286.299022092.apply(Unknown Source:-1)
      at sbt.io.IO$.withTemporaryDirectory(IO.scala:376)
      at sbt.io.IO$.withTemporaryDirectory(IO.scala:383)
      at sbt.internal.io.SourceModificationWatchSpec.$anonfun$new$1(SourceModificationWatchSpec.scala:19)
      at sbt.internal.io.SourceModificationWatchSpec$$Lambda$7059.1280031373.apply(Unknown Source:-1)
      at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
      at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
      at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
      at org.scalatest.Transformer.apply(Transformer.scala:22)
      at org.scalatest.Transformer.apply(Transformer.scala:20)
      at org.scalatest.FlatSpecLike$$anon$1.apply(FlatSpecLike.scala:1682)
      at org.scalatest.TestSuite.withFixture(TestSuite.scala:196)
      at org.scalatest.TestSuite.withFixture$(TestSuite.scala:195)
      at org.scalatest.FlatSpec.withFixture(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.invokeWithFixture$1(FlatSpecLike.scala:1680)
      at org.scalatest.FlatSpecLike.$anonfun$runTest$1(FlatSpecLike.scala:1692)
      at org.scalatest.FlatSpecLike$$Lambda$7237.1406170445.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
      at org.scalatest.FlatSpecLike.runTest(FlatSpecLike.scala:1692)
      at org.scalatest.FlatSpecLike.runTest$(FlatSpecLike.scala:1674)
      at org.scalatest.FlatSpec.runTest(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.$anonfun$runTests$1(FlatSpecLike.scala:1750)
      at org.scalatest.FlatSpecLike$$Lambda$7198.1432112447.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:396)
      at org.scalatest.SuperEngine$$Lambda$7200.2049402740.apply(Unknown Source:-1)
      at scala.collection.immutable.List.foreach(List.scala:389)
      at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
      at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:379)
      at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
      at org.scalatest.FlatSpecLike.runTests(FlatSpecLike.scala:1750)
      at org.scalatest.FlatSpecLike.runTests$(FlatSpecLike.scala:1749)
      at org.scalatest.FlatSpec.runTests(FlatSpec.scala:1685)
      at org.scalatest.Suite.run(Suite.scala:1147)
      at org.scalatest.Suite.run$(Suite.scala:1129)
      at org.scalatest.FlatSpec.org$scalatest$FlatSpecLike$$super$run(FlatSpec.scala:1685)
      at org.scalatest.FlatSpecLike.$anonfun$run$1(FlatSpecLike.scala:1795)
      at org.scalatest.FlatSpecLike$$Lambda$7166.166441666.apply(Unknown Source:-1)
      at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
      at org.scalatest.FlatSpecLike.run(FlatSpecLike.scala:1795)
      at org.scalatest.FlatSpecLike.run$(FlatSpecLike.scala:1793)
      at org.scalatest.FlatSpec.run(FlatSpec.scala:1685)
      at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
      at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:507)
      at sbt.TestRunner.runTest$1(TestFramework.scala:106)
      at sbt.TestRunner.run(TestFramework.scala:117)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.$anonfun$apply$1(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1$$Lambda$7016.1297959693.apply(Unknown Source:-1)
      at sbt.TestFramework$.sbt$TestFramework$$withContextLoader(TestFramework.scala:233)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFramework$$anon$2$$anonfun$$lessinit$greater$1.apply(TestFramework.scala:262)
      at sbt.TestFunction.apply(TestFramework.scala:271)
      at sbt.Tests$.$anonfun$toTask$1(Tests.scala:281)
      at sbt.Tests$$$Lambda$7005.1199965852.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$3.$anonfun$apply$2(System.scala:46)
      at sbt.std.Transform$$anon$3$$Lambda$2477.1508276760.apply(Unknown Source:-1)
      at sbt.std.Transform$$anon$4.work(System.scala:66)
      at sbt.Execute.$anonfun$submit$2(Execute.scala:262)
      at sbt.Execute$$Lambda$2488.311479461.apply(Unknown Source:-1)
      at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
      at sbt.Execute.work(Execute.scala:271)
      at sbt.Execute.$anonfun$submit$1(Execute.scala:262)
      at sbt.Execute$$Lambda$2479.1078426962.apply(Unknown Source:-1)
      at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:174)
      at sbt.ConcurrentRestrictions$$anon$4$$Lambda$2486.1027347651.apply(Unknown Source:-1)
      at sbt.CompletionService$$anon$2.call(CompletionService.scala:36)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
OlegYch commented 6 years ago

parallelExecution := false works around that but it seems there is a deeper problem

eatkins commented 6 years ago

Is this still the case? I've never seen this happen on an appveyor build or on my windows vm.

OlegYch commented 6 years ago

@eatkins yep still hangs in the same way at 95fa6d4ee80cfa593138e5285c7f2d1961899bf1

OlegYch commented 6 years ago

perhaps your machines do not have enough cores to trigger it (i have 4+HT)

eed3si9n commented 6 years ago

Could this be a duplicate of https://github.com/sbt/io/issues/143?

OlegYch commented 6 years ago

@eed3si9n don't think so, since the threads hang in <clinit> and sometimes it doesn't hang at all

eatkins commented 6 years ago

It seems like this may be a jna bug: https://issues.jenkins-ci.org/browse/JENKINS-16070. It probably would be fairly easy to implement (get|set)LastModifiedTime using jni if there were a volunteer. The main complication is that it would require packaging one or more shared libraries in the io jar. I've done this in swoval, but it is a bit of pain to build/package the shared libraries and load them at runtime.

OlegYch commented 6 years ago

@eatkins i just tried with jna 5.0.0-SNAPSHOT on windows and it resolves the issue