Skip to content

race condition in caching of SBT plugin resolution with Extracted.runTask / sbtbuildinfo #2970

New issue
New issue
Closed
Closed
race condition in caching of SBT plugin resolution with Extracted.runTask / sbtbuildinfo#2970
@retronym

Description

@retronym
retronym
opened on Feb 22, 2017

steps (not minimized yet)

  • Clone scala/scala repository.
  • Install some global plugins in ./sbt/0.13/plugins
  • Attach a debugger and set a breakpoint at def eof in io.scala
  • This breakpoint will hit sometimes when repeatedly running the reload command
  • The file project/target/streams/$global/update/$global/streams/update_cache_2.10/output will be zero bytes at that moment.

problem

The failure to parse the outputs cache metadata does not cause a visible error as the EOF exception is caught in:

  def fromFile[T](file: File)(implicit format: Format[T], mf: Manifest[Format[T]]): Option[T] =
    try { Some(Operations.fromFile(file)(stampedFormat(format))) }
    catch { case e: Exception => None }

This exception handler means that the cache is assumed to be stale, and the (expensive) resolution is repeated. This might be a major part of the slowness of SBT at startup and on reload.

Based on the stack trace below, it appears that two update tasks are running concurrently and clobbering the file.

expectation

SBT should avoid racy access to the cache metadata, either by serializing the update tasks, or by using separate metadata files.

notes

"pool-118-thread-2@17625" prio=5 tid=0x45d nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at sbinary.JavaUTF$class.sbinary$JavaUTF$$fetchBuffers(javaprotocol.scala:90)
	  at sbinary.JavaUTF$StringFormat$.writes(javaprotocol.scala:167)
	  at sbinary.JavaUTF$StringFormat$.writes(javaprotocol.scala:100)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:32)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:30)
	  at sbinary.Generic$CollectionFormat.writes(generic.scala:24)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.BasicTypes$$anon$9.writes(standardtypes.scala:170)
	  at sbinary.BasicTypes$$anon$9.writes(standardtypes.scala:154)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:32)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:30)
	  at sbinary.Generic$CollectionFormat.writes(generic.scala:24)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.BasicTypes$$anon$20.writes(standardtypes.scala:747)
	  at sbinary.BasicTypes$$anon$20.writes(standardtypes.scala:704)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:32)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:30)
	  at sbinary.Generic$CollectionFormat.writes(generic.scala:24)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.BasicTypes$$anon$5.writes(standardtypes.scala:57)
	  at sbinary.BasicTypes$$anon$5.writes(standardtypes.scala:44)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:32)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:30)
	  at sbinary.Generic$CollectionFormat.writes(generic.scala:24)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.BasicTypes$$anon$6.writes(standardtypes.scala:81)
	  at sbinary.BasicTypes$$anon$6.writes(standardtypes.scala:67)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at sbinary.Generic$CollectionFormat$$anonfun$writes$1.apply(generic.scala:24)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:32)
	  at sbinary.Generic$LengthEncoded.foreach(generic.scala:30)
	  at sbinary.Generic$CollectionFormat.writes(generic.scala:24)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.BasicTypes$$anon$6.writes(standardtypes.scala:80)
	  at sbinary.BasicTypes$$anon$6.writes(standardtypes.scala:67)
	  at sbinary.Operations$.write(operations.scala:10)
	  at sbinary.Generic$$anon$5.writes(generic.scala:72)
	  at sbinary.Generic$$anon$7.writes(generic.scala:98)
	  at sbinary.Operations$.toByteArray(operations.scala:18)
	  at sbinary.Operations$.toFile(operations.scala:34)
	  at sbt.CacheIO$.toFile(CacheIO.scala:33)
	  at sbt.Tracked$$anonfun$lastOutput$1.apply(Tracked.scala:38)
	  at sbt.Classpaths$$anonfun$doWork$1$1.apply(Defaults.scala:1515)
	  at sbt.Classpaths$$anonfun$doWork$1$1.apply(Defaults.scala:1509)
	  at sbt.Tracked$$anonfun$inputChanged$1.apply(Tracked.scala:60)
	  at sbt.Classpaths$.cachedUpdate(Defaults.scala:1532)
	  at sbt.Classpaths$$anonfun$updateTask$1.apply(Defaults.scala:1459)
	  at sbt.Classpaths$$anonfun$updateTask$1.apply(Defaults.scala:1411)
	  at scala.Function1$$anonfun$compose$1.apply(Function1.scala:47)
	  at sbt.$tilde$greater$$anonfun$$u2219$1.apply(TypeFunctions.scala:40)
	  at sbt.std.Transform$$anon$4.work(System.scala:63)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
	  at sbt.Execute.work(Execute.scala:237)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.ConcurrentRestrictions$$anon$4$$anonfun$1.apply(ConcurrentRestrictions.scala:159)
	  at sbt.CompletionService$$anon$2.call(CompletionService.scala:28)
	  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:1142)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	  at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
	  at sbt.ConcurrentRestrictions$$anon$4.take(ConcurrentRestrictions.scala:188)
	  at sbt.Execute.next$1(Execute.scala:85)
	  at sbt.Execute.processAll(Execute.scala:88)
	  at sbt.Execute.runKeep(Execute.scala:68)
	  at sbt.EvaluateTask$.liftedTree1$1(EvaluateTask.scala:359)
	  at sbt.EvaluateTask$.run$1(EvaluateTask.scala:358)
	  at sbt.EvaluateTask$.runTask(EvaluateTask.scala:378)
	  at sbt.EvaluateTask$$anonfun$apply$1$$anonfun$apply$3.apply(EvaluateTask.scala:279)
	  at sbt.EvaluateTask$$anonfun$apply$1$$anonfun$apply$3.apply(EvaluateTask.scala:279)
	  at scala.Option$WithFilter.map(Option.scala:206)
	  at sbt.EvaluateTask$$anonfun$apply$1.apply(EvaluateTask.scala:279)
	  at sbt.EvaluateTask$$anonfun$apply$1.apply(EvaluateTask.scala:278)
	  at sbt.EvaluateTask$.withStreams(EvaluateTask.scala:314)
	  at sbt.EvaluateTask$.apply(EvaluateTask.scala:278)
	  at sbt.EvaluateTask$.evalPluginDef(EvaluateTask.scala:251)
	  at sbt.Load$$anonfun$3.apply(Load.scala:52)
	  at sbt.Load$$anonfun$3.apply(Load.scala:52)
	  at sbt.Load$.buildPluginDefinition(Load.scala:888)
	  at sbt.Load$.buildPlugins(Load.scala:852)
	  at sbt.Load$.plugins(Load.scala:840)
	  at sbt.Load$$anonfun$loadUnit$1$$anonfun$34.apply(Load.scala:465)
	  at sbt.Load$$anonfun$loadUnit$1$$anonfun$34.apply(Load.scala:465)
	  at sbt.Load$.timed(Load.scala:1025)
	  at sbt.Load$$anonfun$loadUnit$1.apply(Load.scala:464)
	  at sbt.Load$$anonfun$loadUnit$1.apply(Load.scala:459)
	  at sbt.Load$.timed(Load.scala:1025)
	  at sbt.Load$.loadUnit(Load.scala:459)
	  at sbt.Load$$anonfun$25$$anonfun$apply$14.apply(Load.scala:311)
	  at sbt.Load$$anonfun$25$$anonfun$apply$14.apply(Load.scala:310)
	  at sbt.BuildLoader$$anonfun$componentLoader$1$$anonfun$apply$4$$anonfun$apply$5$$anonfun$apply$6.apply(BuildLoader.scala:91)
	  at sbt.BuildLoader$$anonfun$componentLoader$1$$anonfun$apply$4$$anonfun$apply$5$$anonfun$apply$6.apply(BuildLoader.scala:90)
	  at sbt.BuildLoader.apply(BuildLoader.scala:140)
	  at sbt.Load$.loadAll(Load.scala:365)
	  at sbt.Load$.loadURI(Load.scala:320)
	  at sbt.Load$.load(Load.scala:316)
	  at sbt.Load$.load(Load.scala:305)
	  at sbt.Load$$anonfun$4.apply(Load.scala:146)
	  at sbt.Load$$anonfun$4.apply(Load.scala:146)
	  at sbt.Load$.timed(Load.scala:1025)
	  at sbt.Load$.apply(Load.scala:146)
	  at sbt.Load$.defaultLoad(Load.scala:39)
	  at sbt.BuiltinCommands$.liftedTree1$1(Main.scala:496)
	  at sbt.BuiltinCommands$.doLoadProject(Main.scala:496)
	  at sbt.BuiltinCommands$$anonfun$loadProjectImpl$2.apply(Main.scala:488)
	  at sbt.BuiltinCommands$$anonfun$loadProjectImpl$2.apply(Main.scala:488)
	  at sbt.Command$$anonfun$applyEffect$1$$anonfun$apply$2.apply(Command.scala:59)
	  at sbt.Command$$anonfun$applyEffect$1$$anonfun$apply$2.apply(Command.scala:59)
	  at sbt.Command$$anonfun$applyEffect$2$$anonfun$apply$3.apply(Command.scala:61)
	  at sbt.Command$$anonfun$applyEffect$2$$anonfun$apply$3.apply(Command.scala:61)
	  at sbt.Command$.process(Command.scala:93)
	  at sbt.MainLoop$$anonfun$1$$anonfun$apply$1.apply(MainLoop.scala:96)
	  at sbt.MainLoop$$anonfun$1$$anonfun$apply$1.apply(MainLoop.scala:96)
	  at sbt.State$$anon$1.process(State.scala:184)
	  at sbt.MainLoop$$anonfun$1.apply(MainLoop.scala:96)
	  at sbt.MainLoop$$anonfun$1.apply(MainLoop.scala:96)
	  at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
	  at sbt.MainLoop$.next(MainLoop.scala:96)
	  at sbt.MainLoop$.run(MainLoop.scala:89)
	  at sbt.MainLoop$$anonfun$runWithNewLog$1.apply(MainLoop.scala:68)
	  at sbt.MainLoop$$anonfun$runWithNewLog$1.apply(MainLoop.scala:63)
	  at sbt.Using.apply(Using.scala:24)
	  at sbt.MainLoop$.runWithNewLog(MainLoop.scala:63)
	  at sbt.MainLoop$.runAndClearLast(MainLoop.scala:46)
	  at sbt.MainLoop$.runLoggedLoop(MainLoop.scala:30)
	  at sbt.MainLoop$.runLogged(MainLoop.scala:22)
	  at sbt.StandardMain$.runManaged(Main.scala:57)
	  at sbt.xMain.run(Main.scala:29)
	  at xsbt.boot.Launch$$anonfun$run$1.apply(Launch.scala:109)
	  at xsbt.boot.Launch$.withContextLoader(Launch.scala:128)
	  at xsbt.boot.Launch$.run(Launch.scala:109)
	  at xsbt.boot.Launch$$anonfun$apply$1.apply(Launch.scala:35)
	  at xsbt.boot.Launch$.launch(Launch.scala:117)
	  at xsbt.boot.Launch$.apply(Launch.scala:18)
	  at xsbt.boot.Boot$.runImpl(Boot.scala:41)
	  at xsbt.boot.Boot$.main(Boot.scala:17)
	  at xsbt.boot.Boot.main(Boot.scala:-1)

"pool-118-thread-1@17624" prio=5 tid=0x45c nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	  at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
	  at sbt.ConcurrentRestrictions$$anon$4.take(ConcurrentRestrictions.scala:188)
	  at sbt.Execute.next$1(Execute.scala:85)
	  at sbt.Execute.processAll(Execute.scala:88)
	  at sbt.Execute.runKeep(Execute.scala:68)
	  at sbt.EvaluateTask$.liftedTree1$1(EvaluateTask.scala:359)
	  at sbt.EvaluateTask$.run$1(EvaluateTask.scala:358)
	  at sbt.EvaluateTask$.runTask(EvaluateTask.scala:378)
	  at sbt.EvaluateTask$$anonfun$apply$1$$anonfun$apply$3.apply(EvaluateTask.scala:279)
	  at sbt.EvaluateTask$$anonfun$apply$1$$anonfun$apply$3.apply(EvaluateTask.scala:279)
	  at scala.Option$WithFilter.map(Option.scala:206)
	  at sbt.EvaluateTask$$anonfun$apply$1.apply(EvaluateTask.scala:279)
	  at sbt.EvaluateTask$$anonfun$apply$1.apply(EvaluateTask.scala:278)
	  at sbt.EvaluateTask$.withStreams(EvaluateTask.scala:314)
	  at sbt.EvaluateTask$.apply(EvaluateTask.scala:278)
	  at sbt.Extracted.runTask(Extracted.scala:44)
	  at sbtbuildinfo.BuildInfo$BuildInfoTask.entry(BuildInfo.scala:73)
	  at sbtbuildinfo.BuildInfo$BuildInfoTask$$anonfun$2.apply(BuildInfo.scala:63)
	  at sbtbuildinfo.BuildInfo$BuildInfoTask$$anonfun$2.apply(BuildInfo.scala:63)
	  at scala.collection.TraversableLike$$anonfun$flatMap$1.apply(TraversableLike.scala:251)
	  at scala.collection.TraversableLike$$anonfun$flatMap$1.apply(TraversableLike.scala:251)
	  at scala.collection.immutable.List.foreach(List.scala:318)
	  at scala.collection.TraversableLike$class.flatMap(TraversableLike.scala:251)
	  at scala.collection.AbstractTraversable.flatMap(Traversable.scala:105)
	  at sbtbuildinfo.BuildInfo$BuildInfoTask.makeFile(BuildInfo.scala:63)
	  at sbtbuildinfo.BuildInfo$BuildInfoTask.file(BuildInfo.scala:31)
	  at sbtbuildinfo.BuildInfo$.apply(BuildInfo.scala:11)
	  at sbtbuildinfo.BuildInfoPlugin$$anonfun$buildInfoScopedSettings$1.apply(BuildInfoPlugin.scala:43)
	  at sbtbuildinfo.BuildInfoPlugin$$anonfun$buildInfoScopedSettings$1.apply(BuildInfoPlugin.scala:43)
	  at scala.Function1$$anonfun$compose$1.apply(Function1.scala:47)
	  at sbt.$tilde$greater$$anonfun$$u2219$1.apply(TypeFunctions.scala:40)
	  at sbt.std.Transform$$anon$4.work(System.scala:63)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
	  at sbt.Execute.work(Execute.scala:237)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.ConcurrentRestrictions$$anon$4$$anonfun$1.apply(ConcurrentRestrictions.scala:159)
	  at sbt.CompletionService$$anon$2.call(CompletionService.scala:28)
	  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:1142)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-8@17650" prio=5 tid=0x46c nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at sbinary.EOF$.eof(io.scala:5)
	  at sbinary.JavaInput.readByte(io.scala:70)
	  at sbinary.StandardPrimitives$class.sbinary$StandardPrimitives$$readUnsigned(javaprotocol.scala:6)
	  at sbinary.StandardPrimitives$IntFormat$.reads(javaprotocol.scala:32)
	  at sbinary.StandardPrimitives$IntFormat$.reads(javaprotocol.scala:30)
	  at sbinary.Operations$.read(operations.scala:9)
	  at sbinary.Generic$$anon$7.reads(generic.scala:91)
	  at sbinary.Operations$.read(operations.scala:9)
	  at sbinary.Operations$.fromFile(operations.scala:45)
	  at sbt.CacheIO$.fromFile(CacheIO.scala:25)
	  at sbt.Tracked$$anonfun$lastOutput$1.apply(Tracked.scala:36)
	  at sbt.Classpaths$$anonfun$doWork$1$1.apply(Defaults.scala:1515)
	  at sbt.Classpaths$$anonfun$doWork$1$1.apply(Defaults.scala:1509)
	  at sbt.Tracked$$anonfun$inputChanged$1.apply(Tracked.scala:60)
	  at sbt.Classpaths$.cachedUpdate(Defaults.scala:1532)
	  at sbt.Classpaths$$anonfun$updateTask$1.apply(Defaults.scala:1459)
	  at sbt.Classpaths$$anonfun$updateTask$1.apply(Defaults.scala:1411)
	  at scala.Function1$$anonfun$compose$1.apply(Function1.scala:47)
	  at sbt.$tilde$greater$$anonfun$$u2219$1.apply(TypeFunctions.scala:40)
	  at sbt.std.Transform$$anon$4.work(System.scala:63)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
	  at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
	  at sbt.Execute.work(Execute.scala:237)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
	  at sbt.ConcurrentRestrictions$$anon$4$$anonfun$1.apply(ConcurrentRestrictions.scala:159)
	  at sbt.CompletionService$$anon$2.call(CompletionService.scala:28)
	  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:1142)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-7@17649" prio=5 tid=0x46b nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-6@17648" prio=5 tid=0x46a nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-5@17647" prio=5 tid=0x469 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-4@17646" prio=5 tid=0x468 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-3@17645" prio=5 tid=0x467 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-2@17644" prio=5 tid=0x466 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-119-thread-1@17643" prio=5 tid=0x465 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-9@17632" prio=5 tid=0x464 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-8@17631" prio=5 tid=0x463 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-7@17630" prio=5 tid=0x462 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-6@17629" prio=5 tid=0x461 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-5@17628" prio=5 tid=0x460 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-4@17627" prio=5 tid=0x45f nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"pool-118-thread-3@17626" prio=5 tid=0x45e nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"process reaper@12963" daemon prio=10 tid=0x2af nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	  at java.lang.Thread.run(Thread.java:745)

"Finalizer@17670" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	  at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler@17671" daemon prio=10 tid=0x2 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.Object.wait(Object.java:502)
	  at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	  at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"Signal Dispatcher@17669" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

Note that evalPluginDef spawns the tasks in the val evaluated = ... line in:

  def evalPluginDef(log: Logger)(pluginDef: BuildStructure, state: State): PluginData =
    {
      val root = ProjectRef(pluginDef.root, Load.getRootProject(pluginDef.units)(pluginDef.root))
      val pluginKey = pluginData
      val config = extractedTaskConfig(Project.extract(state), pluginDef, state)
      val evaluated = apply(pluginDef, ScopedKey(pluginKey.scope, pluginKey.key), state, root, config)
      val (newS, result) = evaluated getOrElse sys.error("Plugin data does not exist for plugin definition at " + pluginDef.root)
      Project.runUnloadHooks(newS) // discard states
      processResult(result, log)
    }

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions