Jiangjie Qin created KAFKA-2454:
-----------------------------------
Summary: Dead lock between delete log segment and shutting down.
Key: KAFKA-2454
URL: https://issues.apache.org/jira/browse/KAFKA-2454
Project: Kafka
Issue Type: Bug
Reporter: Jiangjie Qin
Assignee: Jiangjie Qin
When the broker shutdown, it will shutdown scheduler which grabs the scheduler
lock then wait for all the threads in scheduler to shutdown.
The dead lock will happen when the scheduled task try to delete old log
segment, it will schedule a log delete task which also needs to acquire the
scheduler lock. In this case the shutdown thread will hold scheduler lock and
wait for the the log deletion thread to finish, but the log deletion thread
will block on waiting for the scheduler lock.
Related stack trace:
{noformat}
"Thread-1" #21 prio=5 os_prio=0 tid=0x00007fe7601a7000 nid=0x1a4e waiting on
condition [0x00007fe7cf698000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000640d53540> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1465)
at kafka.utils.KafkaScheduler.shutdown(KafkaScheduler.scala:94)
- locked <0x0000000640b6d480> (a kafka.utils.KafkaScheduler)
at
kafka.server.KafkaServer$$anonfun$shutdown$4.apply$mcV$sp(KafkaServer.scala:352)
at kafka.utils.CoreUtils$.swallow(CoreUtils.scala:79)
at kafka.utils.Logging$class.swallowWarn(Logging.scala:92)
at kafka.utils.CoreUtils$.swallowWarn(CoreUtils.scala:51)
at kafka.utils.Logging$class.swallow(Logging.scala:94)
at kafka.utils.CoreUtils$.swallow(CoreUtils.scala:51)
at kafka.server.KafkaServer.shutdown(KafkaServer.scala:352)
at
kafka.server.KafkaServerStartable.shutdown(KafkaServerStartable.scala:42)
at com.linkedin.kafka.KafkaServer.notifyShutdown(KafkaServer.java:99)
at
com.linkedin.util.factory.lifecycle.LifeCycleMgr.notifyShutdownListener(LifeCycleMgr.java:123)
at
com.linkedin.util.factory.lifecycle.LifeCycleMgr.notifyListeners(LifeCycleMgr.java:102)
at
com.linkedin.util.factory.lifecycle.LifeCycleMgr.notifyStop(LifeCycleMgr.java:82)
- locked <0x0000000640b77bb0> (a java.util.ArrayDeque)
at com.linkedin.util.factory.Generator.stop(Generator.java:177)
- locked <0x0000000640b77bc8> (a java.lang.Object)
at
com.linkedin.offspring.servlet.OffspringServletRuntime.destroy(OffspringServletRuntime.java:82)
at
com.linkedin.offspring.servlet.OffspringServletContextListener.contextDestroyed(OffspringServletContextListener.java:51)
at
org.eclipse.jetty.server.handler.ContextHandler.doStop(ContextHandler.java:813)
at
org.eclipse.jetty.servlet.ServletContextHandler.doStop(ServletContextHandler.java:160)
at org.eclipse.jetty.webapp.WebAppContext.doStop(WebAppContext.java:516)
at com.linkedin.emweb.WebappContext.doStop(WebappContext.java:35)
at
org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
- locked <0x00000006400018b8> (a java.lang.Object)
at
com.linkedin.emweb.ContextBasedHandlerImpl.doStop(ContextBasedHandlerImpl.java:112)
at
org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
- locked <0x0000000640001900> (a java.lang.Object)
at
com.linkedin.emweb.WebappDeployerImpl.stop(WebappDeployerImpl.java:349)
at
com.linkedin.emweb.WebappDeployerImpl.doStop(WebappDeployerImpl.java:414)
- locked <0x00000006400019c0> (a com.linkedin.emweb.MapBasedHandlerImpl)
at
org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
- locked <0x00000006404ee8e8> (a java.lang.Object)
at
org.eclipse.jetty.util.component.AggregateLifeCycle.doStop(AggregateLifeCycle.java:107)
at
org.eclipse.jetty.server.handler.AbstractHandler.doStop(AbstractHandler.java:69)
at
org.eclipse.jetty.server.handler.HandlerWrapper.doStop(HandlerWrapper.java:108)
at org.eclipse.jetty.server.Server.doStop(Server.java:338)
at
org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
- locked <0x0000000640476ab0> (a java.lang.Object)
at com.linkedin.emweb.BaseRunner.destroy(BaseRunner.java:162)
at
com.linkedin.spring.core.TerminationHandler.destroy(TerminationHandler.java:151)
at
com.linkedin.spring.core.TerminationHandler.runTermination(TerminationHandler.java:113)
at
com.linkedin.spring.core.TerminationHandler.destroy(TerminationHandler.java:79)
at
com.linkedin.spring.core.SettableFactoryBean.destroy(SettableFactoryBean.java:68)
at
org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:211)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:500)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:476)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:445)
at
org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1078)
at
org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1052)
at
org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:1000)
- locked <0x000000064001c718> (a java.lang.Object)
at
com.linkedin.spring.cmdline.CmdLineAppRunner.terminate(CmdLineAppRunner.java:277)
at
com.linkedin.spring.cmdline.CmdLineAppRunner$1.run(CmdLineAppRunner.java:219)
...
"kafka-scheduler-2" #272 daemon prio=5 os_prio=0 tid=0x00007fecd58be000
nid=0x7868 waiting for monitor entry [0x00007feb991d4000]
java.lang.Thread.State: BLOCKED (on object monitor)
at kafka.utils.KafkaScheduler.schedule(KafkaScheduler.scala:103)
- waiting to lock <0x0000000640b6d480> (a kafka.utils.KafkaScheduler)
at kafka.log.Log.kafka$log$Log$$asyncDeleteSegment(Log.scala:789)
at kafka.log.Log.kafka$log$Log$$deleteSegment(Log.scala:775)
- locked <0x0000000641d18030> (a java.lang.Object)
at kafka.log.Log$$anonfun$deleteOldSegments$1.apply(Log.scala:533)
at kafka.log.Log$$anonfun$deleteOldSegments$1.apply(Log.scala:533)
at scala.collection.immutable.List.foreach(List.scala:318)
at kafka.log.Log.deleteOldSegments(Log.scala:533)
- locked <0x0000000641d18030> (a java.lang.Object)
at
kafka.log.LogManager.kafka$log$LogManager$$cleanupExpiredSegments(LogManager.scala:421)
at
kafka.log.LogManager$$anonfun$cleanupLogs$3.apply(LogManager.scala:452)
at
kafka.log.LogManager$$anonfun$cleanupLogs$3.apply(LogManager.scala:450)
at
scala.collection.TraversableLike$WithFilter$$anonfun$foreach$1.apply(TraversableLike.scala:772)
at scala.collection.Iterator$class.foreach(Iterator.scala:727)
at scala.collection.AbstractIterator.foreach(Iterator.scala:1157)
at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
at
scala.collection.TraversableLike$WithFilter.foreach(TraversableLike.scala:771)
at kafka.log.LogManager.cleanupLogs(LogManager.scala:450)
at
kafka.log.LogManager$$anonfun$startup$1.apply$mcV$sp(LogManager.scala:190)
at
kafka.utils.KafkaScheduler$$anonfun$1.apply$mcV$sp(KafkaScheduler.scala:108)
at kafka.utils.CoreUtils$$anon$1.run(CoreUtils.scala:60)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
