【原创 Hadoop&Spark 动手实践 4】Hadoop2.7.3 YARN原理与动手实践

hongleimi

logs
　　Usage: yarn logs -applicationId <application>COMMAND_OPTIONSDescription-applicationId <application>Dump the container logs
　　localhost:~ jonsonli$ yarn logs -applicationId application_1494511663670_0004
　　17/05/11 22:28:17 INFO client.RMProxy: Connecting to ResourceManager at /0.0.0.0:8032

　　17/05/11 22:28:17 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java>　　Container: container_1494511663670_0004_01_000004 on localhost_62244
　　======================================================================
　　LogType:stderr
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stderr
　　LogType:stdout
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stdout
　　LogType:syslog
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:3093
　　Log Contents:

　　2017-05-11 22:22:58,224 WARN [main] org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java>　　2017-05-11 22:22:58,303 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
　　2017-05-11 22:22:58,377 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
　　2017-05-11 22:22:58,377 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: ReduceTask metrics system started
　　2017-05-11 22:22:58,390 INFO [main] org.apache.hadoop.mapred.YarnChild: Executing with tokens:

　　2017-05-11 22:22:58,390 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: mapreduce.job, Service: job_1494511663670_0004,>　　2017-05-11 22:22:58,581 INFO [main] org.apache.hadoop.mapred.YarnChild: Sleeping for 0ms before retrying again. Got null now.
　　2017-05-11 22:22:58,895 INFO [main] org.apache.hadoop.mapred.YarnChild: mapreduce.cluster.local.dir for child: /Users/jonsonli/Bigdata/hadoopdata/nm-local-dir/usercache/jonsonli/appcache/application_1494511663670_0004
　　2017-05-11 22:22:59,280 INFO [main] org.apache.hadoop.conf.Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id
　　2017-05-11 22:22:59,905 INFO [main] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: File Output Committer Algorithm version is 1
　　2017-05-11 22:22:59,918 INFO [main] org.apache.hadoop.yarn.util.ProcfsBasedProcessTree: ProcfsBasedProcessTree currently is supported only on Linux.
　　2017-05-11 22:22:59,919 INFO [main] org.apache.hadoop.mapred.Task:  Using ResourceCalculatorProcessTree : null
　　2017-05-11 22:22:59,924 INFO [main] org.apache.hadoop.mapred.ReduceTask: Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1e7aa82b
　　2017-05-11 22:23:00,347 INFO [main] org.apache.hadoop.conf.Configuration.deprecation: mapred.skip.on is deprecated. Instead, use mapreduce.job.skiprecords
　　2017-05-11 22:23:00,556 INFO [main] org.apache.hadoop.mapred.Task: Task:attempt_1494511663670_0004_r_000000_0 is done. And is in the process of committing
　　2017-05-11 22:23:00,579 INFO [main] org.apache.hadoop.mapred.Task: Task attempt_1494511663670_0004_r_000000_0 is allowed to commit now
　　2017-05-11 22:23:00,591 INFO [main] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: Saved output of task 'attempt_1494511663670_0004_r_000000_0' to hdfs://localhost:9000/output/_temporary/1/task_1494511663670_0004_r_000000
　　2017-05-11 22:23:00,602 INFO [main] org.apache.hadoop.mapred.Task: Task 'attempt_1494511663670_0004_r_000000_0' done.
　　2017-05-11 22:23:00,608 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Stopping ReduceTask metrics system...
　　2017-05-11 22:23:00,608 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: ReduceTask metrics system stopped.
　　2017-05-11 22:23:00,609 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: ReduceTask metrics system shutdown complete.
　　End of LogType:syslog
　　LogType:syslog.shuffle
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:3835
　　Log Contents:
　　2017-05-11 22:22:59,947 INFO [main] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: MergerManager: memoryLimit=130652568, maxSingleShuffleLimit=32663142, mergeThreshold=86230696, ioSortFactor=10, memToMemMergeOutputsThreshold=10
　　2017-05-11 22:22:59,950 INFO [EventFetcher for fetching Map Completion Events] org.apache.hadoop.mapreduce.task.reduce.EventFetcher: attempt_1494511663670_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
　　2017-05-11 22:22:59,959 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.ShuffleSchedulerImpl: Assigning localhost:13562 with 1 to fetcher#1
　　2017-05-11 22:22:59,959 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.ShuffleSchedulerImpl: assigned 2 of 2 to localhost:13562 to fetcher#1
　　2017-05-11 22:22:59,959 INFO [EventFetcher for fetching Map Completion Events] org.apache.hadoop.mapreduce.task.reduce.EventFetcher: attempt_1494511663670_0004_r_000000_0: Got 2 new map-outputs
　　2017-05-11 22:23:00,105 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.Fetcher: for url=13562/mapOutput?job=job_1494511663670_0004&reduce=0&map=attempt_1494511663670_0004_m_000001_0,attempt_1494511663670_0004_m_000000_0 sent hash and received reply
　　2017-05-11 22:23:00,109 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.Fetcher: fetcher#1 about to shuffle output of map attempt_1494511663670_0004_m_000001_0 decomp: 12794 len: 12798 to MEMORY
　　2017-05-11 22:23:00,111 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.InMemoryMapOutput: Read 12794 bytes from map-output for attempt_1494511663670_0004_m_000001_0

　　2017-05-11 22:23:00,113 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: closeInMemoryFile -> map-output of>　　2017-05-11 22:23:00,114 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.Fetcher: fetcher#1 about to shuffle output of map attempt_1494511663670_0004_m_000000_0 decomp: 12794 len: 12798 to MEMORY
　　2017-05-11 22:23:00,115 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.InMemoryMapOutput: Read 12794 bytes from map-output for attempt_1494511663670_0004_m_000000_0

　　2017-05-11 22:23:00,115 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: closeInMemoryFile -> map-output of>　　2017-05-11 22:23:00,116 INFO [fetcher#1] org.apache.hadoop.mapreduce.task.reduce.ShuffleSchedulerImpl: localhost:13562 freed by fetcher#1 in 157ms
　　2017-05-11 22:23:00,116 INFO [EventFetcher for fetching Map Completion Events] org.apache.hadoop.mapreduce.task.reduce.EventFetcher: EventFetcher is interrupted.. Returning
　　2017-05-11 22:23:00,122 INFO [main] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: finalMerge called with 2 in-memory map-outputs and 0 on-disk map-outputs
　　2017-05-11 22:23:00,130 INFO [main] org.apache.hadoop.mapred.Merger: Merging 2 sorted segments

　　2017-05-11 22:23:00,130 INFO [main] org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 2 segments left of total>　　2017-05-11 22:23:00,160 INFO [main] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: Merged 2 segments, 25588 bytes to disk to satisfy reduce memory limit
　　2017-05-11 22:23:00,161 INFO [main] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: Merging 1 files, 25590 bytes from disk
　　2017-05-11 22:23:00,162 INFO [main] org.apache.hadoop.mapreduce.task.reduce.MergeManagerImpl: Merging 0 segments, 0 bytes from memory into reduce
　　2017-05-11 22:23:00,162 INFO [main] org.apache.hadoop.mapred.Merger: Merging 1 sorted segments

　　2017-05-11 22:23:00,184 INFO [main] org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 1 segments left of total>　　End of LogType:syslog.shuffle
　　Container: container_1494511663670_0004_01_000003 on localhost_62244
　　======================================================================
　　LogType:stderr
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stderr
　　LogType:stdout
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stdout
　　LogType:syslog
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:3736
　　Log Contents:

　　2017-05-11 22:22:51,021 WARN [main] org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java>　　2017-05-11 22:22:51,213 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
　　2017-05-11 22:22:51,439 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
　　2017-05-11 22:22:51,439 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system started
　　2017-05-11 22:22:51,455 INFO [main] org.apache.hadoop.mapred.YarnChild: Executing with tokens:

　　2017-05-11 22:22:51,455 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: mapreduce.job, Service: job_1494511663670_0004,>　　2017-05-11 22:22:51,901 INFO [main] org.apache.hadoop.mapred.YarnChild: Sleeping for 0ms before retrying again. Got null now.
　　2017-05-11 22:22:52,515 INFO [main] org.apache.hadoop.mapred.YarnChild: mapreduce.cluster.local.dir for child: /Users/jonsonli/Bigdata/hadoopdata/nm-local-dir/usercache/jonsonli/appcache/application_1494511663670_0004
　　2017-05-11 22:22:52,935 INFO [main] org.apache.hadoop.conf.Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id
　　2017-05-11 22:22:53,495 INFO [main] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: File Output Committer Algorithm version is 1
　　2017-05-11 22:22:53,505 INFO [main] org.apache.hadoop.yarn.util.ProcfsBasedProcessTree: ProcfsBasedProcessTree currently is supported only on Linux.
　　2017-05-11 22:22:53,506 INFO [main] org.apache.hadoop.mapred.Task:  Using ResourceCalculatorProcessTree : null
　　2017-05-11 22:22:53,791 INFO [main] org.apache.hadoop.mapred.MapTask: Processing split: hdfs://localhost:9000/input/file02:0+19002
　　2017-05-11 22:22:53,945 INFO [main] org.apache.hadoop.mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)
　　2017-05-11 22:22:53,945 INFO [main] org.apache.hadoop.mapred.MapTask: mapreduce.task.io.sort.mb: 100
　　2017-05-11 22:22:53,945 INFO [main] org.apache.hadoop.mapred.MapTask: soft limit at 83886080
　　2017-05-11 22:22:53,945 INFO [main] org.apache.hadoop.mapred.MapTask: bufstart = 0; bufvoid = 104857600
　　2017-05-11 22:22:53,945 INFO [main] org.apache.hadoop.mapred.MapTask: kvstart = 26214396; length = 6553600

　　2017-05-11 22:22:53,952 INFO [main] org.apache.hadoop.mapred.MapTask: Map output collector>　　2017-05-11 22:22:54,060 INFO [main] org.apache.hadoop.mapred.MapTask: Starting flush of map output
　　2017-05-11 22:22:54,060 INFO [main] org.apache.hadoop.mapred.MapTask: Spilling map output
　　2017-05-11 22:22:54,060 INFO [main] org.apache.hadoop.mapred.MapTask: bufstart = 0; bufend = 30225; bufvoid = 104857600
　　2017-05-11 22:22:54,060 INFO [main] org.apache.hadoop.mapred.MapTask: kvstart = 26214396(104857584); kvend = 26202940(104811760); length = 11457/6553600
　　2017-05-11 22:22:54,213 INFO [main] org.apache.hadoop.mapred.MapTask: Finished spill 0
　　2017-05-11 22:22:54,272 INFO [main] org.apache.hadoop.mapred.Task: Task:attempt_1494511663670_0004_m_000001_0 is done. And is in the process of committing
　　2017-05-11 22:22:54,331 INFO [main] org.apache.hadoop.mapred.Task: Task 'attempt_1494511663670_0004_m_000001_0' done.
　　2017-05-11 22:22:54,398 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Stopping MapTask metrics system...
　　2017-05-11 22:22:54,411 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system stopped.
　　2017-05-11 22:22:54,412 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system shutdown complete.
　　End of LogType:syslog
　　Container: container_1494511663670_0004_01_000002 on localhost_62244
　　======================================================================
　　LogType:stderr
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stderr
　　LogType:stdout
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stdout
　　LogType:syslog
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:3736
　　Log Contents:

　　2017-05-11 22:22:51,085 WARN [main] org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java>　　2017-05-11 22:22:51,268 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
　　2017-05-11 22:22:51,449 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
　　2017-05-11 22:22:51,449 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system started
　　2017-05-11 22:22:51,466 INFO [main] org.apache.hadoop.mapred.YarnChild: Executing with tokens:

　　2017-05-11 22:22:51,467 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: mapreduce.job, Service: job_1494511663670_0004,>　　2017-05-11 22:22:51,938 INFO [main] org.apache.hadoop.mapred.YarnChild: Sleeping for 0ms before retrying again. Got null now.
　　2017-05-11 22:22:52,527 INFO [main] org.apache.hadoop.mapred.YarnChild: mapreduce.cluster.local.dir for child: /Users/jonsonli/Bigdata/hadoopdata/nm-local-dir/usercache/jonsonli/appcache/application_1494511663670_0004
　　2017-05-11 22:22:52,921 INFO [main] org.apache.hadoop.conf.Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id
　　2017-05-11 22:22:53,515 INFO [main] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: File Output Committer Algorithm version is 1
　　2017-05-11 22:22:53,526 INFO [main] org.apache.hadoop.yarn.util.ProcfsBasedProcessTree: ProcfsBasedProcessTree currently is supported only on Linux.
　　2017-05-11 22:22:53,527 INFO [main] org.apache.hadoop.mapred.Task:  Using ResourceCalculatorProcessTree : null
　　2017-05-11 22:22:53,840 INFO [main] org.apache.hadoop.mapred.MapTask: Processing split: hdfs://localhost:9000/input/file01:0+19002
　　2017-05-11 22:22:54,105 INFO [main] org.apache.hadoop.mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)
　　2017-05-11 22:22:54,105 INFO [main] org.apache.hadoop.mapred.MapTask: mapreduce.task.io.sort.mb: 100
　　2017-05-11 22:22:54,105 INFO [main] org.apache.hadoop.mapred.MapTask: soft limit at 83886080
　　2017-05-11 22:22:54,105 INFO [main] org.apache.hadoop.mapred.MapTask: bufstart = 0; bufvoid = 104857600
　　2017-05-11 22:22:54,106 INFO [main] org.apache.hadoop.mapred.MapTask: kvstart = 26214396; length = 6553600

　　2017-05-11 22:22:54,112 INFO [main] org.apache.hadoop.mapred.MapTask: Map output collector>　　2017-05-11 22:22:54,202 INFO [main] org.apache.hadoop.mapred.MapTask: Starting flush of map output
　　2017-05-11 22:22:54,202 INFO [main] org.apache.hadoop.mapred.MapTask: Spilling map output
　　2017-05-11 22:22:54,202 INFO [main] org.apache.hadoop.mapred.MapTask: bufstart = 0; bufend = 30225; bufvoid = 104857600
　　2017-05-11 22:22:54,202 INFO [main] org.apache.hadoop.mapred.MapTask: kvstart = 26214396(104857584); kvend = 26202940(104811760); length = 11457/6553600
　　2017-05-11 22:22:54,432 INFO [main] org.apache.hadoop.mapred.MapTask: Finished spill 0
　　2017-05-11 22:22:54,451 INFO [main] org.apache.hadoop.mapred.Task: Task:attempt_1494511663670_0004_m_000000_0 is done. And is in the process of committing
　　2017-05-11 22:22:54,480 INFO [main] org.apache.hadoop.mapred.Task: Task 'attempt_1494511663670_0004_m_000000_0' done.
　　2017-05-11 22:22:54,484 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Stopping MapTask metrics system...
　　2017-05-11 22:22:54,485 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system stopped.
　　2017-05-11 22:22:54,485 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system shutdown complete.
　　End of LogType:syslog
　　Container: container_1494511663670_0004_01_000001 on localhost_62244
　　======================================================================
　　LogType:stderr
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:1773
　　Log Contents:
　　五月 11, 2017 10:22:45 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register

　　信息: Registering org.apache.hadoop.mapreduce.v2.app.webapp.JAXBContextResolver as a provider>　　五月 11, 2017 10:22:45 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register

　　信息: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider>　　五月 11, 2017 10:22:45 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register

　　信息: Registering org.apache.hadoop.mapreduce.v2.app.webapp.AMWebServices as a root resource>　　五月 11, 2017 10:22:45 下午 com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
　　信息: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
　　五月 11, 2017 10:22:45 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
　　信息: Binding org.apache.hadoop.mapreduce.v2.app.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
　　五月 11, 2017 10:22:46 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
　　信息: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
　　五月 11, 2017 10:22:46 下午 com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
　　信息: Binding org.apache.hadoop.mapreduce.v2.app.webapp.AMWebServices to GuiceManagedComponentProvider with the scope "PerRequest"
　　log4j:WARN No appenders could be found for logger (org.apache.hadoop.ipc.Server).
　　log4j:WARN Please initialize the log4j system properly.
　　log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
　　End of LogType:stderr
　　LogType:stdout
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:0
　　Log Contents:
　　End of LogType:stdout
　　LogType:syslog
　　Log Upload Time:星期四 五月 11 22:23:08 +0800 2017
　　LogLength:40682
　　Log Contents:
　　2017-05-11 22:22:42,505 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Created MRAppMaster for application appattempt_1494511663670_0004_000001

　　2017-05-11 22:22:42,719 WARN [main] org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java>　　2017-05-11 22:22:42,755 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Executing with tokens:

　　2017-05-11 22:22:42,755 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Kind: YARN_AM_RM_TOKEN, Service: ,>　　2017-05-11 22:22:42,963 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Using mapred newApiCommitter.
　　2017-05-11 22:22:42,965 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter set in config null
　　2017-05-11 22:22:43,018 INFO [main] org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter: File Output Committer Algorithm version is 1
　　2017-05-11 22:22:43,493 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: OutputCommitter is org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter

　　2017-05-11 22:22:43,631 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,632 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,633 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,634 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,634 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,639 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,640 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>
　　2017-05-11 22:22:43,640 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>　　2017-05-11 22:22:43,675 INFO [main] org.apache.hadoop.mapreduce.v2.jobhistory.JobHistoryUtils: Default file system [hdfs://localhost:9000]
　　2017-05-11 22:22:43,701 INFO [main] org.apache.hadoop.mapreduce.v2.jobhistory.JobHistoryUtils: Default file system [hdfs://localhost:9000]
　　2017-05-11 22:22:43,727 INFO [main] org.apache.hadoop.mapreduce.v2.jobhistory.JobHistoryUtils: Default file system [hdfs://localhost:9000]
　　2017-05-11 22:22:43,736 INFO [main] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Emitting job history data to the timeline server is not enabled

　　2017-05-11 22:22:43,775 INFO [main] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering>　　2017-05-11 22:22:43,849 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
　　2017-05-11 22:22:43,904 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
　　2017-05-11 22:22:43,904 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
　　2017-05-11 22:22:43,913 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Adding job token for job_1494511663670_0004 to jobTokenSecretManager
　　2017-05-11 22:22:44,016 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Not uberizing job_1494511663670_0004 because: not enabled;

　　2017-05-11 22:22:44,029 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Input>　　2017-05-11 22:22:44,030 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Number of reduces for job job_1494511663670_0004 = 1
　　2017-05-11 22:22:44,030 INFO [main] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1494511663670_0004Job Transitioned from NEW to INITED
　　2017-05-11 22:22:44,032 INFO [main] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster launching normal, non-uberized, multi-container job job_1494511663670_0004.

　　2017-05-11 22:22:44,057 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue>　　2017-05-11 22:22:44,069 INFO [Socket Reader #1 for port 62654] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 62654
　　2017-05-11 22:22:44,090 INFO [main] org.apache.hadoop.yarn.factories.impl.pb.RpcServerFactoryPBImpl: Adding protocol org.apache.hadoop.mapreduce.v2.api.MRClientProtocolPB to the server
　　2017-05-11 22:22:44,090 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
　　2017-05-11 22:22:44,090 INFO [IPC Server listener on 62654] org.apache.hadoop.ipc.Server: IPC Server listener on 62654: starting
　　2017-05-11 22:22:44,092 INFO [main] org.apache.hadoop.mapreduce.v2.app.client.MRClientService: Instantiated MRClientService at localhost/127.0.0.1:62654
　　2017-05-11 22:22:44,217 INFO [main] org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
　　2017-05-11 22:22:44,228 INFO [main] org.apache.hadoop.security.authentication.server.AuthenticationFilter: Unable to initialize FileSignerSecretProvider, falling back to use random secrets.
　　2017-05-11 22:22:44,236 INFO [main] org.apache.hadoop.http.HttpRequestLog: Http request log for http.requests.mapreduce is not defined
　　2017-05-11 22:22:44,244 INFO [main] org.apache.hadoop.http.HttpServer2: Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
　　2017-05-11 22:22:44,251 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context mapreduce
　　2017-05-11 22:22:44,251 INFO [main] org.apache.hadoop.http.HttpServer2: Added filter AM_PROXY_FILTER (class=org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter) to context static
　　2017-05-11 22:22:44,254 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /mapreduce/*
　　2017-05-11 22:22:44,254 INFO [main] org.apache.hadoop.http.HttpServer2: adding path spec: /ws/*
　　2017-05-11 22:22:44,845 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Registered webapp guice modules
　　2017-05-11 22:22:44,848 INFO [main] org.apache.hadoop.http.HttpServer2: Jetty bound to port 62655
　　2017-05-11 22:22:44,848 INFO [main] org.mortbay.log: jetty-6.1.26
　　2017-05-11 22:22:44,891 INFO [main] org.mortbay.log: Extract jar:file:/Users/jonsonli/Bigdata/hadoop-2.7.3/share/hadoop/yarn/hadoop-yarn-common-2.7.3.jar!/webapps/mapreduce to /Users/jonsonli/Bigdata/hadoopdata/nm-local-dir/usercache/jonsonli/appcache/application_1494511663670_0004/container_1494511663670_0004_01_000001/tmp/Jetty_0_0_0_0_62655_mapreduce____kehpzz/webapp
　　2017-05-11 22:22:46,570 INFO [main] org.mortbay.log: Started HttpServer2$SelectChannelConnectorWithSafeStartup@0.0.0.0:62655
　　2017-05-11 22:22:46,570 INFO [main] org.apache.hadoop.yarn.webapp.WebApps: Web app mapreduce started at 62655
　　2017-05-11 22:22:46,574 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.speculate.DefaultSpeculator: JOB_CREATE job_1494511663670_0004

　　2017-05-11 22:22:46,575 INFO [main] org.apache.hadoop.ipc.CallQueueManager: Using callQueue>　　2017-05-11 22:22:46,576 INFO [Socket Reader #1 for port 62657] org.apache.hadoop.ipc.Server: Starting Socket Reader #1 for port 62657
　　2017-05-11 22:22:46,579 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: IPC Server Responder: starting
　　2017-05-11 22:22:46,579 INFO [IPC Server listener on 62657] org.apache.hadoop.ipc.Server: IPC Server listener on 62657: starting
　　2017-05-11 22:22:46,602 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
　　2017-05-11 22:22:46,603 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
　　2017-05-11 22:22:46,603 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
　　2017-05-11 22:22:46,656 INFO [main] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at /0.0.0.0:8030
　　2017-05-11 22:22:46,735 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: maxContainerCapability: <memory:8192, vCores:32>
　　2017-05-11 22:22:46,735 INFO [main] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: queue: default

　　2017-05-11 22:22:46,740 INFO [main] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Upper limit on the thread pool>
　　2017-05-11 22:22:46,740 INFO [main] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: The thread pool initial>　　2017-05-11 22:22:46,742 INFO [main] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: yarn.client.max-cached-nodemanagers-proxies : 0
　　2017-05-11 22:22:46,749 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1494511663670_0004Job Transitioned from INITED to SETUP
　　2017-05-11 22:22:46,751 INFO [CommitterEvent Processor #0] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_SETUP
　　2017-05-11 22:22:46,759 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1494511663670_0004Job Transitioned from SETUP to RUNNING
　　2017-05-11 22:22:46,777 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved localhost to /default-rack
　　2017-05-11 22:22:46,780 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000000 Task Transitioned from NEW to SCHEDULED
　　2017-05-11 22:22:46,781 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved localhost to /default-rack
　　2017-05-11 22:22:46,781 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000001 Task Transitioned from NEW to SCHEDULED
　　2017-05-11 22:22:46,781 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_r_000000 Task Transitioned from NEW to SCHEDULED
　　2017-05-11 22:22:46,783 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
　　2017-05-11 22:22:46,783 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000001_0 TaskAttempt Transitioned from NEW to UNASSIGNED
　　2017-05-11 22:22:46,783 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from NEW to UNASSIGNED
　　2017-05-11 22:22:46,785 INFO [Thread-50] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: mapResourceRequest:<memory:1024, vCores:1>
　　2017-05-11 22:22:46,793 INFO [Thread-50] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: reduceResourceRequest:<memory:1024, vCores:1>
　　2017-05-11 22:22:46,829 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1494511663670_0004, File: hdfs://localhost:9000/tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004/job_1494511663670_0004_1.jhist
　　2017-05-11 22:22:47,738 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

　　2017-05-11 22:22:47,782 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1494511663670_0004: ask=3>　　2017-05-11 22:22:47,783 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=<memory:6144, vCores:1>
　　2017-05-11 22:22:47,783 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
　　2017-05-11 22:22:48,799 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 2
　　2017-05-11 22:22:48,801 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1494511663670_0004_01_000002 to attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:48,802 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1494511663670_0004_01_000003 to attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:48,803 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=<memory:4096, vCores:1>
　　2017-05-11 22:22:48,803 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold not met. completedMapsForReduceSlowstart 1
　　2017-05-11 22:22:48,803 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
　　2017-05-11 22:22:48,857 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved localhost to /default-rack
　　2017-05-11 22:22:48,877 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-jar file on the remote FS is hdfs://localhost:9000/tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004/job.jar
　　2017-05-11 22:22:48,881 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: The job-conf file on the remote FS is /tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004/job.xml
　　2017-05-11 22:22:48,882 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

　　2017-05-11 22:22:48,882 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl:>　　2017-05-11 22:22:48,883 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Putting shuffle token in serviceData
　　2017-05-11 22:22:48,914 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000000_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
　　2017-05-11 22:22:48,919 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved localhost to /default-rack
　　2017-05-11 22:22:48,919 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000001_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
　　2017-05-11 22:22:48,921 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1494511663670_0004_01_000003 taskAttempt attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:48,921 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1494511663670_0004_01_000002 taskAttempt attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:48,925 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:48,925 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:48,926 INFO [ContainerLauncher #1] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:22:48,953 INFO [ContainerLauncher #0] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:22:49,006 INFO [ContainerLauncher #1] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1494511663670_0004_m_000001_0 : 13562
　　2017-05-11 22:22:49,007 INFO [ContainerLauncher #0] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1494511663670_0004_m_000000_0 : 13562
　　2017-05-11 22:22:49,009 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1494511663670_0004_m_000001_0] using containerId: [container_1494511663670_0004_01_000003 on NM: [localhost:62244]
　　2017-05-11 22:22:49,013 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000001_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
　　2017-05-11 22:22:49,013 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1494511663670_0004_m_000000_0] using containerId: [container_1494511663670_0004_01_000002 on NM: [localhost:62244]
　　2017-05-11 22:22:49,014 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000000_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
　　2017-05-11 22:22:49,014 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.speculate.DefaultSpeculator: ATTEMPT_START task_1494511663670_0004_m_000001
　　2017-05-11 22:22:49,014 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000001 Task Transitioned from SCHEDULED to RUNNING
　　2017-05-11 22:22:49,014 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.speculate.DefaultSpeculator: ATTEMPT_START task_1494511663670_0004_m_000000
　　2017-05-11 22:22:49,014 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000000 Task Transitioned from SCHEDULED to RUNNING

　　2017-05-11 22:22:49,807 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1494511663670_0004: ask=3>　　2017-05-11 22:22:52,307 INFO [Socket Reader #1 for port 62657] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1494511663670_0004 (auth:SIMPLE)

　　2017-05-11 22:22:52,364 INFO [IPC Server handler 6 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>
　　2017-05-11 22:22:52,364 INFO [IPC Server handler 6 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>　　2017-05-11 22:22:52,372 INFO [Socket Reader #1 for port 62657] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1494511663670_0004 (auth:SIMPLE)

　　2017-05-11 22:22:52,387 INFO [IPC Server handler 1 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>
　　2017-05-11 22:22:52,387 INFO [IPC Server handler 1 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>　　2017-05-11 22:22:54,053 INFO [IPC Server handler 6 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_m_000001_0 is : 0.0
　　2017-05-11 22:22:54,200 INFO [IPC Server handler 1 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_m_000000_0 is : 0.0
　　2017-05-11 22:22:54,318 INFO [IPC Server handler 3 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_m_000001_0 is : 1.0
　　2017-05-11 22:22:54,329 INFO [IPC Server handler 2 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:54,331 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000001_0 TaskAttempt Transitioned from RUNNING to SUCCESS_CONTAINER_CLEANUP
　　2017-05-11 22:22:54,331 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1494511663670_0004_01_000003 taskAttempt attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:54,332 INFO [ContainerLauncher #2] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:54,332 INFO [ContainerLauncher #2] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:22:54,351 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000001_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
　　2017-05-11 22:22:54,360 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1494511663670_0004_m_000001_0
　　2017-05-11 22:22:54,361 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000001 Task Transitioned from RUNNING to SUCCEEDED
　　2017-05-11 22:22:54,365 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 1
　　2017-05-11 22:22:54,475 INFO [IPC Server handler 4 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_m_000000_0 is : 1.0
　　2017-05-11 22:22:54,478 INFO [IPC Server handler 5 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:54,480 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000000_0 TaskAttempt Transitioned from RUNNING to SUCCESS_CONTAINER_CLEANUP
　　2017-05-11 22:22:54,481 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1494511663670_0004_01_000002 taskAttempt attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:54,481 INFO [ContainerLauncher #3] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:54,481 INFO [ContainerLauncher #3] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:22:54,491 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_m_000000_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
　　2017-05-11 22:22:54,492 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1494511663670_0004_m_000000_0
　　2017-05-11 22:22:54,492 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_m_000000 Task Transitioned from RUNNING to SUCCEEDED
　　2017-05-11 22:22:54,492 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 2
　　2017-05-11 22:22:54,831 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:1 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:2 AssignedReds:0 CompletedMaps:2 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:2 RackLocal:0
　　2017-05-11 22:22:54,838 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1494511663670_0004_01_000003
　　2017-05-11 22:22:54,840 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1494511663670_0004_01_000002
　　2017-05-11 22:22:54,840 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1494511663670_0004_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
　　2017-05-11 22:22:54,840 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Recalculating schedule, headroom=<memory:6144, vCores:1>
　　2017-05-11 22:22:54,840 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Reduce slow start threshold reached. Scheduling reduces.
　　2017-05-11 22:22:54,840 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: All maps assigned. Ramping up all remaining reduces:1
　　2017-05-11 22:22:54,840 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1494511663670_0004_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
　　2017-05-11 22:22:54,840 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:1 AssignedMaps:0 AssignedReds:0 CompletedMaps:2 CompletedReds:0 ContAlloc:2 ContRel:0 HostLocal:2 RackLocal:0

　　2017-05-11 22:22:55,843 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1494511663670_0004: ask=1>　　2017-05-11 22:22:56,851 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Got allocated containers 1
　　2017-05-11 22:22:56,851 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned to reduce
　　2017-05-11 22:22:56,851 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Assigned container container_1494511663670_0004_01_000004 to attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:22:56,851 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:0 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
　　2017-05-11 22:22:56,858 INFO [AsyncDispatcher event handler] org.apache.hadoop.yarn.util.RackResolver: Resolved localhost to /default-rack
　　2017-05-11 22:22:56,859 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from UNASSIGNED to ASSIGNED
　　2017-05-11 22:22:56,859 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_LAUNCH for container container_1494511663670_0004_01_000004 taskAttempt attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:22:56,860 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Launching attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:22:56,860 INFO [ContainerLauncher #4] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:22:56,877 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Shuffle port returned by ContainerManager for attempt_1494511663670_0004_r_000000_0 : 13562
　　2017-05-11 22:22:56,878 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: TaskAttempt: [attempt_1494511663670_0004_r_000000_0] using containerId: [container_1494511663670_0004_01_000004 on NM: [localhost:62244]
　　2017-05-11 22:22:56,878 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from ASSIGNED to RUNNING
　　2017-05-11 22:22:56,878 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.speculate.DefaultSpeculator: ATTEMPT_START task_1494511663670_0004_r_000000
　　2017-05-11 22:22:56,879 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_r_000000 Task Transitioned from SCHEDULED to RUNNING

　　2017-05-11 22:22:57,854 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: getResources() for application_1494511663670_0004: ask=1>　　2017-05-11 22:22:58,772 INFO [Socket Reader #1 for port 62657] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1494511663670_0004 (auth:SIMPLE)

　　2017-05-11 22:22:58,784 INFO [IPC Server handler 6 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>
　　2017-05-11 22:22:58,784 INFO [IPC Server handler 6 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with>　　2017-05-11 22:22:59,952 INFO [IPC Server handler 1 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1494511663670_0004_r_000000_0. startIndex 0 maxEvents 10000
　　2017-05-11 22:23:00,119 INFO [IPC Server handler 3 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_r_000000_0 is : 0.0
　　2017-05-11 22:23:00,186 INFO [IPC Server handler 2 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_r_000000_0 is : 0.0
　　2017-05-11 22:23:00,575 INFO [IPC Server handler 8 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit-pending state update from attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,576 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from RUNNING to COMMIT_PENDING
　　2017-05-11 22:23:00,576 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: attempt_1494511663670_0004_r_000000_0 given a go for committing the task output.
　　2017-05-11 22:23:00,578 INFO [IPC Server handler 10 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit go/no-go request from attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,578 INFO [IPC Server handler 10 on 62657] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Result of canCommit for attempt_1494511663670_0004_r_000000_0:true
　　2017-05-11 22:23:00,595 INFO [IPC Server handler 7 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1494511663670_0004_r_000000_0 is : 1.0
　　2017-05-11 22:23:00,599 INFO [IPC Server handler 0 on 62657] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,601 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_CONTAINER_CLEANUP
　　2017-05-11 22:23:00,627 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1494511663670_0004_01_000004 taskAttempt attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,627 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,627 INFO [ContainerLauncher #5] org.apache.hadoop.yarn.client.api.impl.ContainerManagementProtocolProxy: Opening proxy : localhost:62244
　　2017-05-11 22:23:00,640 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1494511663670_0004_r_000000_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
　　2017-05-11 22:23:00,640 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1494511663670_0004_r_000000_0
　　2017-05-11 22:23:00,641 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1494511663670_0004_r_000000 Task Transitioned from RUNNING to SUCCEEDED
　　2017-05-11 22:23:00,641 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 3
　　2017-05-11 22:23:00,641 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1494511663670_0004Job Transitioned from RUNNING to COMMITTING
　　2017-05-11 22:23:00,642 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_COMMIT
　　2017-05-11 22:23:00,700 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Calling handler for JobFinishedEvent
　　2017-05-11 22:23:00,701 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1494511663670_0004Job Transitioned from COMMITTING to SUCCEEDED
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: RMCommunicator notified that shouldUnregistered is: true
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
　　2017-05-11 22:23:00,702 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services

　　2017-05-11 22:23:00,703 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler.>　　2017-05-11 22:23:00,744 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://localhost:9000/tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004/job_1494511663670_0004_1.jhist to hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004-1494512560043-jonsonli-word+count-1494512580690-2-1-SUCCEEDED-default-1494512566744.jhist_tmp
　　2017-05-11 22:23:00,770 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004-1494512560043-jonsonli-word+count-1494512580690-2-1-SUCCEEDED-default-1494512566744.jhist_tmp
　　2017-05-11 22:23:00,773 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://localhost:9000/tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004/job_1494511663670_0004_1_conf.xml to hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004_conf.xml_tmp
　　2017-05-11 22:23:00,798 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004_conf.xml_tmp
　　2017-05-11 22:23:00,802 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004.summary_tmp to hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004.summary
　　2017-05-11 22:23:00,805 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004_conf.xml_tmp to hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004_conf.xml
　　2017-05-11 22:23:00,809 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004-1494512560043-jonsonli-word+count-1494512580690-2-1-SUCCEEDED-default-1494512566744.jhist_tmp to hdfs://localhost:9000/tmp/hadoop-yarn/staging/history/done_intermediate/jonsonli/job_1494511663670_0004-1494512560043-jonsonli-word+count-1494512580690-2-1-SUCCEEDED-default-1494512566744.jhist
　　2017-05-11 22:23:00,810 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
　　2017-05-11 22:23:00,812 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: Setting job diagnostics to
　　2017-05-11 22:23:00,812 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: History url is http://localhost:19888/jobhistory/job/job_1494511663670_0004
　　2017-05-11 22:23:00,818 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator: Waiting for application to be successfully unregistered.
　　2017-05-11 22:23:01,821 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:0 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
　　2017-05-11 22:23:01,822 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://localhost:9000 /tmp/hadoop-yarn/staging/jonsonli/.staging/job_1494511663670_0004
　　2017-05-11 22:23:01,825 INFO [Thread-69] org.apache.hadoop.ipc.Server: Stopping server on 62657
　　2017-05-11 22:23:01,828 INFO [IPC Server listener on 62657] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 62657
　　2017-05-11 22:23:01,828 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted
　　2017-05-11 22:23:01,828 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
　　End of LogType:syslog