luke
/
sbt
mirror of https://github.com/sbt/sbt.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Set initial collection time in gc monitor 

The java GarbageCollectorMXBean.getCollectionTime returns the cumulative
amount of time the collector has run during the jvm session. The GC
monitor is tracking how much time has been spent in garbage collection
during each task evaluation run. In order for this calculation to work
correctly, it is necessary to set the initial elapsed time to the bean's
current collection time when we create the gc monitor. Without doing
this, we can get completely incorrect results that are reporting based
on the total gc time for the entire process, not just in the last 10
seconds.

Should fix https://github.com/sbt/sbt/issues/5818
This commit is contained in:
Ethan Atkins 2020-09-08 10:25:01 -07:00
parent a34181b078
commit 4e3d351e71
1 changed files with 12 additions and 22 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

34
main/src/main/scala/sbt/internal/GCMonitor.scala
View File

@ -22,20 +22,21 @@ class GCMonitor(logger: Logger) extends AutoCloseable {
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] val queue = new LinkedBlockingQueue[(FiniteDuration, Long)]
private[this] val lastWarned = new AtomicReference(Deadline(0.millis))
private[this] def handleNotification(
notification: Notification,
bean: GarbageCollectorMXBean,
info: (LinkedBlockingQueue[(Deadline, Long)], AtomicLong, AtomicReference[Deadline])
totalCollectionTime: AtomicLong
): Unit = {
val (queue, lastCollectionTime, lastWarned) = info
val now = Deadline.now
val now = notification.getTimeStamp.millis
val collectionTime = bean.getCollectionTime
val elapsed = collectionTime - lastCollectionTime.getAndSet(collectionTime)
queue.removeIf { case (d, _) => (d + window).isOverdue }
val elapsed = collectionTime - totalCollectionTime.getAndSet(collectionTime)
queue.removeIf { case (whenEventHappened, _) => now > whenEventHappened + window }
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)
lastWarned.set(Deadline.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)
@ -43,23 +44,12 @@ class GCMonitor(logger: Logger) extends AutoCloseable {
}
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))
case bean: NotificationEmitter =>
val elapsedTime = new AtomicLong(bean.getCollectionTime)
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))
(notification, _) => handleNotification(notification, bean, elapsedTime)
bean.addNotificationListener(listener, null, null)
Some(() => bean.removeNotificationListener(listener))
case _ => None
}
override def close(): Unit = {