[
https://issues.apache.org/jira/browse/GROOVY-12732?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18140594#comment-18140594
]
ASF GitHub Bot commented on GROOVY-12732:
-----------------------------------------
codeconsole opened a new pull request, #3267:
URL: https://github.com/apache/groovy/pull/3267
https://issues.apache.org/jira/browse/GROOVY-12732
When a script throws, the `groovy` command printed `SEVERE: Caught: {0}` and
then the stack trace twice. `GroovyMain.run()` has called `LOGGER.log(ERROR,
"Caught: {0}", e)` since GROOVY-11886. Because `e` is a `Throwable`, Java
selects `System.Logger.log(Level, String, Throwable)` rather than `log(Level,
String, Object...)`, so the placeholder is never filled. The logger also
printed the full stack trace before `StackTraceUtils.deepSanitize` ran, so that
copy ignored `-d`. `printStackTrace()` then printed the sanitized trace a
second time.
The message is now `"Caught: " + e`, the text the command printed before
GROOVY-11886, and the trace is printed once by `printStackTrace()`, sanitized
unless `-d` is given. The other logging calls with a `{0}` placeholder pass
arguments that are not throwables and are not affected.
Test:
`GroovyMainTest.testUncaughtExceptionIsLoggedWithItsTextAndItsStackTracePrintedOnce`
captures the `groovy.ui.GroovyMain` log records. It checks for one SEVERE
record whose formatted message is `Caught: java.lang.IllegalStateException:
boom` and which carries no throwable, and for exactly one printed trace. On
master it fails with `'Caught: {0}'`. With the fix, `GroovyMainTest` passes
locally (17 tests, 1 already `@Disabled`) on JDK 21.
The same line is on `GROOVY_6_0_X`, so this could be backported for 6.0.1.
> groovy command logs "Caught: {0}" without filling the placeholder and prints
> the stack trace twice
> --------------------------------------------------------------------------------------------------
>
> Key: GROOVY-12732
> URL: https://issues.apache.org/jira/browse/GROOVY-12732
> Project: Groovy
> Issue Type: Bug
> Components: command line processing
> Affects Versions: 6.0.0
> Reporter: Scott Murphy Heiberg
> Priority: Minor
>
> When a script throws, the {{groovy}} command logs its message with the
> placeholder unfilled, then prints the exception's stack trace twice: first
> unsanitized, through the logger, then sanitized, by {{printStackTrace()}}.
> Throws.groovy:
> {code:groovy}
> throw new IllegalStateException('boom')
> {code}
> Groovy 6.0.0 on JDK 25:
> {noformat}
> $ groovy Throws.groovy
> Nov 07, 2026 10:58:15 PM groovy.ui.GroovyMain run
> SEVERE: Caught: {0}
> java.lang.IllegalStateException: boom
> at Throws.run(Throws.groovy:1)
> at
> groovy.lang.GroovyShell.runScriptOrMainOrTestOrRunnable(GroovyShell.java:322)
> at groovy.lang.GroovyShell.run(GroovyShell.java:468)
> at groovy.lang.GroovyShell.run(GroovyShell.java:457)
> at groovy.ui.GroovyMain.processOnce(GroovyMain.java:851)
> at groovy.ui.GroovyMain.run(GroovyMain.java:450)
> at groovy.ui.GroovyMain$GroovyCommand.process(GroovyMain.java:355)
> at groovy.ui.GroovyMain.processArgs(GroovyMain.java:168)
> at groovy.ui.GroovyMain.main(GroovyMain.java:127)
> at
> java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
> at java.base/java.lang.reflect.Method.invoke(Method.java:565)
> at
> org.codehaus.groovy.tools.GroovyStarter.rootLoader(GroovyStarter.java:150)
> at org.codehaus.groovy.tools.GroovyStarter.main(GroovyStarter.java:52)
> java.lang.IllegalStateException: boom
> at Throws.run(Throws.groovy:1)
> {noformat}
> The 6.0.1-SNAPSHOT and master behave the same. Before GROOVY-11886 the
> command printed {{Caught: java.lang.IllegalStateException: boom}} and then
> the sanitized trace once.
> Cause: GROOVY-11886 replaced {{System.err.println("Caught: " + e)}} in
> {{GroovyMain.run()}} with
> {code:java}
> LOGGER.log(ERROR, "Caught: {0}", e);
> {code}
> Because {{e}} is a {{Throwable}}, Java selects {{System.Logger.log(Level,
> String, Throwable)}} rather than {{log(Level, String, Object...)}}. The
> message is not formatted, and the throwable is logged with its full stack
> trace before {{StackTraceUtils.deepSanitize}} runs, so that copy ignores the
> {{-d}} setting. The other logging calls with a \{0\} placeholder pass
> arguments that are not throwables and are not affected.
> The line was noticed, as a side note, in the description of GROOVY-12683.
> Proposed fix: log the text only, {{LOGGER.log(ERROR, "Caught: " + e)}}, and
> keep the single sanitized {{printStackTrace()}}. A pull request with a test
> in GroovyMainTest follows.
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
