[infinispan-dev] JBoss Logged and conversion formats failures

[Sanne Grinovero]

So the problem is LOGTOOL-34; briefly:
The generated loggers invoke toString() on the parameters, so anything
you might pass to a tracef, tracev, debugf, debugv method is going to
be treated as a String.

Performance wise, the toString() on the parameter is evaluated
*before* the logging level is checked, so an innocently looking method
like

log.tracef("Wait for on-going transactions to finish for %d seconds.", 5);

is actually concealing two additional method invocations: it's actually

log.tracef("Wait for on-going transactions to finish for %d seconds.",
Integer.valueOf( 5 ).toString() );

(More specifically the above line doesn't even work, as it's passing a
String where a number is expected)

LOGTOOL-34 was fixed already, but not released yet. I'm checking if we
can get a quick tag including the fix, or if we should
rollback/workaround our logging (I'd rather move forward).

Sanne


On 21 October 2011 12:28, Sanne Grinovero <sanne at infinispan.org> wrote:
> We're failing on log messages; I'm having a look but wondering if it
> rings a bell to someone?
>
> It complains about illegal formats, while the format is correct:
>
> In this case the stop method is passing a long, and converting it via %d
>
> Caused by: java.util.IllegalFormatConversionException: d != java.lang.String
>        at java.util.Formatter$FormatSpecifier.failConversion(Formatter.java:3999)
>        at java.util.Formatter$FormatSpecifier.printInteger(Formatter.java:2709)
>        at java.util.Formatter$FormatSpecifier.print(Formatter.java:2661)
>        at java.util.Formatter.format(Formatter.java:2433)
>        at java.util.Formatter.format(Formatter.java:2367)
>        at java.lang.String.format(String.java:2769)
>        at org.jboss.logging.Log4jLogger.doLogf(Log4jLogger.java:48)
>        at org.jboss.logging.Logger.logf(Logger.java:2097)
>        at org.infinispan.util.logging.Log_$logger.tracef(Log_$logger.java:650)
>        at org.infinispan.transaction.TransactionTable.stop(TransactionTable.java:134)
>
> In this other case, it's a debug message passing an int value, again
> formatted with %d :
>
> Caused by: java.util.IllegalFormatConversionException: d != java.lang.String
>       at java.util.Formatter$FormatSpecifier.failConversion(Formatter.java:3999)
>       at java.util.Formatter$FormatSpecifier.printInteger(Formatter.java:2709)
>       at java.util.Formatter$FormatSpecifier.print(Formatter.java:2661)
>       at java.util.Formatter.format(Formatter.java:2433)
>       at java.util.Formatter.format(Formatter.java:2367)
>       at java.lang.String.format(String.java:2769)
>       at org.jboss.logging.Log4jLogger.doLogf(Log4jLogger.java:48)
>       at org.jboss.logging.Logger.logf(Logger.java:2097)
>       at org.infinispan.util.logging.Log_$logger.debugf(Log_$logger.java:875)
>       at org.infinispan.interceptors.InterceptorChain.printChainInfo(InterceptorChain.java:71)
>
> Using org.jboss.logging:jboss-logging:jar:3.0.1 and version 1.0.0.CR2
> of jboss-logging-processor
>