If we made a change that results in degraded performance, we should investigate and fix it. I imagine this would have an impact on application startup time even if all loggers are loaded once as static fields.
Can you confirm the log4j2 version that you're using in this example? It appears that logger instances are not stored, but instead requested from the context as needed. The process of loading a logger is meant to be potentially more expensive than subsequent uses (we want to front-load work so that each event logged later is less expensive), so minimizing calls to LogManager/LoggerFactory.getLogger is ideal regardless of other factors. Would you mind filing a jira ticket for this? Thanks, Carter On Fri, Dec 18, 2020, at 16:27, Sean McCauliff wrote: > There are many threads in our Kafka server performing logging. Their > stacks look like the stack trace below. I see from other email threads > that java.lang.StackWalker in JDK 11 is not as performant as the old sun.* > classes that are used for the same functionality. > > Since this is logged at debug level and I'm not seeing this in my logs why > does StackWalker need to be called? > > "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) >
