Gonzalo Calvo
Gonzalo Calvo

Reputation: 314

Sonarlint complaint in log writting method

log.info(String.format("Execution of method %s finished in %d ms", pointcut.getSignature().getName(), ms))

Sonarlint shows the following error:

"Preconditions" and logging arguments should not require evaluation

Compliant Solution:

logger.log(Level.SEVERE, "Something went wrong: {0} ", message);

Lets try that:

log.info("Execution of method {0} finished in {1} ms", pointcut.getSignature().getName(), ms);

Printf-style format strings should be used correctly

Compliant Solution:

String.format("First %s and then %s", "foo", "bar");

I feel like sonarlint is just mocking me.

This is my out of his judgement but I don't really understand whats going or why he complaints in the first place:

String logMessage = String.format("Execution of method %s finished in %d ms", pointcut.getSignature().getName(), ms);
log.info(logMessage);

Any ideas?

Upvotes: 3

Views: 3016

Answers (2)

Stephen C
Stephen C

Reputation: 718788

I don't really understand whats going or why he complaints in the first place:

The reason for the complaint in the first example is that you are unconditionally doing substantial work to construct a log message. The work will be wasted if the log level is higher than INFO.


The second example is better than the first because the log message string is only created from the template if the log level is at INFO or lower. The pointcut.getSignature().getName() expression is still evaluated unconditionally, but that may be unavoidable depending on the specific logging API you are using.

(If evaluating that is expensive, you still have a performance issue. You could look at using an if (log.isInfoLevel()) { ... } guard, or something to make the expression evaluation lazy; e.g. a Supplier<String>. But the best solution may be to avoid logging that expensive expression.)


The Sonar complaint in the second example seems to be about the particular syntax you used in the message / format string. @C.Lechner's answer explains it thus:

  • In the first version with {} the type of {} is evaluated at runtime.
  • In the 2nd with %s, %d you define the type at compile time.

If possible you should use a type to avoid misuse of placeholder variables and allow java compiler to do some additional checks.

I'm not entirely convinced that the Java compiler would do the checking. (It is certainly not required by the JLS.) But it is certainly plausible that a compiler or a (smart) static code analyzer could check.

Either way, the format string will be checked (again) at runtime.


Finally, this version:

String logMessage = String.format("Execution of method %s finished in %d ms",
                                  pointcut.getSignature().getName(), ms);
log.info(logMessage);

has the same performance issue as the first version, but I suspect that Sonar is not smart enough to figure that out.

Upvotes: 4

C.Lechner
C.Lechner

Reputation: 25

  • In the first version with {} the type of {} is evaluated at runtime.
  • In the 2nd with %s, %d you define the type at compile time.

If possible you should use a type to avoid misuse of placeholder variables and allow java compiler to do some additional checks.

Upvotes: 0

Related Questions