[slf4j-dev] [JIRA] Updates for SLF4J-497: SLF4JLocationAwareLog avoid building message when logging level is disabled
QOS.CH (JIRA)
noreply-jira at qos.ch
Thu Aug 6 16:05:00 CEST 2020
SLF4J / SLF4J-497 [Open]
SLF4JLocationAwareLog avoid building message when logging level is disabled
==============================
Here's what changed in this issue in the last few minutes.
This issue has been created
This issue is now assigned to you.
View or comment on issue using this link
https://jira.qos.ch/browse/SLF4J-497
==============================
Issue created
------------------------------
Antonio Tomac created this issue on 06/Aug/20 3:53 PM
Summary: SLF4JLocationAwareLog avoid building message when logging level is disabled
Issue Type: Improvement
Affects Versions: 1.7.30
Assignee: SLF4J developers list
Components: jcl-over-slf4j
Created: 06/Aug/20 3:53 PM
Environment:
Docker
Java: 1.8
Spring Boot: 2.2.5
Spring-Kafka. 2.4.4
SL4J: 1.7.30
Labels: Performance
Priority: Minor
Reporter: Antonio Tomac
Severity: major
Description:
SLF4JLocationAwareLog converts input message {{*Object*}} into {{*String*}} on each invocation of logging method regardless if specific logging level is enabled.
This conversion is done using String.valueOf(message).
{code:java}
public void trace(Object message, Throwable t) {
logger.log(null, FQCN, LocationAwareLogger.TRACE_INT, String.valueOf(message), null, t);
}
{code}
Link to source: [https://github.com/qos-ch/slf4j/blob/v_1.8.0_beta2/jcl-over-slf4j/src/main/java/org/apache/commons/logging/impl/SLF4JLocationAwareLog.java#L120]
Passed in message object can typically be some wrapper object around of lazy lambda to produce message. Here is example where lambda is passed from spring kafka: [https://github.com/spring-projects/spring-kafka/blob/v2.4.4.RELEASE/spring-kafka/src/main/java/org/springframework/kafka/core/DefaultKafkaProducerFactory.java#L596]
Problem is that even though trace level is disabled, those messages do get constructed causing a performance penalty. In my concrete example on production, sampling showed that 20-45% of cpu time is spent here constructing message which won't even be logged.
My thinking is that it should be checked if logger is enabled for specific level before doing "expensive" operation of rendering message by converting it to string.
==============================
This message was sent by Atlassian Jira (v8.8.0#808000-sha1:e2c7e59)
More information about the slf4j-dev
mailing list