FORMAT_FAILURE when using Log.errorf or Log.infof with throwable, message and string parameter containing {

[Skrethel]

Describe the bug

Reproducible on Quarkus 3.13.0 and 3.17.5 by adding following log message. Parameter must contain "{" for error to reproduce.

Log.infof(new RuntimeException("Not important"), "Hello %s", "{world}");

Expected behavior

Quarkus should log specified message with the stacktrace from provided throwable.

Actual behavior

Quarkus throws following error

LogManager error of type FORMAT_FAILURE: Formatting error
java.lang.IllegalArgumentException: can't parse argument number: world
        at java.base/java.text.MessageFormat.makeFormat(MessageFormat.java:1485)
        at java.base/java.text.MessageFormat.applyPattern(MessageFormat.java:512)
        at java.base/java.text.MessageFormat.<init>(MessageFormat.java:383)
        at java.base/java.text.MessageFormat.format(MessageFormat.java:883)
        at org.jboss.logmanager.ExtFormatter.formatMessageLegacy(ExtFormatter.java:133)
        at org.jboss.logmanager.ExtFormatter.formatMessage(ExtFormatter.java:96)
        at org.jboss.logmanager.formatters.ColorPatternFormatter.formatMessage(ColorPatternFormatter.java:129)
        at org.jboss.logmanager.formatters.Formatters$16.renderRaw(Formatters.java:832)
        at org.jboss.logmanager.formatters.Formatters$JustifyingFormatStep.render(Formatters.java:227)
        at org.jboss.logmanager.formatters.ColorPatternFormatter$ColorStep.render(ColorPatternFormatter.java:152)
        at org.jboss.logmanager.formatters.MultistepFormatter.format(MultistepFormatter.java:90)
        at org.jboss.logmanager.ExtFormatter$Delegating.format(ExtFormatter.java:196)
        at org.jboss.logmanager.ExtFormatter.format(ExtFormatter.java:58)
        at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:54)
        at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:88)
        at io.quarkus.deployment.logging.LoggingResourceProcessor$2.accept(LoggingResourceProcessor.java:485)
        at io.quarkus.deployment.logging.LoggingResourceProcessor$2.accept(LoggingResourceProcessor.java:420)
        at io.quarkus.runtime.logging.LoggingSetupRecorder$7.publish(LoggingSetupRecorder.java:621)
        at org.jboss.logmanager.ExtHandler.publishToNestedHandlers(ExtHandler.java:138)
        at io.quarkus.bootstrap.logging.QuarkusDelayedHandler.doPublish(QuarkusDelayedHandler.java:81)
        at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:88)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:438)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:480)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:480)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:480)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:480)
        at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:480)
        at org.jboss.logmanager.Logger.logRaw(Logger.java:921)
        at org.jboss.logmanager.Logger.log(Logger.java:884)
        at org.jboss.logging.JBossLogManagerLogger.doLogf(JBossLogManagerLogger.java:56)
        at org.jboss.logging.Logger.infof(Logger.java:1189)
        at org.acme.getting.started.GreetingResource.hello(GreetingResource.java:26)
        at org.acme.getting.started.GreetingResource$quarkusrestinvoker$hello_e747664148511e1e5212d3e0f4b40d45c56ab8a1.invoke(Unknown Source)
        at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
        at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
        at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
        at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:637)
        at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654)
        at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: java.lang.NumberFormatException: For input string: "world"
        at java.base/java.lang.NumberFormatException.forInputString(NumberFormatException.java:67)
        at java.base/java.lang.Integer.parseInt(Integer.java:662)
        at java.base/java.lang.Integer.parseInt(Integer.java:778)
        at java.base/java.text.MessageFormat.makeFormat(MessageFormat.java:1483)
        ... 44 more

How to Reproduce?

Add following log message and run the code

Log.infof(new RuntimeException("Not important"), "Hello %s", "{world}");

Output of uname -a or ver

Linux REDACTED 5.14.0-547.el9.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Dec 30 20:10:38 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

OpenJDK 64-Bit Server VM Corretto-21.0.5.11.1 (build 21.0.5+11-LTS, mixed mode, sharing)

Quarkus version or git rev

3.17.5

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.9.9 (8e8579a9e76f7d015ee5ec7bfcdc97d260186937)

Additional information

No response

[gastaldi]

Fixed in 3.15.3. See #44540

[gsmet]

The OP is saying it's reproducible with 3.17.5 so it looks like we haven't fully fixed things.

[gsmet]

@Skrethel can you confirm you can only reproduce it in dev mode for 3.17.5?

I got it working with tests and prod mode but it's failing in dev mode for me.

[gastaldi]

Funny I can't reproduce with 999-SNAPSHOT, maybe something in main wasn't backported to 3.17?

[gastaldi]

Probably 3.17 is missing #44565

[Skrethel]

I've tested on 3.17.5 and it reproduces in dev mode.

[Skrethel]

I've used getting started with provided log message in one methods.

[gastaldi]

I can confirm that backporting 8fe3c76 to 3.17 solves the problem

[Skrethel]

Sorry I've missed the part about checking dev mode only.
It is not reproducing in compiled jar run from outside dev mode.

[gsmet]

Yeah, so I think the bug is in JBoss Log Manager even if the commit pointed by @gastaldi also fixes the issue:

https://github.com/jboss-logging/jboss-logmanager/blob/9482bdadfdceff48350a869dc3d24914ce367c12/src/main/java/org/jboss/logmanager/ExtHandler.java#L127-L137

When translating the message from printf to messageformat, we should escape the parameters or we can end up with a parameter injecting something that won't work with the new format.

In the case of the OP, when the translation occurs, we end up with hello {world}.

/cc @jamezp @dmlloyd