You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tez.apache.org by "asko (JIRA)" <ji...@apache.org> on 2014/08/20 05:31:18 UTC
[jira] [Updated] (TEZ-1468) Continued socket communication ,but
can't complete communication task
[ https://issues.apache.org/jira/browse/TEZ-1468?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
asko updated TEZ-1468:
----------------------
Priority: Major (was: Trivial)
> Continued socket communication ,but can't complete communication task
> -----------------------------------------------------------------------
>
> Key: TEZ-1468
> URL: https://issues.apache.org/jira/browse/TEZ-1468
> Project: Apache Tez
> Issue Type: Bug
> Affects Versions: 0.4.1
> Reporter: asko
>
> i aimed to test Hive-0.13 performance by TPCH , when i used 10G randomly generate dataset to test Q7, the task need take a long time , and can not finished. through setting log level parameter wihtin tez-site.xml, the debug information is printing socket communication information of between container and container ,which is continued until tez automatically shutdown .Meanwhile , Q9 and Q18 also have this problem. i try to change hadoop memory size , such as resource manage memory , map and reduce memory ,and heap memory etc..these ways is unavailable. now i don't know where is problem.
> the follow is debug info :
> 2014-08-20 11:21:17,855 DEBUG [IPC Server handler 16 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:17,855 DEBUG [IPC Server handler 16 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:17,855 DEBUG [IPC Server handler 16 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5927, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6213 Retry#0
> 2014-08-20 11:21:17,855 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,855 DEBUG [IPC Server handler 16 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5927, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6213 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:17,855 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,855 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:17,855 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,855 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,882 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6162
> 2014-08-20 11:21:17,882 DEBUG [IPC Server handler 21 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 21 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6114, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6162 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6114, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6114, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6162 Retry#0
> 2014-08-20 11:21:17,883 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,883 DEBUG [IPC Server handler 21 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6114, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6162 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:17,883 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,883 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:17,883 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,883 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,932 DEBUG [Socket Reader #1 for port 38374] org.apache.hadoop.ipc.Server: got #3286
> 2014-08-20 11:21:17,932 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server handler 0 on 38374: org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3286 Retry#0 for RpcKind RPC_PROTOCOL_BUFFER
> 2014-08-20 11:21:17,932 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:zhangweitao (auth:SIMPLE) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:17,932 INFO [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: Served: getDAGStatus queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:17,932 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3286 Retry#0
> 2014-08-20 11:21:17,932 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3286 Retry#0 Wrote 256 bytes.
> 2014-08-20 11:21:17,956 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6214
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 14 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5928, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6214 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5928, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5928, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6214 Retry#0
> 2014-08-20 11:21:17,956 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,956 DEBUG [IPC Server handler 14 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5928, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6214 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:17,956 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,956 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:17,956 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,956 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,984 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6163
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 2 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6115, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6163 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6115, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6115, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6163 Retry#0
> 2014-08-20 11:21:17,984 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,984 DEBUG [IPC Server handler 2 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6115, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6163 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:17,985 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:17,985 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:17,985 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:17,985 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,057 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6215
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 24 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5929, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6215 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5929, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5929, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6215 Retry#0
> 2014-08-20 11:21:18,058 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,058 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,058 DEBUG [IPC Server handler 24 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5929, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6215 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,058 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,058 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,058 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,085 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6164
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 22 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6116, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6164 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6116, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6116, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6164 Retry#0
> 2014-08-20 11:21:18,086 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,086 DEBUG [IPC Server handler 22 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6116, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6164 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,086 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,086 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,086 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,086 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,133 DEBUG [Socket Reader #1 for port 38374] org.apache.hadoop.ipc.Server: got #3287
> 2014-08-20 11:21:18,133 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server handler 0 on 38374: org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3287 Retry#0 for RpcKind RPC_PROTOCOL_BUFFER
> 2014-08-20 11:21:18,134 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:zhangweitao (auth:SIMPLE) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,134 INFO [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: Served: getDAGStatus queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:18,134 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3287 Retry#0
> 2014-08-20 11:21:18,134 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3287 Retry#0 Wrote 256 bytes.
> 2014-08-20 11:21:18,159 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6216
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 12 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5930, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6216 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5930, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5930, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6216 Retry#0
> 2014-08-20 11:21:18,159 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,159 DEBUG [IPC Server handler 12 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5930, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6216 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,159 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,159 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,159 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,160 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,187 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6165
> 2014-08-20 11:21:18,187 DEBUG [IPC Server handler 28 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 28 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6117, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6165 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,187 DEBUG [IPC Server handler 28 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,187 DEBUG [IPC Server handler 28 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6117, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,187 DEBUG [IPC Server handler 28 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:18,187 DEBUG [IPC Server handler 28 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,188 DEBUG [IPC Server handler 28 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6117, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6165 Retry#0
> 2014-08-20 11:21:18,188 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,188 DEBUG [IPC Server handler 28 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6117, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6165 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,188 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,188 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,188 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,188 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,260 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6217
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 15 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5931, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6217 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5931, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5931, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6217 Retry#0
> 2014-08-20 11:21:18,261 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,261 DEBUG [IPC Server handler 15 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5931, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6217 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,261 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,261 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,261 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,261 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,289 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6166
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 11 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6118, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6166 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6118, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6118, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6166 Retry#0
> 2014-08-20 11:21:18,289 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,289 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,289 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,289 DEBUG [IPC Server handler 11 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6118, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6166 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,289 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,289 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,335 DEBUG [Socket Reader #1 for port 38374] org.apache.hadoop.ipc.Server: got #3288
> 2014-08-20 11:21:18,335 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server handler 0 on 38374: org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3288 Retry#0 for RpcKind RPC_PROTOCOL_BUFFER
> 2014-08-20 11:21:18,335 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:zhangweitao (auth:SIMPLE) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,336 INFO [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: Served: getDAGStatus queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,336 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3288 Retry#0
> 2014-08-20 11:21:18,336 DEBUG [IPC Server handler 0 on 38374] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to org.apache.tez.dag.api.client.rpc.DAGClientAMProtocolBlockingPB.getDAGStatus from 10.3.1.76:60544 Call#3288 Retry#0 Wrote 256 bytes.
> 2014-08-20 11:21:18,362 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6218
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 9 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5932, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6218 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5932, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5932, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6218 Retry#0
> 2014-08-20 11:21:18,362 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,362 DEBUG [IPC Server handler 9 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5932, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6218 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,362 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,362 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,362 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,362 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,390 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6167
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 4 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6119, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6167 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6119, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6119, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6167 Retry#0
> 2014-08-20 11:21:18,391 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,391 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,391 DEBUG [IPC Server handler 4 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6119, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6167 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,391 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,391 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,391 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,425 DEBUG [IPC Parameter Sending Thread #1] org.apache.hadoop.ipc.Client: IPC Client (1720854532) connection to /10.3.1.76:28004 from zhangweitao sending #820
> 2014-08-20 11:21:18,426 DEBUG [IPC Client (1720854532) connection to /10.3.1.76:28004 from zhangweitao] org.apache.hadoop.ipc.Client: IPC Client (1720854532) connection to /10.3.1.76:28004 from zhangweitao got value #820
> 2014-08-20 11:21:18,426 DEBUG [AMRM Heartbeater thread] org.apache.hadoop.ipc.ProtobufRpcEngine: Call: allocate took 1ms
> 2014-08-20 11:21:18,426 DEBUG [AMRM Callback Handler Thread] org.apache.tez.dag.app.rm.TaskScheduler: Allocated resource memory: 8192 cpu:2 delayedContainers: 0
> 2014-08-20 11:21:18,463 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6219
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 29 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5933, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6219 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000009, requestId=5933, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_02_000000_0 events: 1
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 1 procesingTime= 0
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5933, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6219 Retry#0
> 2014-08-20 11:21:18,464 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,464 DEBUG [IPC Server handler 29 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000009, requestId=5933, startIndex=9, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_02_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.77:49177 Call#6219 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,464 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_02 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,464 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 4 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,464 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,464 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_02_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,492 DEBUG [Socket Reader #1 for port 37422] org.apache.hadoop.ipc.Server: got #6168
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.hadoop.ipc.Server: IPC Server handler 1 on 37422: heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6120, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6168 Retry#0 for RpcKind RPC_WRITABLE
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.hadoop.security.UserGroupInformation: PrivilegedAction as:application_1406886789033_0032 (auth:TOKEN) from:org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Received heartbeat from container, request={ containerId=container_1406886789033_0032_01_000007, requestId=6120, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.tez.dag.app.TaskAttemptListenerImpTezDag: Ping from attempt_1406886789033_0032_2_06_000000_0 events: 1
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.hadoop.ipc.Server: Served: heartbeat queueTime= 0 procesingTime= 0
> 2014-08-20 11:21:18,492 DEBUG [IPC Server handler 1 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6120, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6168 Retry#0
> 2014-08-20 11:21:18,492 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.VertexEventRouteEvent.EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,493 DEBUG [IPC Server handler 1 on 37422] org.apache.hadoop.ipc.Server: IPC Server Responder: responding to heartbeat({ containerId=container_1406886789033_0032_01_000007, requestId=6120, startIndex=28, maxEventsToGet=100, taskAttemptId=attempt_1406886789033_0032_2_06_000000_0, eventCount=1 }), rpc version=2, client version=19, methodsFingerPrint=557389974 from 10.3.1.79:53289 Call#6168 Retry#0 Wrote 154 bytes.
> 2014-08-20 11:21:18,493 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Processing VertexEvent vertex_1406886789033_0032_2_06 of type V_ROUTE_EVENT while in state RUNNING. Event: EventType: V_ROUTE_EVENT
> 2014-08-20 11:21:18,493 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.VertexImpl: Vertex: Reducer 3 routing event: TASK_STATUS_UPDATE_EVENT Recovered:false
> 2014-08-20 11:21:18,493 DEBUG [AsyncDispatcher event handler] org.apache.hadoop.yarn.event.AsyncDispatcher: Dispatching the event org.apache.tez.dag.app.dag.event.TaskAttemptEventStatusUpdate.EventType: TA_STATUS_UPDATE
> 2014-08-20 11:21:18,493 DEBUG [AsyncDispatcher event handler] org.apache.tez.dag.app.dag.impl.TaskAttemptImpl: Processing TaskAttemptEvent attempt_1406886789033_0032_2_06_000000_0 of type TA_STATUS_UPDATE while in state RUNNING. Event: EventType: TA_STATUS_UPDATE
--
This message was sent by Atlassian JIRA
(v6.2#6252)