[
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)
