[
https://issues.apache.org/jira/browse/QPID-8439?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tomas Vavricka updated QPID-8439:
---------------------------------
Description:
We are occasionally seeing stack overflow during logging in QPid. This
completely kills the broker because some data structure are not initialized
correctly any more afterwards. The problems lies in the combination of SLf4j
use in QPid and the logging in the BDB implementation. BDB is configured using
the Slf4jLoggingHandler in
{{org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.StandardEnvironmentFacade(StandardEnvironmentConfiguration)}}
which eventually ends up at the JDK logger (at least in our setup). However,
BDB has a {{com.sleepycat.je.utilint.ConfiguredRedirectHandler}} which is
appended to the the JDK logger and logs records from it to the configured
Slf4jLoggingHandler. Which in turn forwards them to the JDK logger and there it
starts again. The error is so obvious which makes me wonder why nobody else has
reported it before. Is there some kind of configuration that we have set wrong?
*Analysis*
BDB JE uses JUL logging and adds its own logging handlers to its internal
loggers. When it logs something, the
com.sleepycat.je.utilint.ConfiguredRedirectHandler calls
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler forming a
chain of recursive calls:
{noformat}
at java.util.logging.Logger.log(Logger.java:738)
at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
at
com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
at java.util.logging.Logger.log(Logger.java:738)
at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
at
com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
at java.util.logging.Logger.log(Logger.java:738)
at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
at
com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
at java.util.logging.Logger.log(Logger.java:738)
at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
at
org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
at
com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
at java.util.logging.Logger.log(Logger.java:738)
at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
{noformat}
*Implementation*
To fix the issue a ThreadLocal switch is added to the Slf4jLoggingHandler,
checking whether this call is recursive or not. To improve performance an
additional static check is added, verifying if slf4j-jdk14 library s loaded or
not.
was:We are occasionally seeing stack overflow during logging in QPid. This
completely kills the broker because some data structure are not initialized
correctly any more afterwards. The problems lies in the combination of SLf4j
use in QPid and the logging in the BDB implementation. BDB is configured using
the Slf4jLoggingHandler in
{{org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.StandardEnvironmentFacade(StandardEnvironmentConfiguration)}}
which eventually ends up at the JDK logger (at least in our setup). However,
BDB has a {{com.sleepycat.je.utilint.ConfiguredRedirectHandler}} which is
appended to the the JDK logger and logs records from it to the configured
Slf4jLoggingHandler. Which in turn forwards them to the JDK logger and there it
starts again. The error is so obvious which makes me wonder why nobody else has
reported it before. Is there some kind of configuration that we have set wrong?
> [Broker-J] Stack overflow during logging
> ----------------------------------------
>
> Key: QPID-8439
> URL: https://issues.apache.org/jira/browse/QPID-8439
> Project: Qpid
> Issue Type: Bug
> Components: Broker-J
> Affects Versions: qpid-java-broker-7.0.6
> Reporter: Thorsten Meinl
> Priority: Major
> Fix For: qpid-java-broker-9.2.1
>
> Attachments: catalina.out
>
>
> We are occasionally seeing stack overflow during logging in QPid. This
> completely kills the broker because some data structure are not initialized
> correctly any more afterwards. The problems lies in the combination of SLf4j
> use in QPid and the logging in the BDB implementation. BDB is configured
> using the Slf4jLoggingHandler in
> {{org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.StandardEnvironmentFacade(StandardEnvironmentConfiguration)}}
> which eventually ends up at the JDK logger (at least in our setup). However,
> BDB has a {{com.sleepycat.je.utilint.ConfiguredRedirectHandler}} which is
> appended to the the JDK logger and logs records from it to the configured
> Slf4jLoggingHandler. Which in turn forwards them to the JDK logger and there
> it starts again. The error is so obvious which makes me wonder why nobody
> else has reported it before. Is there some kind of configuration that we have
> set wrong?
> *Analysis*
> BDB JE uses JUL logging and adds its own logging handlers to its internal
> loggers. When it logs something, the
> com.sleepycat.je.utilint.ConfiguredRedirectHandler calls
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler forming a
> chain of recursive calls:
> {noformat}
> at java.util.logging.Logger.log(Logger.java:738)
> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
> at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
> at
> com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
> at java.util.logging.Logger.log(Logger.java:738)
> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
> at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
> at
> com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
> at java.util.logging.Logger.log(Logger.java:738)
> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
> at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
> at
> com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
> at java.util.logging.Logger.log(Logger.java:738)
> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
> at org.slf4j.impl.JDK14LoggerAdapter.warn(JDK14LoggerAdapter.java:378)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler$3.log(Slf4jLoggingHandler.java:148)
> at
> org.apache.qpid.server.store.berkeleydb.logging.Slf4jLoggingHandler.publish(Slf4jLoggingHandler.java:229)
> at
> com.sleepycat.je.utilint.ConfiguredRedirectHandler.publish(ConfiguredRedirectHandler.java:40)
> at java.util.logging.Logger.log(Logger.java:738)
> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:582)
> {noformat}
> *Implementation*
> To fix the issue a ThreadLocal switch is added to the Slf4jLoggingHandler,
> checking whether this call is recursive or not. To improve performance an
> additional static check is added, verifying if slf4j-jdk14 library s loaded
> or not.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
