Skip to content

Failure in incremental bootstrapped builds #4929

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

Closed
Blaisorblade opened this issue Aug 10, 2018 · 8 comments
Closed

Failure in incremental bootstrapped builds #4929

Blaisorblade opened this issue Aug 10, 2018 · 8 comments

Comments

@Blaisorblade
Copy link
Contributor

Blaisorblade commented Aug 10, 2018

Since a few days (I guess since c9f782c and #4857), I get non-repeatably traces such as, which are only worked around by a clean compilation:

info] No tests to run for dotty-sbt-bridge-bootstrapped / Test / testOnly
[error] ## Exception when compiling 73 sources to /Users/pgiarrusso/git/dotty/compiler/../out/bootstrap/dotty-compiler-bootstrapped/scala-0.10/test-classes
[error] No such file or directory
[error] java.io.UnixFileSystem.createFileExclusively(Native Method)
[error] java.io.File.createTempFile(File.java:2024)
[error] dotty.tools.sbtplugin.TastyFileManager.move(TastyFileManager.scala:59)
[error] dotty.tools.sbtplugin.TastyFileManager.$anonfun$delete$2(TastyFileManager.scala:33)
[error] scala.collection.IndexedSeqOptimized.foreach(IndexedSeqOptimized.scala:32)
[error] scala.collection.IndexedSeqOptimized.foreach$(IndexedSeqOptimized.scala:29)
[error] scala.collection.mutable.ArrayOps$ofRef.foreach(ArrayOps.scala:194)
[error] dotty.tools.sbtplugin.TastyFileManager.delete(TastyFileManager.scala:32)
[error] xsbti.compile.WrappedClassFileManager.delete(WrappedClassFileManager.java:41)
[error] sbt.internal.inc.Incremental$.prune(Incremental.scala:123)
[error] sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:107)
[error] sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:57)
[error] sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:61)
[error] sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1443)
[error] sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1417)

Apparently, that's because a single TastyFileManager can be reused after complete is called: then, we use tempDir after complete has removed it. Logs with instrumentation (after the fix) witnessing this (beware the different instance pointers):

[info] Packaging /Users/pgiarrusso/git/dotty/compiler/target/scala-2.12/dotty-compiler_2.12-0.10.0-bin-SNAPSHOT-nonbootstrapped.jar ...
[info] Done packaging.
ClassFileManager.tempDir: creating /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup5376822862912513440 in dotty.tools.sbtplugin.TastyFileManager@2f7fcfe4
ClassFileManager.delete: maybe using /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup5376822862912513440 in dotty.tools.sbtplugin.TastyFileManager@2f7fcfe4
[info] Compiling 1 Scala source to /Users/pgiarrusso/git/dotty/library/../out/bootstrap/dotty-library-bootstrapped/scala-0.10/classes ...
[info] Done compiling.
ClassFileManager.complete(true): deleting /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup5376822862912513440 from dotty.tools.sbtplugin.TastyFileManager@2f7fcfe4
ClassFileManager.tempDir: creating /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup2539411289080354206 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6
ClassFileManager.delete: maybe using /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup2539411289080354206 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6
[info] Compiling 2 Scala sources to /Users/pgiarrusso/git/dotty/compiler/../out/bootstrap/dotty-compiler-bootstrapped/scala-0.10/classes ...
[info] Done compiling.
ClassFileManager.complete(true): deleting /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup2539411289080354206 from dotty.tools.sbtplugin.TastyFileManager@cb2bec6
ClassFileManager.tempDir: creating /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup7561286245069696276 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6
ClassFileManager.delete: maybe using /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup7561286245069696276 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6
[info] Compiling 1 Scala source to /Users/pgiarrusso/git/dotty/compiler/../out/bootstrap/dotty-compiler-bootstrapped/scala-0.10/test-classes ...
[info] Done compiling.
ClassFileManager.complete(true): deleting /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup7561286245069696276 from dotty.tools.sbtplugin.TastyFileManager@cb2bec6

IIUC, @jvican suggested that the lifecycle of external ClassFileManager (which TastyFileManager is) might be different from the one of internal ones. That would explain why this bug appears here but not in TransactionalClassFileManager (which uses the same pattern).

Blaisorblade added a commit to dotty-staging/dotty that referenced this issue Aug 10, 2018
Recreate `tempDir` if we're reused after `complete` was called and deleted the
existing `tempDir`.

The output in scala#4929 was produced by this commit.
@allanrenucci
Copy link
Contributor

Looking at the logs you posted, I don’t fully understand the life-cycle of the external class file manager. I see two instances of the TASTY file manager, so I’m not sure when an instance is reused. Can we figure this out before committing to any fix?

Sorry, I cannot look into this currently. I’m on vacation with limited access to internet and a computer.

@Blaisorblade
Copy link
Contributor Author

@jvican answered my questions and approved the fix in #4930. Since this is hard to workaround and you're on vacation (enjoy!), do you mind if I merge this quickfix but reopen the issue for further investigation when you're back? See also below for an answer to your question.

I see two instances of the TASTY file manager, so I’m not sure when an instance is reused.

There are two instances, but we see deletion and reuse on the same instance in these lines:

ClassFileManager.complete(true): deleting /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup2539411289080354206 from dotty.tools.sbtplugin.TastyFileManager@cb2bec6
ClassFileManager.tempDir: creating /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup7561286245069696276 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6
ClassFileManager.delete: maybe using /var/folders/kb/bmw9vpm93vl3d5tyc15v8rp40000gn/T/backup7561286245069696276 in dotty.tools.sbtplugin.TastyFileManager@cb2bec6

And if reuse is possible at all, we need to reinitialize the tempDir.

Based on the output, it also seems we have one file manager for dotty/library and one for dotty/compiler, which is reused for compile and test:compile. That makes sense because of the setup in https://github.com/lampepfl/dotty/blob/17e892194d6c29ce6601966b2508a404bb27feec/sbt-dotty/src/dotty/tools/sbtplugin/DottyPlugin.scala#L115, which seems forced by sbt/zinc's APIs.

I found the zinc code calling complete in https://github.com/sbt/zinc/blob/f5114ea25516c49a87e184d89bd8b0accd0c6599/internal/zinc-core/src/main/scala/sbt/internal/inc/Incremental.scala#L132-L142, and that shows we only call complete after a cycle of incremental compilations.

@allanrenucci allanrenucci self-assigned this Aug 11, 2018
@allanrenucci allanrenucci added this to the 0.10 Tech Preview milestone Aug 11, 2018
Blaisorblade added a commit to dotty-staging/dotty that referenced this issue Aug 11, 2018
Recreate `tempDir` if we're reused after `complete` was called and deleted the
existing `tempDir`.

The output in scala#4929 was produced by this commit.
Blaisorblade added a commit that referenced this issue Aug 11, 2018
Recreate `tempDir` if the TastyFileManager is reused after `complete` was called
and deleted the existing `tempDir`.
@Blaisorblade Blaisorblade reopened this Aug 11, 2018
@allanrenucci
Copy link
Contributor

Note to myself: generatedTastyFiles and movedTastyFiles should be cleared on complete
https://github.com/lampepfl/dotty/blob/e8f137cab384bfa96d94d2817a2962bb9282298b/sbt-dotty/src/dotty/tools/sbtplugin/TastyFileManager.scala#L31-L32

@allanrenucci
Copy link
Contributor

allanrenucci commented Aug 20, 2018

I cannot reproduce the original issue. I set up a sbt project with the Dotty plugin enabled and some instrumentation.

diff --git a/sbt-dotty/src/dotty/tools/sbtplugin/TastyFileManager.scala b/sbt-dotty/src/dotty/tools/sbtplugin/TastyFileManager.scala
index 38d4d029f..448e70688 100644
--- a/sbt-dotty/src/dotty/tools/sbtplugin/TastyFileManager.scala
+++ b/sbt-dotty/src/dotty/tools/sbtplugin/TastyFileManager.scala
@@ -20,18 +20,13 @@ import scala.collection.mutable
  *  temporary directory as class files.
  */
 final class TastyFileManager extends ClassFileManager {
-  private[this] var _tempDir: File = null
-  private[this] def tempDir = {
-    if (_tempDir == null) {
-      _tempDir = Files.createTempDirectory("backup").toFile
-    }
-    _tempDir
-  }
+  private[this] val tempDir = Files.createTempDirectory("backup").toFile
 
   private[this] val generatedTastyFiles = new mutable.HashSet[File]
   private[this] val movedTastyFiles = new mutable.HashMap[File, File]
 
   override def delete(classes: Array[File]): Unit = {
+    println(s"ClassFileManager.delete: $this")
     val tasties = tastyFiles(classes)
     val toBeBackedUp = tasties
       .filter(t => t.exists && !movedTastyFiles.contains(t) && !generatedTastyFiles(t))
@@ -40,18 +35,17 @@ final class TastyFileManager extends ClassFileManager {
     IO.deleteFilesEmptyDirs(tasties)
   }
 
-  override def generated(classes: Array[File]): Unit =
+  override def generated(classes: Array[File]): Unit = {
+    println(s"ClassFileManager.generated: $this")
     generatedTastyFiles ++= tastyFiles(classes)
+  }
 
   override def complete(success: Boolean): Unit = {
+    println(s"ClassFileManager.complete($success): $this")
     if (!success) {
       IO.deleteFilesEmptyDirs(generatedTastyFiles)
       for ((orig, tmp) <- movedTastyFiles) IO.move(tmp, orig)
     }
-    if (_tempDir != null) {
-      IO.delete(tempDir)
-      _tempDir = null
-    }
   }

The TastyFileManger is never reused across multiple compilations:

sbt:root> playground/compile
ClassFileManager.delete: dotty.tools.sbtplugin.TastyFileManager@1c0a2ed1
[info] Compiling 1 Scala source to /Users/renucci/workspace/playground/playground/target/scala-0.10/classes ...
[info] Done compiling.
ClassFileManager.generated: dotty.tools.sbtplugin.TastyFileManager@1c0a2ed1
ClassFileManager.complete(true): dotty.tools.sbtplugin.TastyFileManager@1c0a2ed1
[success] Total time: 1 s, completed Aug 20, 2018 11:39:28 AM
sbt:root> playground/compile
ClassFileManager.complete(true): dotty.tools.sbtplugin.TastyFileManager@317d2313
[success] Total time: 0 s, completed Aug 20, 2018 11:39:31 AM
sbt:root> playground/compile
ClassFileManager.complete(true): dotty.tools.sbtplugin.TastyFileManager@302e6c57
[success] Total time: 0 s, completed Aug 20, 2018 11:39:32 AM

It is only reused when a compilation has multiple incremental steps. But this is expected and should not be an issue since the complete callback (which deletes the directory) is called only once at the end of the compilation:

sbt:root> playground/compile
ClassFileManager.delete: dotty.tools.sbtplugin.TastyFileManager@91b1d0e
[info] Compiling 1 Scala source to /Users/renucci/workspace/playground/playground/target/scala-0.10/classes ...
[info] Done compiling.
ClassFileManager.generated: dotty.tools.sbtplugin.TastyFileManager@91b1d0e
ClassFileManager.delete: dotty.tools.sbtplugin.TastyFileManager@91b1d0e
[info] Compiling 1 Scala source to /Users/renucci/workspace/playground/playground/target/scala-0.10/classes ...
[info] Done compiling.
ClassFileManager.generated: dotty.tools.sbtplugin.TastyFileManager@91b1d0e
ClassFileManager.complete(true): dotty.tools.sbtplugin.TastyFileManager@91b1d0e
[success] Total time: 0 s, completed Aug 20, 2018 11:39:39 AM

@Blaisorblade Do you know how I could reproduce the crash you reported?

@Blaisorblade
Copy link
Contributor Author

I forget, but assuming what I wrote is accurate:

Based on the output, it also seems we have one file manager for dotty/library and one for dotty/compiler, which is reused for compile and test:compile.

the manager is reused for compile and test:compile, so it's expected your tests won't run into problems. I agree multiple incremental steps aren't a problem.

That suggests having different managers for compile and test:compile might be an alternative fix, but I'd double-check with @jvican.

@allanrenucci
Copy link
Contributor

allanrenucci commented Aug 20, 2018

the manager is reused for compile and test:compile

Right, I was able to reproduce.

That suggests having different managers for compile and test:compile might be an alternative fix

Yes, I think that's the proper fix. A project and its tests should be treated as two separate modules.

If I have a sbt project with two modules, Zinc already uses two separate TastyFileManager

@allanrenucci
Copy link
Contributor

Looking more into it, it seems that the external class file manager must be reusable.

The reason we get multiple instances of the TastyFileManager is sbt taskKey evaluation semantic. Here the task is evaluated every time we call compile, so we get a new class file manager each time. But if you call test:compile which depends on compile, it will also be evaluated once and thus you share the same class file manager for the compile and test:compile steps.

Here is the code in Zinc that deals with class file manager. For the default class file manager, getDefaultClassFileManager is called which returns a new instance of a class file manager. The external class file manager however, is extracted from the incOptions. So you might not get a new one depending on when the incOptions were generated

@Blaisorblade
Copy link
Contributor Author

@allanrenucci Yes, that fits with my understanding and @jvican's comments on Gitter.

(if that's your question the answer is yes, the external class file manager is reused because ExternalHooks requires an instance of it)

allanrenucci added a commit that referenced this issue Aug 20, 2018
Fix #4929: Make TastyFileManager reusable
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants