asko created TEZ-1468:
-------------------------
Summary: 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
Priority: Trivial
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)
