You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tez.apache.org by "Jason Lowe (JIRA)" <ji...@apache.org> on 2016/04/01 01:12:25 UTC
[jira] [Commented] (TEZ-3193) Deadlock in AM during task commit
request
[ https://issues.apache.org/jira/browse/TEZ-3193?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15220835#comment-15220835 ]
Jason Lowe commented on TEZ-3193:
---------------------------------
Here are the relevant portions of the AM stacktrace when it deadlocks:
{noformat}
"TaskSchedulerAppCaller #0" #106 daemon prio=5 os_prio=0 tid=0x00007fb1cc1bb800 nid=0x4619 waiting on condition [0x00007fb1b6509000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000c5d8e398> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:967)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1283)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl.getState(TaskAttemptImpl.java:630)
at org.apache.tez.dag.app.dag.impl.TaskImpl.selectBestAttempt(TaskImpl.java:745)
at org.apache.tez.dag.app.dag.impl.TaskImpl.getProgress(TaskImpl.java:483)
at org.apache.tez.dag.app.dag.impl.VertexImpl.computeProgress(VertexImpl.java:1285)
at org.apache.tez.dag.app.dag.impl.VertexImpl.getProgress(VertexImpl.java:1195)
at org.apache.tez.dag.app.dag.impl.DAGImpl.getProgress(DAGImpl.java:829)
at org.apache.tez.dag.app.DAGAppMaster.getProgress(DAGAppMaster.java:1181)
at org.apache.tez.dag.app.rm.TaskSchedulerEventHandler.getProgress(TaskSchedulerEventHandler.java:560)
at org.apache.tez.dag.app.rm.TaskSchedulerAppCallbackWrapper$GetProgressCallable.call(TaskSchedulerAppCallbackWrapper.java:291)
at org.apache.tez.dag.app.rm.TaskSchedulerAppCallbackWrapper$GetProgressCallable.call(TaskSchedulerAppCallbackWrapper.java:282)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
"IPC Server handler 4 on 52743" #64 daemon prio=5 os_prio=0 tid=0x00007fb1c454c800 nid=0x45ca waiting on condition [0x00007fb1b920e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000c1421810> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:943)
at org.apache.tez.dag.app.dag.impl.TaskImpl.canCommit(TaskImpl.java:768)
at org.apache.tez.dag.app.TaskAttemptListenerImpTezDag.canCommit(TaskAttemptListenerImpTezDag.java:274)
at sun.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at org.apache.hadoop.ipc.WritableRpcEngine$Server$WritableRpcInvoker.call(WritableRpcEngine.java:514)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:962)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2096)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2092)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1694)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2090)
"Dispatcher thread {Central}" #37 prio=5 os_prio=0 tid=0x00007fb1c422f000 nid=0x45aa waiting on condition [0x00007fb1ba722000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000c1421810> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:967)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1283)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727)
at org.apache.tez.dag.app.dag.impl.TaskImpl.getTaskLocationHint(TaskImpl.java:541)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl.getTaskLocationHint(TaskAttemptImpl.java:1068)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl.access$100(TaskAttemptImpl.java:116)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl$StartedTransition.transition(TaskAttemptImpl.java:1349)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl$StartedTransition.transition(TaskAttemptImpl.java:1308)
at org.apache.hadoop.yarn.state.StateMachineFactory$SingleInternalArc.doTransition(StateMachineFactory.java:362)
at org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:302)
at org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46)
at org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448)
- locked <0x00000000c5d8e600> (a org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl.handle(TaskAttemptImpl.java:786)
at org.apache.tez.dag.app.dag.impl.TaskAttemptImpl.handle(TaskAttemptImpl.java:116)
at org.apache.tez.dag.app.DAGAppMaster$TaskAttemptEventDispatcher.handle(DAGAppMaster.java:2097)
at org.apache.tez.dag.app.DAGAppMaster$TaskAttemptEventDispatcher.handle(DAGAppMaster.java:2082)
at org.apache.tez.common.AsyncDispatcher.dispatch(AsyncDispatcher.java:183)
at org.apache.tez.common.AsyncDispatcher$1.run(AsyncDispatcher.java:114)
at java.lang.Thread.run(Thread.java:745)
{noformat}
This is the sequence of events that I believe leads to the deadlock:
# The attempt started transition grabs the write lock on the TaskAttemptImpl and starts processing
# Progress is being requested on the task, so another thread grabs the read lock on the TaskImpl and tries to get the attempt state. Since the attempt write lock is held, it blocks
# Either the task attempt runs very fast and/or the AM is running slowly, and the attempt heartbeats in requesting a commit go/no-go, but that thread blocks trying to grab the TaskImpl lock
# The TaskAttemptImpl processing proceeds and eventually tries to call getTaskLocationHint on the task, but it blocks on the lock to avoid complete starvation of the thread currently waiting for the write lock.
It looks like one potential fix would be to have TaskImpl#getTaskLocationHint and TaskImpl#getBaseTaskSpec avoid grabbing the task read lock and simply mark those task fields as volatile so the TaskAttempt can safely call them. I didn't see any other invocations of TaskImpl methods from the TaskAttemptImpl which could cause reverse locking order issues.
> Deadlock in AM during task commit request
> -----------------------------------------
>
> Key: TEZ-3193
> URL: https://issues.apache.org/jira/browse/TEZ-3193
> Project: Apache Tez
> Issue Type: Bug
> Affects Versions: 0.7.1, 0.8.2
> Reporter: Jason Lowe
> Priority: Blocker
>
> The AM can deadlock between TaskImpl and TaskAttemptImpl. Stacktrace and details in a followup comment.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)