RHadoop not working: Java heap space error

926 views
Skip to first unread message

Manuel

unread,
Sep 1, 2014, 1:11:38 PM9/1/14
to rha...@googlegroups.com
Hello!

I am trying to get RHadoop working on a Hadoop cluster.

This is a test cluster for development / proof of concept.
It has 5 nodes, virtualized in VMware.
The OS on all nodes is centos 6.4

To install R on Hadoop, I followed these instructions:
https://github.com/RevolutionAnalytics/RHadoop/wiki

The following example analysis is constantly failing with a Java heap size error:

groups = rbinom(100, n = 500, prob = 0.5)
tapply(groups, groups, length)
require('rmr2')
groups = rbinom(100, n = 500, prob = 0.5)
groups = to.dfs(groups)
result = mapreduce(
    input = groups,
    map = function(k,v) keyval(v, 1),
    reduce = function(k,vv) keyval(k, length(vv)))
print(result())
print(from.dfs(result, to.data.frame=T))


The code above is from this repo:
https://github.com/hortonworks/HDP-Public-Utilities/tree/master/Installation/r#rhadoop-validation

Any help to get this solved would be very much appreciated!

Best,

Manuel

___________________________________________________


The software versions are:

Cluster Stack Version: HDP-2.1
# Service   Version

HDFS    2.4.0.2.1
YARN + MapReduce2    2.4.0.2.1
Tez    0.4.0.2.1
Nagios    3.5.0
Ganglia    3.5.0
Hive    0.13.0.2.1
Pig    0.12.1.2.1
Sqoop    1.4.4.2.1
Oozie    4.0.0.2.1
ZooKeeper    3.4.5.2.1
Falcon    0.5.0.2.1


Repositories: 2.1
# OS
# Base URL

redhat5    http://public-repo-1.hortonworks.com/HDP/centos5/2.x/updates/2.1.3.0
redhat6    http://public-repo-1.hortonworks.com/HDP/centos6/2.x/updates/2.1.4.0
suse11    http://public-repo-1.hortonworks.com/HDP/suse11/2.x/updates/2.1.3.0

___________________________________________________


The components installed on each node are:

centos1

App Timeline Server
Falcon Server
Ganglia Monitor
HDFS Client
History Server
Hive Client
Hive Metastore
HiveServer2
MySQL Server
Oozie Server
ResourceManager
SNameNode
Tez Client
WebHCat Server
YARN Client
ZooKeeper Client
ZooKeeper Server


centos2

Ganglia Monitor
Ganglia Server
HCat
Nagios Server
NameNode
Oozie Client
Tez Client
YARN Client
ZooKeeper Server


centos3

DataNode
Falcon Client
Ganglia Monitor
HCat
HDFS Client
Hive Client
MapReduce2 Client
NodeManager
Oozie Client
Pig
Sqoop
Tez Client
YARN Client
ZooKeeper Client
ZooKeeper Server


centos4

DataNode
Falcon Client
Ganglia Monitor
HCat
HDFS Client
Hive Client
MapReduce2 Client
NodeManager
Oozie Client
Pig
Sqoop
Tez Client
YARN Client
ZooKeeper Client


centos5

DataNode
Falcon Client
Ganglia Monitor
HCat
HDFS Client
Hive Client
MapReduce2 Client
NodeManager
Oozie Client
Pig
Sqoop
Tez Client
YARN Client
ZooKeeper Client

___________________________________________________


"top" command for each of the five nodes:
* After a complete cluster shut-down and restart
* Including ambari-server / -agent restart


centos1

top - 17:28:35 up 4 days,  2:25,  1 user,  load average: 0.13, 0.97, 0.81
Tasks: 151 total,   1 running, 150 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.7%us,  1.3%sy,  0.0%ni, 96.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8062808k total,  3874752k used,  4188056k free,   256076k buffers
Swap:  8208376k total,        0k used,  8208376k free,  1586400k cached


centos2

top - 17:29:48 up 4 days,  2:27,  1 user,  load average: 0.15, 0.34, 0.24
Tasks: 144 total,   1 running, 143 sleeping,   0 stopped,   0 zombie
Cpu(s):  4.4%us,  3.4%sy,  0.0%ni, 92.3%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8063004k total,  1775852k used,  6287152k free,   194616k buffers
Swap:  8208376k total,        0k used,  8208376k free,   711400k cached


centos3

top - 17:30:11 up 4 days,  2:21,  1 user,  load average: 0.00, 0.05, 0.05
Tasks: 129 total,   1 running, 128 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.1%us,  1.0%sy,  0.0%ni, 95.9%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8063004k total,  1310588k used,  6752416k free,   196932k buffers
Swap:  8208376k total,        0k used,  8208376k free,   549112k cached


centos4

top - 17:30:32 up 4 days,  2:21,  1 user,  load average: 0.01, 0.03, 0.00
Tasks: 128 total,   1 running, 127 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.9%us,  0.9%sy,  0.0%ni, 96.1%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8063004k total,  1338692k used,  6724312k free,   195128k buffers
Swap:  8208376k total,        0k used,  8208376k free,   596916k cached


centos5

top - 17:30:53 up 4 days,  2:21,  1 user,  load average: 0.01, 0.09, 0.08
Tasks: 127 total,   1 running, 126 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.0%us,  0.9%sy,  0.0%ni, 96.0%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8063004k total,  1332576k used,  6730428k free,   195328k buffers
Swap:  8208376k total,        0k used,  8208376k free,   598012k cached

___________________________________________________

Yarn / MapReduce memory configuration:

Number of containers: 2           
RAM per container: 2048 MB           
           
Configuration Setting                                   Value Calculation                    Value    Override

yarn.nodemanager.resource.memory-mb    = containers * RAM-p.-cont.    4096    no
yarn.scheduler.minimum-allocation-mb        = RAM-per-container               2048    no
yarn.scheduler.maximum-allocation-mb       = containers * RAM-p.-cont.    4096    no
mapreduce.map.memory.mb                        = RAM-per-container               2048    no
mapreduce.reduce.memory.mb                    = 2 * RAM-per-container         4096    no
mapreduce.map.java.opts                            = 0.8 * RAM-per-container      1638,4  yes, set to 2048 MB
mapreduce.reduce.java.opts                        = 0.8 * 2 * RAM-per-container 3276,8  yes, set to 4096 MB
yarn.app.mapreduce.am.resource.mb         = 2 * RAM-per-container          4096     no
yarn.app.mapreduce.am.command-opts     = 0.8 * 2 * RAM-per-container  3276,8  yes, set to 4096 MB

___________________________________________________


Shell output:


[root@centos1 ~]# R

R version 3.1.0 (2014-04-10) -- "Spring Dance"
Copyright (C) 2014 The R Foundation for Statistical Computing
Platform: x86_64-redhat-linux-gnu (64-bit)

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

  Natural language support but running in an English locale

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> groups = rbinom(100, n = 500, prob = 0.5)
> tapply(groups, groups, length)
36 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62
 1  3  1  6  9 13 16 17 30 34 46 39 40 41 38 34 29 21 14 22 12  6 14  7  3  2
64
 2
> require('rmr2')
Loading required package: rmr2
> groups = rbinom(100, n = 500, prob = 0.5)
> groups = to.dfs(groups)
14/09/01 17:32:42 INFO zlib.ZlibFactory: Successfully loaded & initialized native-zlib library
14/09/01 17:32:42 INFO compress.CodecPool: Got brand-new compressor [.deflate]
> result = mapreduce(
+     input = groups,
+     map = function(k,v) keyval(v, 1),
+     reduce = function(k,vv) keyval(k, length(vv)))
packageJobJar: [] [/usr/lib/hadoop-mapreduce/hadoop-streaming-2.4.0.2.1.4.0-632.jar] /tmp/streamjob7414054980203160633.jar tmpDir=null
14/09/01 17:32:52 INFO impl.TimelineClientImpl: Timeline service address: http://centos1.local:8188/ws/v1/timeline/
14/09/01 17:32:52 INFO client.RMProxy: Connecting to ResourceManager at centos1.local/10.157.16.93:8050
14/09/01 17:32:53 INFO impl.TimelineClientImpl: Timeline service address: http://centos1.local:8188/ws/v1/timeline/
14/09/01 17:32:53 INFO client.RMProxy: Connecting to ResourceManager at centos1.local/10.157.16.93:8050
14/09/01 17:32:55 INFO mapred.FileInputFormat: Total input paths to process : 1
14/09/01 17:32:55 INFO mapreduce.JobSubmitter: number of splits:2
14/09/01 17:32:55 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1409584998239_0001
14/09/01 17:32:56 INFO impl.YarnClientImpl: Submitted application application_1409584998239_0001
14/09/01 17:32:56 INFO mapreduce.Job: The url to track the job: http://centos1.local:8088/proxy/application_1409584998239_0001/
14/09/01 17:32:56 INFO mapreduce.Job: Running job: job_1409584998239_0001
14/09/01 17:33:08 INFO mapreduce.Job: Job job_1409584998239_0001 running in uber mode : false
14/09/01 17:33:08 INFO mapreduce.Job:  map 0% reduce 0%
14/09/01 17:33:18 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000001_0, Status : FAILED Error: Java heap space
14/09/01 17:33:18 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000000_0, Status : FAILED Error: Java heap space
14/09/01 17:33:25 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000001_1, Status : FAILED Error: Java heap space
14/09/01 17:33:26 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000000_1, Status : FAILED Error: Java heap space
14/09/01 17:33:32 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000001_2, Status : FAILED Error: Java heap space
14/09/01 17:33:32 INFO mapreduce.Job: Task Id : attempt_1409584998239_0001_m_000000_2, Status : FAILED Error: Java heap space
14/09/01 17:33:41 INFO mapreduce.Job:  map 100% reduce 100%
14/09/01 17:33:41 INFO mapreduce.Job: Job job_1409584998239_0001 failed with state FAILED due to: Task failed task_1409584998239_0001_m_000000 Job failed as tasks failed. failedMaps:1 failedReduces:0

14/09/01 17:33:41 INFO mapreduce.Job: Counters: 13
        Job Counters
                Failed map tasks=7
                Killed map tasks=1
                Launched map tasks=8
                Other local map tasks=6
                Data-local map tasks=2
                Total time spent by all maps in occupied slots (ms)=96292
                Total time spent by all reduces in occupied slots (ms)=0
                Total time spent by all map tasks (ms)=48146
                Total vcore-seconds taken by all map tasks=48146
                Total megabyte-seconds taken by all map tasks=197206016
        Map-Reduce Framework
                CPU time spent (ms)=0
                Physical memory (bytes) snapshot=0
                Virtual memory (bytes) snapshot=0
14/09/01 17:33:41 ERROR streaming.StreamJob: Job not Successful!
Streaming Command Failed!
Error in mr(map = map, reduce = reduce, combine = combine, vectorized.reduce,  :
  hadoop streaming failed with error code 1

___________________________________________________


jobhistory:

Job Name:     streamjob7414054980203160633.jar
User Name:     root
Queue:     default
State:     FAILED
Uberized:     false
Submitted:     Mon Sep 01 17:32:56 CEST 2014
Started:     Mon Sep 01 17:33:02 CEST 2014
Finished:     Mon Sep 01 17:33:35 CEST 2014
Elapsed:     32sec
Diagnostics:    
Task failed task_1409584998239_0001_m_000000
Job failed as tasks failed. failedMaps:1 failedReduces:0

___________________________________________________


NodeManager information:

Total Vmem allocated for Containers     8.40 GB
Vmem enforcement enabled     false
Total Pmem allocated for Container     4 GB
Pmem enforcement enabled     false
NodeHealthyStatus     true
LastNodeHealthTime     Mon Sep 01 17:35:36 CEST 2014
NodeHealthReport    
Node Manager Version:     2.4.0.2.1.4.0-632 from 5875a08eb52c3c2dc082b48eba7282be7dc8c6c2 by jenkins source checksum 3794ba3e940493c98b319b321b593 on 2014-07-29T21:57Z
Hadoop Version:     2.4.0.2.1.4.0-632 from 5875a08eb52c3c2dc082b48eba7282be7dc8c6c2 by jenkins source checksum 30f74f836e24bea45b4883fec56f621c on 2014-07-29T21:56Z

___________________________________________________


Log file:

 Log Type: syslog

Log Length: 77017

2014-09-01 17:32:56,348 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Created MRAppMaster for application appattempt_1409584998239_0001_000001
2014-09-01 17:32:57,404 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Executing with tokens:
2014-09-01 17:32:57,404 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Kind: YARN_AM_RM_TOKEN, Service: , Ident: (org.apache.hadoop.yarn.security.AMRMTokenIdentifier@6cf1f051)
2014-09-01 17:32:58,811 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter set in config null
2014-09-01 17:32:58,813 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-09-01 17:32:58,937 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.jobhistory.EventType for class org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler
2014-09-01 17:32:58,939 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher
2014-09-01 17:32:58,942 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher
2014-09-01 17:32:58,944 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskAttemptEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskAttemptEventDispatcher
2014-09-01 17:32:58,944 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventType for class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler
2014-09-01 17:32:58,947 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.speculate.Speculator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$SpeculatorEventDispatcher
2014-09-01 17:32:58,948 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.rm.ContainerAllocator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter
2014-09-01 17:32:58,949 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncher$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerLauncherRouter
2014-09-01 17:32:59,044 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler
2014-09-01 17:32:59,331 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
2014-09-01 17:32:59,469 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 60 second(s).
2014-09-01 17:32:59,469 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
2014-09-01 17:32:59,479 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Adding job token for job_1409584998239_0001 to jobTokenSecretManager
2014-09-01 17:32:59,757 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Not uberizing job_1409584998239_0001 because: not enabled;
2014-09-01 17:32:59,828 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Input size for job job_1409584998239_0001 = 908. Number of splits = 2
2014-09-01 17:32:59,830 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Number of reduces for job job_1409584998239_0001 = 1
2014-09-01 17:32:59,830 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from NEW to INITED
2014-09-01 17:32:59,833 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster launching normal, non-uberized, multi-container job job_1409584998239_0001.
2014-09-01 17:32:59,927 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-01 17:32:59,978 INFO [Socket Reader #1 for port 34988] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 34988
2014-09-01 17:33:00,049 INFO [main] org.apache.hadoop.yarn.factories.impl.pb.RpcServerFactoryPBImpl: Adding protocol org.apache.hadoop.mapreduce.v2.api.MRClientProtocolPB to the server
2014-09-01 17:33:00,053 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-01 17:33:00,057 INFO [IPC Server listener on 34988] org.apache.hadoop.ipc.Server: IPC Server listener on 34988: starting
2014-09-01 17:33:00,059 INFO [main] org.apache.hadoop.mapreduce.v2.app.client.MRClientService: Instantiated MRClientService at centos3.local/10.157.16.95:34988
2014-09-01 17:33:00,262 INFO [main] org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2014-09-01 17:33:00,276 INFO [main] org.apache.hadoop.http.HttpRequestLog: Http request log for http.requests.mapreduce is not defined
2014-09-01 17:33:00,309 INFO [main] org.apache.hadoop.http.HttpServer2: Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2014-09-01 17:33:00,326 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context mapreduce
2014-09-01 17:33:00,328 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context static
2014-09-01 17:33:00,338 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /mapreduce/*
2014-09-01 17:33:00,338 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /ws/*
2014-09-01 17:33:00,378 INFO [main] org.apache.hadoop.http.HttpServer2: Jetty bound to port 54341
2014-09-01 17:33:00,378 INFO [main] org.mortbay.log: jetty-6.1.26
2014-09-01 17:33:00,611 INFO [main] org.mortbay.log: Extract jar:file:/usr/lib/hadoop-yarn/hadoop-yarn-common-2.4.0.2.1.4.0-632.jar!/webapps/mapreduce to /tmp/Jetty_0_0_0_0_54341_mapreduce____.qkcfbs/webapp
2014-09-01 17:33:01,271 INFO [main] org.mortbay.log: Started SelectChann...@0.0.0.0:54341
2014-09-01 17:33:01,271 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Web app /mapreduce started at 54341
2014-09-01 17:33:02,147 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Registered webapp guice modules
2014-09-01 17:33:02,153 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-01 17:33:02,155 INFO [Socket Reader #1 for port 55313] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 55313
2014-09-01 17:33:02,161 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-01 17:33:02,161 INFO [IPC Server listener on 55313] org.apache.hadoop.ipc.Server: IPC Server listener on 55313: starting
2014-09-01 17:33:02,181 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
2014-09-01 17:33:02,181 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
2014-09-01 17:33:02,181 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
2014-09-01 17:33:02,301 INFO [main] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at centos1.local/10.157.16.93:8030
2014-09-01 17:33:02,674 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: maxContainerCapability: 4096
2014-09-01 17:33:02,674 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: queue: default
2014-09-01 17:33:02,683 INFO [main] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Upper limit on the thread pool size is 500
2014-09-01 17:33:02,686 INFO [main] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: yarn.client.max-nodemanagers-proxies : 500
2014-09-01 17:33:02,700 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from INITED to SETUP
2014-09-01 17:33:02,707 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_SETUP
2014-09-01 17:33:02,732 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from SETUP to RUNNING
2014-09-01 17:33:02,984 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:02,988 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:02,995 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:03,040 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000000 Task Transitioned from NEW to SCHEDULED
2014-09-01 17:33:03,040 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:03,040 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:03,040 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:03,042 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000001 Task Transitioned from NEW to SCHEDULED
2014-09-01 17:33:03,042 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_r_000000 Task Transitioned from NEW to SCHEDULED
2014-09-01 17:33:03,043 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:03,052 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:03,052 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_r_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:03,054 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: mapResourceReqt:4096
2014-09-01 17:33:03,085 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: reduceResourceReqt:4096
2014-09-01 17:33:03,163 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1409584998239_0001, File: hdfs://centos2.local:8020/user/root/.staging/job_1409584998239_0001/job_1409584998239_0001_1.jhist
2014-09-01 17:33:03,687 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:0 ContRel:0 HostLocal:0 RackLocal:0
2014-09-01 17:33:03,821 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:8192, vCores:0> knownNMs=3
2014-09-01 17:33:03,821 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=8192
2014-09-01 17:33:03,821 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:04,839 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-01 17:33:04,845 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000002 to attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:04,853 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000003 to attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:04,853 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:04,853 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:04,853 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:04,904 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:04,919 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-jar file on the remote FS is hdfs://centos2.local:8020/user/root/.staging/job_1409584998239_0001/job.jar
2014-09-01 17:33:04,922 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-conf file on the remote FS is /user/root/.staging/job_1409584998239_0001/job.xml
2014-09-01 17:33:04,930 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Adding #0 tokens and #1 secret keys for NM use for launching container
2014-09-01 17:33:04,930 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Size of containertokens_dob is 1
2014-09-01 17:33:04,930 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Putting shuffle token in serviceData
2014-09-01 17:33:04,954 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:04,957 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:04,957 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:04,959 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000002 taskAttempt attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:04,961 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:04,961 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000003 taskAttempt attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:04,964 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:04,965 INFO [ContainerLauncher #0] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos4.local:45454
2014-09-01 17:33:04,984 INFO [ContainerLauncher #1] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos5.local:45454
2014-09-01 17:33:05,373 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000000_0 : 13562
2014-09-01 17:33:05,374 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000001_0 : 13562
2014-09-01 17:33:05,375 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000000_0] using containerId: [container_1409584998239_0001_01_000002 on NM: [centos4.local:45454]
2014-09-01 17:33:05,378 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:05,378 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000001_0] using containerId: [container_1409584998239_0001_01_000003 on NM: [centos5.local:45454]
2014-09-01 17:33:05,379 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:05,380 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000000 Task Transitioned from SCHEDULED to RUNNING
2014-09-01 17:33:05,381 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000001 Task Transitioned from SCHEDULED to RUNNING
2014-09-01 17:33:05,857 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:10,046 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:10,101 INFO [IPC Server handler 0 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000003 asked for a task
2014-09-01 17:33:10,101 INFO [IPC Server handler 0 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000003 given task: attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:10,197 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:10,240 INFO [IPC Server handler 0 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000002 asked for a task
2014-09-01 17:33:10,240 INFO [IPC Server handler 0 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000002 given task: attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:12,872 FATAL [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000001_0 - exited : Java heap space
2014-09-01 17:33:12,872 INFO [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_0: Error: Java heap space
2014-09-01 17:33:12,874 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_0: Error: Java heap space
2014-09-01 17:33:12,880 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:12,880 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000003 taskAttempt attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:12,881 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:12,906 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:12,907 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:12,916 WARN [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000001_0
2014-09-01 17:33:12,917 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_0 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:12,932 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:12,933 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:12,933 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:12,934 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos5.local
2014-09-01 17:33:12,936 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:12,936 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000001_1 to list of failed maps
2014-09-01 17:33:13,062 FATAL [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000000_0 - exited : Java heap space
2014-09-01 17:33:13,062 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_0: Error: Java heap space
2014-09-01 17:33:13,063 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_0: Error: Java heap space
2014-09-01 17:33:13,063 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:13,064 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000002 taskAttempt attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:13,064 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:13,081 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:13,081 INFO [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:13,083 WARN [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000000_0
2014-09-01 17:33:13,084 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_0 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:13,084 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:13,084 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:13,084 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:13,086 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos4.local
2014-09-01 17:33:13,086 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:13,086 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000000_1 to list of failed maps
2014-09-01 17:33:13,876 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:13,878 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:13,878 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:13,878 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:14,888 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000003
2014-09-01 17:33:14,888 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_0: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:14,889 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000002
2014-09-01 17:33:14,889 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_0: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:14,889 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-01 17:33:14,889 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000004, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ] to fast fail map
2014-09-01 17:33:14,889 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:14,890 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:14,891 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:14,891 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000004 to attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:14,891 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000005, NodeId: centos4.local:45454, NodeHttpAddress: centos4.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.96:45454 }, ] to fast fail map
2014-09-01 17:33:14,891 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:14,892 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:14,892 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:14,898 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000005 to attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:14,898 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:14,898 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:14,898 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:4 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:14,899 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000004 taskAttempt attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:14,899 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:14,903 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000005 taskAttempt attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:14,903 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:14,912 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000001_1 : 13562
2014-09-01 17:33:14,913 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000001_1] using containerId: [container_1409584998239_0001_01_000004 on NM: [centos5.local:45454]
2014-09-01 17:33:14,913 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:14,916 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000000_1 : 13562
2014-09-01 17:33:14,916 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000000_1] using containerId: [container_1409584998239_0001_01_000005 on NM: [centos4.local:45454]
2014-09-01 17:33:14,916 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:15,900 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:17,518 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:17,545 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:17,560 INFO [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000005 asked for a task
2014-09-01 17:33:17,560 INFO [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000005 given task: attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:17,585 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000004 asked for a task
2014-09-01 17:33:17,585 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000004 given task: attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:20,336 FATAL [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000001_1 - exited : Java heap space
2014-09-01 17:33:20,336 INFO [IPC Server handler 1 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_1: Error: Java heap space
2014-09-01 17:33:20,337 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_1: Error: Java heap space
2014-09-01 17:33:20,337 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:20,338 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000004 taskAttempt attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:20,338 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:20,341 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:20,341 INFO [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:20,343 WARN [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000001_1
2014-09-01 17:33:20,344 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_1 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:20,344 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:20,344 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:20,344 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:20,346 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 2 failures on node centos5.local
2014-09-01 17:33:20,346 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:20,346 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000001_2 to list of failed maps
2014-09-01 17:33:20,572 FATAL [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000000_1 - exited : Java heap space
2014-09-01 17:33:20,572 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_1: Error: Java heap space
2014-09-01 17:33:20,573 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_1: Error: Java heap space
2014-09-01 17:33:20,575 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:20,575 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000005 taskAttempt attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:20,576 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:20,578 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:20,578 INFO [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:20,580 WARN [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000000_1
2014-09-01 17:33:20,580 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_1 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:20,581 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:20,581 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:20,581 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:20,581 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:20,582 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 2 failures on node centos4.local
2014-09-01 17:33:20,583 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000000_2 to list of failed maps
2014-09-01 17:33:20,910 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:4 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:20,913 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:20,913 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:20,913 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:21,917 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000004
2014-09-01 17:33:21,917 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000005
2014-09-01 17:33:21,917 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-01 17:33:21,918 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000006, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ] to fast fail map
2014-09-01 17:33:21,918 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:21,918 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000006 to attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:21,918 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000007, NodeId: centos4.local:45454, NodeHttpAddress: centos4.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.96:45454 }, ] to fast fail map
2014-09-01 17:33:21,918 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_1: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:21,918 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_1: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:21,919 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:21,919 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:21,920 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:21,921 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000007 to attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:21,921 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:21,921 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:21,921 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:6 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:21,921 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:21,922 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:21,922 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000006 taskAttempt attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:21,922 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:21,925 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000007 taskAttempt attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:21,925 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:21,934 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000001_2 : 13562
2014-09-01 17:33:21,934 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000001_2] using containerId: [container_1409584998239_0001_01_000006 on NM: [centos5.local:45454]
2014-09-01 17:33:21,935 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:21,936 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000000_2 : 13562
2014-09-01 17:33:21,936 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000000_2] using containerId: [container_1409584998239_0001_01_000007 on NM: [centos4.local:45454]
2014-09-01 17:33:21,936 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:22,924 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:24,578 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:24,581 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:24,622 INFO [IPC Server handler 3 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000006 asked for a task
2014-09-01 17:33:24,622 INFO [IPC Server handler 3 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000006 given task: attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:24,623 INFO [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000007 asked for a task
2014-09-01 17:33:24,623 INFO [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000007 given task: attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:27,405 FATAL [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000001_2 - exited : Java heap space
2014-09-01 17:33:27,405 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_2: Error: Java heap space
2014-09-01 17:33:27,407 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_2: Error: Java heap space
2014-09-01 17:33:27,407 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:27,407 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000006 taskAttempt attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:27,408 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:27,410 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:27,410 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:27,412 WARN [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000001_2
2014-09-01 17:33:27,412 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_2 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:27,414 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:27,414 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:27,414 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:27,415 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 3 failures on node centos5.local
2014-09-01 17:33:27,415 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Blacklisted host centos5.local
2014-09-01 17:33:27,415 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:27,416 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000001_3 to list of failed maps
2014-09-01 17:33:27,447 FATAL [IPC Server handler 3 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000000_2 - exited : Java heap space
2014-09-01 17:33:27,448 INFO [IPC Server handler 3 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_2: Error: Java heap space
2014-09-01 17:33:27,449 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_2: Error: Java heap space
2014-09-01 17:33:27,450 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:27,450 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000007 taskAttempt attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:27,450 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:27,452 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:27,452 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:27,454 WARN [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000000_2
2014-09-01 17:33:27,455 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_2 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:27,456 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:27,457 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-01 17:33:27,457 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:27,457 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 3 failures on node centos4.local
2014-09-01 17:33:27,457 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Blacklisted host centos4.local
2014-09-01 17:33:27,458 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-01 17:33:27,458 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409584998239_0001_m_000000_3 to list of failed maps
2014-09-01 17:33:27,933 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:6 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:27,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:27,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Update the blacklist for application_1409584998239_0001: blacklistAdditions=2 blacklistRemovals=0
2014-09-01 17:33:27,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Ignore blacklisting set to true. Known: 3, Blacklisted: 2, 66%
2014-09-01 17:33:27,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:27,936 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:28,938 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Update the blacklist for application_1409584998239_0001: blacklistAdditions=0 blacklistRemovals=2
2014-09-01 17:33:28,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000006
2014-09-01 17:33:28,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409584998239_0001_01_000007
2014-09-01 17:33:28,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Ramping down all scheduled reduces:0
2014-09-01 17:33:28,939 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Going to preempt 0
2014-09-01 17:33:28,940 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_2: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:28,940 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_2: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-01 17:33:28,940 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:28,940 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:28,940 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:6 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:29,944 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000008, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ] to fast fail map
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000008 to attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409584998239_0001_01_000009, NodeId: centos4.local:45454, NodeHttpAddress: centos4.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.96:45454 }, ] to fast fail map
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409584998239_0001_01_000009 to attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-01 17:33:29,945 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:8 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:29,946 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-01 17:33:29,946 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:29,947 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-01 17:33:29,947 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-01 17:33:29,947 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000008 taskAttempt attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:29,947 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:29,949 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409584998239_0001_01_000009 taskAttempt attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:29,949 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:29,954 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000000_3 : 13562
2014-09-01 17:33:29,955 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000000_3] using containerId: [container_1409584998239_0001_01_000009 on NM: [centos4.local:45454]
2014-09-01 17:33:29,955 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:29,962 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409584998239_0001_m_000001_3 : 13562
2014-09-01 17:33:29,962 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409584998239_0001_m_000001_3] using containerId: [container_1409584998239_0001_01_000008 on NM: [centos5.local:45454]
2014-09-01 17:33:29,962 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-01 17:33:30,948 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409584998239_0001: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-2> knownNMs=3
2014-09-01 17:33:32,567 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:32,590 INFO [Socket Reader #1 for port 55313] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409584998239_0001 (auth:SIMPLE)
2014-09-01 17:33:32,609 INFO [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000009 asked for a task
2014-09-01 17:33:32,609 INFO [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000009 given task: attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:32,637 INFO [IPC Server handler 5 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409584998239_0001_m_000008 asked for a task
2014-09-01 17:33:32,637 INFO [IPC Server handler 5 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409584998239_0001_m_000008 given task: attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:35,345 FATAL [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000000_3 - exited : Java heap space
2014-09-01 17:33:35,346 INFO [IPC Server handler 2 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_3: Error: Java heap space
2014-09-01 17:33:35,347 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000000_3: Error: Java heap space
2014-09-01 17:33:35,348 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-01 17:33:35,348 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000009 taskAttempt attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:35,348 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:35,350 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-01 17:33:35,350 INFO [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:35,352 WARN [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000000_3
2014-09-01 17:33:35,352 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000000_3 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-01 17:33:35,356 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000000 Task Transitioned from RUNNING to FAILED
2014-09-01 17:33:35,359 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 1
2014-09-01 17:33:35,360 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Job failed as tasks failed. failedMaps:1 failedReduces:0
2014-09-01 17:33:35,361 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from RUNNING to FAIL_WAIT
2014-09-01 17:33:35,361 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000001 Task Transitioned from RUNNING to KILL_WAIT
2014-09-01 17:33:35,361 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_r_000000 Task Transitioned from SCHEDULED to KILL_WAIT
2014-09-01 17:33:35,361 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from RUNNING to KILL_CONTAINER_CLEANUP
2014-09-01 17:33:35,362 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_r_000000_0 TaskAttempt Transitioned from UNASSIGNED to KILLED
2014-09-01 17:33:35,362 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409584998239_0001_01_000008 taskAttempt attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:35,363 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:35,363 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Processing the event EventType: CONTAINER_DEALLOCATE
2014-09-01 17:33:35,363 ERROR [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Could not deallocate container for task attemptId attempt_1409584998239_0001_r_000000_0
2014-09-01 17:33:35,364 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_r_000000 Task Transitioned from KILL_WAIT to KILLED
2014-09-01 17:33:35,368 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from KILL_CONTAINER_CLEANUP to KILL_TASK_CLEANUP
2014-09-01 17:33:35,369 INFO [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-01 17:33:35,372 WARN [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file4edf2e90ca28/_temporary/1/_temporary/attempt_1409584998239_0001_m_000001_3
2014-09-01 17:33:35,372 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409584998239_0001_m_000001_3 TaskAttempt Transitioned from KILL_TASK_CLEANUP to KILLED
2014-09-01 17:33:35,374 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409584998239_0001_m_000001 Task Transitioned from KILL_WAIT to KILLED
2014-09-01 17:33:35,377 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from FAIL_WAIT to FAIL_ABORT
2014-09-01 17:33:35,377 INFO [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_ABORT
2014-09-01 17:33:35,386 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409584998239_0001Job Transitioned from FAIL_ABORT to FAILED
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2014-09-01 17:33:35,387 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
2014-09-01 17:33:35,389 INFO [Thread-63] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 0
2014-09-01 17:33:35,461 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409584998239_0001/job_1409584998239_0001_1.jhist to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001-1409585576222-root-streamjob7414054980203160633.jar-1409585615360-0-0-FAILED-default-1409585582692.jhist_tmp
2014-09-01 17:33:35,485 FATAL [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409584998239_0001_m_000001_3 - exited : Java heap space
2014-09-01 17:33:35,485 INFO [IPC Server handler 4 on 55313] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_3: Error: Java heap space
2014-09-01 17:33:35,486 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409584998239_0001_m_000001_3: Error: Java heap space
2014-09-01 17:33:35,505 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001-1409585576222-root-streamjob7414054980203160633.jar-1409585615360-0-0-FAILED-default-1409585582692.jhist_tmp
2014-09-01 17:33:35,508 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409584998239_0001/job_1409584998239_0001_1_conf.xml to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001_conf.xml_tmp
2014-09-01 17:33:35,539 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001_conf.xml_tmp
2014-09-01 17:33:35,550 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001.summary_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001.summary
2014-09-01 17:33:35,552 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001_conf.xml_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001_conf.xml
2014-09-01 17:33:35,557 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001-1409585576222-root-streamjob7414054980203160633.jar-1409585615360-0-0-FAILED-default-1409585582692.jhist_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409584998239_0001-1409585576222-root-streamjob7414054980203160633.jar-1409585615360-0-0-FAILED-default-1409585582692.jhist
2014-09-01 17:33:35,558 INFO [Thread-63] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2014-09-01 17:33:35,560 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to Task failed task_1409584998239_0001_m_000000
Job failed as tasks failed. failedMaps:1 failedReduces:0

2014-09-01 17:33:35,561 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: History url is http://centos1.local:19888/jobhistory/job/job_1409584998239_0001
2014-09-01 17:33:35,588 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Waiting for application to be successfully unregistered.
2014-09-01 17:33:36,590 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:8 ContRel:0 HostLocal:2 RackLocal:0
2014-09-01 17:33:36,591 INFO [Thread-63] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://centos2.local:8020 /user/root/.staging/job_1409584998239_0001
2014-09-01 17:33:36,595 INFO [Thread-63] org.apache.hadoop.ipc.Server: Stopping server on 55313
2014-09-01 17:33:36,598 INFO [IPC Server listener on 55313] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 55313
2014-09-01 17:33:36,598 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2014-09-01 17:33:36,598 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted


Antonio Piccolboni

unread,
Sep 1, 2014, 2:30:54 PM9/1/14
to RHadoop Google Group
Please consult the debugging guide first.


Antonio



--
post: rha...@googlegroups.com ||
unsubscribe: rhadoop+u...@googlegroups.com ||
web: https://groups.google.com/d/forum/rhadoop?hl=en-US
---
You received this message because you are subscribed to the Google Groups "RHadoop" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rhadoop+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Manuel

unread,
Sep 1, 2014, 5:22:15 PM9/1/14
to rha...@googlegroups.com
Many thanks for the quick feedback and the link!

Meanwhile I would like to add some further information on software versions used, just in case:
* plyrmr_0.4.0.tar.gz
* rhdfs_1.0.8.tar.gz
* rmr2_3.2.0.tar.gz
* epel-release-6-8.noarch.rpm
* rstudio-server-0.98.1028-x86_64.rpm
* R 3.1.0 (2014-04-10)

Best,

Manuel
...

Antonio Piccolboni

unread,
Sep 1, 2014, 5:28:10 PM9/1/14
to RHadoop Google Group
That's helpful, please update to rmr2 3.2.1


Antonio


--

Manuel

unread,
Sep 4, 2014, 9:58:00 AM9/4/14
to rha...@googlegroups.com, ant...@piccolboni.info
I installed rmr2_3.2.1 (version from 2014-09-02) and tried the tutorial:
https://github.com/RevolutionAnalytics/rmr2/blob/master/docs/tutorial.md

The first example (with only the map phase) works.
The second example (with map and reduce) still crashes.

I tried the tutorial from above as well with the previous version, rmr2_3.2.0.
Map phase only works, reduce phase crashes with Java heap space error.

Please find below the logs for the runs with rmr2_3.2.1

Best,

Manuel


First example, only map
__________________________________
 Log Type: syslog

Log Length: 30948

2014-09-02 18:44:52,909 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Created MRAppMaster for application appattempt_1409663488190_0005_000001
2014-09-02 18:44:53,994 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Executing with tokens:
2014-09-02 18:44:53,996 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Kind: YARN_AM_RM_TOKEN, Service: , Ident: (org.apache.hadoop.yarn.security.AMRMTokenIdentifier@6cf1f051)
2014-09-02 18:44:55,355 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter set in config null
2014-09-02 18:44:55,360 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-09-02 18:44:55,483 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.jobhistory.EventType for class org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler
2014-09-02 18:44:55,486 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher
2014-09-02 18:44:55,488 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher
2014-09-02 18:44:55,490 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskAttemptEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskAttemptEventDispatcher
2014-09-02 18:44:55,491 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventType for class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler
2014-09-02 18:44:55,493 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.speculate.Speculator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$SpeculatorEventDispatcher
2014-09-02 18:44:55,494 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.rm.ContainerAllocator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter
2014-09-02 18:44:55,495 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncher$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerLauncherRouter
2014-09-02 18:44:55,590 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler
2014-09-02 18:44:55,878 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
2014-09-02 18:44:56,014 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 60 second(s).
2014-09-02 18:44:56,014 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
2014-09-02 18:44:56,024 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Adding job token for job_1409663488190_0005 to jobTokenSecretManager
2014-09-02 18:44:56,295 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Not uberizing job_1409663488190_0005 because: not enabled;
2014-09-02 18:44:56,366 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Input size for job job_1409663488190_0005 = 2142. Number of splits = 2
2014-09-02 18:44:56,366 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Number of reduces for job job_1409663488190_0005 = 0
2014-09-02 18:44:56,366 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0005Job Transitioned from NEW to INITED
2014-09-02 18:44:56,369 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster launching normal, non-uberized, multi-container job job_1409663488190_0005.
2014-09-02 18:44:56,468 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-02 18:44:56,532 INFO [Socket Reader #1 for port 50434] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 50434
2014-09-02 18:44:56,603 INFO [main] org.apache.hadoop.yarn.factories.impl.pb.RpcServerFactoryPBImpl: Adding protocol org.apache.hadoop.mapreduce.v2.api.MRClientProtocolPB to the server
2014-09-02 18:44:56,606 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-02 18:44:56,609 INFO [IPC Server listener on 50434] org.apache.hadoop.ipc.Server: IPC Server listener on 50434: starting
2014-09-02 18:44:56,612 INFO [main] org.apache.hadoop.mapreduce.v2.app.client.MRClientService: Instantiated MRClientService at centos5.local/10.157.16.97:50434
2014-09-02 18:44:56,816 INFO [main] org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2014-09-02 18:44:56,830 INFO [main] org.apache.hadoop.http.HttpRequestLog: Http request log for http.requests.mapreduce is not defined
2014-09-02 18:44:56,865 INFO [main] org.apache.hadoop.http.HttpServer2: Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2014-09-02 18:44:56,881 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context mapreduce
2014-09-02 18:44:56,883 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context static
2014-09-02 18:44:56,892 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /mapreduce/*
2014-09-02 18:44:56,892 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /ws/*
2014-09-02 18:44:56,929 INFO [main] org.apache.hadoop.http.HttpServer2: Jetty bound to port 57857
2014-09-02 18:44:56,929 INFO [main] org.mortbay.log: jetty-6.1.26
2014-09-02 18:44:57,157 INFO [main] org.mortbay.log: Extract jar:file:/usr/lib/hadoop-yarn/hadoop-yarn-common-2.4.0.2.1.4.0-632.jar!/webapps/mapreduce to /tmp/Jetty_0_0_0_0_57857_mapreduce____.qvdu7z/webapp
2014-09-02 18:44:57,815 INFO [main] org.mortbay.log: Started SelectChann...@0.0.0.0:57857
2014-09-02 18:44:57,817 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Web app /mapreduce started at 57857
2014-09-02 18:44:58,678 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Registered webapp guice modules
2014-09-02 18:44:58,683 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-02 18:44:58,685 INFO [Socket Reader #1 for port 32807] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 32807
2014-09-02 18:44:58,691 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-02 18:44:58,692 INFO [IPC Server listener on 32807] org.apache.hadoop.ipc.Server: IPC Server listener on 32807: starting
2014-09-02 18:44:58,712 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
2014-09-02 18:44:58,712 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
2014-09-02 18:44:58,712 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
2014-09-02 18:44:58,839 INFO [main] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at centos1.local/10.157.16.93:8030
2014-09-02 18:44:58,999 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: maxContainerCapability: 4096
2014-09-02 18:44:58,999 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: queue: default
2014-09-02 18:44:59,007 INFO [main] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Upper limit on the thread pool size is 500
2014-09-02 18:44:59,011 INFO [main] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: yarn.client.max-nodemanagers-proxies : 500
2014-09-02 18:44:59,024 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0005Job Transitioned from INITED to SETUP
2014-09-02 18:44:59,030 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_SETUP
2014-09-02 18:44:59,618 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0005Job Transitioned from SETUP to RUNNING
2014-09-02 18:44:59,710 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:44:59,729 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:44:59,730 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:44:59,757 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000000 Task Transitioned from NEW to SCHEDULED
2014-09-02 18:44:59,757 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:44:59,757 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:44:59,757 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:44:59,758 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000001 Task Transitioned from NEW to SCHEDULED
2014-09-02 18:44:59,780 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:44:59,785 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:44:59,786 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: mapResourceReqt:4096
2014-09-02 18:44:59,848 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1409663488190_0005, File: hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0005/job_1409663488190_0005_1.jhist
2014-09-02 18:45:00,009 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:0 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:0 ContRel:0 HostLocal:0 RackLocal:0
2014-09-02 18:45:00,134 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0005: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:16384, vCores:0> knownNMs=5
2014-09-02 18:45:01,150 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-02 18:45:01,155 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0005_01_000002 to attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:01,158 INFO [RMCommunicator Allocator] org.apache.hadoop.yarn.util.RackResolver: Resolved centos1.local to /default-rack
2014-09-02 18:45:01,159 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0005_01_000003 to attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:01,159 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:45:01,209 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:45:01,224 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-jar file on the remote FS is hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0005/job.jar
2014-09-02 18:45:01,226 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-conf file on the remote FS is /user/root/.staging/job_1409663488190_0005/job.xml
2014-09-02 18:45:01,231 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Adding #0 tokens and #1 secret keys for NM use for launching container
2014-09-02 18:45:01,231 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Size of containertokens_dob is 1
2014-09-02 18:45:01,232 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Putting shuffle token in serviceData
2014-09-02 18:45:01,256 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:45:01,259 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos1.local to /default-rack
2014-09-02 18:45:01,259 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:45:01,261 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0005_01_000002 taskAttempt attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:01,263 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:01,263 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0005_01_000003 taskAttempt attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:01,264 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:01,264 INFO [ContainerLauncher #0] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos4.local:45454
2014-09-02 18:45:01,283 INFO [ContainerLauncher #1] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos1.local:45454
2014-09-02 18:45:01,471 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0005_m_000001_0 : 13562
2014-09-02 18:45:01,472 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0005_m_000000_0 : 13562
2014-09-02 18:45:01,473 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0005_m_000001_0] using containerId: [container_1409663488190_0005_01_000003 on NM: [centos1.local:45454]
2014-09-02 18:45:01,477 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:45:01,477 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0005_m_000000_0] using containerId: [container_1409663488190_0005_01_000002 on NM: [centos4.local:45454]
2014-09-02 18:45:01,478 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:45:01,480 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000001 Task Transitioned from SCHEDULED to RUNNING
2014-09-02 18:45:01,482 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000000 Task Transitioned from SCHEDULED to RUNNING
2014-09-02 18:45:02,161 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0005: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:8192, vCores:-2> knownNMs=5
2014-09-02 18:45:04,408 INFO [Socket Reader #1 for port 32807] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0005 (auth:SIMPLE)
2014-09-02 18:45:04,455 INFO [IPC Server handler 0 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0005_m_000002 asked for a task
2014-09-02 18:45:04,456 INFO [IPC Server handler 0 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0005_m_000002 given task: attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:04,529 INFO [Socket Reader #1 for port 32807] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0005 (auth:SIMPLE)
2014-09-02 18:45:04,576 INFO [IPC Server handler 1 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0005_m_000003 asked for a task
2014-09-02 18:45:04,576 INFO [IPC Server handler 1 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0005_m_000003 given task: attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,465 INFO [IPC Server handler 1 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1409663488190_0005_m_000001_0 is : 0.0
2014-09-02 18:45:08,730 INFO [IPC Server handler 0 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit-pending state update from attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,731 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from RUNNING to COMMIT_PENDING
2014-09-02 18:45:08,731 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: attempt_1409663488190_0005_m_000001_0 given a go for committing the task output.
2014-09-02 18:45:08,732 INFO [IPC Server handler 1 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit go/no-go request from attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,732 INFO [IPC Server handler 1 on 32807] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Result of canCommit for attempt_1409663488190_0005_m_000001_0:true
2014-09-02 18:45:08,835 INFO [IPC Server handler 2 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1409663488190_0005_m_000001_0 is : 1.0
2014-09-02 18:45:08,842 INFO [IPC Server handler 3 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,843 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_CONTAINER_CLEANUP
2014-09-02 18:45:08,844 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0005_01_000003 taskAttempt attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,844 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,853 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000001_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
2014-09-02 18:45:08,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1409663488190_0005_m_000001_0
2014-09-02 18:45:08,868 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000001 Task Transitioned from RUNNING to SUCCEEDED
2014-09-02 18:45:08,871 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 1
2014-09-02 18:45:09,171 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:45:10,178 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0005_01_000003
2014-09-02 18:45:10,179 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0005_m_000001_0: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:45:10,179 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:1 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:45:10,376 INFO [IPC Server handler 4 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1409663488190_0005_m_000000_0 is : 0.0
2014-09-02 18:45:10,602 INFO [IPC Server handler 5 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit-pending state update from attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,603 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from RUNNING to COMMIT_PENDING
2014-09-02 18:45:10,603 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: attempt_1409663488190_0005_m_000000_0 given a go for committing the task output.
2014-09-02 18:45:10,603 INFO [IPC Server handler 6 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit go/no-go request from attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,604 INFO [IPC Server handler 6 on 32807] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Result of canCommit for attempt_1409663488190_0005_m_000000_0:true
2014-09-02 18:45:10,692 INFO [IPC Server handler 7 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1409663488190_0005_m_000000_0 is : 1.0
2014-09-02 18:45:10,695 INFO [IPC Server handler 16 on 32807] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,696 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_CONTAINER_CLEANUP
2014-09-02 18:45:10,697 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0005_01_000002 taskAttempt attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,697 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,705 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0005_m_000000_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
2014-09-02 18:45:10,706 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1409663488190_0005_m_000000_0
2014-09-02 18:45:10,706 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0005_m_000000 Task Transitioned from RUNNING to SUCCEEDED
2014-09-02 18:45:10,706 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 2
2014-09-02 18:45:10,709 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0005Job Transitioned from RUNNING to COMMITTING
2014-09-02 18:45:10,710 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_COMMIT
2014-09-02 18:45:10,759 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Calling handler for JobFinishedEvent
2014-09-02 18:45:10,760 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0005Job Transitioned from COMMITTING to SUCCEEDED
2014-09-02 18:45:10,767 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
2014-09-02 18:45:10,767 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2014-09-02 18:45:10,768 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
2014-09-02 18:45:10,768 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2014-09-02 18:45:10,768 INFO [Thread-66] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2014-09-02 18:45:10,768 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
2014-09-02 18:45:10,769 INFO [Thread-66] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 0
2014-09-02 18:45:10,808 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0005/job_1409663488190_0005_1.jhist to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005-1409676298950-root-streamjob5785431039032918530.jar-1409676310757-2-0-SUCCEEDED-default-1409676299016.jhist_tmp
2014-09-02 18:45:10,840 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005-1409676298950-root-streamjob5785431039032918530.jar-1409676310757-2-0-SUCCEEDED-default-1409676299016.jhist_tmp
2014-09-02 18:45:10,843 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0005/job_1409663488190_0005_1_conf.xml to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005_conf.xml_tmp
2014-09-02 18:45:10,868 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005_conf.xml_tmp
2014-09-02 18:45:10,871 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005.summary_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005.summary
2014-09-02 18:45:10,873 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005_conf.xml_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005_conf.xml
2014-09-02 18:45:10,874 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005-1409676298950-root-streamjob5785431039032918530.jar-1409676310757-2-0-SUCCEEDED-default-1409676299016.jhist_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0005-1409676298950-root-streamjob5785431039032918530.jar-1409676310757-2-0-SUCCEEDED-default-1409676299016.jhist
2014-09-02 18:45:10,875 INFO [Thread-66] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2014-09-02 18:45:10,876 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to
2014-09-02 18:45:10,877 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: History url is http://centos1.local:19888/jobhistory/job/job_1409663488190_0005
2014-09-02 18:45:10,882 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Waiting for application to be successfully unregistered.
2014-09-02 18:45:11,884 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:1 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:45:11,885 INFO [Thread-66] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://centos2.local:8020 /user/root/.staging/job_1409663488190_0005
2014-09-02 18:45:11,889 INFO [Thread-66] org.apache.hadoop.ipc.Server: Stopping server on 32807
2014-09-02 18:45:11,891 INFO [IPC Server listener on 32807] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 32807
2014-09-02 18:45:11,892 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2014-09-02 18:45:11,892 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted

__________________________________





Second example, map and reduce
__________________________________
 Log Type: syslog

Log Length: 81820

2014-09-02 18:48:02,763 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Created MRAppMaster for application appattempt_1409663488190_0006_000001
2014-09-02 18:48:03,833 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Executing with tokens:
2014-09-02 18:48:03,833 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Kind: YARN_AM_RM_TOKEN, Service: , Ident: (org.apache.hadoop.yarn.security.AMRMTokenIdentifier@6cf1f051)
2014-09-02 18:48:05,494 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter set in config null
2014-09-02 18:48:05,498 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-09-02 18:48:05,645 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.jobhistory.EventType for class org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler
2014-09-02 18:48:05,648 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher
2014-09-02 18:48:05,653 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher
2014-09-02 18:48:05,656 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskAttemptEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskAttemptEventDispatcher
2014-09-02 18:48:05,656 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventType for class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler
2014-09-02 18:48:05,662 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.speculate.Speculator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$SpeculatorEventDispatcher
2014-09-02 18:48:05,663 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.rm.ContainerAllocator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter
2014-09-02 18:48:05,666 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncher$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerLauncherRouter
2014-09-02 18:48:05,876 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler
2014-09-02 18:48:06,351 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
2014-09-02 18:48:06,488 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 60 second(s).
2014-09-02 18:48:06,488 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
2014-09-02 18:48:06,498 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Adding job token for job_1409663488190_0006 to jobTokenSecretManager
2014-09-02 18:48:06,753 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Not uberizing job_1409663488190_0006 because: not enabled;
2014-09-02 18:48:06,810 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Input size for job job_1409663488190_0006 = 459. Number of splits = 2
2014-09-02 18:48:06,812 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Number of reduces for job job_1409663488190_0006 = 1
2014-09-02 18:48:06,814 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from NEW to INITED
2014-09-02 18:48:06,816 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster launching normal, non-uberized, multi-container job job_1409663488190_0006.
2014-09-02 18:48:06,936 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-02 18:48:06,987 INFO [Socket Reader #1 for port 47752] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 47752
2014-09-02 18:48:07,056 INFO [main] org.apache.hadoop.yarn.factories.impl.pb.RpcServerFactoryPBImpl: Adding protocol org.apache.hadoop.mapreduce.v2.api.MRClientProtocolPB to the server
2014-09-02 18:48:07,060 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-02 18:48:07,064 INFO [IPC Server listener on 47752] org.apache.hadoop.ipc.Server: IPC Server listener on 47752: starting
2014-09-02 18:48:07,066 INFO [main] org.apache.hadoop.mapreduce.v2.app.client.MRClientService: Instantiated MRClientService at centos4.local/10.157.16.96:47752
2014-09-02 18:48:07,272 INFO [main] org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2014-09-02 18:48:07,287 INFO [main] org.apache.hadoop.http.HttpRequestLog: Http request log for http.requests.mapreduce is not defined
2014-09-02 18:48:07,322 INFO [main] org.apache.hadoop.http.HttpServer2: Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2014-09-02 18:48:07,340 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context mapreduce
2014-09-02 18:48:07,340 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context static
2014-09-02 18:48:07,349 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /mapreduce/*
2014-09-02 18:48:07,349 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /ws/*
2014-09-02 18:48:07,388 INFO [main] org.apache.hadoop.http.HttpServer2: Jetty bound to port 48205
2014-09-02 18:48:07,390 INFO [main] org.mortbay.log: jetty-6.1.26
2014-09-02 18:48:07,614 INFO [main] org.mortbay.log: Extract jar:file:/usr/lib/hadoop-yarn/hadoop-yarn-common-2.4.0.2.1.4.0-632.jar!/webapps/mapreduce to /tmp/Jetty_0_0_0_0_48205_mapreduce____pr1l9i/webapp
2014-09-02 18:48:08,297 INFO [main] org.mortbay.log: Started SelectChann...@0.0.0.0:48205
2014-09-02 18:48:08,297 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Web app /mapreduce started at 48205
2014-09-02 18:48:09,172 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Registered webapp guice modules
2014-09-02 18:48:09,186 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue class java.util.concurrent.LinkedBlockingQueue
2014-09-02 18:48:09,189 INFO [Socket Reader #1 for port 50740] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 50740
2014-09-02 18:48:09,200 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2014-09-02 18:48:09,201 INFO [IPC Server listener on 50740] org.apache.hadoop.ipc.Server: IPC Server listener on 50740: starting
2014-09-02 18:48:09,266 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
2014-09-02 18:48:09,266 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
2014-09-02 18:48:09,266 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
2014-09-02 18:48:09,404 INFO [main] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at centos1.local/10.157.16.93:8030
2014-09-02 18:48:09,536 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: maxContainerCapability: 4096
2014-09-02 18:48:09,536 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: queue: default
2014-09-02 18:48:09,544 INFO [main] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Upper limit on the thread pool size is 500
2014-09-02 18:48:09,548 INFO [main] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: yarn.client.max-nodemanagers-proxies : 500
2014-09-02 18:48:09,561 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from INITED to SETUP
2014-09-02 18:48:09,569 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_SETUP
2014-09-02 18:48:09,593 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from SETUP to RUNNING
2014-09-02 18:48:09,836 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:09,839 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:09,839 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:09,861 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000000 Task Transitioned from NEW to SCHEDULED
2014-09-02 18:48:09,861 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:09,862 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:09,862 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:09,868 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000001 Task Transitioned from NEW to SCHEDULED
2014-09-02 18:48:09,869 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_r_000000 Task Transitioned from NEW to SCHEDULED
2014-09-02 18:48:09,870 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:09,879 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:09,879 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_r_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:09,880 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: mapResourceReqt:4096
2014-09-02 18:48:09,915 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: reduceResourceReqt:4096
2014-09-02 18:48:09,981 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1409663488190_0006, File: hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0006/job_1409663488190_0006_1.jhist
2014-09-02 18:48:10,545 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:0 ContRel:0 HostLocal:0 RackLocal:0
2014-09-02 18:48:10,710 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:16384, vCores:0> knownNMs=5
2014-09-02 18:48:10,710 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=16384
2014-09-02 18:48:10,710 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:11,722 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-02 18:48:11,726 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000003 to attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:11,729 INFO [RMCommunicator Allocator] org.apache.hadoop.yarn.util.RackResolver: Resolved centos1.local to /default-rack
2014-09-02 18:48:11,730 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000002 to attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:11,730 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=8192
2014-09-02 18:48:11,730 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:11,730 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:11,834 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:11,864 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-jar file on the remote FS is hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0006/job.jar
2014-09-02 18:48:11,866 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-conf file on the remote FS is /user/root/.staging/job_1409663488190_0006/job.xml
2014-09-02 18:48:11,877 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Adding #0 tokens and #1 secret keys for NM use for launching container
2014-09-02 18:48:11,877 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Size of containertokens_dob is 1
2014-09-02 18:48:11,877 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Putting shuffle token in serviceData
2014-09-02 18:48:11,920 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:11,926 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos1.local to /default-rack
2014-09-02 18:48:11,929 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:11,932 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000003 taskAttempt attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:11,937 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:11,935 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000002 taskAttempt attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:11,938 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:11,939 INFO [ContainerLauncher #0] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos3.local:45454
2014-09-02 18:48:11,987 INFO [ContainerLauncher #1] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos1.local:45454
2014-09-02 18:48:12,304 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000000_0 : 13562
2014-09-02 18:48:12,306 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000000_0] using containerId: [container_1409663488190_0006_01_000003 on NM: [centos3.local:45454]
2014-09-02 18:48:12,309 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:12,309 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000001_0 : 13562
2014-09-02 18:48:12,315 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000000 Task Transitioned from SCHEDULED to RUNNING
2014-09-02 18:48:12,316 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000001_0] using containerId: [container_1409663488190_0006_01_000002 on NM: [centos1.local:45454]
2014-09-02 18:48:12,316 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:12,317 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000001 Task Transitioned from SCHEDULED to RUNNING
2014-09-02 18:48:12,732 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=5 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:8192, vCores:-2> knownNMs=5
2014-09-02 18:48:15,297 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:15,346 INFO [IPC Server handler 29 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000003 asked for a task
2014-09-02 18:48:15,347 INFO [IPC Server handler 29 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000003 given task: attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:15,468 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:15,533 INFO [IPC Server handler 28 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000002 asked for a task
2014-09-02 18:48:15,533 INFO [IPC Server handler 28 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000002 given task: attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:18,089 FATAL [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000000_0 - exited : Java heap space
2014-09-02 18:48:18,089 INFO [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_0: Error: Java heap space
2014-09-02 18:48:18,091 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_0: Error: Java heap space
2014-09-02 18:48:18,096 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:18,096 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000003 taskAttempt attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:18,097 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:18,106 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:18,107 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:18,112 WARN [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000000_0
2014-09-02 18:48:18,114 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_0 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:18,128 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:18,128 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:18,128 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:18,130 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos3.local
2014-09-02 18:48:18,132 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:18,132 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000000_1 to list of failed maps
2014-09-02 18:48:18,589 FATAL [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000001_0 - exited : Java heap space
2014-09-02 18:48:18,589 INFO [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_0: Error: Java heap space
2014-09-02 18:48:18,590 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_0: Error: Java heap space
2014-09-02 18:48:18,590 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:18,591 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000002 taskAttempt attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:18,591 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:18,593 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:18,594 INFO [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:18,595 WARN [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000001_0
2014-09-02 18:48:18,596 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_0 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:18,596 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:18,596 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:18,597 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:18,598 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos1.local
2014-09-02 18:48:18,598 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:18,598 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000001_1 to list of failed maps
2014-09-02 18:48:18,743 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:18,745 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:8192, vCores:-2> knownNMs=5
2014-09-02 18:48:18,745 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=8192
2014-09-02 18:48:18,745 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:19,752 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000003
2014-09-02 18:48:19,753 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_0: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:19,753 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000002
2014-09-02 18:48:19,753 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_0: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:19,753 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-02 18:48:19,753 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000004, NodeId: centos2.local:45454, NodeHttpAddress: centos2.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.94:45454 }, ] to fast fail map
2014-09-02 18:48:19,753 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:19,754 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos2.local to /default-rack
2014-09-02 18:48:19,755 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:19,755 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000004 to attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:19,755 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000005, NodeId: centos3.local:45454, NodeHttpAddress: centos3.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.95:45454 }, ] to fast fail map
2014-09-02 18:48:19,755 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:19,756 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:19,756 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:19,762 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000005 to attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:19,762 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=4096
2014-09-02 18:48:19,762 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:19,762 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:4 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:19,763 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000004 taskAttempt attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:19,763 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:19,763 INFO [ContainerLauncher #4] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos2.local:45454
2014-09-02 18:48:19,764 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000005 taskAttempt attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:19,764 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:19,772 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000001_1 : 13562
2014-09-02 18:48:19,773 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000001_1] using containerId: [container_1409663488190_0006_01_000005 on NM: [centos3.local:45454]
2014-09-02 18:48:19,773 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:19,786 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000000_1 : 13562
2014-09-02 18:48:19,786 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000000_1] using containerId: [container_1409663488190_0006_01_000004 on NM: [centos2.local:45454]
2014-09-02 18:48:19,786 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:20,764 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:4096, vCores:-3> knownNMs=5
2014-09-02 18:48:22,920 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:22,981 INFO [IPC Server handler 26 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000004 asked for a task
2014-09-02 18:48:22,981 INFO [IPC Server handler 26 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000004 given task: attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:23,557 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:23,621 INFO [IPC Server handler 26 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000005 asked for a task
2014-09-02 18:48:23,621 INFO [IPC Server handler 26 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000005 given task: attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:26,221 FATAL [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000000_1 - exited : Java heap space
2014-09-02 18:48:26,221 INFO [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_1: Error: Java heap space
2014-09-02 18:48:26,222 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_1: Error: Java heap space
2014-09-02 18:48:26,223 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:26,223 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000004 taskAttempt attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:26,224 INFO [ContainerLauncher #6] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:26,226 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:26,226 INFO [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:26,228 WARN [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000000_1
2014-09-02 18:48:26,228 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_1 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:26,229 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:26,229 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:26,229 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:26,230 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos2.local
2014-09-02 18:48:26,231 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:26,231 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000000_2 to list of failed maps
2014-09-02 18:48:26,774 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:1 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:4 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:26,776 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:4096, vCores:-3> knownNMs=5
2014-09-02 18:48:26,776 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=4096
2014-09-02 18:48:26,776 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:26,886 FATAL [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000001_1 - exited : Java heap space
2014-09-02 18:48:26,886 INFO [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_1: Error: Java heap space
2014-09-02 18:48:26,887 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_1: Error: Java heap space
2014-09-02 18:48:26,887 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:26,888 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000005 taskAttempt attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:26,888 INFO [ContainerLauncher #7] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:26,891 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:26,891 INFO [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:26,892 WARN [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000001_1
2014-09-02 18:48:26,893 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_1 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:26,893 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:26,893 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:26,893 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:26,894 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 2 failures on node centos3.local
2014-09-02 18:48:26,895 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:26,895 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000001_2 to list of failed maps
2014-09-02 18:48:27,776 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:4 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:27,779 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=1 finishedContainers=1 resourcelimit=<memory:8192, vCores:-2> knownNMs=5
2014-09-02 18:48:27,779 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000004
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 1
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000006, NodeId: centos2.local:45454, NodeHttpAddress: centos2.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.94:45454 }, ] to fast fail map
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000006 to attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=8192
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:27,780 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:1 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:5 ContRel:0 HostLocal:1 RackLocal:1
2014-09-02 18:48:27,780 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_1: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:27,781 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos2.local to /default-rack
2014-09-02 18:48:27,781 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:27,782 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000006 taskAttempt attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:27,782 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:27,788 INFO [ContainerLauncher #8] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000000_2 : 13562
2014-09-02 18:48:27,789 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000000_2] using containerId: [container_1409663488190_0006_01_000006 on NM: [centos2.local:45454]
2014-09-02 18:48:27,789 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:28,784 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=2 finishedContainers=1 resourcelimit=<memory:4096, vCores:-3> knownNMs=5
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000005
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000007, NodeId: centos3.local:45454, NodeHttpAddress: centos3.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.95:45454 }, ] to fast fail map
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000007 to attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000008, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ] to fast fail map
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Releasing unassigned and invalid container Container: [ContainerId: container_1409663488190_0006_01_000008, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ]. RM may have assignment issues
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=4096
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:28,785 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:7 ContRel:1 HostLocal:1 RackLocal:1
2014-09-02 18:48:28,786 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_1: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:28,787 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:28,788 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:28,788 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000007 taskAttempt attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:28,789 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:28,798 INFO [ContainerLauncher #9] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000001_2 : 13562
2014-09-02 18:48:28,798 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000001_2] using containerId: [container_1409663488190_0006_01_000007 on NM: [centos3.local:45454]
2014-09-02 18:48:28,799 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:29,791 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 1 newContainers=1 finishedContainers=1 resourcelimit=<memory:0, vCores:-4> knownNMs=5
2014-09-02 18:48:29,791 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000008
2014-09-02 18:48:29,791 ERROR [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Container complete event for unknown container id container_1409663488190_0006_01_000008
2014-09-02 18:48:29,791 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 1
2014-09-02 18:48:29,791 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Cannot assign container Container: [ContainerId: container_1409663488190_0006_01_000009, NodeId: centos1.local:45454, NodeHttpAddress: centos1.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.93:45454 }, ] for a map as either  container memory less than required 4096 or no pending map tasks - maps.isEmpty=true
2014-09-02 18:48:29,792 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-02 18:48:29,792 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:29,792 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:8 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:30,718 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:30,760 INFO [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000006 asked for a task
2014-09-02 18:48:30,760 INFO [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000006 given task: attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:30,796 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=0 release= 1 newContainers=0 finishedContainers=1 resourcelimit=<memory:0, vCores:-4> knownNMs=5
2014-09-02 18:48:30,796 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000009
2014-09-02 18:48:30,796 ERROR [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Container complete event for unknown container id container_1409663488190_0006_01_000009
2014-09-02 18:48:30,796 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-02 18:48:30,796 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:31,515 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:31,557 INFO [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000007 asked for a task
2014-09-02 18:48:31,557 INFO [IPC Server handler 27 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000007 given task: attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:33,854 FATAL [IPC Server handler 24 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000000_2 - exited : Java heap space
2014-09-02 18:48:33,854 INFO [IPC Server handler 24 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_2: Error: Java heap space
2014-09-02 18:48:33,855 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_2: Error: Java heap space
2014-09-02 18:48:33,857 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:33,857 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000006 taskAttempt attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:33,857 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:33,859 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:33,859 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:33,861 WARN [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000000_2
2014-09-02 18:48:33,861 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_2 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:33,863 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:33,863 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:33,864 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:33,864 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 2 failures on node centos2.local
2014-09-02 18:48:33,864 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:33,865 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000000_3 to list of failed maps
2014-09-02 18:48:34,314 FATAL [IPC Server handler 29 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000001_2 - exited : Java heap space
2014-09-02 18:48:34,314 INFO [IPC Server handler 29 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_2: Error: Java heap space
2014-09-02 18:48:34,315 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_2: Error: Java heap space
2014-09-02 18:48:34,316 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:34,316 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000007 taskAttempt attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:34,316 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:34,318 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:34,318 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:34,320 WARN [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000001_2
2014-09-02 18:48:34,320 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_2 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:34,322 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:34,322 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos3.local to /default-rack
2014-09-02 18:48:34,322 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos4.local to /default-rack
2014-09-02 18:48:34,323 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 3 failures on node centos3.local
2014-09-02 18:48:34,323 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Blacklisted host centos3.local
2014-09-02 18:48:34,323 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from NEW to UNASSIGNED
2014-09-02 18:48:34,323 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Added attempt_1409663488190_0006_m_000001_3 to list of failed maps
2014-09-02 18:48:34,801 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:2 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:8 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:34,804 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:0, vCores:-4> knownNMs=5
2014-09-02 18:48:34,804 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: Update the blacklist for application_1409663488190_0006: blacklistAdditions=1 blacklistRemovals=0
2014-09-02 18:48:34,804 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=0
2014-09-02 18:48:34,804 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:35,808 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000006
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1409663488190_0006_01_000007
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000010, NodeId: centos2.local:45454, NodeHttpAddress: centos2.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.94:45454 }, ] to fast fail map
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000010 to attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigning container Container: [ContainerId: container_1409663488190_0006_01_000011, NodeId: centos5.local:45454, NodeHttpAddress: centos5.local:8042, Resource: <memory:4096, vCores:1>, Priority: 5, Token: Token { kind: ContainerToken, service: 10.157.16.97:45454 }, ] to fast fail map
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned from earlierFailedMaps
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1409663488190_0006_01_000011 to attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=4096
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
2014-09-02 18:48:35,809 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:10 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:35,810 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000000_2: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:35,810 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_2: Container killed by the ApplicationMaster.

Container killed on request. Exit code is 143
Container exited with a non-zero exit code 143

2014-09-02 18:48:35,810 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos2.local to /default-rack
2014-09-02 18:48:35,811 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:35,811 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved centos5.local to /default-rack
2014-09-02 18:48:35,812 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
2014-09-02 18:48:35,812 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000010 taskAttempt attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:35,812 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:35,813 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1409663488190_0006_01_000011 taskAttempt attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:35,813 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:35,813 INFO [ContainerLauncher #3] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : centos5.local:45454
2014-09-02 18:48:35,823 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000000_3 : 13562
2014-09-02 18:48:35,823 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000000_3] using containerId: [container_1409663488190_0006_01_000010 on NM: [centos2.local:45454]
2014-09-02 18:48:35,824 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:35,827 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1409663488190_0006_m_000001_3 : 13562
2014-09-02 18:48:35,828 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1409663488190_0006_m_000001_3] using containerId: [container_1409663488190_0006_01_000011 on NM: [centos5.local:45454]
2014-09-02 18:48:35,828 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from ASSIGNED to RUNNING
2014-09-02 18:48:36,811 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1409663488190_0006: ask=1 release= 0 newContainers=0 finishedContainers=0 resourcelimit=<memory:4096, vCores:-3> knownNMs=5
2014-09-02 18:48:38,771 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:38,815 INFO [IPC Server handler 24 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000011 asked for a task
2014-09-02 18:48:38,816 INFO [IPC Server handler 24 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000011 given task: attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:39,036 INFO [Socket Reader #1 for port 50740] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1409663488190_0006 (auth:SIMPLE)
2014-09-02 18:48:39,088 INFO [IPC Server handler 23 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1409663488190_0006_m_000010 asked for a task
2014-09-02 18:48:39,088 INFO [IPC Server handler 23 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1409663488190_0006_m_000010 given task: attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:41,705 FATAL [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Task: attempt_1409663488190_0006_m_000001_3 - exited : Java heap space
2014-09-02 18:48:41,705 INFO [IPC Server handler 25 on 50740] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_3: Error: Java heap space
2014-09-02 18:48:41,706 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1409663488190_0006_m_000001_3: Error: Java heap space
2014-09-02 18:48:41,707 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2014-09-02 18:48:41,707 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000011 taskAttempt attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:41,707 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:41,709 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2014-09-02 18:48:41,709 INFO [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:41,711 WARN [CommitterEvent Processor #2] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000001_3
2014-09-02 18:48:41,711 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000001_3 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2014-09-02 18:48:41,715 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000001 Task Transitioned from RUNNING to FAILED
2014-09-02 18:48:41,715 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node centos5.local
2014-09-02 18:48:41,719 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 1
2014-09-02 18:48:41,719 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Job failed as tasks failed. failedMaps:1 failedReduces:0
2014-09-02 18:48:41,720 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from RUNNING to FAIL_WAIT
2014-09-02 18:48:41,721 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000000 Task Transitioned from RUNNING to KILL_WAIT
2014-09-02 18:48:41,721 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_r_000000 Task Transitioned from SCHEDULED to KILL_WAIT
2014-09-02 18:48:41,721 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from RUNNING to KILL_CONTAINER_CLEANUP
2014-09-02 18:48:41,721 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_r_000000_0 TaskAttempt Transitioned from UNASSIGNED to KILLED
2014-09-02 18:48:41,721 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_r_000000 Task Transitioned from KILL_WAIT to KILLED
2014-09-02 18:48:41,722 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Processing the event EventType: CONTAINER_DEALLOCATE
2014-09-02 18:48:41,722 ERROR [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Could not deallocate container for task attemptId attempt_1409663488190_0006_r_000000_0
2014-09-02 18:48:41,722 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1409663488190_0006_01_000010 taskAttempt attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:41,724 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:41,727 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from KILL_CONTAINER_CLEANUP to KILL_TASK_CLEANUP
2014-09-02 18:48:41,728 INFO [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2014-09-02 18:48:41,729 WARN [CommitterEvent Processor #3] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Could not delete hdfs://centos2.local:8020/tmp/file3a647851cbc6/_temporary/1/_temporary/attempt_1409663488190_0006_m_000000_3
2014-09-02 18:48:41,729 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1409663488190_0006_m_000000_3 TaskAttempt Transitioned from KILL_TASK_CLEANUP to KILLED
2014-09-02 18:48:41,731 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1409663488190_0006_m_000000 Task Transitioned from KILL_WAIT to KILLED
2014-09-02 18:48:41,734 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from FAIL_WAIT to FAIL_ABORT
2014-09-02 18:48:41,735 INFO [CommitterEvent Processor #4] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_ABORT
2014-09-02 18:48:41,745 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1409663488190_0006Job Transitioned from FAIL_ABORT to FAILED
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2014-09-02 18:48:41,749 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
2014-09-02 18:48:41,750 INFO [Thread-65] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 0
2014-09-02 18:48:41,785 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0006/job_1409663488190_0006_1.jhist to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006-1409676487303-root-streamjob1865652695133523272.jar-1409676521719-0-0-FAILED-default-1409676489553.jhist_tmp
2014-09-02 18:48:41,817 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006-1409676487303-root-streamjob1865652695133523272.jar-1409676521719-0-0-FAILED-default-1409676489553.jhist_tmp
2014-09-02 18:48:41,818 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:10 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:41,820 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=4096
2014-09-02 18:48:41,820 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold reached. Scheduling reduces.
2014-09-02 18:48:41,820 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: All maps assigned. Ramping up all remaining reduces:1
2014-09-02 18:48:41,820 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:2 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:10 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:41,820 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://centos2.local:8020/user/root/.staging/job_1409663488190_0006/job_1409663488190_0006_1_conf.xml to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006_conf.xml_tmp
2014-09-02 18:48:41,845 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006_conf.xml_tmp
2014-09-02 18:48:41,856 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006.summary_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006.summary
2014-09-02 18:48:41,857 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006_conf.xml_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006_conf.xml
2014-09-02 18:48:41,862 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006-1409676487303-root-streamjob1865652695133523272.jar-1409676521719-0-0-FAILED-default-1409676489553.jhist_tmp to hdfs://centos2.local:8020/mr-history/tmp/root/job_1409663488190_0006-1409676487303-root-streamjob1865652695133523272.jar-1409676521719-0-0-FAILED-default-1409676489553.jhist
2014-09-02 18:48:41,863 INFO [Thread-65] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2014-09-02 18:48:41,865 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to Task failed task_1409663488190_0006_m_000001

Job failed as tasks failed. failedMaps:1 failedReduces:0

2014-09-02 18:48:41,866 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: History url is http://centos1.local:19888/jobhistory/job/job_1409663488190_0006
2014-09-02 18:48:41,874 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Waiting for application to be successfully unregistered.
2014-09-02 18:48:42,876 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:2 AssignedReds:0 CompletedMaps:1 CompletedReds:0 ContAlloc:10 ContRel:2 HostLocal:1 RackLocal:1
2014-09-02 18:48:42,877 INFO [Thread-65] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://centos2.local:8020 /user/root/.staging/job_1409663488190_0006
2014-09-02 18:48:42,882 INFO [Thread-65] org.apache.hadoop.ipc.Server: Stopping server on 50740
2014-09-02 18:48:42,884 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2014-09-02 18:48:42,886 INFO [IPC Server listener on 50740] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 50740
2014-09-02 18:48:42,884 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted

__________________________________
...

Antonio Piccolboni

unread,
Sep 4, 2014, 12:02:20 PM9/4/14
to RHadoop Google Group
For the record, this is not the logs, nor the type of logs that the debugging guide recommends to look for initially. In this case though I think you are onto something with this log. Until recently, I think the last version, we let Hadoop run at configuration defaults with rmr jobs. That doesn't work very well with YARN because containers are monitored for memory use and java is allocated most of the space and R is left with nothing. So we set up rmr2 to modify the configuration for each job as follows

$hadoop
$hadoop$D
[1] "mapreduce.map.java.opts=-Xmx400M"

$hadoop$D
[1] "mapreduce.reduce.java.opts=-Xmx400M"

$hadoop$D
[1] "mapreduce.map.memory.mb=4096"

$hadoop$D
[1] "mapreduce.reduce.memory.mb=4096"


The values  have been generated asking around and trying a few jobs. They may be in need of refinement or maybe it's impossible to set them in a way that covers most needs. In your specific case it appears that mapreduce.reduce.java.opts is set too low. I am not sure why 400M shouldn't be enough though, as you are running one of the standard examples. Anyway, let's push that higher and see if we get through the reduce phase, at least we will have learnt something. To do that, get the current confguration:

bp  = rmr.options("backend.parameters")

#change

bp$hadoop[2] = "mapreduce.reduce.java.opts=-Xmx800M"

#check
bp

#set

rmr.options(backend.parameters = bp)

#check

rmr.options("backend.parameters")

And rerun. If it goes through, you have a workaround and I have a clue to work from, at least. In alternative or combination, you could try to increase mapreduce.reduce.memory.mb following similar steps. Thanks


Antonio

--
Reply all
Reply to author
Forward
0 new messages