Support Questions
Find answers, ask questions, and share your expertise
Announcements
Alert: Welcome to the Unified Cloudera Community. Former HCC members be sure to read and learn how to activate your account here.

Mapreduce -Timeout while reducer reaches 67%

Highlighted

Mapreduce -Timeout while reducer reaches 67%

Explorer

We are getting a timeout exception when the reducer reaches 67% which I believe is after the sort phase and before reduce phase. Please advise which parameters we should be looking to resolve the issue.

16/06/15 16:58:13 INFO mapreduce.Job:  map 100% reduce 0%
16/06/15 16:58:23 INFO mapreduce.Job:  map 100% reduce 24%
16/06/15 16:59:05 INFO mapreduce.Job:  map 100% reduce 28%
16/06/15 16:59:08 INFO mapreduce.Job:  map 100% reduce 30%
16/06/15 16:59:39 INFO mapreduce.Job:  map 100% reduce 33%
16/06/15 17:00:09 INFO mapreduce.Job:  map 100% reduce 52%
16/06/15 17:00:12 INFO mapreduce.Job:  map 100% reduce 67%
16/06/15 17:05:42 INFO mapreduce.Job: Task Id : attempt_1465992294703_0001_r_000000_2, Status : FAILED
7 REPLIES 7
Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

Please share the logs for this attempt id attempt_1465992294703_0001_r_000000_2

Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

Explorer
2016-06-15 16:58:11,789 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from NEW to UNASSIGNED
2016-06-15 16:58:11,926 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_1 is : 0.6680941
2016-06-15 16:58:11,934 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:312 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 16:58:11,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=<memory:33280, vCores:1>
2016-06-15 16:58:11,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: All maps assigned. Ramping up all remaining reduces:1
2016-06-15 16:58:11,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:312 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 16:58:12,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1465992294703_0001: ask=1 release= 0 newContainers=0 finishedContainers=1 resourcelimit=<memory:43520, vCores:1> knownNMs=4
2016-06-15 16:58:12,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_e75_1465992294703_0001_01_000314
2016-06-15 16:58:12,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:0 AssignedReds:0 CompletedMaps:310 CompletedReds:0 ContAlloc:312 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 16:58:12,939 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1465992294703_0001_r_000000_1: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143
2016-06-15 16:58:13,942 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 1
2016-06-15 16:58:13,942 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned to reduce
2016-06-15 16:58:13,942 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_e75_1465992294703_0001_01_000315 to attempt_1465992294703_0001_r_000000_2
2016-06-15 16:58:13,942 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:313 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 16:58:13,943 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved emrbldbgdapd5.emaar.ae to /default-rack
2016-06-15 16:58:13,943 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2016-06-15 16:58:13,944 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_e75_1465992294703_0001_01_000315 taskAttempt attempt_1465992294703_0001_r_000000_2
2016-06-15 16:58:13,944 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1465992294703_0001_r_000000_2
2016-06-15 16:58:13,944 INFO [ContainerLauncher #4] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : emrbldbgdapd5.emaar.ae:45454
2016-06-15 16:58:13,955 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1465992294703_0001_r_000000_2 : 13562
2016-06-15 16:58:13,955 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1465992294703_0001_r_000000_2] using containerId: [container_e75_1465992294703_0001_01_000315 on NM: [emrbldbgdapd5.emaar.ae:45454]
2016-06-15 16:58:13,956 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from ASSIGNED to RUNNING
2016-06-15 16:58:14,944 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1465992294703_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:33280, vCores:1> knownNMs=4
2016-06-15 16:58:15,430 INFO [Socket Reader #1 for port 54058] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1465992294703_0001 (auth:SIMPLE)
2016-06-15 16:58:15,445 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1465992294703_0001_r_82463372083515 asked for a task
2016-06-15 16:58:15,445 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1465992294703_0001_r_82463372083515 given task: attempt_1465992294703_0001_r_000000_2
2016-06-15 16:58:16,393 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 0 maxEvents 10000
2016-06-15 16:58:17,443 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:18,446 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:19,449 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:20,452 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:21,458 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:22,361 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:22,473 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:23,474 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:24,475 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:25,417 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:25,477 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:26,478 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:27,479 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:28,446 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:28,481 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:29,483 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:30,484 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:31,473 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:31,485 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:32,487 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:33,488 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:34,486 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:34,489 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:35,490 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:36,492 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:37,493 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:37,500 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:38,503 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:39,504 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:40,505 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:40,515 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:41,506 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:42,507 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:43,509 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:43,528 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:44,510 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:45,511 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:46,513 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:46,540 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:47,514 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:48,515 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:49,517 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:49,561 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:50,518 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:51,519 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:52,521 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:52,573 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:53,522 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:54,524 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:55,525 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:55,592 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:56,526 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:57,527 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:58,528 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:58:58,604 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:58:59,530 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:00,531 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:01,533 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:01,616 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.24086022
2016-06-15 16:59:02,534 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:03,535 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:04,536 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:04,646 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.28064516
2016-06-15 16:59:05,539 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:06,541 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:07,547 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:07,659 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:08,548 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:09,549 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:10,550 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:10,677 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:11,552 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:12,554 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:13,555 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:13,702 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:14,556 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:15,557 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:16,558 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:16,714 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:17,560 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:18,561 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:19,562 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:19,726 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:20,563 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:21,564 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:22,566 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:22,761 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:23,568 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:24,569 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:25,570 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:25,780 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:26,572 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:27,573 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:28,575 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:28,793 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:29,576 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:30,577 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:31,578 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:31,804 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:32,579 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:33,580 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:34,582 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:34,816 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:35,583 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:36,852 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_2. startIndex 310 maxEvents 10000
2016-06-15 16:59:36,906 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.29892474
2016-06-15 16:59:37,836 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:40,848 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:43,860 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:46,873 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:49,888 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:52,904 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:55,916 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 16:59:58,927 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 17:00:01,941 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 17:00:04,953 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.33333334
2016-06-15 17:00:07,980 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.5214024
2016-06-15 17:00:09,387 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.5214024
2016-06-15 17:00:10,997 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.6680941
2016-06-15 17:00:14,013 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_2 is : 0.6680941
2016-06-15 17:05:41,775 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1465992294703_0001_r_000000_2: AttemptID:attempt_1465992294703_0001_r_000000_2 Timed out after 300 secs
2016-06-15 17:05:41,775 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2016-06-15 17:05:41,775 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_e75_1465992294703_0001_01_000315 taskAttempt attempt_1465992294703_0001_r_000000_2
2016-06-15 17:05:41,776 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1465992294703_0001_r_000000_2
2016-06-15 17:05:41,776 INFO [ContainerLauncher #7] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : emrbldbgdapd5.emaar.ae:45454
2016-06-15 17:05:41,784 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2016-06-15 17:05:41,784 INFO [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2016-06-15 17:05:41,795 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_2 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2016-06-15 17:05:41,796 INFO [Thread-52] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node emrbldbgdapd5.emaar.ae
2016-06-15 17:05:41,796 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from NEW to UNASSIGNED
2016-06-15 17:05:42,599 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:313 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 17:05:42,600 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=<memory:33280, vCores:1>
2016-06-15 17:05:42,600 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: All maps assigned. Ramping up all remaining reduces:1
2016-06-15 17:05:42,600 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:313 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 17:05:43,603 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1465992294703_0001: ask=1 release= 0 newContainers=0 finishedContainers=1 resourcelimit=<memory:43520, vCores:1> knownNMs=4
2016-06-15 17:05:43,603 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_e75_1465992294703_0001_01_000315
2016-06-15 17:05:43,603 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:0 AssignedReds:0 CompletedMaps:310 CompletedReds:0 ContAlloc:313 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 17:05:43,603 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1465992294703_0001_r_000000_2: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143
2016-06-15 17:05:44,605 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 1
2016-06-15 17:05:44,606 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned to reduce
2016-06-15 17:05:44,606 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_e75_1465992294703_0001_01_000316 to attempt_1465992294703_0001_r_000000_3
2016-06-15 17:05:44,606 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:314 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 17:05:44,606 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved emrbldbgdapd5.emaar.ae to /default-rack
2016-06-15 17:05:44,606 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2016-06-15 17:05:44,607 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_e75_1465992294703_0001_01_000316 taskAttempt attempt_1465992294703_0001_r_000000_3
2016-06-15 17:05:44,607 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1465992294703_0001_r_000000_3
2016-06-15 17:05:44,607 INFO [ContainerLauncher #5] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : emrbldbgdapd5.emaar.ae:45454
2016-06-15 17:05:44,620 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1465992294703_0001_r_000000_3 : 13562
2016-06-15 17:05:44,620 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1465992294703_0001_r_000000_3] using containerId: [container_e75_1465992294703_0001_01_000316 on NM: [emrbldbgdapd5.emaar.ae:45454]
2016-06-15 17:05:44,620 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from ASSIGNED to RUNNING
2016-06-15 17:05:45,607 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1465992294703_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:33280, vCores:1> knownNMs=4
2016-06-15 17:05:46,379 INFO [Socket Reader #1 for port 54058] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1465992294703_0001 (auth:SIMPLE)
2016-06-15 17:05:46,395 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1465992294703_0001_r_82463372083516 asked for a task
2016-06-15 17:05:46,395 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1465992294703_0001_r_82463372083516 given task: attempt_1465992294703_0001_r_000000_3
2016-06-15 17:05:47,198 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 0 maxEvents 10000
2016-06-15 17:05:48,327 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:49,329 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:50,397 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:51,410 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:52,416 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:53,200 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:05:53,419 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:54,420 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:55,422 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:56,233 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:05:56,425 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:57,427 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:58,428 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:05:59,264 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:05:59,430 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:00,433 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:01,434 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:02,307 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:02,435 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:03,438 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:04,440 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:05,328 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:05,442 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:06,443 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:07,444 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:08,341 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:08,446 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:09,447 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:10,456 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:11,358 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:11,457 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:12,459 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:13,460 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:14,379 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:14,461 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:15,463 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:16,464 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:17,391 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:17,467 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:18,468 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:19,469 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:20,404 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:20,472 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:21,473 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:22,474 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:23,425 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:23,476 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:24,477 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:25,478 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:26,443 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:26,479 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:27,480 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:28,482 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:29,455 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:29,483 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:30,484 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:31,485 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:32,469 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.24193549
2016-06-15 17:06:32,486 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:33,487 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:34,489 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:35,607 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:35,616 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29462367
2016-06-15 17:06:36,612 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:37,613 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:38,614 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:38,628 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:39,616 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:40,617 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:41,619 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:41,657 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:42,623 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:43,624 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:44,625 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:44,669 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:45,626 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:46,627 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:47,628 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:47,687 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:48,629 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:49,631 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:50,633 INFO [IPC Server handler 2 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:50,699 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:51,634 INFO [IPC Server handler 29 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:52,635 INFO [IPC Server handler 0 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:53,636 INFO [IPC Server handler 3 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:53,710 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:54,637 INFO [IPC Server handler 4 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:55,638 INFO [IPC Server handler 8 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:56,639 INFO [IPC Server handler 6 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:56,722 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:06:57,640 INFO [IPC Server handler 5 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:58,642 INFO [IPC Server handler 7 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:59,643 INFO [IPC Server handler 12 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:06:59,735 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:07:00,644 INFO [IPC Server handler 10 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:01,645 INFO [IPC Server handler 9 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:02,646 INFO [IPC Server handler 11 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:02,746 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.29569894
2016-06-15 17:07:03,647 INFO [IPC Server handler 13 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:04,648 INFO [IPC Server handler 15 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:05,937 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1465992294703_0001_r_000000_3. startIndex 310 maxEvents 10000
2016-06-15 17:07:05,945 INFO [IPC Server handler 17 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.32903227
2016-06-15 17:07:06,170 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.32903227
2016-06-15 17:07:08,963 INFO [IPC Server handler 20 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:11,975 INFO [IPC Server handler 18 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:14,987 INFO [IPC Server handler 16 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:17,998 INFO [IPC Server handler 22 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:21,011 INFO [IPC Server handler 21 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:24,028 INFO [IPC Server handler 19 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:27,040 INFO [IPC Server handler 25 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:30,051 INFO [IPC Server handler 23 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:33,066 INFO [IPC Server handler 26 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.33333334
2016-06-15 17:07:36,077 INFO [IPC Server handler 24 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.3956634
2016-06-15 17:07:39,092 INFO [IPC Server handler 28 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.5745713
2016-06-15 17:07:40,669 INFO [IPC Server handler 14 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.5745713
2016-06-15 17:07:42,115 INFO [IPC Server handler 27 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.6680941
2016-06-15 17:07:45,139 INFO [IPC Server handler 1 on 54058] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1465992294703_0001_r_000000_3 is : 0.6680941
2016-06-15 17:13:11,777 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1465992294703_0001_r_000000_3: AttemptID:attempt_1465992294703_0001_r_000000_3 Timed out after 300 secs
2016-06-15 17:13:11,777 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2016-06-15 17:13:11,777 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_e75_1465992294703_0001_01_000316 taskAttempt attempt_1465992294703_0001_r_000000_3
2016-06-15 17:13:11,778 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1465992294703_0001_r_000000_3
2016-06-15 17:13:11,778 INFO [ContainerLauncher #6] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : emrbldbgdapd5.emaar.ae:45454
2016-06-15 17:13:11,784 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2016-06-15 17:13:11,784 INFO [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2016-06-15 17:13:11,788 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1465992294703_0001_r_000000_3 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2016-06-15 17:13:11,790 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1465992294703_0001_r_000000 Task Transitioned from RUNNING to FAILED
2016-06-15 17:13:11,790 INFO [Thread-52] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 2 failures on node emrbldbgdapd5.emaar.ae
2016-06-15 17:13:11,790 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 311
2016-06-15 17:13:11,790 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Job failed as tasks failed. failedMaps:0 failedReduces:1
2016-06-15 17:13:11,790 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1465992294703_0001Job Transitioned from RUNNING to FAIL_ABORT
2016-06-15 17:13:11,791 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_ABORT
2016-06-15 17:13:11,794 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1465992294703_0001Job Transitioned from FAIL_ABORT to FAILED
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: RMCommunicator notified that shouldUnregistered is: true
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2016-06-15 17:13:11,795 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
2016-06-15 17:13:11,799 INFO [Thread-855] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 0
2016-06-15 17:13:11,860 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://emaarnn:8020/user/root/.staging/job_1465992294703_0001/job_1465992294703_0001_1.jhist to hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001-1465992423577-root-ExchangeLogsMR.jar-1465996391790-310-0-FAILED-default-1465992431972.jhist_tmp
2016-06-15 17:13:11,914 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001-1465992423577-root-ExchangeLogsMR.jar-1465996391790-310-0-FAILED-default-1465992431972.jhist_tmp
2016-06-15 17:13:11,917 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://emaarnn:8020/user/root/.staging/job_1465992294703_0001/job_1465992294703_0001_1_conf.xml to hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001_conf.xml_tmp
2016-06-15 17:13:11,947 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001_conf.xml_tmp
2016-06-15 17:13:11,954 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001.summary_tmp to hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001.summary
2016-06-15 17:13:11,956 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001_conf.xml_tmp to hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001_conf.xml
2016-06-15 17:13:11,958 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001-1465992423577-root-ExchangeLogsMR.jar-1465996391790-310-0-FAILED-default-1465992431972.jhist_tmp to hdfs://emaarnn:8020/mr-history/tmp/root/job_1465992294703_0001-1465992423577-root-ExchangeLogsMR.jar-1465996391790-310-0-FAILED-default-1465992431972.jhist
2016-06-15 17:13:11,965 INFO [Thread-855] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2016-06-15 17:13:11,967 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: Setting job diagnostics to Task failed task_1465992294703_0001_r_000000
Job failed as tasks failed. failedMaps:0 failedReduces:1
2016-06-15 17:13:11,968 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: History url is http://emrbldbgdapd2.emaar.ae:19888/jobhistory/job/job_1465992294703_0001
2016-06-15 17:13:11,980 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: Waiting for application to be successfully unregistered.
2016-06-15 17:13:12,982 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:310 CompletedReds:0 ContAlloc:314 ContRel:0 HostLocal:310 RackLocal:0
2016-06-15 17:13:12,983 INFO [Thread-855] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://emaarnn /user/root/.staging/job_1465992294703_0001
2016-06-15 17:13:12,987 INFO [Thread-855] org.apache.hadoop.ipc.Server: Stopping server on 54058
2016-06-15 17:13:12,990 INFO [IPC Server listener on 54058] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 54058
2016-06-15 17:13:12,990 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted
2016-06-15 17:13:12,990 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

There should be syslog and stderr logs also which has more info. Can go through RM UI and find the failed container logs? Also which exception it showed when you ran the job at console?.

Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

Explorer

@Jitendra Yadav At the console its timeout error.

16/06/15 18:36:07 INFO mapreduce.Job: Task Id : attempt_1465997799084_0001_r_000000_0, Status : FAILED AttemptID:attempt_1465997799084_0001_r_000000_0 Timed out after 600 secs

Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

@Venkadesh Sivalingam lets try to tweak the timeout parameter and see if reducer get completed.

mapreduce.task.timeout=1800000
Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

Explorer

@Jitendra Yadav Will increasing the numer of reducers helpful in this case ? The weird thing is if I set the number of reducers more than 1 it throws exception as below.

java.lang.Exception: java.lang.ClassCastException: com.emaar.bigdata.exchg.logs.CompositeWritable cannot be cast to org.apache.hadoop.io.Text at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462) at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522) Caused by: java.lang.ClassCastException: com.emaar.bigdata.exchg.logs.CompositeWritable cannot be cast to org.apache.hadoop.io.Text at com.emaar.bigdata.exchg.logs.ActualKeyPartitioner.getPartition(ActualKeyPartitioner.java:1) at org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:716) at org.apache.hadoop.mapreduce.task.TaskInputOutputContextImpl.write(TaskInputOutputContextImpl.java:89) at org.apache.hadoop.mapreduce.lib.map.WrappedMapper$Context.write(WrappedMapper.java:112) at com.emaar.bigdata.exchg.logs.ExchgLogsMapper.map(ExchgLogsMapper.java:56) at com.emaar.bigdata.exchg.logs.ExchgLogsMapper.map(ExchgLogsMapper.java:1) at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:146) at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:787) at org.apache.hadoop.mapred.MapTask.run(MapTask.java:341) at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

Highlighted

Re: Mapreduce -Timeout while reducer reaches 67%

@Venkadesh Sivalingam It looks like the error is coming due to wrong row key type mismatch your used in com.emaar.bigdata.exchg.logs.CompositeWritable, see this post that might help you.

http://stackoverflow.com/questions/11541345/class-cast-exception-for-the-hadoop-new-api

Don't have an account?
Coming from Hortonworks? Activate your account here