sbt / zinc

Scala incremental compiler library, used by sbt and other build tools
Apache License 2.0
335 stars 121 forks source link

Log4j formatting error #1122

Open tballard opened 2 years ago

tballard commented 2 years ago
 s"Recompiling all sources: number of invalidated sources > ${recompileAllFraction * 100.00}% of all sources"

That line is from IncrementalCommon.scala. The "%" should be "%%" to prevent it from breaking. Or something.

Have a stacktrace:

2022-09-14 13:00:48,046 MillServerActionRunner ERROR Unable to format msg: Recompiling all sources: number of invalidated sources > 50.0% of all sources java.util.IllegalFormatConversionException: o != [Ljava.lang.Object;
    at java.base/java.util.Formatter$FormatSpecifier.failConversion(Formatter.java:4442)
    at java.base/java.util.Formatter$FormatSpecifier.printInteger(Formatter.java:2963)
    at java.base/java.util.Formatter$FormatSpecifier.print(Formatter.java:2918)
    at java.base/java.util.Formatter.format(Formatter.java:2689)
    at java.base/java.util.Formatter.format(Formatter.java:2625)
    at java.base/java.lang.String.format(String.java:4184)
    at org.apache.logging.log4j.message.StringFormattedMessage.formatMessage(StringFormattedMessage.java:120)
    at org.apache.logging.log4j.message.StringFormattedMessage.getFormattedMessage(StringFormattedMessage.java:88)
    at sbt.internal.util.Appender.$anonfun$appendMessage$1(ConsoleAppender.scala:508)
    at sbt.internal.util.Appender.appendLog(ConsoleAppender.scala:426)
    at sbt.internal.util.Appender.appendLog$(ConsoleAppender.scala:425)
    at sbt.internal.util.ConsoleAppender.appendLog(ConsoleAppender.scala:336)
    at sbt.internal.util.Appender.appendMessage(ConsoleAppender.scala:508)
    at sbt.internal.util.Appender.appendMessage$(ConsoleAppender.scala:504)
    at sbt.internal.util.ConsoleAppender.appendMessage(ConsoleAppender.scala:336)
    at sbt.internal.util.ConsoleAppender.$anonfun$toLog4J$1(ConsoleAppender.scala:350)
    at sbt.internal.util.ConsoleAppender.$anonfun$toLog4J$1$adapted(ConsoleAppender.scala:347)
    at sbt.internal.util.Log4JConsoleAppender.append(ConsoleAppender.scala:571)
    at sbt.internal.util.ConsoleAppenderFromLog4J.appendLog(ConsoleAppender.scala:584)
    at sbt.util.LoggerContext$LoggerContextImpl$Log.$anonfun$log$2(LoggerContext.scala:123)
    at sbt.util.LoggerContext$LoggerContextImpl$Log.$anonfun$log$2$adapted(LoggerContext.scala:123)
    at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
    at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
    at scala.collection.AbstractIterable.foreach(Iterable.scala:926)
    at sbt.util.LoggerContext$LoggerContextImpl$Log.log(LoggerContext.scala:123)
    at sbt.internal.util.ManagedLogger.log(ManagedLogger.scala:41)
    at sbt.util.Logger.debug(Logger.scala:25)
    at sbt.internal.inc.IncrementalCommon.expand$1(IncrementalCommon.scala:285)
    at sbt.internal.inc.IncrementalCommon.mapInvalidationsToSources(IncrementalCommon.scala:291)
    at sbt.internal.inc.IncrementalCommon$CycleState.next(IncrementalCommon.scala:88)
    at sbt.internal.inc.IncrementalCommon$$anon$1.next(IncrementalCommon.scala:56)
    at sbt.internal.inc.IncrementalCommon$$anon$1.next(IncrementalCommon.scala:52)
    at sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:263)
    at sbt.internal.inc.Incremental$.$anonfun$incrementalCompile$8(Incremental.scala:418)
    at sbt.internal.inc.Incremental$.withClassfileManager(Incremental.scala:506)
    at sbt.internal.inc.Incremental$.incrementalCompile(Incremental.scala:405)
    at sbt.internal.inc.Incremental$.apply(Incremental.scala:171)
    at sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:534)
    at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:488)
    at sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:332)
    at sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:425)
    at sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:137)
    at mill.scalalib.worker.ZincWorkerImpl.compileInternal(ZincWorkerImpl.scala:569)
    at mill.scalalib.worker.ZincWorkerImpl.$anonfun$compileMixed0$1(ZincWorkerImpl.scala:340)
    at mill.api.FixSizedCache.withCachedValue(FixSizedCache.scala:66)
    at mill.scalalib.worker.ZincWorkerImpl.withCompilers(ZincWorkerImpl.scala:422)
    at mill.scalalib.worker.ZincWorkerImpl.compileMixed0(ZincWorkerImpl.scala:339)
    at mill.scalalib.worker.ZincWorkerImpl.compileMixed(ZincWorkerImpl.scala:307)
    at mill.scalalib.ScalaModule.$anonfun$compile$2(ScalaModule.scala:198)
    at mill.define.Task$TraverseCtx.evaluate(Task.scala:380)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$13(Evaluator.scala:627)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withErr(Console.scala:193)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$12(Evaluator.scala:627)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withOut(Console.scala:164)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$11(Evaluator.scala:626)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withIn(Console.scala:227)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$8(Evaluator.scala:625)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$8$adapted(Evaluator.scala:586)
    at scala.collection.immutable.Vector.foreach(Vector.scala:1856)
    at mill.eval.Evaluator.evaluateGroup(Evaluator.scala:586)
    at mill.eval.Evaluator.$anonfun$evaluateGroupCached$21(Evaluator.scala:478)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at mill.eval.Evaluator.evaluateGroupCached(Evaluator.scala:469)
    at mill.eval.Evaluator.$anonfun$sequentialEvaluate$2(Evaluator.scala:202)
    at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
    at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
    at scala.collection.AbstractIterator.foreach(Iterator.scala:1293)
    at mill.eval.Evaluator.sequentialEvaluate(Evaluator.scala:177)
    at mill.eval.Evaluator.evaluate(Evaluator.scala:162)
    at mill.main.RunScript$.evaluateNamed(RunScript.scala:363)
    at mill.main.RunScript$.$anonfun$evaluateTasksNamed$1(RunScript.scala:333)
    at scala.util.Either.map(Either.scala:382)
    at mill.main.RunScript$.evaluateTasksNamed(RunScript.scala:331)
    at mill.main.MainModule$.evaluateTasksNamed(MainModule.scala:71)
    at mill.main.MainModule.$anonfun$show$1(MainModule.scala:276)
    at mill.define.Task$TraverseCtx.evaluate(Task.scala:380)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$13(Evaluator.scala:627)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withErr(Console.scala:193)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$12(Evaluator.scala:627)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withOut(Console.scala:164)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$11(Evaluator.scala:626)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at scala.Console$.withIn(Console.scala:227)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$8(Evaluator.scala:625)
    at mill.eval.Evaluator.$anonfun$evaluateGroup$8$adapted(Evaluator.scala:586)
    at scala.collection.immutable.Vector.foreach(Vector.scala:1856)
    at mill.eval.Evaluator.evaluateGroup(Evaluator.scala:586)
    at mill.eval.Evaluator.$anonfun$evaluateGroupCached$21(Evaluator.scala:478)
    at scala.util.DynamicVariable.withValue(DynamicVariable.scala:59)
    at mill.eval.Evaluator.evaluateGroupCached(Evaluator.scala:469)
    at mill.eval.Evaluator.$anonfun$sequentialEvaluate$2(Evaluator.scala:202)
    at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
    at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
    at scala.collection.AbstractIterator.foreach(Iterator.scala:1293)
    at mill.eval.Evaluator.sequentialEvaluate(Evaluator.scala:177)
    at mill.eval.Evaluator.evaluate(Evaluator.scala:162)
    at mill.main.RunScript$.evaluateNamed(RunScript.scala:363)
    at mill.main.RunScript$.evaluate(RunScript.scala:349)
    at mill.main.RunScript$.$anonfun$evaluateTasks$1(RunScript.scala:314)
    at scala.util.Either.map(Either.scala:382)
    at mill.main.RunScript$.evaluateTasks(RunScript.scala:312)
    at mill.main.RunScript$.$anonfun$runScript$8(RunScript.scala:105)
    at ammonite.util.Res$Success.flatMap(Res.scala:62)
    at mill.main.RunScript$.runScript(RunScript.scala:104)
    at mill.main.MainRunner.$anonfun$runScript$1(MainRunner.scala:119)
    at mill.main.MainRunner.watchLoop2(MainRunner.scala:67)
    at mill.main.MainRunner.runScript(MainRunner.scala:92)
    at mill.MillMain$.main0(MillMain.scala:310)
    at mill.main.MillServerMain$.main0(MillServerMain.scala:79)
    at mill.main.Server.$anonfun$handleRun$1(MillServerMain.scala:184)
    at java.base/java.lang.Thread.run(Thread.java:833)
szeiger commented 1 year ago

Should this be fixed in https://github.com/sbt/sbt/blob/78f9b318e2d13e9bdffb8661c2dc4bd451db521e/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala#L600 instead? sbt's loggers do not support formatting and ConsoleAppender always appends an empty argument list so it would make sense to make this explicit by passing the string as an argument to prevent further expansion.

lefou commented 1 year ago

Should this be fixed in https://github.com/sbt/sbt/blob/78f9b318e2d13e9bdffb8661c2dc4bd451db521e/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala#L600 instead? sbt's loggers do not support formatting and ConsoleAppender always appends an empty argument list so it would make sense to make this explicit by passing the string as an argument to prevent further expansion.

The idea and location looks right to me. But it would be even better to find a Message constructor which avoids any kind of formatting or template processing, maybe new SimpleMessage(String) or MessageFactory.newMessage(String)