[slf4j-user] When more parameters than placeholders, extra parameters are not logged

[Ceki Gulcu]

Hi Joachim,

Thank you for your thoughtful comments.

As a side note, I would like to insist that using parameters messages 
should be preferred to message and parameter concatenation for the 
performance argument of the no-log case you mentioned.

For the log-enabled case, for parameterized message the back-end can 
perform optimizations that it cannot perform if the message already 
incorporates the parameters via string concatenation.

Best regards,

On 02/02/2025 10:30, Joachim Durchholz via slf4j-user wrote:
> On 25.01.25 02:38, Russ Block via slf4j-user wrote:
>> With this method or any similar method,
>>      public void info(String format, Object... arguments) {
>>          if (isInfoEnabled()) {
>>              handleArgArrayCall(Level.INFO, null, format, arguments);
>>          }
>>      }
>> If the number of objects in 'arguments' is more than the number of 
>> placeholders, {}, the extra argument objects are not logged.  Is there 
>> a reason for that?
> 
> I can't answer authoritatively, but I guess it is outside the scope of 
> the specification as-is.
> 
> For people using IntelliJ it is not a problem as it knows about SLF4J 
> and flags log lines with extra or missing arguments.
> Even better, IntelliJ will give you a refactoring option to replace
>    logger.log("foo is: " + foo)
> with
>    logger.log("foo is: {}", foo)
> It also correctly handles the case with multiple parameters, and there's 
> even a hotkey for making it happen that my brain does not remember 
> anymore but my fingers do.
> 
> I hope other IDEs have started offering similar functionality, but I 
> don't know specifics.
> IntelliJ does have some deficits, in particular its cache management if 
> pretty flaky compared to Eclipse's, but I found IntelliJ's refactoring 
> support such a time-save that I embraced it and never looked back, 
> though other IDEs might (should, actually!) have caught up since.
> 
>> If I get into a situation where I have sent more argument objects than 
>> placeholders that it should append those un-placed arguments to the 
>> end of the logged string.  The intent of the developer is to have the 
>> parameter logged.  Finding this out from production is not good.  What 
>> is sent to be logged is important information, depending on the log 
>> level.
> 
> The knee-jerk answer to that would be "you have a bug in your code, just 
> fix it".
> (I believe that you want something sensible but your arguments are not 
> strong enough. I.e. I'm going to strike down the arguments and 
> suggesting a solution, so don't get disappointed before the end.)
> 
>> My use case is that I want to push some legacy code to start looking 
>> like SLF4J so we can migrate away from the older pattern filled with 
>> isLogTraceEnabled calls.
> 
> I'd assume that you had extra parameters in the legacy code as well, so 
> your situation did not get worse, did it?
> 
>  > I learned of the above when I was writing > JUnit tests to see all 
> the things the code would do and not do.
>  >
>> I feel that https://www.slf4j.org/faq.html#logging_performance is 
>> telling me that, in some way, the placeholder string substitution is 
>> faster than appending multiple strings together.  I understood the 
>> main point of the argument as converting items to string before I 
>> needed them was where the overhead was.  Keeping them as type Object 
>> reduces that overhead.
> 
> Actually, while the placeholder substitution _is_ faster than a string 
> append, the real advantage is this:
> With logger.debug("foo is: " + foo), the + operator will be called 
> before logger.debug starts, and foo.toString() and string concatenation 
> happen whether logger.debug does anything with it or not.
> With logger.debug("foo is: {}", foo), logger.debug will FIRST check if 
> it needs to do anything, and ONLY THEN will it do string substitution.
> 
> The string substitution can actually be slightly slower than the 
> concatenation, because there's the extra step of extracting the 
> substitution markers and copying the text to the left and right of them. 
> However, the substitution code is heavily optimized and should still be 
> faster anyway in the vast majority of the cases.
> This is, however, just for the do-log case. The main speedup comes from 
> the no-log case doing less work.
> 
> 
>> I understand there are Sonarqube rules and PMD to prevent me from not 
>> having the correct number of argument objects.  This would help, but I 
>> feel like there are still going to be misses.  Since my code is 
>> custom, Sonarqube and PMD do not feel like options.
> You can configure these things to report only those bugs that you are 
> interested in.
> The main deterrent is that the setup takes time.
> 
> Now to the promised solution, should you still need it:
> 
> You can do your own Formatter that appends any the extraneous parameters.
> 
> Caveat: Formatters do not live in SLF4J, they live in the logging 
> backend - typically Logback. (SLF4J has a different and somewhat 
> confusing terminology for "backend" that I don't remember.) SLF4J merely 
> manages all the information needed to decide whether a log message 
> should actually be output, and leaves the actual outputting to the backend.
> 
> Anyway, you'll have to dive into the code of the existing standard 
> formatter, find out how it's working and how to make it append the extra 
> parameters.
> For Logback, you do not have to write your own backend, you can 
> configure your Formatter, and even inherit from Logback's standard 
> Formatter so you do not have to do a lot; however, you'll want to make 
> 150% sure that you do not introduce any bugs, so plan a lot of review 
> (if possible) and testing. Fortunately it is more time reading docs and 
> code than actual coding, so the extra effort for quality control will 
> not be very noticeable.
> 
> Still, I believe the refactoring support of an IDE, if possible, will be 
> easier :-)
> 
> HTH!
> Jo
> _______________________________________________
> slf4j-user mailing list
> slf4j-user at qos.ch
> https://mailman.qos.ch/cgi-bin/mailman/listinfo/slf4j-user

-- 
Ceki Gülcü

Sponsoring SLF4J/logback/reload4j at https://github.com/sponsors/qos-ch