Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mill build fails to render compiler warning with format specifiers #2105

Closed
informarte opened this issue Nov 6, 2022 · 6 comments
Closed
Labels
upstream The issue originates in an upstream dependency

Comments

@informarte
Copy link

Reproduction

Install or switch to Java 19, then execute:

git clone https://github.com/informarte/yuck.git
cd yuck
make ci-tests

The build does not fail but reports an error because some sbt library fails to format a warning produced by dotty:

2022-11-06 09:02:23,358 MillServerActionRunner ERROR Unable to format msg: -- Deprecation Warning: /home/informarte/Workspaces/yuck/src/main/yuck/util/logging/YuckLogging.scala:13:127 
13 |    protected val nativeLogger = java.util.logging.Logger.getLogger("%s-%d".format(this.getClass.getName, Thread.currentThread.getId))
   |                                                                                                          ^^^^^^^^^^^^^^^^^^^^^^^^^^
   |method getId in class Thread is deprecated since : see corresponding Javadoc for more information. java.util.MissingFormatArgumentException: Format specifier '%d'

Notice that the warning contains application code with format specifiers.

I am reporting this as a mill issue because it's not clear to me which component (dotty, mill, or sbt) is supposed to escape the format specifiers.

Full output

/scripts/test-runner.py yuck.test.ContinuousIntegrationTestSuite
[46/83] yuck.dev.compile 
[info] compiling 216 Scala sources and 1 Java source to /home/informarte/Workspaces/yuck/out/yuck/dev/compile.dest/classes ...
[warn] -- Deprecation Warning: /home/informarte/Workspaces/yuck/src/main/yuck/util/logging/Formatter.scala:18:37 
[warn] 18 |                Thread.currentThread.getId, Thread.currentThread.getName)
[warn]    |                ^^^^^^^^^^^^^^^^^^^^^^^^^^
[warn]    |method getId in class Thread is deprecated since : see corresponding Javadoc for more information.
2022-11-06 09:02:23,358 MillServerActionRunner ERROR Unable to format msg: -- Deprecation Warning: /home/informarte/Workspaces/yuck/src/main/yuck/util/logging/YuckLogging.scala:13:127 
13 |    protected val nativeLogger = java.util.logging.Logger.getLogger("%s-%d".format(this.getClass.getName, Thread.currentThread.getId))
   |                                                                                                          ^^^^^^^^^^^^^^^^^^^^^^^^^^
   |method getId in class Thread is deprecated since : see corresponding Javadoc for more information. java.util.MissingFormatArgumentException: Format specifier '%d'
	at java.base/java.util.Formatter.format(Formatter.java:2780)
	at java.base/java.util.Formatter.format(Formatter.java:2717)
	at java.base/java.lang.String.format(String.java:4191)
	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.internal.util.Appender.$anonfun$appendMessageContent$3(ConsoleAppender.scala:544)
	at sbt.internal.util.Appender.$anonfun$appendMessageContent$3$adapted(ConsoleAppender.scala:542)
	at scala.collection.immutable.Vector.foreach(Vector.scala:1856)
	at sbt.internal.util.Appender.appendEvent$1(ConsoleAppender.scala:542)
	at sbt.internal.util.Appender.appendMessageContent(ConsoleAppender.scala:553)
	at sbt.internal.util.Appender.appendObjectEvent(ConsoleAppender.scala:558)
	at sbt.internal.util.Appender.appendObjectEvent$(ConsoleAppender.scala:557)
	at sbt.internal.util.ConsoleAppenderFromLog4J.appendObjectEvent(ConsoleAppender.scala:573)
	at sbt.util.LoggerContext$LoggerContextImpl$Log.$anonfun$log$4(LoggerContext.scala:129)
	at java.base/java.util.Vector.forEach(Vector.java:1359)
	at sbt.util.LoggerContext$LoggerContextImpl$Log.log(LoggerContext.scala:127)
	at sbt.internal.util.ManagedLogger.logEvent(ManagedLogger.scala:92)
	at sbt.internal.util.ManagedLogger.warnEvent(ManagedLogger.scala:80)
	at sbt.internal.inc.ManagedLoggedReporter.logWarning(LoggedReporter.scala:87)
	at sbt.internal.inc.LoggedReporter.display(LoggedReporter.scala:174)
	at sbt.internal.inc.LoggedReporter.log(LoggedReporter.scala:148)
	at dotty.tools.xsbt.DelegatingReporter.doReport(DelegatingReporter.java:47)
	at dotty.tools.dotc.reporting.Reporter.issueUnconfigured(Reporter.scala:157)
	at dotty.tools.dotc.reporting.Reporter.go$1(Reporter.scala:176)
	at dotty.tools.dotc.reporting.Reporter.issueIfNotSuppressed(Reporter.scala:190)
	at dotty.tools.dotc.reporting.Reporter.report(Reporter.scala:202)
	at dotty.tools.dotc.report$.issueWarning(report.scala:24)
	at dotty.tools.dotc.report$.deprecationWarning(report.scala:27)
	at dotty.tools.dotc.transform.CrossVersionChecks.checkDeprecated$$anonfun$1(CrossVersionChecks.scala:70)
	at scala.runtime.function.JProcedure1.apply(JProcedure1.java:15)
	at scala.runtime.function.JProcedure1.apply(JProcedure1.java:10)
	at scala.Option.foreach(Option.scala:437)
	at dotty.tools.dotc.transform.CrossVersionChecks.checkDeprecated(CrossVersionChecks.scala:70)
	at dotty.tools.dotc.transform.CrossVersionChecks.checkUndesiredProperties(CrossVersionChecks.scala:29)
	at dotty.tools.dotc.transform.CrossVersionChecks.transformSelect(CrossVersionChecks.scala:181)
	at dotty.tools.dotc.transform.CrossVersionChecks.transformSelect(CrossVersionChecks.scala:180)
	at dotty.tools.dotc.transform.MegaPhase.goSelect(MegaPhase.scala:605)
	at dotty.tools.dotc.transform.MegaPhase.transformNamed$1(MegaPhase.scala:228)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:425)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:278)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.recur$1(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.recur$1(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformTrees(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:346)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.recur$1(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformTrees(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:279)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.recur$1(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformTrees(MegaPhase.scala:459)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:279)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.mapValDef$1(MegaPhase.scala:234)
	at dotty.tools.dotc.transform.MegaPhase.transformNamed$1(MegaPhase.scala:239)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:425)
	at dotty.tools.dotc.transform.MegaPhase.loop$1(MegaPhase.scala:438)
	at dotty.tools.dotc.transform.MegaPhase.transformStats(MegaPhase.scala:438)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:359)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.transformNamed$1(MegaPhase.scala:255)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:425)
	at dotty.tools.dotc.transform.MegaPhase.loop$1(MegaPhase.scala:438)
	at dotty.tools.dotc.transform.MegaPhase.transformStats(MegaPhase.scala:438)
	at dotty.tools.dotc.transform.MegaPhase.mapPackage$1(MegaPhase.scala:379)
	at dotty.tools.dotc.transform.MegaPhase.transformUnnamed$1(MegaPhase.scala:382)
	at dotty.tools.dotc.transform.MegaPhase.transformTree(MegaPhase.scala:427)
	at dotty.tools.dotc.transform.MegaPhase.transformUnit(MegaPhase.scala:454)
	at dotty.tools.dotc.transform.MegaPhase.run(MegaPhase.scala:466)
	at dotty.tools.dotc.core.Phases$Phase.runOn$$anonfun$1(Phases.scala:311)
	at scala.collection.immutable.List.map(List.scala:250)
	at dotty.tools.dotc.core.Phases$Phase.runOn(Phases.scala:312)
	at dotty.tools.dotc.Run.runPhases$1$$anonfun$1(Run.scala:225)
	at scala.runtime.function.JProcedure1.apply(JProcedure1.java:15)
	at scala.runtime.function.JProcedure1.apply(JProcedure1.java:10)
	at scala.collection.ArrayOps$.foreach$extension(ArrayOps.scala:1328)
	at dotty.tools.dotc.Run.runPhases$1(Run.scala:236)
	at dotty.tools.dotc.Run.compileUnits$$anonfun$1(Run.scala:244)
	at dotty.tools.dotc.Run.compileUnits$$anonfun$adapted$1(Run.scala:253)
	at dotty.tools.dotc.util.Stats$.maybeMonitored(Stats.scala:68)
	at dotty.tools.dotc.Run.compileUnits(Run.scala:253)
	at dotty.tools.dotc.Run.compileSources(Run.scala:186)
	at dotty.tools.dotc.Run.compile(Run.scala:170)
	at dotty.tools.dotc.Driver.doCompile(Driver.scala:35)
	at dotty.tools.xsbt.CompilerBridgeDriver.run(CompilerBridgeDriver.java:88)
	at dotty.tools.xsbt.CompilerBridge.run(CompilerBridge.java:22)
	at sbt.internal.inc.AnalyzingCompiler.compile(AnalyzingCompiler.scala:91)
	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$7(MixedAnalyzingCompiler.scala:193)
	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
	at sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:248)
	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:183)
	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4$adapted(MixedAnalyzingCompiler.scala:163)
	at sbt.internal.inc.JarUtils$.withPreviousJar(JarUtils.scala:239)
	at sbt.internal.inc.MixedAnalyzingCompiler.compileScala$1(MixedAnalyzingCompiler.scala:163)
	at sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:211)
	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:534)
	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:534)
	at sbt.internal.inc.Incremental$.$anonfun$apply$5(Incremental.scala:179)
	at sbt.internal.inc.Incremental$.$anonfun$apply$5$adapted(Incremental.scala:177)
	at sbt.internal.inc.Incremental$$anon$2.run(Incremental.scala:463)
	at sbt.internal.inc.IncrementalCommon$CycleState.next(IncrementalCommon.scala:116)
	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:570)
	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$.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:1589)

[warn] -- Deprecation Warning: /home/informarte/Workspaces/yuck/src/main/yuck/util/logging/YuckLogging.scala:13:127 
[warn] 13 |    protected val nativeLogger = java.util.logging.Logger.getLogger("%s-%d".format(this.getClass.getName, Thread.currentThread.getId))
[warn]    |                                                                                                          ^^^^^^^^^^^^^^^^^^^^^^^^^^
[warn]    |method getId in class Thread is deprecated since : see corresponding Javadoc for more information.
[warn] two warnings found
[info] done compiling
[70/83] yuck.dev.test.compile 
[info] compiling 155 Scala sources to /home/informarte/Workspaces/yuck/out/yuck/dev/test/compile.dest/classes ...
[info] done compiling
[83/83] yuck.dev.test.run 
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................I
Time: 37.252

OK (846 tests)

Expected output

./scripts/test-runner.py yuck.test.ContinuousIntegrationTestSuite
[83/83] yuck.dev.test.run 
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................I
Time: 36.915

OK (846 tests)
@lefou
Copy link
Member

lefou commented Nov 7, 2022

Thanks for this report. I think, this is an issue in sbt zinc regarding handling of log messages, and it should be reported upstream. We previously reported similar issues , e.g. in sbt/zinc#1122, but also in chats.

Can you check with a recent Mill snapshot release? Maybe, #2087 already fixes (in the sense of "avoid") it already? If not, please report it upstream.

@lefou
Copy link
Member

lefou commented Nov 7, 2022

To elaborate on this. I'm not familiar with log4j2, I only used older version log4j1 and friends, as well as SLF4J with logback, which don't have such problems. But it seems to me, that the log messages are post-processed after given to the log4j2 logger with something like String.format or printf. This results in symbols like % to have a special meaning. I'm quite shocked about this, but maybe, I'm completely misinterpreting it?

@informarte
Copy link
Author

What do I have to put into .mill-version to use the latest Mill snapshot release? The README mentions #.#.#-n-hash but does not explain the n and hash parts.

@lefou
Copy link
Member

lefou commented Nov 7, 2022

The release pages list all released snapshot artifacts. E.g. latest snapshot after 0.10.8 is 0.10.8-29-72ea15.

@informarte
Copy link
Author

GitHub hides the snapshot releases from me. Anyway, 0.10.8-29-72ea15 fixes my build issue!

@lefou
Copy link
Member

lefou commented Nov 7, 2022

I forgot to mention, that snapshot releases are attached to the page of the latest previous tag, so you'll find all "after 0.10.8" snapshots on the "0.10.8" release page as attached artifacts.

Great, that it fixes the issue. I'm closing this issue then, as we do what we can to work around it in Mill. To really fix the upstream issue, it should be reported to sbt-zinc.

@lefou lefou closed this as completed Nov 7, 2022
@lefou lefou added the upstream The issue originates in an upstream dependency label Jan 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
upstream The issue originates in an upstream dependency
Projects
None yet
Development

No branches or pull requests

2 participants