[
https://issues.redhat.com/browse/LOGMGR-263?page=com.atlassian.jira.plugi...
]
Emond Papegaaij commented on LOGMGR-263:
----------------------------------------
We are hitting this problem as well. In our application we see a lot of threads in
{{getLogger}} (see attached stackdump). Many of these come from OpenSAML, where they use
instance fields for loggers (or in some cases even create a new logger per log statement).
See this link for more information on OpenSAML and the reason why they do logging like
this:
[
SIDP-425|https://issues.shibboleth.net/jira/browse/SIDP-425?focusedCommen...]
. The effect is that on a single SAML request, hundreds, if not thousands of loggers are
instantiated.
To make things worse, the {{StackWalker}} seems to accumulate state on every call, making
it slower over time. We see a steady increase in response times over time (see attached
graph). This increase continues until a full GC runs, after which the response times
return to normal. The entire delta (from less than 100ms to over 1s) is caused by logger
lookups.
For now, we've developed a workaround for this issue by setting the {{LogContext}} at
the beginning of the request and clearing it at the end (classes attached). This reduces
the number of stack walks to one. This workaround also shows a severe weakness in the
stack walking approach. When {{LogContextCacher}} is deployed in a war inside an ear, the
call stack only contains stack frames in WildFly and Undertow and 1 frame in
{{LogContextCacher}}. The {{LogContext}} that it should resolve is registered for the ear
classloader. However, because none of the stack frames touch code in the ear classloader,
it doesn't find this {{LogContext}} and returns the {{SYSTEM_CONTEXT}}. The parent
classloader of a war deployment inside an ear is the
{{jdk.internal.loader.ClassLoaders$AppClassLoader}}, not the ear classloader.
Logger Lookup is much slower as with JDK 8
------------------------------------------
Key: LOGMGR-263
URL:
https://issues.redhat.com/browse/LOGMGR-263
Project: JBoss Log Manager
Issue Type: Bug
Environment: WildFly 17, OpenJDK 11
Reporter: Andreas Liebscher
Priority: Major
Attachments: ClassInEar.java, LogContextCacher.java, getlogger-stack.txt,
grafik1570016303722 (1).png, grafik1570016303722.png, grafik1570016791285.png,
responsetimes.png
During upgrading a Java EE application from WildFly 13 with JDK 8 to WildFly 17 with JDK
11 we had a serious performance issue. We identified the usage of the logging framework
SLF4J with the pattern `Logger log = LoggerFactory.getLogger(XXX.class)` was the reason
when a lot of calls to `getLogger` occur in parallel. As workaround we added `static` to
some code hotspots to get back the performance we were used to. Also WildFly 13 with JDK 8
got a performance improvement with the added `static` keyword.
Please check the VisualVM output as prove of JDKSpecific got slower:
--
This message was sent by Atlassian Jira
(v7.13.8#713008)