[
Date Prev][
Date Next][
Thread Prev][
Thread Next][
Date Index][
Thread Index]
[
List Home]
|
[jetty-dev] Deadlock between WebAppClassLoader and Logback
|
Hi Jetty-Dev,
During tests of my application I experienced a deadlock between the Jetty WebAppClassLoader and the AppenderBase class of logback.
This issue has been reported to Logback on Jun 2009 (
LOGBACK-648).
Unfortunately I didn't find any post related to this issue in the Jetty mailing lists; if I'm wrong, please give me a pointer to the discussion.
I attached the jstack dump of the two threads that block each other:
- One thread (ForkJoinPool-1-worker-1) is loading a class and for debug reasons WebAppClassLoader tries to log;
- the second thread (ForkJoinPool-1-worker-2) tries to log a CometD outgoing message and in order to format the messsage, a new object is needed.
In this specific scenario I'm using Jetty 9.3.9.v20160517 but the issue is also replicable with Jetty 9.3.11.
Please note that the WebAppClassLoader#loadClass(String,boolean) has an unprotected LOG.debug statement.
Do you have any suggestion to avoid the deadlock?
Thanks,
Marco
--
Email sent by Signorini Marco.
Found one Java-level deadlock:
=============================
"ForkJoinPool-1-worker-2":
waiting to lock monitor 0x00007f9b34005458 (object 0x0000000604fdb7e8, a mycompany.launcher.MyWebAppClassLoader),
which is held by "ForkJoinPool-1-worker-1"
"ForkJoinPool-1-worker-1":
waiting to lock monitor 0x00007f9af00302b8 (object 0x0000000604e8d3e0, a mycompany.utils.logging.MyAppender),
which is held by "ForkJoinPool-1-worker-2"
Java stack information for the threads listed above:
===================================================
"ForkJoinPool-1-worker-2":
at mycompany.streaming.e.e.a(SubscriptionServerMessage.java:151)
at mycompany.streaming.e.e.a(SubscriptionServerMessage.java:140)
at mycompany.streaming.e.e.getJSON(SubscriptionServerMessage.java:122)
at mycompany.streaming.e.e.toString(SubscriptionServerMessage.java:311)
at org.slf4j.helpers.MessageFormatter.safeObjectAppend(MessageFormatter.java:298)
at org.slf4j.helpers.MessageFormatter.deeplyAppendParameter(MessageFormatter.java:270)
at org.slf4j.helpers.MessageFormatter.arrayFormat(MessageFormatter.java:232)
at org.slf4j.helpers.MessageFormatter.arrayFormat(MessageFormatter.java:172)
at ch.qos.logback.classic.spi.LoggingEvent.getFormattedMessage(LoggingEvent.java:293)
at ch.qos.logback.classic.pattern.MessageConverter.convert(MessageConverter.java:26)
at ch.qos.logback.classic.pattern.MessageConverter.convert(MessageConverter.java:1)
at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:114)
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:141)
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:1)
at mycompany.utils.logging.MyAppender.append(MyAppender.java:152)
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:82)
- locked <0x0000000604e8d3e0> (a mycompany.utils.logging.MyAppender)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:422)
at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:399)
at ch.qos.logback.classic.Logger.debug(Logger.java:487)
at org.cometd.server.BayeuxServerImpl.extendSend(BayeuxServerImpl.java:1097)
at org.cometd.server.ServerSessionImpl.deliver(ServerSessionImpl.java:218)
at mycompany.streaming.e.d.a(DefaultPrivateChannelPublisher.java:65)
at mycompany.streaming.handlers.a.c(Message.java:29)
at mycompany.streaming.b.b.a(BufferedServerSessionImpl.java:354)
- locked <0x0000000730ef9c50> (a mycompany.streaming.b.b)
at mycompany.streaming.b.b.g(BufferedServerSessionImpl.java:309)
- locked <0x0000000730ef9c50> (a mycompany.streaming.b.b)
at mycompany.streaming.b.b.f(BufferedServerSessionImpl.java:43)
at mycompany.streaming.b.b$2.run(BufferedServerSessionImpl.java:260)
at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
"ForkJoinPool-1-worker-1":
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:63)
- waiting to lock <0x0000000604e8d3e0> (a mycompany.utils.logging.MyAppender)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:422)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:384)
at ch.qos.logback.classic.Logger.log(Logger.java:766)
at org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:620)
at org.eclipse.jetty.util.log.JettyAwareLogger.debug(JettyAwareLogger.java:206)
at org.eclipse.jetty.util.log.Slf4jLog.debug(Slf4jLog.java:89)
at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:445)
- locked <0x0000000604fdb7e8> (a mycompany.launcher.MyWebAppClassLoader)
at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:428)
at com.google.common.collect.Sets.newHashSetWithExpectedSize(Sets.java:202)
at com.google.common.collect.HashMultimap.createCollection(HashMultimap.java:114)
at com.google.common.collect.HashMultimap.createCollection(HashMultimap.java:49)
at com.google.common.collect.AbstractMapBasedMultimap.createCollection(AbstractMapBasedMultimap.java:167)
at com.google.common.collect.AbstractMapBasedMultimap.put(AbstractMapBasedMultimap.java:192)
at com.google.common.collect.AbstractSetMultimap.put(AbstractSetMultimap.java:121)
at com.google.common.collect.HashMultimap.put(HashMultimap.java:49)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.a.a(AvailabilityService.java:56)
- locked <0x0000000604b5c8d0> (a mycompany.mkv.MkvPublishManager)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.g$d.a(ChainSubscriptionManagerImpl.java:82)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.g$c.a(ChainSubscriptionManagerImpl.java:46)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.g.c(ChainSubscriptionManagerImpl.java:253)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.e$d.b(ChainRecordSubscriptionManagerImpl.java:98)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.e$c.a(ChainRecordSubscriptionManagerImpl.java:57)
at mycompany.streaming.handlers.subscriptions.ionbus.utils.e.b(ChainRecordSubscriptionManagerImpl.java:266)
at mycompany.streaming.handlers.subscriptions.ionbus.b.a(ChainRecordsSubscriptionHandler.java:50)
at mycompany.streaming.handlers.subscriptions.ionbus.a.x(AbstractChainSubscriptionHandler.java:286)
at mycompany.streaming.handlers.subscriptions.ionbus.a$$Lambda$9/941797661.run(Unknown Source)
at mycompany.streaming.handlers.subscriptions.ionbus.e$1.a(IonBusUnderlyingSubscriptionHandler.java:235)
at mycompany.streaming.shared.g.run(DispatcherTask.java:12)
at mycompany.streaming.shared.i.a(IonDispatcherExecutor.java:103)
at mycompany.streaming.shared.i$1.run(IonDispatcherExecutor.java:67)
at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Found 1 deadlock.
