[AURORA-920] Deadlock during scheduler startup

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Fix Version/s: 0.6.0
• Component/s: Scheduler
• Sprint: Twitter Aurora Q4 Sprint 3
• Assignee: Kevin Sweeney
• Reporter: Bill Farner
• Created: 06/Nov/14 00:25
• Updated: 10/Nov/14 18:56
• Resolved: 10/Nov/14 18:53

Description

'Lifecycle-0' Id=270 BLOCKED
Waiting for lock: org.apache.aurora.scheduler.storage.log.LogStorage$$EnhancerByGuice$$702c4587@6fca188c
Lock is currently held by thread: AsyncProcessor-0
Wait time: 676461 ms.
    org.apache.aurora.scheduler.storage.log.LogStorage.write(LogStorage.java:558)
    org.apache.aurora.scheduler.storage.CallOrderEnforcingStorage.write(CallOrderEnforcingStorage.java:130)
    org.apache.aurora.scheduler.updater.JobUpdateControllerImpl.instanceChanged(JobUpdateControllerImpl.java:235)
    org.apache.aurora.scheduler.updater.JobUpdateControllerImpl.instanceDeleted(JobUpdateControllerImpl.java:231)
    org.apache.aurora.scheduler.updater.JobUpdateEventSubscriber.tasksDeleted(JobUpdateEventSubscriber.java:68)
    sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source)
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    java.lang.reflect.Method.invoke(Method.java:606)
    com.google.common.eventbus.EventSubscriber.handleEvent(EventSubscriber.java:74)
    com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:47)
    com.google.common.eventbus.EventBus.dispatch(EventBus.java:322)
    com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304)
    com.google.common.eventbus.EventBus.post(EventBus.java:275)
    org.apache.aurora.scheduler.events.PubsubEventModule$2.post(PubsubEventModule.java:68)
    org.apache.aurora.scheduler.SchedulerLifecycle$7$2.run(SchedulerLifecycle.java:352)
    java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    java.util.concurrent.FutureTask.run(FutureTask.java:262)
    java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
    java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    java.lang.Thread.run(Thread.java:745)


'AsyncProcessor-0' Id=269 BLOCKED
Waiting for lock: com.google.common.eventbus.SynchronizedEventSubscriber@5a8d3038
Lock is currently held by thread: Lifecycle-0
Wait time: 676615 ms.
    com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:46)
    com.google.common.eventbus.EventBus.dispatch(EventBus.java:322)
    com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304)
    com.google.common.eventbus.EventBus.post(EventBus.java:275)
    org.apache.aurora.scheduler.events.PubsubEventModule$2.post(PubsubEventModule.java:68)
    org.apache.aurora.scheduler.state.StateManagerImpl.updateTaskAndExternalState(StateManagerImpl.java:442)
    org.apache.aurora.scheduler.state.StateManagerImpl.access$100(StateManagerImpl.java:79)
    org.apache.aurora.scheduler.state.StateManagerImpl$8.execute(StateManagerImpl.java:459)
    org.apache.aurora.scheduler.storage.Storage$MutateWork$NoResult.apply(Storage.java:132)
    org.apache.aurora.scheduler.storage.Storage$MutateWork$NoResult$Quiet.apply(Storage.java:149)
    org.apache.aurora.scheduler.storage.log.LogStorage$7.apply(LogStorage.java:573)
    org.apache.aurora.scheduler.storage.log.LogStorage$7.apply(LogStorage.java:570)
    org.apache.aurora.scheduler.storage.mem.MemStorage.doWork(MemStorage.java:200)
    org.apache.aurora.scheduler.storage.mem.MemStorage.access$400(MemStorage.java:61)
    org.apache.aurora.scheduler.storage.mem.MemStorage$5.apply(MemStorage.java:225)
    org.apache.aurora.scheduler.storage.mem.MemStorage$5.apply(MemStorage.java:222)
    org.apache.aurora.scheduler.storage.db.DbStorage.write(DbStorage.java:150)
    org.apache.aurora.scheduler.storage.db.DbStorage$$EnhancerByGuice$$4db2f244.CGLIB$write$4(<generated>)
    org.apache.aurora.scheduler.storage.db.DbStorage$$EnhancerByGuice$$4db2f244$$FastClassByGuice$$b73a3503.invoke(<generated>)
    com.google.inject.internal.cglib.proxy.$MethodProxy.invokeSuper(MethodProxy.java:228)
    com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
    org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:101)
    com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
    com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52)
    org.apache.aurora.scheduler.storage.db.DbStorage$$EnhancerByGuice$$4db2f244.write(<generated>)
    org.apache.aurora.scheduler.storage.mem.MemStorage.write(MemStorage.java:222)
    org.apache.aurora.scheduler.storage.log.LogStorage.write(LogStorage.java:570)
    org.apache.aurora.scheduler.storage.CallOrderEnforcingStorage.write(CallOrderEnforcingStorage.java:130)
    org.apache.aurora.scheduler.state.StateManagerImpl.deleteTasks(StateManagerImpl.java:450)
    org.apache.aurora.scheduler.async.TaskHistoryPruner.deleteTasks(TaskHistoryPruner.java:126)
    org.apache.aurora.scheduler.async.TaskHistoryPruner.access$500(TaskHistoryPruner.java:51)
    org.apache.aurora.scheduler.async.TaskHistoryPruner$3.run(TaskHistoryPruner.java:164)
    java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    java.util.concurrent.FutureTask.run(FutureTask.java:262)
    java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
    java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    java.lang.Thread.run(Thread.java:745)

Issue Links

• blocks: AURORA-711 0.6.0 Release Candidate