From e28e052b5bd7ced9e55ccc5665fb44e4009f3ce0 Mon Sep 17 00:00:00 2001 From: Eugene Yokota Date: Thu, 4 Apr 2019 22:27:33 -0400 Subject: [PATCH] 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. --- build.sbt | 2 + .../sbt/internal/util/ProgressEvent.scala | 59 +++++++++++++++ .../sbt/internal/util/ProgressItem.scala | 41 +++++++++++ .../util/codec/AbstractEntryFormats.scala | 4 +- .../internal/util/codec/JsonProtocol.scala | 2 + .../util/codec/ProgressEventFormats.scala | 35 +++++++++ .../util/codec/ProgressItemFormats.scala | 29 ++++++++ .../util/codec/TaskProgressFormats.scala | 29 ++++++++ .../src/main/contraband/logging.contra | 17 +++++ .../sbt/internal/util/ConsoleAppender.scala | 73 +++++++++++++------ 10 files changed, 266 insertions(+), 25 deletions(-) create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressEvent.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/ProgressItem.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressEventFormats.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ProgressItemFormats.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/TaskProgressFormats.scala diff --git a/build.sbt b/build.sbt index 1c0b3106f..e1f77c2b9 100644 --- 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) diff --git 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 new file mode 100644 index 000000000..9c0c09368 --- /dev/null +++ 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)) +} diff --git 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 new file mode 100644 index 000000000..f7b30dc6f --- /dev/null +++ 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) +} diff --git 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 index 55784f9ac..37b4cfc91 100644 --- 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") } diff --git 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 index 15e4d9cb2..54bc48141 100644 --- 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 diff --git 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 new file mode 100644 index 000000000..4d836c02d --- /dev/null +++ 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() + } +} +} diff --git 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 new file mode 100644 index 000000000..3aac75e91 --- /dev/null +++ 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() + } +} +} diff --git 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 new file mode 100644 index 000000000..fa79adffc --- /dev/null +++ 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() + } +} +} diff --git a/internal/util-logging/src/main/contraband/logging.contra b/internal/util-logging/src/main/contraband/logging.contra index 73d0b1a56..34fa75c24 100644 --- 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! } diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala index 6cd21e55c..bc30045c8 100644 --- 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 {