Add file watching to bloop #125

jvican · 2017-12-09T23:55:04Z

For information on why it's done the way it is, commit messages are rich in details.

This PR adds file watching to bloop and also happens to do a much needed rework of the logger infrastructure to make it more modular, solid and flexible to our needs.

It is still a WIP since I'd like to add one or two more file watching tests, but the one it is right now proves that it works (it's kind of cool we can programmatically test this without emulating a file system of our own).

This removes `prependCompile` from the test command -- unlike before, where we were reusing the `Interpreter` to make sure we compiled the project before running tests, this time we need to compile and test in a every watch cycle, so the logic needs to be handled by the test implementation in `Interpreter`.

This makes it clear that this is the default logger, while `Logger` is just the interface.

Per build loggers allow bloop to log project specific logs into the console or a possible file backing without having interferences from other projects being compiled by bloop. This change is instrumental for more fundamental improvements to bloop in the near future.

`CommonOptions` is required in the state so that we can modify the logger every time the common options change. This can happen when users pass in command redirecting input and output, or when bloop is run by a nailgun server. This is also extremely important for testing. The reconfiguration of logging is not done in this PR, but will be done in a follow up.

@Duhemm

Every time we change the common options in `State`, via an action, the loggers have to update their backings so that logs are redirected to those streams. This is especially important because of Nailgun. Until this PR, we were changing the common options in the `Cli` entrypoint but we were not updating the loggers with those options which meant that we were subject to losing logs. I think this fixes the problem that @Duhemm has been experiencing several times with Nailgun, but on top of that it allows users to redirect output streams whenever they want (though it's a feature that should not be used very frequently). As a plus, we get a nice way to test bloop: we can always redirect output streams at the test call site and see what the complete output of it is.

jvican · 2017-12-09T23:56:05Z

Fixes #7, by the way.

Now that we can programmatically get the output of bloop, our test for file watching the compilation of a project works. This PR also removes scalog as a library dependency.

Duhemm · 2017-12-10T15:07:22Z

backend/src/main/scala/bloop/logging/BloopLogger.scala

+    ()
+  }
+
+  type LoggerUpdateKey = (BloopLogger, OutputStream)


That's not used anywhere?

Duhemm · 2017-12-10T15:16:10Z

backend/src/main/scala/bloop/logging/BloopLogger.scala

+        logger.debug(s"Update of out ($out) in logger ${logger.name} is cached.")
+      case _ => swapAndCache
+    }
+  }


I'm not sure if I understood everything completely here. You're keeping track of what output stream each logger uses, right? And before changing the output stream, you're checking whether the new output stream is different from the current output stream? I've been a bit confused by the name updateCache. That's just a suggestion, but I'd have called that currentOutputStreams or loggerToStream maybe.

Amazing work cleaning up this L4J madness!

That's just a suggestion, but I'd have called that currentOutputStreams or loggerToStream maybe.

Good suggestion!

Duhemm · 2017-12-10T15:17:18Z

benchmarks/src/main/scala/bloop/HotBloopBenchmark.scala

@@ -41,7 +40,8 @@ class HotBloopBenchmark {
    val configDir = Files.createDirectory(tempDir.resolve(".bloop-config"))

    val path = Paths.get(s"../frontend/src/test/resources/projects")
-    val state = ProjectHelpers.loadTestProject(path, project, Logger.get)
+    val logger = BloopLogger(path.toRealPath().toAbsolutePath().toString)


I think that this logger is not used anywhere

Duhemm · 2017-12-10T15:26:40Z

frontend/src/main/scala/bloop/cli/Commands.scala

      scalacstyle: Boolean = false,
+      @ExtraName("w")
+      @HelpMessage("If set, run a command whenever projects' source files change.")


run this command maybe?

Duhemm · 2017-12-10T15:28:17Z

frontend/src/main/scala/bloop/engine/Interpreter.scala

    def logAndTime[T](cliOptions: CliOptions, action: => T): T =
-      logger.verboseIf(cliOptions.verbose) { timed(state.logger) { action } }
+      logger.verboseIf(cliOptions.verbose) { timed(state0.logger) { action } }


timed(logger), no?

Duhemm · 2017-12-10T15:32:28Z

frontend/src/main/scala/bloop/engine/Interpreter.scala

+      logger.verboseIf(cliOptions.verbose) { timed(state0.logger) { action } }
+    def updateState(state: State, commonOptions: CommonOptions): State = {
+      State.updateLogger(state.logger, commonOptions)
+      val logger = BloopLogger(state.logger.name)


Why do you need to create a new logger? If I use state.logger again, it won't have the right output stream?

We need a new logger because log4j forces us to call the logger again to get the changes we just made, that involves calling LogManager.getLogger (which is done in the constructor of BloopLogger).

You should think of the logger as immutable, and that's why it's important to import it always from the current state.

We do it because we need to call LogManager.getLogger every time we modify it (because apparentely changes are not propagated by log4j).

Duhemm · 2017-12-10T15:33:18Z

frontend/src/main/scala/bloop/engine/Interpreter.scala

    action match {
-      case Exit(exitStatus) if state.status.isOk => state.copy(status = exitStatus)
-      case Exit(exitStatus) => state
+      case Exit(exitStatus) if state0.status.isOk => state0.copy(status = exitStatus)


Why not use mergeStatus?

Duhemm · 2017-12-10T15:58:07Z

frontend/src/main/scala/bloop/engine/State.scala

+      val jars = Paths.getCacheDirectory("scala-jars")
+      singleCompilerCache = new CompilerCache(provider, jars, logger)
+      singleCompilerCache
+    }


So in the end you may still get a CompilerCache that has a different Logger than the one that's passed to getCompilerCache?

The compilerCache needs a Logger only if we're asking for a compiler for which we don't have a compiler bridge yet (IIRC). Maybe that we could do something here to avoid this weird situation with the compiler cache and the logger, but I'm not sure what.

Yes, this is a tricky part, the compiler cache is not owned by a build in particular, but we still need a logger. As I wanted the first build to trigger the compilation to register the logs of the compiler cache, I did it this way. I agree it's not ideal, but the other solution is to create a global bloop logger that we pass around.

However, this will complicate things for not much in return and has some design issues. For example, for every compile command that the server receive we need to swap the output streams. This can cause race conditions and misbehaviours.

Duhemm · 2017-12-10T15:59:52Z

frontend/src/main/scala/bloop/io/SourceWatcher.scala

+import io.methvin.watcher.DirectoryChangeEvent.EventType
+import io.methvin.watcher.{DirectoryChangeEvent, DirectoryWatcher}
+
+final class SourceWatcher(paths0: Seq[Path], logger: Logger) {


Do all the paths have to be directories? Maybe rename to watchedDirectories, if that's the case.

Yes, I assume so. I mimicked the name that DirectoryWatcher uses, but it looks like it only accepts directories.

Duhemm · 2017-12-10T16:03:05Z

frontend/src/test/scala/bloop/engine/InterpreterSpec.scala

-    val cliOptions = defaultCli.copy(common = defaultCli.common.copy(out = newOut))
-    val action = Run(Commands.Projects(dotGraph = true, cliOptions), Exit(ExitStatus.Ok))
+    defaultCli.copy(common = state.commonOptions.copy(out = newOut)) -> inMemory
+  }


There could be more deduplication, but there's a good balance.

Duhemm · 2017-12-11T13:40:46Z

frontend/src/test/scala/bloop/engine/FileWatchingSpec.scala

+class FileWatchingSpec {
+  @scala.annotation.tailrec
+  final def readCompilingLines(target: Int, msg: String, out: ByteArrayOutputStream): Int = {
+    Thread.sleep(100) // Wait 10ms for the OS's file system


Yes, to avoid reading all the time until it appears (since it happens concurrently).

Sorry I keep being unclear. The code says 100ms, the comment says 10.

I'll make an effort 💃

Hahaha, makes sense, removing it 😄

Duhemm · 2017-12-11T13:44:31Z

frontend/src/test/scala/bloop/engine/FileWatchingSpec.scala

+
+class FileWatchingSpec {
+  @scala.annotation.tailrec
+  final def readCompilingLines(target: Int, msg: String, out: ByteArrayOutputStream): Int = {


I'd rename readCompilingLines to outputContains, and target to times or expected. WDYT?

Sounds goooooooood.

This is more in-line with the result of doing `reset`, plus it fixes an issue with compilation tasks complaining about the results cache being un-initialized.

Latest nailgun has a fix wrt reading that may fix #92. Let's try to see if it does.

Duhemm · 2017-12-12T08:20:37Z

frontend/src/main/scala/bloop/engine/Interpreter.scala

-      case Exit(exitStatus) if state.status.isOk => state.copy(status = exitStatus)
-      case Exit(exitStatus) => state
+      case Exit(exitStatus) if state0.status.isOk => state0.mergeStatus(exitStatus)
+      case Exit(exitStatus) => state0


Couldn't we just have case Exit(exitStatus) => state0.mergeStatus(exitStatus) ?

No, because the implementation of mergeStatus is very naive at this point and has to improve. When there are two errors, it's best to at least report the first one and not a weird mix for two. I plan to improve this in a future PR

This is often used to stop file watching. Before, we were not making sure that we persisted all the states. Now we do.

Duhemm

Two small comments and then let's !

Duhemm · 2017-12-12T12:31:48Z

frontend/src/test/scala/bloop/engine/FileWatchingSpec.scala

+    implicit val context = state.executionContext
+    val testFuture = scala.concurrent.Future { testAction(ctx, workerThread) }
+    try Await.ready(testFuture, duration.Duration(15, duration.SECONDS))
+    catch { case t: Throwable => println(s"LOGS WERE ${bloopOut.toString("UTF-8")}"); throw t }


Is the println a leftover from debugging?

No, it's something that should help us debug in case these tests fail 😄.

Duhemm · 2017-12-12T12:34:11Z

backend/src/main/scala/bloop/logging/BloopLogger.scala

+
+  def update(logger: BloopLogger, out: OutputStream): Unit = {
+    def swapAndCache: Unit = {
+      logger.debug(s"Logger ${logger.name} has not been updated to use $out.")


The message reads a bit like a failure, rather than an announcement of what bloop is about to do. Maybe say logger has not been updated yet or updating logger to use?

jvican · 2017-12-12T12:45:10Z

Done, check the last commit 😄.

…into topic/file-watching

Merge upstream changes

jvican added 10 commits December 8, 2017 14:03

Make init of compiler caches lazy

3238521

Add scalog to backend

f027196

Force compilation before watching

72a4716

Add wip test for file watching

a1fd8d3

Add insane infrastructure for log4j

c3ec75a

Rename Log4J to BloopLogger

f6fac82

This makes it clear that this is the default logger, while `Logger` is just the interface.

jvican added the feature label Dec 9, 2017

jvican added 3 commits December 10, 2017 09:53

Make benchmarks compile with changes in test suite

4444dea

Make file watching test work

bec772b

Now that we can programmatically get the output of bloop, our test for file watching the compilation of a project works. This PR also removes scalog as a library dependency.

Separate file watching tests from normal tests

5da69d8

jvican force-pushed the topic/file-watching branch from 32f8759 to 5da69d8 Compare December 10, 2017 08:53

Duhemm reviewed Dec 10, 2017

View reviewed changes

Add file watching tests for compile and test

4e25b98

There could be more deduplication, but there's a good balance.

Duhemm reviewed Dec 11, 2017

View reviewed changes

jvican mentioned this pull request Dec 11, 2017

Return EmptyResult by default in ResultsCache #126

Closed

jvican and others added 3 commits December 11, 2017 17:03

Address Martin's feedback

7b83973

Return EmptyResult by default in ResultsCache

f803800

This is more in-line with the result of doing `reset`, plus it fixes an issue with compilation tasks complaining about the results cache being un-initialized.

Change comment to reflect the reality [CI SKIP]

9152eeb

jvican force-pushed the topic/file-watching branch from 0bd7e38 to 9152eeb Compare December 11, 2017 16:03

Remove unnecessary file deletion in file watching

7ca3783

jvican mentioned this pull request Dec 11, 2017

Add support for file watching ~ #7

Closed

Update to latest nailgun

60e6e78

Latest nailgun has a fix wrt reading that may fix #92. Let's try to see if it does.

This was referenced Dec 11, 2017

Fix #75: Add configure command to set up global state #127

Merged

Add better testing for compile and test #123

Closed

Duhemm reviewed Dec 12, 2017

View reviewed changes

jvican and others added 4 commits December 12, 2017 12:31

Make some changes to detect if exceptions are thrown

2de3aff

Fix cyclic recursion in Cli

6bae1dc

Persist all projects when CTRL-C is used in cli

f52c5cb

This is often used to stop file watching. Before, we were not making sure that we persisted all the states. Now we do.

Merge branch 'master' into topic/file-watching

c2bc7a9

jvican added this to the Bloop 0.1 milestone Dec 12, 2017

Duhemm requested changes Dec 12, 2017

View reviewed changes

jvican modified the milestone: Bloop 0.1 Dec 12, 2017

Improve log message in update cache

f2fc910

Merge branch 'topic/file-watching' of github.com:scalacenter/blossom …

2edda4e

…into topic/file-watching

Duhemm approved these changes Dec 12, 2017

View reviewed changes

Eing? What's up CI.

2713511

Duhemm merged commit eeca151 into master Dec 12, 2017

Duhemm deleted the topic/file-watching branch December 29, 2017 10:39

tgodzik pushed a commit to tgodzik/bloop that referenced this pull request Jul 5, 2023

Merge pull request scalacenter#125 from alexarchambault/merge-upstream

20d804f

Merge upstream changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add file watching to bloop #125

Add file watching to bloop #125

jvican commented Dec 9, 2017

jvican commented Dec 9, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

jvican Dec 11, 2017

jvican Dec 11, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

jvican Dec 11, 2017

jvican Dec 11, 2017

jvican Dec 11, 2017

Duhemm Dec 10, 2017

Duhemm Dec 10, 2017

jvican Dec 11, 2017

Duhemm Dec 10, 2017

jvican Dec 11, 2017

Duhemm Dec 10, 2017

Duhemm Dec 11, 2017

jvican Dec 11, 2017

Duhemm Dec 11, 2017

Duhemm Dec 11, 2017

jvican Dec 11, 2017

Duhemm Dec 11, 2017

jvican Dec 11, 2017

Duhemm Dec 12, 2017

jvican Dec 12, 2017

Duhemm left a comment

Duhemm Dec 12, 2017

jvican Dec 12, 2017

Duhemm Dec 12, 2017

jvican commented Dec 12, 2017

Add file watching to bloop #125

Add file watching to bloop #125

Conversation

jvican commented Dec 9, 2017

jvican commented Dec 9, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Duhemm left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jvican commented Dec 12, 2017