move super shell rendering to ConsoleAppender

Ref https://github.com/sbt/sbt/issues/4583 This moves the super shell rendering to ConsoleAppender with several improvements. Instead of scrolling up, supershell is now changed to normal scrolling down, with more traditional cursor position. Before printing out the logs, last known progress reports are wiped out. In addition, there's now 5 lines of blank lines to accomodate for `println(...)` by tasks.
2019-04-04 22:27:33 -04:00 · 2019-04-04 22:27:33 -04:00 · e28e052b5b
parent 98ec0075f4
commit e28e052b5b
10 changed files with 266 additions and 25 deletions
--- a/build.sbt
+++ b/build.sbt
@ -124,6 +124,8 @@ lazy val utilLogging = (project in internalPath / "util-logging")
      exclude[ReversedMissingMethodProblem]("sbt.internal.util.ConsoleOut.flush"),
      // This affects Scala 2.11 only it seems, so it's ok?
      exclude[InheritedNewAbstractMethodProblem]("sbt.internal.util.codec.JsonProtocol.LogOptionFormat"),
+      exclude[InheritedNewAbstractMethodProblem]("sbt.internal.util.codec.JsonProtocol.ProgressItemFormat"),
+      exclude[InheritedNewAbstractMethodProblem]("sbt.internal.util.codec.JsonProtocol.ProgressEventFormat"),
    ),
  )
  .configure(addSbtIO)
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressEvent.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressEvent.scala
@ -0,0 +1,59 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util
+/** used by super shell */
+final class ProgressEvent private (
+  val level: String,
+  val items: Vector[sbt.internal.util.ProgressItem],
+  val lastTaskCount: Option[Int],
+  channelName: Option[String],
+  execId: Option[String]) extends sbt.internal.util.AbstractEntry(channelName, execId) with Serializable {
+  
+  
+  
+  override def equals(o: Any): Boolean = o match {
+    case x: ProgressEvent => (this.level == x.level) && (this.items == x.items) && (this.lastTaskCount == x.lastTaskCount) && (this.channelName == x.channelName) && (this.execId == x.execId)
+    case _ => false
+  }
+  override def hashCode: Int = {
+    37 * (37 * (37 * (37 * (37 * (37 * (17 + "sbt.internal.util.ProgressEvent".##) + level.##) + items.##) + lastTaskCount.##) + channelName.##) + execId.##)
+  }
+  override def toString: String = {
+    "ProgressEvent(" + level + ", " + items + ", " + lastTaskCount + ", " + channelName + ", " + execId + ")"
+  }
+  private[this] def copy(level: String = level, items: Vector[sbt.internal.util.ProgressItem] = items, lastTaskCount: Option[Int] = lastTaskCount, channelName: Option[String] = channelName, execId: Option[String] = execId): ProgressEvent = {
+    new ProgressEvent(level, items, lastTaskCount, channelName, execId)
+  }
+  def withLevel(level: String): ProgressEvent = {
+    copy(level = level)
+  }
+  def withItems(items: Vector[sbt.internal.util.ProgressItem]): ProgressEvent = {
+    copy(items = items)
+  }
+  def withLastTaskCount(lastTaskCount: Option[Int]): ProgressEvent = {
+    copy(lastTaskCount = lastTaskCount)
+  }
+  def withLastTaskCount(lastTaskCount: Int): ProgressEvent = {
+    copy(lastTaskCount = Option(lastTaskCount))
+  }
+  def withChannelName(channelName: Option[String]): ProgressEvent = {
+    copy(channelName = channelName)
+  }
+  def withChannelName(channelName: String): ProgressEvent = {
+    copy(channelName = Option(channelName))
+  }
+  def withExecId(execId: Option[String]): ProgressEvent = {
+    copy(execId = execId)
+  }
+  def withExecId(execId: String): ProgressEvent = {
+    copy(execId = Option(execId))
+  }
+}
+object ProgressEvent {
+  
+  def apply(level: String, items: Vector[sbt.internal.util.ProgressItem], lastTaskCount: Option[Int], channelName: Option[String], execId: Option[String]): ProgressEvent = new ProgressEvent(level, items, lastTaskCount, channelName, execId)
+  def apply(level: String, items: Vector[sbt.internal.util.ProgressItem], lastTaskCount: Int, channelName: String, execId: String): ProgressEvent = new ProgressEvent(level, items, Option(lastTaskCount), Option(channelName), Option(execId))
+}
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressItem.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressItem.scala
@ -0,0 +1,41 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util
+/**
+ * used by super shell
+ * @param name name of a task
+ * @param elapsedMicros current elapsed time in micro seconds
+ */
+final class ProgressItem private (
+  val name: String,
+  val elapsedMicros: Long) extends Serializable {
+  
+  
+  
+  override def equals(o: Any): Boolean = o match {
+    case x: ProgressItem => (this.name == x.name) && (this.elapsedMicros == x.elapsedMicros)
+    case _ => false
+  }
+  override def hashCode: Int = {
+    37 * (37 * (37 * (17 + "sbt.internal.util.ProgressItem".##) + name.##) + elapsedMicros.##)
+  }
+  override def toString: String = {
+    "ProgressItem(" + name + ", " + elapsedMicros + ")"
+  }
+  private[this] def copy(name: String = name, elapsedMicros: Long = elapsedMicros): ProgressItem = {
+    new ProgressItem(name, elapsedMicros)
+  }
+  def withName(name: String): ProgressItem = {
+    copy(name = name)
+  }
+  def withElapsedMicros(elapsedMicros: Long): ProgressItem = {
+    copy(elapsedMicros = elapsedMicros)
+  }
+}
+object ProgressItem {
+  
+  def apply(name: String, elapsedMicros: Long): ProgressItem = new ProgressItem(name, elapsedMicros)
+}
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala
@ -6,6 +6,6 @@
 package sbt.internal.util.codec

 import _root_.sjsonnew.JsonFormat
-trait AbstractEntryFormats { self: sjsonnew.BasicJsonProtocol with sbt.internal.util.codec.StringEventFormats with sbt.internal.util.codec.TraceEventFormats =>
-implicit lazy val AbstractEntryFormat: JsonFormat[sbt.internal.util.AbstractEntry] = flatUnionFormat2[sbt.internal.util.AbstractEntry, sbt.internal.util.StringEvent, sbt.internal.util.TraceEvent]("type")
+trait AbstractEntryFormats { self: sjsonnew.BasicJsonProtocol with sbt.internal.util.codec.StringEventFormats with sbt.internal.util.codec.TraceEventFormats with sbt.internal.util.codec.ProgressItemFormats with sbt.internal.util.codec.ProgressEventFormats =>
+implicit lazy val AbstractEntryFormat: JsonFormat[sbt.internal.util.AbstractEntry] = flatUnionFormat3[sbt.internal.util.AbstractEntry, sbt.internal.util.StringEvent, sbt.internal.util.TraceEvent, sbt.internal.util.ProgressEvent]("type")
 }
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala
@ -7,6 +7,8 @@ package sbt.internal.util.codec
 trait JsonProtocol extends sjsonnew.BasicJsonProtocol
  with sbt.internal.util.codec.StringEventFormats
  with sbt.internal.util.codec.TraceEventFormats
+  with sbt.internal.util.codec.ProgressItemFormats
+  with sbt.internal.util.codec.ProgressEventFormats
  with sbt.internal.util.codec.AbstractEntryFormats
  with sbt.internal.util.codec.SuccessEventFormats
  with sbt.internal.util.codec.LogOptionFormats
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressEventFormats.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressEventFormats.scala
@ -0,0 +1,35 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util.codec
+import _root_.sjsonnew.{ Unbuilder, Builder, JsonFormat, deserializationError }
+trait ProgressEventFormats { self: sbt.internal.util.codec.ProgressItemFormats with sjsonnew.BasicJsonProtocol =>
+implicit lazy val ProgressEventFormat: JsonFormat[sbt.internal.util.ProgressEvent] = new JsonFormat[sbt.internal.util.ProgressEvent] {
+  override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.ProgressEvent = {
+    jsOpt match {
+      case Some(js) =>
+      unbuilder.beginObject(js)
+      val level = unbuilder.readField[String]("level")
+      val items = unbuilder.readField[Vector[sbt.internal.util.ProgressItem]]("items")
+      val lastTaskCount = unbuilder.readField[Option[Int]]("lastTaskCount")
+      val channelName = unbuilder.readField[Option[String]]("channelName")
+      val execId = unbuilder.readField[Option[String]]("execId")
+      unbuilder.endObject()
+      sbt.internal.util.ProgressEvent(level, items, lastTaskCount, channelName, execId)
+      case None =>
+      deserializationError("Expected JsObject but found None")
+    }
+  }
+  override def write[J](obj: sbt.internal.util.ProgressEvent, builder: Builder[J]): Unit = {
+    builder.beginObject()
+    builder.addField("level", obj.level)
+    builder.addField("items", obj.items)
+    builder.addField("lastTaskCount", obj.lastTaskCount)
+    builder.addField("channelName", obj.channelName)
+    builder.addField("execId", obj.execId)
+    builder.endObject()
+  }
+}
+}
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressItemFormats.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressItemFormats.scala
@ -0,0 +1,29 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util.codec
+import _root_.sjsonnew.{ Unbuilder, Builder, JsonFormat, deserializationError }
+trait ProgressItemFormats { self: sjsonnew.BasicJsonProtocol =>
+implicit lazy val ProgressItemFormat: JsonFormat[sbt.internal.util.ProgressItem] = new JsonFormat[sbt.internal.util.ProgressItem] {
+  override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.ProgressItem = {
+    jsOpt match {
+      case Some(js) =>
+      unbuilder.beginObject(js)
+      val name = unbuilder.readField[String]("name")
+      val elapsedMicros = unbuilder.readField[Long]("elapsedMicros")
+      unbuilder.endObject()
+      sbt.internal.util.ProgressItem(name, elapsedMicros)
+      case None =>
+      deserializationError("Expected JsObject but found None")
+    }
+  }
+  override def write[J](obj: sbt.internal.util.ProgressItem, builder: Builder[J]): Unit = {
+    builder.beginObject()
+    builder.addField("name", obj.name)
+    builder.addField("elapsedMicros", obj.elapsedMicros)
+    builder.endObject()
+  }
+}
+}
--- a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/TaskProgressFormats.scala
+++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/TaskProgressFormats.scala
@ -0,0 +1,29 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util.codec
+import _root_.sjsonnew.{ Unbuilder, Builder, JsonFormat, deserializationError }
+trait TaskProgressFormats { self: sjsonnew.BasicJsonProtocol =>
+implicit lazy val TaskProgressFormat: JsonFormat[sbt.internal.util.TaskProgress] = new JsonFormat[sbt.internal.util.TaskProgress] {
+  override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.TaskProgress = {
+    jsOpt match {
+      case Some(js) =>
+      unbuilder.beginObject(js)
+      val name = unbuilder.readField[String]("name")
+      val elapsedMicros = unbuilder.readField[Option[Long]]("elapsedMicros")
+      unbuilder.endObject()
+      sbt.internal.util.TaskProgress(name, elapsedMicros)
+      case None =>
+      deserializationError("Expected JsObject but found None")
+    }
+  }
+  override def write[J](obj: sbt.internal.util.TaskProgress, builder: Builder[J]): Unit = {
+    builder.beginObject()
+    builder.addField("name", obj.name)
+    builder.addField("elapsedMicros", obj.elapsedMicros)
+    builder.endObject()
+  }
+}
+}
--- a/internal/util-logging/src/main/contraband/logging.contra
+++ b/internal/util-logging/src/main/contraband/logging.contra
@ -22,6 +22,23 @@ type TraceEvent implements sbt.internal.util.AbstractEntry {
  execId: String
 }

+## used by super shell
+type ProgressEvent implements sbt.internal.util.AbstractEntry {
+  level: String!
+  items: [sbt.internal.util.ProgressItem]
+  lastTaskCount: Int
+  channelName: String
+  execId: String
+}
+
+## used by super shell
+type ProgressItem {
+  ## name of a task
+  name: String!
+  ## current elapsed time in micro seconds
+  elapsedMicros: Long!
+}
+
 type SuccessEvent {
  message: String!
 }
--- a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala
+++ b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala
@ -96,18 +96,19 @@ class ConsoleLogger private[ConsoleLogger] (
 }

 object ConsoleAppender {
-  private[sbt] final val ScrollUp = "\u001B[S"
  private[sbt] def cursorUp(n: Int): String = s"\u001B[${n}A"
  private[sbt] def cursorDown(n: Int): String = s"\u001B[${n}B"
  private[sbt] def scrollUp(n: Int): String = s"\u001B[${n}S"
  private[sbt] final val DeleteLine = "\u001B[2K"
  private[sbt] final val CursorLeft1000 = "\u001B[1000D"
+  private[sbt] final val CursorDown1 = cursorDown(1)
  private[this] val widthHolder: AtomicInteger = new AtomicInteger
  private[sbt] def terminalWidth = widthHolder.get
  private[sbt] def setTerminalWidth(n: Int): Unit = widthHolder.set(n)
  private[this] val showProgressHolder: AtomicBoolean = new AtomicBoolean(false)
  def setShowProgress(b: Boolean): Unit = showProgressHolder.set(b)
  def showProgress: Boolean = showProgressHolder.get
+  private[sbt] val lastTaskCount = new AtomicInteger(0)

  /** Hide stack trace altogether. */
  val noSuppressedMessage = (_: SuppressedTraceContext) => None
@ -454,23 +455,18 @@ class ConsoleAppender private[ConsoleAppender] (
    appendLog(SUCCESS_LABEL_COLOR, Level.SuccessLabel, SUCCESS_MESSAGE_COLOR, message)
  }

+  // leave some blank lines for tasks that might use println(...)
+  private val blankZone = 5
  private def write(msg: String): Unit = {
    if (!useFormat || !ansiCodesSupported) {
      out.println(EscHelpers.removeEscapeSequences(msg))
    } else if (ConsoleAppender.showProgress) {
-      val textLength = msg.length - 5
-      val scrollNum =
-        if (ConsoleAppender.terminalWidth == 0) 1
-        else (textLength / ConsoleAppender.terminalWidth) + 1
-      if (scrollNum > 1) {
-        out.print(s"${cursorDown(1)}$DeleteLine" * (scrollNum - 1) + s"${cursorUp(scrollNum - 1)}")
+      val clearNum = lastTaskCount.get + blankZone
+      if (clearNum > 1) {
+        deleteConsoleLines(clearNum)
+        out.print(s"${cursorUp(clearNum)}")
      }
-      out.print(
-        s"$ScrollUp$DeleteLine$msg${CursorLeft1000}" + (
-          if (scrollNum <= 1) ""
-          else scrollUp(scrollNum - 1)
-        )
-      )
+      out.println(msg)
      out.flush()
    } else {
      out.println(msg)
@ -497,19 +493,50 @@ class ConsoleAppender private[ConsoleAppender] (
    codec.showLines(te).toVector foreach { appendLog(Level.Error, _) }
  }

+  private def appendProgressEvent(pe: ProgressEvent): Unit =
+    if (ConsoleAppender.showProgress) {
+      out.lockObject.synchronized {
+        deleteConsoleLines(blankZone)
+        val currentTasksCount = pe.items.size
+        val ltc = pe.lastTaskCount.getOrElse(0)
+        val sorted = pe.items.sortBy(_.name).sortBy(x => -x.elapsedMicros)
+        sorted foreach { item =>
+          val elapsed = item.elapsedMicros / 1000000L
+          out.println(s"$DeleteLine  | => ${item.name} ${elapsed}s")
+        }
+        if (ltc > currentTasksCount) deleteConsoleLines(ltc - currentTasksCount)
+        else ()
+        out.print(cursorUp(math.max(currentTasksCount, ltc) + blankZone))
+        out.flush()
+        lastTaskCount.set(ltc)
+      }
+    } else ()
+
+  private def deleteConsoleLines(n: Int): Unit = {
+    (1 to n) foreach { _ =>
+      out.println(DeleteLine)
+    }
+  }
+
  private def appendMessageContent(level: Level.Value, o: AnyRef): Unit = {
    def appendEvent(oe: ObjectEvent[_]): Unit = {
      val contentType = oe.contentType
-      if (contentType == "sbt.internal.util.TraceEvent") {
-        appendTraceEvent(oe.message.asInstanceOf[TraceEvent])
-      } else
-        LogExchange.stringCodec[AnyRef](contentType) match {
-          case Some(codec) if contentType == "sbt.internal.util.SuccessEvent" =>
-            codec.showLines(oe.message.asInstanceOf[AnyRef]).toVector foreach { success(_) }
-          case Some(codec) =>
-            codec.showLines(oe.message.asInstanceOf[AnyRef]).toVector foreach (appendLog(level, _))
-          case _ => appendLog(level, oe.message.toString)
-        }
+      contentType match {
+        case "sbt.internal.util.TraceEvent" => appendTraceEvent(oe.message.asInstanceOf[TraceEvent])
+        case "sbt.internal.util.ProgressEvent" =>
+          appendProgressEvent(oe.message.asInstanceOf[ProgressEvent])
+        case _ =>
+          LogExchange.stringCodec[AnyRef](contentType) match {
+            case Some(codec) if contentType == "sbt.internal.util.SuccessEvent" =>
+              codec.showLines(oe.message.asInstanceOf[AnyRef]).toVector foreach { success(_) }
+            case Some(codec) =>
+              codec.showLines(oe.message.asInstanceOf[AnyRef]).toVector foreach (appendLog(
+                level,
+                _
+              ))
+            case _ => appendLog(level, oe.message.toString)
+          }
+      }
    }

    o match {