Add gc monitor to warn users about excessive gc

It is not uncommon in large projects for the jvm to silently be running
frequent full gcs in the background. This can slow progress to a crawl.
Usually the fix is to bump the -Xmx parameter but if the users do not
realize that their tasks are slow because of gc thrashing, they may not
think to do that. This PR adds a monitor that hooks into the jvm's event
notification system to keep track of how much time is spent in GC. If
the ratio of the amount of time in gc to the total elapsed time exceeds
some threshold, we emit a warning.

I was motivated to do this because publishLocal can take forever in the
zinc project because a 1G heap isn't big enough.

main/src/main/scala/sbt/MainLoop.scala

@@ -153,6 +153,7 @@ object MainLoop {
     val superShellThreshold =
       state.get(Keys.superShellThreshold.key).getOrElse(SysProp.supershellThreshold)
     val taskProgress = new TaskProgress(superShellSleep, superShellThreshold)
+    val gcMonitor = if (SysProp.gcMonitor) Some(new sbt.internal.GCMonitor(state.log)) else None
     try {
       ErrorHandling.wideConvert {
         state
@@ -193,6 +194,7 @@ object MainLoop {
         state.log.error("\n")
         state.handleError(oom)
     } finally {
+      gcMonitor.foreach(_.close())
       context.close()
       taskProgress.close()
     }

main/src/main/scala/sbt/internal/GCMonitor.scala

@@ -0,0 +1,68 @@
+/*
+ * sbt
+ * Copyright 2011 - 2018, Lightbend, Inc.
+ * Copyright 2008 - 2010, Mark Harrah
+ * Licensed under Apache License 2.0 (see LICENSE)
+ */
+
+package sbt.internal
+
+import javax.management.{ Notification, NotificationEmitter, NotificationListener }
+import java.lang.management.ManagementFactory
+import java.lang.management.GarbageCollectorMXBean
+import java.util.concurrent.LinkedBlockingQueue
+import java.util.concurrent.atomic.{ AtomicLong, AtomicReference }
+import scala.concurrent.duration._
+import scala.collection.JavaConverters._
+import scala.util.Try
+import sbt.util.Logger
+
+class GCMonitor(logger: Logger) extends AutoCloseable {
+  private[this] val window =
+    Try(System.getProperty("sbt.gc.monitor.window", "10").toInt).getOrElse(10).seconds
+  private[this] val ratio =
+    Try(System.getProperty("sbt.gc.monitor.ratio", "0.5").toDouble).getOrElse(0.5)
+  private[this] def handleNotification(
+      notification: Notification,
+      bean: GarbageCollectorMXBean,
+      info: (LinkedBlockingQueue[(Deadline, Long)], AtomicLong, AtomicReference[Deadline])
+  ): Unit = {
+    val (queue, lastCollectionTime, lastWarned) = info
+    val now = Deadline.now
+    val collectionTime = bean.getCollectionTime
+    val elapsed = collectionTime - lastCollectionTime.getAndSet(collectionTime)
+    queue.removeIf { case (d, _) => (d + window).isOverdue }
+    queue.add(now -> elapsed)
+    val total = queue.asScala.foldLeft(0L) { case (total, (_, t)) => total + t }
+    if ((total > window.toMillis * ratio) && (lastWarned.get + window).isOverdue) {
+      lastWarned.set(now)
+      val msg = s"${total / 1000.0} seconds of the last $window were spent in garbage " +
+        "collection. You may want to increase the project heap size for better performance."
+      logger.warn(msg)
+    }
+  }
+
+  val removers = ManagementFactory.getGarbageCollectorMXBeans.asScala.flatMap {
+    case e: NotificationEmitter =>
+      val queue = new LinkedBlockingQueue[(Deadline, Long)]
+      val lastCollectionTime = new AtomicLong(0L)
+      val lastLogged = new AtomicReference(Deadline(0.millis))
+      val listener: NotificationListener =
+        (notification, queue) =>
+          queue match {
+            case (
+                q: LinkedBlockingQueue[(Deadline, Long)] @unchecked,
+                lct: AtomicLong,
+                ll: AtomicReference[Deadline] @unchecked
+                ) =>
+              handleNotification(notification, e, (q, lct, ll))
+            case _ =>
+          }
+      e.addNotificationListener(listener, null, (queue, lastCollectionTime, lastLogged))
+      Some(() => e.removeNotificationListener(listener))
+    case _ => None
+  }
+  override def close(): Unit = {
+    removers.foreach(_.apply())
+  }
+}

main/src/main/scala/sbt/internal/SysProp.scala

@@ -60,6 +60,17 @@ object SysProp {
       case _ => default
     }
 
+  def double(name: String, default: Double): Double =
+    sys.props.get(name) match {
+      case Some(str) =>
+        try {
+          str.toDouble
+        } catch {
+          case NonFatal(_) => default
+        }
+      case _ => default
+    }
+
   // System property style:
   //   1. use sbt. prefix
   //   2. prefer short nouns
@@ -137,6 +148,10 @@ object SysProp {
         ("ms", 6)
     }
 
+  def gcMonitor: Boolean = getOrTrue("sbt.gc.monitor")
+  def gcWindow: FiniteDuration = int("sbt.gc.monitor.window", 10).seconds
+  def gcRatio: Double = double("sbt.gc.monitor.ratio", 0.5)
+
   /** Generate build.properties if missing. */
   def genBuildProps: Boolean =
     booleanOpt("sbt.genbuildprops") match {