[
https://issues.apache.org/jira/browse/KAFKA-10877?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17253143#comment-17253143
]
Sean McCauliff commented on KAFKA-10877:
----------------------------------------
An example thread dump.
"data-plane-kafka-request-handler-5" #187 daemon prio=5 os_prio=0
cpu=128019254.19ms elapsed=340579.66s tid=0x00007fe3092e1800 nid=0x2be4
runnable [0x00007fd58c9f5000] java.lang.Thread.State: RUNNABLE at
java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk(java.base@11.0.8/Native
Method) at
java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk(java.base@11.0.8
/StackStreamFactory.java:370) at
java.lang.StackStreamFactory$AbstractStackWalker.walk(java.base@11.0.8
/StackStreamFactory.java:243) at
java.lang.StackWalker.walk(java.base@11.0.8/StackWalker.java:498) at
org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:57)
at
org.apache.logging.log4j.util.StackLocatorUtil.getCallerClass(StackLocatorUtil.java:67)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:45)
at
org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:48)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:30)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:363) at
kafka.utils.Logging.logger(Logging.scala:43) at
kafka.utils.Logging.logger$(Logging.scala:43) at
kafka.server.IncrementalFetchContext.logger$lzycompute(FetchSession.scala:400)
- locked <0x00000005f016f650> (a kafka.server.IncrementalFetchContext) at
kafka.server.IncrementalFetchContext.logger(FetchSession.scala:400) at
kafka.utils.Logging.debug(Logging.scala:62) at
kafka.utils.Logging.debug$(Logging.scala:62) at
kafka.server.IncrementalFetchContext.debug(FetchSession.scala:400) at
kafka.server.IncrementalFetchContext.updateAndGenerateResponseData(FetchSession.scala:482)
- locked <0x00000002632d0d70> (a kafka.server.FetchSession) at
kafka.server.KafkaApis.processResponseCallback$1(KafkaApis.scala:769) at
kafka.server.KafkaApis.$anonfun$handleFetchRequest$29(KafkaApis.scala:833) at
kafka.server.KafkaApis.$anonfun$handleFetchRequest$29$adapted(KafkaApis.scala:833)
at kafka.server.KafkaApis$$Lambda$2090/0x0000000800ffb040.apply(Unknown
Source) at kafka.server.ReplicaManager.fetchMessages(ReplicaManager.scala:963)
at kafka.server.KafkaApis.handleFetchRequest(KafkaApis.scala:835) at
kafka.server.KafkaApis.handle(KafkaApis.scala:130) at
kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:70) at
java.lang.Thread.run(java.base@11.0.8/Thread.java:834)
> Instantiating loggers for every FetchContext causes low request handler idle
> pool ratio.
> ----------------------------------------------------------------------------------------
>
> Key: KAFKA-10877
> URL: https://issues.apache.org/jira/browse/KAFKA-10877
> Project: Kafka
> Issue Type: Bug
> Reporter: Sean McCauliff
> Priority: Major
>
> JDK11 has removed some classes used by log4j2 to initialize logging contexts.
> Now log4j2 uses StackWalker to discover where it has been instantiated.
> StackWalker is apparently very expensive.
> Kafka has a Logging trait. Classes which want to log application messages
> get access to the methods provided by the trait by mixing them in using "with
> Logging". When this is done on scala object (a singleton) this is fine as
> the logging context in the Logging trait is only initialized at most once.
> When this is done on class (e.g. class X extends Logging) the logging context
> is potentially created for each instance. The logging context is needed to
> determine if a log message will be emitted. So if the method debug("log me")
> is called the logging context is still initialized to determine if debug
> logging is enabled. Initializing the logging context calls StackWalker.
> This can't be avoided even if the log message would never be written to the
> log.
> IncrementalFetchContext is one such class that is inheriting from Logging and
> incurring a very high cpu cost. It also does this inside of locks.
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
