From 5ff33fad3e5310136d3a0ae1e1bbe1ecd88be1b1 Mon Sep 17 00:00:00 2001 From: Mark Harrah Date: Sat, 19 May 2012 18:20:19 -0400 Subject: [PATCH] Second try at printing message when stack trace suppressed. Problems: 1. Without a message, users don't find 'last' 2. Showing a message for every error clutters output. This tries to address these issues by: 1. Only showing the message when other feedback has not been provided and 'last' would not usually be helpful. This will require ongoing tweaking. For now, all commands except 'compile' display the message. 'update' could omit the message as well, but perhaps knowing about 'last' might be useful there. 2. Including the exact command to show the output: last test:compile and not just last 3. Highlighting the command in blue for visibility as an experiment. Review by @ijuma and @retronym, please. --- compile/AnalyzingCompiler.scala | 9 ++++-- compile/JavaCompiler.scala | 2 +- compile/RawCompiler.scala | 7 ++--- main/EvaluateTask.scala | 20 ++++++++++--- main/Load.scala | 4 +-- main/LogManager.scala | 22 +++++++++++--- main/command/ExceptionCategory.scala | 25 ++++++++++++++++ main/command/MainLoop.scala | 19 +++++------- util/control/MessageOnlyException.scala | 8 +++-- util/log/ConsoleLogger.scala | 39 +++++++++++++++---------- util/log/MainLogging.scala | 8 +++-- 11 files changed, 112 insertions(+), 51 deletions(-) create mode 100644 main/command/ExceptionCategory.scala diff --git a/compile/AnalyzingCompiler.scala b/compile/AnalyzingCompiler.scala index e812fdf89..bae5a3b31 100644 --- a/compile/AnalyzingCompiler.scala +++ b/compile/AnalyzingCompiler.scala @@ -71,7 +71,12 @@ final class AnalyzingCompiler(val scalaInstance: xsbti.compile.ScalaInstance, va val interface = interfaceClass.newInstance.asInstanceOf[AnyRef] val method = interfaceClass.getMethod(methodName, argTypes : _*) try { method.invoke(interface, args: _*) } - catch { case e: java.lang.reflect.InvocationTargetException => throw e.getCause } + catch { case e: java.lang.reflect.InvocationTargetException => + e.getCause match { + case c: xsbti.CompileFailed => throw new CompileFailed(c.arguments, c.toString, c.problems) + case t => throw t + } + } } private[this] def loader = { @@ -111,7 +116,7 @@ object AnalyzingCompiler compiler(sourceFiles.toSeq, xsbtiJars.toSeq ++ sourceJars, outputDirectory, "-nowarn" :: Nil) log.info(" Compilation completed in " + (System.currentTimeMillis - start) / 1000.0 + " s") } - catch { case e: xsbti.CompileFailed => throw new CompileFailed(e.arguments, "Error compiling sbt component '" + id + "'") } + catch { case e: xsbti.CompileFailed => throw new CompileFailed(e.arguments, "Error compiling sbt component '" + id + "'", e.problems) } import sbt.Path._ copy(resources x rebase(dir, outputDirectory)) zip((outputDirectory ***) x_! relativeTo(outputDirectory), targetJar) diff --git a/compile/JavaCompiler.scala b/compile/JavaCompiler.scala index 817f171d3..d782f7cbb 100644 --- a/compile/JavaCompiler.scala +++ b/compile/JavaCompiler.scala @@ -56,7 +56,7 @@ object JavaCompiler log.debug("Calling " + contract.name.capitalize + " with arguments:\n\t" + arguments.mkString("\n\t")) val code: Int = f(contract, arguments, log) log.debug(contract.name + " returned exit code: " + code) - if( code != 0 ) throw new CompileFailed(arguments.toArray, contract.name + " returned nonzero exit code") + if( code != 0 ) throw new CompileFailed(arguments.toArray, contract.name + " returned nonzero exit code", Array()) } } def directOrFork(cp: ClasspathOptions, scalaInstance: ScalaInstance)(implicit doFork: Fork): JavaTool = diff --git a/compile/RawCompiler.scala b/compile/RawCompiler.scala index f3419ed55..43bda6f1b 100644 --- a/compile/RawCompiler.scala +++ b/compile/RawCompiler.scala @@ -31,10 +31,7 @@ class RawCompiler(val scalaInstance: xsbti.compile.ScalaInstance, cp: ClasspathO { val reporter = mainClass.getMethod("reporter").invoke(null) val failed = reporter.getClass.getMethod("hasErrors").invoke(reporter).asInstanceOf[Boolean] - if(failed) throw new CompileFailed(args, "Plain compile failed") + if(failed) throw new CompileFailed(args, "Plain compile failed", Array()) } } -class CompileFailed(val arguments: Array[String], override val toString: String) extends xsbti.CompileFailed -{ - def problems = Array() -} \ No newline at end of file +class CompileFailed(val arguments: Array[String], override val toString: String, val problems: Array[xsbti.Problem]) extends xsbti.CompileFailed with FeedbackProvidedException diff --git a/main/EvaluateTask.scala b/main/EvaluateTask.scala index 68e826059..143d63c96 100644 --- a/main/EvaluateTask.scala +++ b/main/EvaluateTask.scala @@ -9,7 +9,7 @@ package sbt import Keys.{dummyRoots, dummyState, dummyStreamsManager, executionRoots, pluginData, streamsManager, taskDefinitionKey, transformState} import Scope.{GlobalScope, ThisScope} import Types.const - import scala.Console.{RED, RESET} + import scala.Console.RED final case class EvaluateConfig(cancelable: Boolean, restrictions: Seq[Tags.Rule], checkCycles: Boolean = false) final case class PluginData(classpath: Seq[Attributed[File]], resolvers: Option[Seq[Resolver]]) @@ -89,17 +89,29 @@ object EvaluateTask val all = Incomplete linearize result val keyed = for(Incomplete(Some(key: Project.ScopedKey[_]), _, msg, _, ex) <- all) yield (key, msg, ex) val un = all.filter { i => i.node.isEmpty || i.message.isEmpty } - for( (key, _, Some(ex)) <- keyed) - getStreams(key, streams).log.trace(ex) + + import ExceptionCategory._ + for( (key, msg, Some(ex)) <- keyed) { + def log = getStreams(key, streams).log + ExceptionCategory(ex) match { + case AlreadyHandled => () + case m: MessageOnly => if(msg.isEmpty) log.error(m.message) + case f: Full => log.trace(f.exception) + } + } for( (key, msg, ex) <- keyed if(msg.isDefined || ex.isDefined) ) { val msgString = (msg.toList ++ ex.toList.map(ErrorHandling.reducedToString)).mkString("\n\t") val log = getStreams(key, streams).log - val display = Project.showContextKey(state, if(log.ansiCodesSupported) Some(scala.Console.RED) else None) + val display = contextDisplay(state, log.ansiCodesSupported) log.error("(" + display(key) + ") " + msgString) } } + private[this] def contextDisplay(state: State, highlight: Boolean) = Project.showContextKey(state, if(highlight) Some(RED) else None) + def suppressedMessage(key: ScopedKey[_])(implicit display: Show[ScopedKey[_]]): String = + "Stack trace suppressed. Run 'last %s' for the full log.".format(display(key)) + def getStreams(key: ScopedKey[_], streams: Streams): TaskStreams = streams(ScopedKey(Project.fillTaskAxis(key).scope, Keys.streams.key)) def withStreams[T](structure: BuildStructure, state: State)(f: Streams => T): T = diff --git a/main/Load.scala b/main/Load.scala index c86c2715e..2f3f485f3 100755 --- a/main/Load.scala +++ b/main/Load.scala @@ -508,9 +508,7 @@ object Load { // TODO: make used of classpath metadata for recompilation val inputs = Compiler.inputs(data(classpath), sources, target, Nil, Nil, definesClass, Compiler.DefaultMaxErrors, CompileOrder.Mixed)(compilers, log) - val analysis = - try { Compiler(inputs, log) } - catch { case _: xsbti.CompileFailed => throw new AlreadyHandledException } // compiler already logged errors + val analysis = Compiler(inputs, log) (inputs, analysis) } diff --git a/main/LogManager.scala b/main/LogManager.scala index 3f82a3601..652a39d98 100644 --- a/main/LogManager.scala +++ b/main/LogManager.scala @@ -11,6 +11,7 @@ package sbt import Scope.GlobalScope import MainLogging._ import Keys.{logLevel, logManager, persistLogLevel, persistTraceLevel, state, traceLevel} + import scala.Console.{BLUE,RESET} object LogManager { @@ -20,14 +21,16 @@ object LogManager manager(data, state, task, to) } lazy val default: LogManager = withLoggers() - def defaults(extra: ScopedKey[_] => Seq[AbstractLogger]): LogManager = withLoggers(extra = extra) - def withScreenLogger(mk: => AbstractLogger): LogManager = withLoggers(mk) + def defaults(extra: ScopedKey[_] => Seq[AbstractLogger]): LogManager = + withLoggers((task,state) => defaultScreen(suppressedMessage(task, state)), extra = extra) + + def withScreenLogger(mk: (ScopedKey[_], State) => AbstractLogger): LogManager = withLoggers(screen = mk) - def withLoggers(screen: => AbstractLogger = defaultScreen, backed: PrintWriter => AbstractLogger = defaultBacked(), extra: ScopedKey[_] => Seq[AbstractLogger] = _ => Nil): LogManager = + def withLoggers(screen: (ScopedKey[_], State) => AbstractLogger = (sk, s) => defaultScreen(), backed: PrintWriter => AbstractLogger = defaultBacked(), extra: ScopedKey[_] => Seq[AbstractLogger] = _ => Nil): LogManager = new LogManager { def apply(data: Settings[Scope], state: State, task: ScopedKey[_], to: PrintWriter): Logger = - defaultLogger(data, state, task, screen, backed(to), extra(task).toList) + defaultLogger(data, state, task, screen(task, state), backed(to), extra(task).toList) } def defaultLogger(data: Settings[Scope], state: State, task: ScopedKey[_], console: AbstractLogger, backed: AbstractLogger, extra: List[AbstractLogger]): Logger = @@ -41,6 +44,17 @@ object LogManager val extraBacked = state.globalLogging.backed :: Nil multiLogger( new MultiLoggerConfig(console, backed, extraBacked ::: extra, screenLevel, backingLevel, screenTrace, backingTrace) ) } + def suppressedMessage(key: ScopedKey[_], state: State): SuppressedTraceContext => Option[String] = + { + lazy val display = Project.showContextKey(state) + def commandBase = "last " + display(unwrapStreamsKey(key)) + def command(useColor: Boolean) = if(useColor) BLUE + commandBase + RESET else "'" + commandBase + "'" + context => Some( "Stack trace suppressed: run %s for the full output.".format(command(context.useColor))) + } + def unwrapStreamsKey(key: ScopedKey[_]): ScopedKey[_] = key.scope.task match { + case Select(task) => ScopedKey(key.scope.copy(task = Global), task) + case _ => key // should never get here + } } trait LogManager diff --git a/main/command/ExceptionCategory.scala b/main/command/ExceptionCategory.scala new file mode 100644 index 000000000..92e34496d --- /dev/null +++ b/main/command/ExceptionCategory.scala @@ -0,0 +1,25 @@ +package sbt + + import java.lang.reflect.InvocationTargetException + import scala.annotation.tailrec + +private[sbt] sealed abstract class ExceptionCategory { + def isFull: Boolean = false +} +private[sbt] object ExceptionCategory { + + @tailrec def apply(t: Throwable): ExceptionCategory = t match { + case _: AlreadyHandledException | _: UnprintableException => AlreadyHandled + case ite: InvocationTargetException => + val cause = ite.getCause + if(cause == null || cause == ite) new Full(ite) else apply(cause) + case _: MessageOnlyException => new MessageOnly(t.toString) + case _ => new Full(t) + } + + object AlreadyHandled extends ExceptionCategory + final class MessageOnly(val message: String) extends ExceptionCategory + final class Full(val exception: Throwable) extends ExceptionCategory { + override def isFull = true + } +} diff --git a/main/command/MainLoop.scala b/main/command/MainLoop.scala index 1e1048598..2b912ee5b 100644 --- a/main/command/MainLoop.scala +++ b/main/command/MainLoop.scala @@ -5,7 +5,6 @@ package sbt import scala.annotation.tailrec import java.io.{File, PrintWriter} - import java.lang.reflect.InvocationTargetException object MainLoop { @@ -76,18 +75,16 @@ object MainLoop case Left(t) => handleException(t, state) } + import ExceptionCategory._ + def handleException(e: Throwable, s: State): State = handleException(e, s, s.log) - def handleException(e: Throwable, s: State, log: Logger): State = + def handleException(t: Throwable, s: State, log: Logger): State = { - e match - { - case _: AlreadyHandledException | _: UnprintableException => () - case ite: InvocationTargetException => - val cause = ite.getCause - if(cause == null || cause == ite) logFullException(ite, log) else handleException(cause, s, log) - case _: MessageOnlyException => log.error(e.toString) - case _ => logFullException(e, log) + ExceptionCategory(t) match { + case AlreadyHandled => () + case m: MessageOnly => log.error(m.message) + case f: Full => logFullException(f.exception, log) } s.fail } @@ -97,4 +94,4 @@ object MainLoop log.error(ErrorHandling reducedToString e) log.error("Use 'last' for the full log.") } -} +} \ No newline at end of file diff --git a/util/control/MessageOnlyException.scala b/util/control/MessageOnlyException.scala index 7fa43746d..75b7737d8 100644 --- a/util/control/MessageOnlyException.scala +++ b/util/control/MessageOnlyException.scala @@ -7,8 +7,12 @@ final class MessageOnlyException(override val toString: String) extends RuntimeE /** A dummy exception for the top-level exception handler to know that an exception * has been handled, but is being passed further up to indicate general failure. */ -final class AlreadyHandledException extends RuntimeException +final class AlreadyHandledException(val underlying: Throwable) extends RuntimeException /** A marker trait for a top-level exception handler to know that this exception * doesn't make sense to display. */ -trait UnprintableException extends Throwable \ No newline at end of file +trait UnprintableException extends Throwable + +/** A marker trait that refines UnprintableException to indicate to a top-level exception handler +* that the code throwing this exception has already provided feedback to the user about the error condition. */ +trait FeedbackProvidedException extends UnprintableException diff --git a/util/log/ConsoleLogger.scala b/util/log/ConsoleLogger.scala index ad626336f..d8ce50dd0 100644 --- a/util/log/ConsoleLogger.scala +++ b/util/log/ConsoleLogger.scala @@ -42,15 +42,16 @@ object ConsoleLogger } catch { case e: Exception => !isWindows } + val noSuppressedMessage = (_: SuppressedTraceContext) => None private[this] def os = System.getProperty("os.name") private[this] def isWindows = os.toLowerCase.indexOf("windows") >= 0 - def apply(): ConsoleLogger = apply(systemOut) def apply(out: PrintStream): ConsoleLogger = apply(printStreamOut(out)) def apply(out: PrintWriter): ConsoleLogger = apply(printWriterOut(out)) - def apply(out: ConsoleOut, ansiCodesSupported: Boolean = formatEnabled, useColor: Boolean = formatEnabled): ConsoleLogger = - new ConsoleLogger(out, ansiCodesSupported, useColor) + def apply(out: ConsoleOut = systemOut, ansiCodesSupported: Boolean = formatEnabled, + useColor: Boolean = formatEnabled, suppressedMessage: SuppressedTraceContext => Option[String] = noSuppressedMessage): ConsoleLogger = + new ConsoleLogger(out, ansiCodesSupported, useColor, suppressedMessage) private[this] val EscapeSequence = (27.toChar + "[^@-~]*[@-~]").r def stripEscapeSequences(s: String): String = @@ -61,7 +62,7 @@ object ConsoleLogger * colored. * * This logger is not thread-safe.*/ -class ConsoleLogger private[ConsoleLogger](val out: ConsoleOut, override val ansiCodesSupported: Boolean, val useColor: Boolean) extends BasicLogger +class ConsoleLogger private[ConsoleLogger](val out: ConsoleOut, override val ansiCodesSupported: Boolean, val useColor: Boolean, val suppressedMessage: SuppressedTraceContext => Option[String]) extends BasicLogger { import scala.Console.{BLUE, GREEN, RED, RESET, YELLOW} def messageColor(level: Level.Value) = RESET @@ -85,6 +86,9 @@ class ConsoleLogger private[ConsoleLogger](val out: ConsoleOut, override val ans val traceLevel = getTrace if(traceLevel >= 0) out.print(StackTrace.trimmed(t, traceLevel)) + if(traceLevel <= 2) + for(msg <- suppressedMessage(new SuppressedTraceContext(traceLevel, ansiCodesSupported && useColor))) + printLabeledLine(labelColor(Level.Error), "trace", messageColor(Level.Error), msg) } def log(level: Level.Value, message: => String) { @@ -102,24 +106,27 @@ class ConsoleLogger private[ConsoleLogger](val out: ConsoleOut, override val ans out.lockObject.synchronized { for(line <- message.split("""\n""")) - { - reset() - out.print("[") - setColor(labelColor) - out.print(label) - reset() - out.print("] ") - setColor(messageColor) - out.print(line) - reset() - out.println() - } + printLabeledLine(labelColor, label, messageColor, line) } + private def printLabeledLine(labelColor: String, label: String, messageColor: String, line: String): Unit = + { + reset() + out.print("[") + setColor(labelColor) + out.print(label) + reset() + out.print("] ") + setColor(messageColor) + out.print(line) + reset() + out.println() + } def logAll(events: Seq[LogEvent]) = out.lockObject.synchronized { events.foreach(log) } def control(event: ControlEvent.Value, message: => String) { log(labelColor(Level.Info), Level.Info.toString, BLUE, message) } } +final class SuppressedTraceContext(val traceLevel: Int, val useColor: Boolean) sealed trait ConsoleOut { val lockObject: AnyRef diff --git a/util/log/MainLogging.scala b/util/log/MainLogging.scala index b07abf4e3..25f42a6af 100644 --- a/util/log/MainLogging.scala +++ b/util/log/MainLogging.scala @@ -25,12 +25,14 @@ object MainLogging } def defaultMultiConfig(backing: AbstractLogger): MultiLoggerConfig = - new MultiLoggerConfig(defaultScreen, backing, Nil, Level.Info, Level.Debug, -1, Int.MaxValue) + new MultiLoggerConfig(defaultScreen(ConsoleLogger.noSuppressedMessage), backing, Nil, Level.Info, Level.Debug, -1, Int.MaxValue) - def defaultScreen: AbstractLogger = ConsoleLogger() + def defaultScreen(): AbstractLogger = ConsoleLogger() + def defaultScreen(suppressedMessage: SuppressedTraceContext => Option[String]): AbstractLogger = ConsoleLogger(suppressedMessage = suppressedMessage) def defaultBacked(useColor: Boolean = ConsoleLogger.formatEnabled): PrintWriter => ConsoleLogger = to => ConsoleLogger(ConsoleLogger.printWriterOut(to), useColor = useColor) // TODO: should probably filter ANSI codes when useColor=false } -final case class MultiLoggerConfig(console: AbstractLogger, backed: AbstractLogger, extra: List[AbstractLogger], screenLevel: Level.Value, backingLevel: Level.Value, screenTrace: Int, backingTrace: Int) \ No newline at end of file +final case class MultiLoggerConfig(console: AbstractLogger, backed: AbstractLogger, extra: List[AbstractLogger], + screenLevel: Level.Value, backingLevel: Level.Value, screenTrace: Int, backingTrace: Int) \ No newline at end of file