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

Use logger rather than ConsoleOut for TaskTimings 

When running sbt -Dtask.timings=true, the task timings get printed to
the console which can overwrite the shell prompt. When we use a logger,
the timing lines are correctly separated from the prompt lines.
This commit is contained in:
Ethan Atkins 2019-10-05 13:10:01 -07:00
parent 22a9fd4de0
commit 367461e586
2 changed files with 16 additions and 6 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
main/src/main/scala/sbt/EvaluateTask.scala
View File

@ -245,7 +245,9 @@ object EvaluateTask {
case _ => None case _ => None
} }
val reporters = maker.map(_.progress) ++ progressReporter ++ val reporters = maker.map(_.progress) ++ progressReporter ++
(if (SysProp.taskTimings) new TaskTimings(reportOnShutdown = false) :: Nil else Nil) (if (SysProp.taskTimings)
new TaskTimings(reportOnShutdown = false, state.globalLogging.full) :: Nil
else Nil)
reporters match { reporters match {
case xs if xs.isEmpty => ExecuteProgress.empty[Task] case xs if xs.isEmpty => ExecuteProgress.empty[Task]
case xs if xs.size == 1 => xs.head case xs if xs.size == 1 => xs.head

18
main/src/main/scala/sbt/internal/TaskTimings.scala
View File

@ -8,7 +8,8 @@
package sbt package sbt
package internal package internal
import sbt.internal.util.{ RMap, ConsoleOut } import sbt.internal.util.{ ConsoleOut, RMap }
import sbt.util.{ Level, Logger }
/** /**
* Measure the time elapsed for running tasks. * Measure the time elapsed for running tasks.
@ -19,9 +20,17 @@ import sbt.internal.util.{ RMap, ConsoleOut }
* - -Dsbt.task.timings.threshold=number * - -Dsbt.task.timings.threshold=number
* @param reportOnShutdown Should the report be given when exiting the JVM (true) or immediately (false)? * @param reportOnShutdown Should the report be given when exiting the JVM (true) or immediately (false)?
*/ */
private[sbt] final class TaskTimings(reportOnShutdown: Boolean) private[sbt] final class TaskTimings(reportOnShutdown: Boolean, logger: Logger)
extends AbstractTaskExecuteProgress extends AbstractTaskExecuteProgress
with ExecuteProgress[Task] { with ExecuteProgress[Task] {
@deprecated("Use the constructor that takes an sbt.util.Logger parameter.", "1.3.3")
def this(reportOnShutdown: Boolean) =
this(reportOnShutdown, new Logger {
override def trace(t: => Throwable): Unit = {}
override def success(message: => String): Unit = {}
override def log(level: Level.Value, message: => String): Unit =
ConsoleOut.systemOut.println(message)
})
import AbstractTaskExecuteProgress.Timer import AbstractTaskExecuteProgress.Timer
private[this] var start = 0L private[this] var start = 0L
private[this] val threshold = SysProp.taskTimingsThreshold private[this] val threshold = SysProp.taskTimingsThreshold
@ -48,11 +57,10 @@ private[sbt] final class TaskTimings(reportOnShutdown: Boolean)
override def stop(): Unit = () override def stop(): Unit = ()
private[this] val reFilePath = raw"\{[^}]+\}".r private[this] val reFilePath = raw"\{[^}]+\}".r
private[this] val console = ConsoleOut.systemOut
private[this] def report() = { private[this] def report() = {
val total = divide(System.nanoTime - start) val total = divide(System.nanoTime - start)
console.println(s"Total time: $total $unit") logger.info(s"Total time: $total $unit")
import collection.JavaConverters._ import collection.JavaConverters._
def sumTimes(in: Seq[(Task[_], Timer)]) = in.map(_._2.durationNanos).sum def sumTimes(in: Seq[(Task[_], Timer)]) = in.map(_._2.durationNanos).sum
val timingsByName = timings.asScala.toSeq.groupBy { case (t, _) => taskName(t) } mapValues (sumTimes) val timingsByName = timings.asScala.toSeq.groupBy { case (t, _) => taskName(t) } mapValues (sumTimes)
@ -69,7 +77,7 @@ private[sbt] final class TaskTimings(reportOnShutdown: Boolean)
val maxTime = times.map { _._2 }.max.toString.length val maxTime = times.map { _._2 }.max.toString.length
times.foreach { times.foreach {
case (taskName, time) => case (taskName, time) =>
console.println(s" ${taskName.padTo(maxTaskNameLength, ' ')}: ${"" logger.info(s" ${taskName.padTo(maxTaskNameLength, ' ')}: ${""
.padTo(maxTime - time.toString.length, ' ')}$time $unit") .padTo(maxTime - time.toString.length, ' ')}$time $unit")
} }
} }