Merge pull request #5812 from eatkins/gc-monitor

Add gc monitor to warn users about excessive gc

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 {