Hadoop学习笔记(二)设置单节点集群

来源:互联网 发布:java math 生成随机数 编辑:程序博客网 时间:2024/06/07 12:06

描述如何设置一个单一节点的 Hadoop 安装以便可以快速执行简单操作使用 Hadoop MapReduce  Hadoop 分布式文件系统 (HDFS)。

参考官方文档:Hadoop MapReduce Next Generation - Setting up a Single Node Cluster.

Hadoop版本:Apache Hadoop 2.5.1

系统版本:CentOS 6.5,内核(uname -r):2.6.32-431.el6.x86_64

系统必备组件

支持的系统平台

GNU/Linux 作为开发生产平台,毫无疑问。Windows 受支持平台但是以下步骤用于 Linux。

依赖的软件

在Linux系统上安装所需要的软件包

1、JAVA(JDK)必须安装,推荐的版本请参考Hadoop JAVA Version,我这里安装的是1.7。

2、ssh 必须安装必须运行 sshd 才能使用管理远程 Hadoop 守护程序 Hadoop 脚本

安装依赖的软件

如果系统没有软件需要安装

例如在Ubuntu Linux上使用以下命令:

  $ sudo apt-get install ssh  $ sudo apt-get install rsync

CentOS应该是即使是最小安装也带了ssh(Secure Shell),刚开始我给弄混了,以为是JAVA的SSH(Spring + Struts +Hibernate),汗!尴尬

安装JDK,参考:CentOS下安装JDK7

下载

就不多说了,上一篇下过了。链接:Hadoop学习笔记(一)从官网下载安装包

准备启动 Hadoop 集群

解压文件hadoop-2.5.1.tar.gz,执行:tar xvf hadoop-2.5.1.tar.gz,会将文件解压到hadoop-2.5.1目录下;

切换目录:cd hadoop-2.5.1/etc/hadoop/

编辑“hadoop-env.sh”文件,添加参考定义;

vi hadoop-env.sh

个人觉得比较好的习惯是编辑文件之前先做个备份(cp hadoop-env.sh hadoop-env.sh.bak);

找到以下位置:

[plain] view plain copy
  1. # The java implementation to use.  
  2. export JAVA_HOME={JAVA_HOME}  
将其改为:

[plain] view plain copy
  1. # The java implementation to use.  
  2. export JAVA_HOME=/usr/java/latest  
在下面再添加一句:

[plain] view plain copy
  1. # Assuming your installation directory is /usr/local/hadoop  
  2. export HADOOP_PREFIX=/usr/local/hadoop  
保存并退出,ESC,:wq

切换目录(cd ../..),返回“/opt/hadoop-2.5.1”;

尝试执行以下命令:

 ./bin/hadoop

这将显示 hadoop 脚本的使用文档,输出如下:

[plain] view plain copy
  1. Usage: hadoop [--config confdir] COMMAND  
  2.        where COMMAND is one of:  
  3.   fs                   run a generic filesystem user client  
  4.   version              print the version  
  5.   jar <jar>            run a jar file  
  6.   checknative [-a|-h]  check native hadoop and compression libraries availability  
  7.   distcp <srcurl> <desturl> copy file or directories recursively  
  8.   archive -archiveName NAME -p <parent path> <src>* <dest> create a hadoop archive  
  9.   classpath            prints the class path needed to get the  
  10.                        Hadoop jar and the required libraries  
  11.   daemonlog            get/set the log level for each daemon  
  12.  or  
  13.   CLASSNAME            run the class named CLASSNAME  
  14.   
  15. Most commands print help when invoked w/o parameters.  
你现在准备好开始您的 Hadoop 集群三个受支持的模式之一:
  • 本地 (独立) 模式
  • 伪分布的模式
  • 完全分布式模式

本地模式操作方法

默认情况下,Hadoop 被配置为运行在非分布式模式下,作为一个单一的 Java 进程。这比较适合用于调试。
下面的示例复制要使用作为输入的解压缩的 conf 目录,然后查找并显示给定正则表达式的每一场比赛。输出被写入给定的输出目录。

[plain] view plain copy
  1. $ mkdir input  
  2. $ cp etc/hadoop/*.xml input  
  3. $ bin/hadoop jar share/hadoop/mapreduce/hadoop-mapreduce-examples-2.5.1.jar grep input output 'dfs[a-z.]+'  
  4. $ cat output/*  

执行“bin/hadoop jar share/hadoop/mapreduce/hadoop-mapreduce-examples-2.5.1.jar grep input output 'dfs[a-z.]+'”时

却出现错误:Error: Could not find or load main class org.apache.hadoop.util.RunJar

此问题只在Stack Overflow上见到

What does “Error: Could not find or load main class org.apache.hadoop.util.RunJar”?

但是也没能找到解决的办法;还是自己摸索吧!

解决步骤:

刚刚备份的hadoop-env.sh”文件现在用上了,还原它。

再执行“bin/hadoop jar share/hadoop/mapreduce/hadoop-mapreduce-examples-2.5.1.jar grep input output 'dfs[a-z.]+'”,

提示:

[plain] view plain copy
  1. ./bin/hadoop: line 133: /usr/java/jdk1.7.0/bin/java: No such file or directory  
  2. ./bin/hadoop: line 133: exec: /usr/java/jdk1.7.0/bin/java: cannot execute: No such file or directory  
按提示应该还是JAVA(JDK)的安装的问题,我安装JDK的时候只执行到
rpm -ivh /目录/jdk-7-linux-x64.rpm

再没执行其它操作,将后续的步骤执行完成后,再执行“bin/hadoop jar share/hadoop/mapreduce/hadoop-mapreduce-examples-2.5.1.jar grep input output 'dfs[a-z.]+'”,

输出:

[plain] view plain copy
  1. 14/10/07 03:35:57 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable  
  2. 14/10/07 03:35:58 INFO Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id  
  3. 14/10/07 03:35:58 INFO jvm.JvmMetrics: Initializing JVM Metrics with processName=JobTracker, sessionId=  
  4. 14/10/07 03:35:59 WARN mapreduce.JobSubmitter: No job jar file set.  User classes may not be found. See Job or Job#setJar(String).  
  5. 14/10/07 03:35:59 INFO input.FileInputFormat: Total input paths to process : 6  
  6. 14/10/07 03:35:59 INFO mapreduce.JobSubmitter: number of splits:6  
  7. 14/10/07 03:36:00 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_local1185570365_0001  
  8. 14/10/07 03:36:00 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root1185570365/.staging/job_local1185570365_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  9. 14/10/07 03:36:01 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root1185570365/.staging/job_local1185570365_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  10. 14/10/07 03:36:01 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local1185570365_0001/job_local1185570365_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  11. 14/10/07 03:36:01 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local1185570365_0001/job_local1185570365_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  12. 14/10/07 03:36:01 INFO mapreduce.Job: The url to track the job: http://localhost:8080/  
  13. 14/10/07 03:36:01 INFO mapreduce.Job: Running job: job_local1185570365_0001  
  14. 14/10/07 03:36:01 INFO mapred.LocalJobRunner: OutputCommitter set in config null  
  15. 14/10/07 03:36:01 INFO mapred.LocalJobRunner: OutputCommitter is org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter  
  16. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Waiting for map tasks  
  17. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000000_0  
  18. 14/10/07 03:36:02 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  19. 14/10/07 03:36:02 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/hadoop-policy.xml:0+9201  
  20. 14/10/07 03:36:02 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  21. 14/10/07 03:36:02 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  22. 14/10/07 03:36:02 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  23. 14/10/07 03:36:02 INFO mapred.MapTask: soft limit at 83886080  
  24. 14/10/07 03:36:02 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  25. 14/10/07 03:36:02 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  26. 14/10/07 03:36:02 INFO mapred.LocalJobRunner:   
  27. 14/10/07 03:36:02 INFO mapred.MapTask: Starting flush of map output  
  28. 14/10/07 03:36:02 INFO mapred.MapTask: Spilling map output  
  29. 14/10/07 03:36:02 INFO mapred.MapTask: bufstart = 0; bufend = 17; bufvoid = 104857600  
  30. 14/10/07 03:36:02 INFO mapred.MapTask: kvstart = 26214396(104857584); kvend = 26214396(104857584); length = 1/6553600  
  31. 14/10/07 03:36:02 INFO mapreduce.Job: Job job_local1185570365_0001 running in uber mode : false  
  32. 14/10/07 03:36:02 INFO mapred.MapTask: Finished spill 0  
  33. 14/10/07 03:36:02 INFO mapreduce.Job:  map 0% reduce 0%  
  34. 14/10/07 03:36:02 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000000_0 is done. And is in the process of committing  
  35. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: map  
  36. 14/10/07 03:36:02 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000000_0' done.  
  37. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000000_0  
  38. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000001_0  
  39. 14/10/07 03:36:02 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  40. 14/10/07 03:36:02 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/capacity-scheduler.xml:0+3589  
  41. 14/10/07 03:36:02 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  42. 14/10/07 03:36:02 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  43. 14/10/07 03:36:02 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  44. 14/10/07 03:36:02 INFO mapred.MapTask: soft limit at 83886080  
  45. 14/10/07 03:36:02 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  46. 14/10/07 03:36:02 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  47. 14/10/07 03:36:02 INFO mapred.LocalJobRunner:   
  48. 14/10/07 03:36:02 INFO mapred.MapTask: Starting flush of map output  
  49. 14/10/07 03:36:02 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000001_0 is done. And is in the process of committing  
  50. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: map  
  51. 14/10/07 03:36:02 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000001_0' done.  
  52. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000001_0  
  53. 14/10/07 03:36:02 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000002_0  
  54. 14/10/07 03:36:02 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  55. 14/10/07 03:36:02 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/hdfs-site.xml:0+775  
  56. 14/10/07 03:36:02 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  57. 14/10/07 03:36:03 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  58. 14/10/07 03:36:03 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  59. 14/10/07 03:36:03 INFO mapred.MapTask: soft limit at 83886080  
  60. 14/10/07 03:36:03 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  61. 14/10/07 03:36:03 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  62. 14/10/07 03:36:03 INFO mapred.LocalJobRunner:   
  63. 14/10/07 03:36:03 INFO mapred.MapTask: Starting flush of map output  
  64. 14/10/07 03:36:03 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000002_0 is done. And is in the process of committing  
  65. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: map  
  66. 14/10/07 03:36:03 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000002_0' done.  
  67. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000002_0  
  68. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000003_0  
  69. 14/10/07 03:36:03 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  70. 14/10/07 03:36:03 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/core-site.xml:0+774  
  71. 14/10/07 03:36:03 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  72. 14/10/07 03:36:03 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  73. 14/10/07 03:36:03 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  74. 14/10/07 03:36:03 INFO mapred.MapTask: soft limit at 83886080  
  75. 14/10/07 03:36:03 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  76. 14/10/07 03:36:03 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  77. 14/10/07 03:36:03 INFO mapred.LocalJobRunner:   
  78. 14/10/07 03:36:03 INFO mapred.MapTask: Starting flush of map output  
  79. 14/10/07 03:36:03 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000003_0 is done. And is in the process of committing  
  80. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: map  
  81. 14/10/07 03:36:03 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000003_0' done.  
  82. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000003_0  
  83. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000004_0  
  84. 14/10/07 03:36:03 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  85. 14/10/07 03:36:03 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/yarn-site.xml:0+690  
  86. 14/10/07 03:36:03 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  87. 14/10/07 03:36:03 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  88. 14/10/07 03:36:03 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  89. 14/10/07 03:36:03 INFO mapred.MapTask: soft limit at 83886080  
  90. 14/10/07 03:36:03 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  91. 14/10/07 03:36:03 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  92. 14/10/07 03:36:03 INFO mapred.LocalJobRunner:   
  93. 14/10/07 03:36:03 INFO mapred.MapTask: Starting flush of map output  
  94. 14/10/07 03:36:03 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000004_0 is done. And is in the process of committing  
  95. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: map  
  96. 14/10/07 03:36:03 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000004_0' done.  
  97. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000004_0  
  98. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_m_000005_0  
  99. 14/10/07 03:36:03 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  100. 14/10/07 03:36:03 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/httpfs-site.xml:0+620  
  101. 14/10/07 03:36:03 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  102. 14/10/07 03:36:03 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  103. 14/10/07 03:36:03 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  104. 14/10/07 03:36:03 INFO mapred.MapTask: soft limit at 83886080  
  105. 14/10/07 03:36:03 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  106. 14/10/07 03:36:03 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  107. 14/10/07 03:36:03 INFO mapred.LocalJobRunner:   
  108. 14/10/07 03:36:03 INFO mapred.MapTask: Starting flush of map output  
  109. 14/10/07 03:36:03 INFO mapred.Task: Task:attempt_local1185570365_0001_m_000005_0 is done. And is in the process of committing  
  110. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: map  
  111. 14/10/07 03:36:03 INFO mapred.Task: Task 'attempt_local1185570365_0001_m_000005_0' done.  
  112. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_m_000005_0  
  113. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: map task executor complete.  
  114. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Waiting for reduce tasks  
  115. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: Starting task: attempt_local1185570365_0001_r_000000_0  
  116. 14/10/07 03:36:03 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  117. 14/10/07 03:36:03 INFO mapred.ReduceTask: Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@57931be2  
  118. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: MergerManager: memoryLimit=363285696, maxSingleShuffleLimit=90821424, mergeThreshold=239768576, ioSortFactor=10, memToMemMergeOutputsThreshold=10  
  119. 14/10/07 03:36:03 INFO reduce.EventFetcher: attempt_local1185570365_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events  
  120. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000001_0 decomp: 2 len: 6 to MEMORY  
  121. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local1185570365_0001_m_000001_0  
  122. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->2  
  123. 14/10/07 03:36:03 INFO mapreduce.Job:  map 100% reduce 0%  
  124. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000004_0 decomp: 2 len: 6 to MEMORY  
  125. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local1185570365_0001_m_000004_0  
  126. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 2, commitMemory -> 2, usedMemory ->4  
  127. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000005_0 decomp: 2 len: 6 to MEMORY  
  128. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local1185570365_0001_m_000005_0  
  129. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 3, commitMemory -> 4, usedMemory ->6  
  130. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000002_0 decomp: 2 len: 6 to MEMORY  
  131. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local1185570365_0001_m_000002_0  
  132. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 4, commitMemory -> 6, usedMemory ->8  
  133. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000003_0 decomp: 2 len: 6 to MEMORY  
  134. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local1185570365_0001_m_000003_0  
  135. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 5, commitMemory -> 8, usedMemory ->10  
  136. 14/10/07 03:36:03 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local1185570365_0001_m_000000_0 decomp: 21 len: 25 to MEMORY  
  137. 14/10/07 03:36:03 INFO reduce.InMemoryMapOutput: Read 21 bytes from map-output for attempt_local1185570365_0001_m_000000_0  
  138. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 21, inMemoryMapOutputs.size() -> 6, commitMemory -> 10, usedMemory ->31  
  139. 14/10/07 03:36:03 INFO reduce.EventFetcher: EventFetcher is interrupted.. Returning  
  140. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  141. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: finalMerge called with 6 in-memory map-outputs and 0 on-disk map-outputs  
  142. 14/10/07 03:36:03 INFO mapred.Merger: Merging 6 sorted segments  
  143. 14/10/07 03:36:03 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 10 bytes  
  144. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: Merged 6 segments, 31 bytes to disk to satisfy reduce memory limit  
  145. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: Merging 1 files, 25 bytes from disk  
  146. 14/10/07 03:36:03 INFO reduce.MergeManagerImpl: Merging 0 segments, 0 bytes from memory into reduce  
  147. 14/10/07 03:36:03 INFO mapred.Merger: Merging 1 sorted segments  
  148. 14/10/07 03:36:03 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 10 bytes  
  149. 14/10/07 03:36:03 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  150. 14/10/07 03:36:04 INFO Configuration.deprecation: mapred.skip.on is deprecated. Instead, use mapreduce.job.skiprecords  
  151. 14/10/07 03:36:04 INFO mapred.Task: Task:attempt_local1185570365_0001_r_000000_0 is done. And is in the process of committing  
  152. 14/10/07 03:36:04 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  153. 14/10/07 03:36:04 INFO mapred.Task: Task attempt_local1185570365_0001_r_000000_0 is allowed to commit now  
  154. 14/10/07 03:36:04 INFO output.FileOutputCommitter: Saved output of task 'attempt_local1185570365_0001_r_000000_0' to file:/opt/hadoop-2.5.1/grep-temp-767563685/_temporary/0/task_local1185570365_0001_r_000000  
  155. 14/10/07 03:36:04 INFO mapred.LocalJobRunner: reduce > reduce  
  156. 14/10/07 03:36:04 INFO mapred.Task: Task 'attempt_local1185570365_0001_r_000000_0' done.  
  157. 14/10/07 03:36:04 INFO mapred.LocalJobRunner: Finishing task: attempt_local1185570365_0001_r_000000_0  
  158. 14/10/07 03:36:04 INFO mapred.LocalJobRunner: reduce task executor complete.  
  159. 14/10/07 03:36:04 INFO mapreduce.Job:  map 100% reduce 100%  
  160. 14/10/07 03:36:04 INFO mapreduce.Job: Job job_local1185570365_0001 completed successfully  
  161. 14/10/07 03:36:04 INFO mapreduce.Job: Counters: 33  
  162.     File System Counters  
  163.         FILE: Number of bytes read=114663  
  164.         FILE: Number of bytes written=1613316  
  165.         FILE: Number of read operations=0  
  166.         FILE: Number of large read operations=0  
  167.         FILE: Number of write operations=0  
  168.     Map-Reduce Framework  
  169.         Map input records=405  
  170.         Map output records=1  
  171.         Map output bytes=17  
  172.         Map output materialized bytes=55  
  173.         Input split bytes=657  
  174.         Combine input records=1  
  175.         Combine output records=1  
  176.         Reduce input groups=1  
  177.         Reduce shuffle bytes=55  
  178.         Reduce input records=1  
  179.         Reduce output records=1  
  180.         Spilled Records=2  
  181.         Shuffled Maps =6  
  182.         Failed Shuffles=0  
  183.         Merged Map outputs=6  
  184.         GC time elapsed (ms)=225  
  185.         CPU time spent (ms)=0  
  186.         Physical memory (bytes) snapshot=0  
  187.         Virtual memory (bytes) snapshot=0  
  188.         Total committed heap usage (bytes)=1106100224  
  189.     Shuffle Errors  
  190.         BAD_ID=0  
  191.         CONNECTION=0  
  192.         IO_ERROR=0  
  193.         WRONG_LENGTH=0  
  194.         WRONG_MAP=0  
  195.         WRONG_REDUCE=0  
  196.     File Input Format Counters   
  197.         Bytes Read=15649  
  198.     File Output Format Counters   
  199.         Bytes Written=123  
  200. 14/10/07 03:36:04 INFO jvm.JvmMetrics: Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized  
  201. org.apache.hadoop.mapred.FileAlreadyExistsException: Output directory file:/opt/hadoop-2.5.1/output already exists  
  202.     at org.apache.hadoop.mapreduce.lib.output.FileOutputFormat.checkOutputSpecs(FileOutputFormat.java:146)  
  203.     at org.apache.hadoop.mapreduce.JobSubmitter.checkSpecs(JobSubmitter.java:458)  
  204.     at org.apache.hadoop.mapreduce.JobSubmitter.submitJobInternal(JobSubmitter.java:343)  
  205.     at org.apache.hadoop.mapreduce.Job$10.run(Job.java:1285)  
  206.     at org.apache.hadoop.mapreduce.Job$10.run(Job.java:1282)  
  207.     at java.security.AccessController.doPrivileged(Native Method)  
  208.     at javax.security.auth.Subject.doAs(Subject.java:415)  
  209.     at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1614)  
  210.     at org.apache.hadoop.mapreduce.Job.submit(Job.java:1282)  
  211.     at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:1303)  
  212.     at org.apache.hadoop.examples.Grep.run(Grep.java:92)  
  213.     at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)  
  214.     at org.apache.hadoop.examples.Grep.main(Grep.java:101)  
  215.     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)  
  216.     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)  
  217.     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)  
  218.     at java.lang.reflect.Method.invoke(Method.java:606)  
  219.     at org.apache.hadoop.util.ProgramDriver$ProgramDescription.invoke(ProgramDriver.java:72)  
  220.     at org.apache.hadoop.util.ProgramDriver.run(ProgramDriver.java:145)  
  221.     at org.apache.hadoop.examples.ExampleDriver.main(ExampleDriver.java:74)  
  222.     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)  
  223.     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)  
  224.     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)  
  225.     at java.lang.reflect.Method.invoke(Method.java:606)  
  226.     at org.apache.hadoop.util.RunJar.main(RunJar.java:212)  

Output directory file:/opt/hadoop-2.5.1/output already exists,噢,原因是output目录已经存在了(之前我排查问题的时候创建的);

删除output目录(rm -rf output);

再执行“bin/hadoop jar share/hadoop/mapreduce/hadoop-mapreduce-examples-2.5.1.jar grep input output 'dfs[a-z.]+'”命令,输出如下:

[plain] view plain copy
  1. 14/10/08 05:57:34 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable  
  2. 14/10/08 05:57:35 INFO Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id  
  3. 14/10/08 05:57:35 INFO jvm.JvmMetrics: Initializing JVM Metrics with processName=JobTracker, sessionId=  
  4. 14/10/08 05:57:36 WARN mapreduce.JobSubmitter: No job jar file set.  User classes may not be found. See Job or Job#setJar(String).  
  5. 14/10/08 05:57:36 INFO input.FileInputFormat: Total input paths to process : 6  
  6. 14/10/08 05:57:36 INFO mapreduce.JobSubmitter: number of splits:6  
  7. 14/10/08 05:57:37 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_local380762736_0001  
  8. 14/10/08 05:57:37 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root380762736/.staging/job_local380762736_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  9. 14/10/08 05:57:37 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root380762736/.staging/job_local380762736_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  10. 14/10/08 05:57:38 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local380762736_0001/job_local380762736_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  11. 14/10/08 05:57:38 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local380762736_0001/job_local380762736_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  12. 14/10/08 05:57:38 INFO mapreduce.Job: The url to track the job: http://localhost:8080/  
  13. 14/10/08 05:57:38 INFO mapreduce.Job: Running job: job_local380762736_0001  
  14. 14/10/08 05:57:38 INFO mapred.LocalJobRunner: OutputCommitter set in config null  
  15. 14/10/08 05:57:38 INFO mapred.LocalJobRunner: OutputCommitter is org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter  
  16. 14/10/08 05:57:38 INFO mapred.LocalJobRunner: Waiting for map tasks  
  17. 14/10/08 05:57:38 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000000_0  
  18. 14/10/08 05:57:39 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  19. 14/10/08 05:57:39 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/hadoop-policy.xml:0+9201  
  20. 14/10/08 05:57:39 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  21. 14/10/08 05:57:39 INFO mapreduce.Job: Job job_local380762736_0001 running in uber mode : false  
  22. 14/10/08 05:57:39 INFO mapreduce.Job:  map 0% reduce 0%  
  23. 14/10/08 05:57:43 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  24. 14/10/08 05:57:43 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  25. 14/10/08 05:57:43 INFO mapred.MapTask: soft limit at 83886080  
  26. 14/10/08 05:57:43 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  27. 14/10/08 05:57:43 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  28. 14/10/08 05:57:44 INFO mapred.LocalJobRunner:   
  29. 14/10/08 05:57:44 INFO mapred.MapTask: Starting flush of map output  
  30. 14/10/08 05:57:44 INFO mapred.MapTask: Spilling map output  
  31. 14/10/08 05:57:44 INFO mapred.MapTask: bufstart = 0; bufend = 17; bufvoid = 104857600  
  32. 14/10/08 05:57:44 INFO mapred.MapTask: kvstart = 26214396(104857584); kvend = 26214396(104857584); length = 1/6553600  
  33. 14/10/08 05:57:44 INFO mapred.MapTask: Finished spill 0  
  34. 14/10/08 05:57:44 INFO mapred.Task: Task:attempt_local380762736_0001_m_000000_0 is done. And is in the process of committing  
  35. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: map  
  36. 14/10/08 05:57:45 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000000_0' done.  
  37. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000000_0  
  38. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000001_0  
  39. 14/10/08 05:57:45 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  40. 14/10/08 05:57:45 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/capacity-scheduler.xml:0+3589  
  41. 14/10/08 05:57:45 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  42. 14/10/08 05:57:45 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  43. 14/10/08 05:57:45 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  44. 14/10/08 05:57:45 INFO mapred.MapTask: soft limit at 83886080  
  45. 14/10/08 05:57:45 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  46. 14/10/08 05:57:45 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  47. 14/10/08 05:57:45 INFO mapred.LocalJobRunner:   
  48. 14/10/08 05:57:45 INFO mapred.MapTask: Starting flush of map output  
  49. 14/10/08 05:57:45 INFO mapred.Task: Task:attempt_local380762736_0001_m_000001_0 is done. And is in the process of committing  
  50. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: map  
  51. 14/10/08 05:57:45 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000001_0' done.  
  52. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000001_0  
  53. 14/10/08 05:57:45 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000002_0  
  54. 14/10/08 05:57:45 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  55. 14/10/08 05:57:45 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/hdfs-site.xml:0+775  
  56. 14/10/08 05:57:45 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  57. 14/10/08 05:57:46 INFO mapreduce.Job:  map 100% reduce 0%  
  58. 14/10/08 05:57:46 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  59. 14/10/08 05:57:46 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  60. 14/10/08 05:57:46 INFO mapred.MapTask: soft limit at 83886080  
  61. 14/10/08 05:57:46 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  62. 14/10/08 05:57:46 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  63. 14/10/08 05:57:46 INFO mapred.LocalJobRunner:   
  64. 14/10/08 05:57:46 INFO mapred.MapTask: Starting flush of map output  
  65. 14/10/08 05:57:46 INFO mapred.Task: Task:attempt_local380762736_0001_m_000002_0 is done. And is in the process of committing  
  66. 14/10/08 05:57:46 INFO mapred.LocalJobRunner: map  
  67. 14/10/08 05:57:46 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000002_0' done.  
  68. 14/10/08 05:57:46 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000002_0  
  69. 14/10/08 05:57:46 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000003_0  
  70. 14/10/08 05:57:46 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  71. 14/10/08 05:57:46 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/core-site.xml:0+774  
  72. 14/10/08 05:57:46 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  73. 14/10/08 05:57:47 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  74. 14/10/08 05:57:47 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  75. 14/10/08 05:57:47 INFO mapred.MapTask: soft limit at 83886080  
  76. 14/10/08 05:57:47 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  77. 14/10/08 05:57:47 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  78. 14/10/08 05:57:47 INFO mapred.LocalJobRunner:   
  79. 14/10/08 05:57:47 INFO mapred.MapTask: Starting flush of map output  
  80. 14/10/08 05:57:47 INFO mapred.Task: Task:attempt_local380762736_0001_m_000003_0 is done. And is in the process of committing  
  81. 14/10/08 05:57:47 INFO mapred.LocalJobRunner: map  
  82. 14/10/08 05:57:47 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000003_0' done.  
  83. 14/10/08 05:57:47 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000003_0  
  84. 14/10/08 05:57:47 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000004_0  
  85. 14/10/08 05:57:47 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  86. 14/10/08 05:57:47 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/yarn-site.xml:0+690  
  87. 14/10/08 05:57:47 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  88. 14/10/08 05:57:49 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  89. 14/10/08 05:57:49 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  90. 14/10/08 05:57:49 INFO mapred.MapTask: soft limit at 83886080  
  91. 14/10/08 05:57:49 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  92. 14/10/08 05:57:49 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  93. 14/10/08 05:57:49 INFO mapred.LocalJobRunner:   
  94. 14/10/08 05:57:49 INFO mapred.MapTask: Starting flush of map output  
  95. 14/10/08 05:57:49 INFO mapred.Task: Task:attempt_local380762736_0001_m_000004_0 is done. And is in the process of committing  
  96. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: map  
  97. 14/10/08 05:57:49 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000004_0' done.  
  98. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000004_0  
  99. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_m_000005_0  
  100. 14/10/08 05:57:49 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  101. 14/10/08 05:57:49 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/input/httpfs-site.xml:0+620  
  102. 14/10/08 05:57:49 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  103. 14/10/08 05:57:49 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  104. 14/10/08 05:57:49 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  105. 14/10/08 05:57:49 INFO mapred.MapTask: soft limit at 83886080  
  106. 14/10/08 05:57:49 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  107. 14/10/08 05:57:49 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  108. 14/10/08 05:57:49 INFO mapred.LocalJobRunner:   
  109. 14/10/08 05:57:49 INFO mapred.MapTask: Starting flush of map output  
  110. 14/10/08 05:57:49 INFO mapred.Task: Task:attempt_local380762736_0001_m_000005_0 is done. And is in the process of committing  
  111. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: map  
  112. 14/10/08 05:57:49 INFO mapred.Task: Task 'attempt_local380762736_0001_m_000005_0' done.  
  113. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_m_000005_0  
  114. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: map task executor complete.  
  115. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: Waiting for reduce tasks  
  116. 14/10/08 05:57:49 INFO mapred.LocalJobRunner: Starting task: attempt_local380762736_0001_r_000000_0  
  117. 14/10/08 05:57:49 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  118. 14/10/08 05:57:49 INFO mapred.ReduceTask: Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@6d36df08  
  119. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: MergerManager: memoryLimit=363285696, maxSingleShuffleLimit=90821424, mergeThreshold=239768576, ioSortFactor=10, memToMemMergeOutputsThreshold=10  
  120. 14/10/08 05:57:50 INFO reduce.EventFetcher: attempt_local380762736_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events  
  121. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000000_0 decomp: 21 len: 25 to MEMORY  
  122. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 21 bytes from map-output for attempt_local380762736_0001_m_000000_0  
  123. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 21, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->21  
  124. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000004_0 decomp: 2 len: 6 to MEMORY  
  125. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local380762736_0001_m_000004_0  
  126. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 2, commitMemory -> 21, usedMemory ->23  
  127. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000003_0 decomp: 2 len: 6 to MEMORY  
  128. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local380762736_0001_m_000003_0  
  129. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 3, commitMemory -> 23, usedMemory ->25  
  130. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000005_0 decomp: 2 len: 6 to MEMORY  
  131. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local380762736_0001_m_000005_0  
  132. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 4, commitMemory -> 25, usedMemory ->27  
  133. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000001_0 decomp: 2 len: 6 to MEMORY  
  134. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local380762736_0001_m_000001_0  
  135. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 5, commitMemory -> 27, usedMemory ->29  
  136. 14/10/08 05:57:50 INFO reduce.LocalFetcher: localfetcher#1 about to shuffle output of map attempt_local380762736_0001_m_000002_0 decomp: 2 len: 6 to MEMORY  
  137. 14/10/08 05:57:50 INFO reduce.InMemoryMapOutput: Read 2 bytes from map-output for attempt_local380762736_0001_m_000002_0  
  138. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 2, inMemoryMapOutputs.size() -> 6, commitMemory -> 29, usedMemory ->31  
  139. 14/10/08 05:57:50 INFO reduce.EventFetcher: EventFetcher is interrupted.. Returning  
  140. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  141. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: finalMerge called with 6 in-memory map-outputs and 0 on-disk map-outputs  
  142. 14/10/08 05:57:50 INFO mapred.Merger: Merging 6 sorted segments  
  143. 14/10/08 05:57:50 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 10 bytes  
  144. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: Merged 6 segments, 31 bytes to disk to satisfy reduce memory limit  
  145. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: Merging 1 files, 25 bytes from disk  
  146. 14/10/08 05:57:50 INFO reduce.MergeManagerImpl: Merging 0 segments, 0 bytes from memory into reduce  
  147. 14/10/08 05:57:50 INFO mapred.Merger: Merging 1 sorted segments  
  148. 14/10/08 05:57:50 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 10 bytes  
  149. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  150. 14/10/08 05:57:50 INFO Configuration.deprecation: mapred.skip.on is deprecated. Instead, use mapreduce.job.skiprecords  
  151. 14/10/08 05:57:50 INFO mapred.Task: Task:attempt_local380762736_0001_r_000000_0 is done. And is in the process of committing  
  152. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: 6 / 6 copied.  
  153. 14/10/08 05:57:50 INFO mapred.Task: Task attempt_local380762736_0001_r_000000_0 is allowed to commit now  
  154. 14/10/08 05:57:50 INFO output.FileOutputCommitter: Saved output of task 'attempt_local380762736_0001_r_000000_0' to file:/opt/hadoop-2.5.1/grep-temp-913340630/_temporary/0/task_local380762736_0001_r_000000  
  155. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: reduce > reduce  
  156. 14/10/08 05:57:50 INFO mapred.Task: Task 'attempt_local380762736_0001_r_000000_0' done.  
  157. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: Finishing task: attempt_local380762736_0001_r_000000_0  
  158. 14/10/08 05:57:50 INFO mapred.LocalJobRunner: reduce task executor complete.  
  159. 14/10/08 05:57:51 INFO mapreduce.Job:  map 100% reduce 100%  
  160. 14/10/08 05:57:51 INFO mapreduce.Job: Job job_local380762736_0001 completed successfully  
  161. 14/10/08 05:57:51 INFO mapreduce.Job: Counters: 33  
  162.     File System Counters  
  163.         FILE: Number of bytes read=114663  
  164.         FILE: Number of bytes written=1604636  
  165.         FILE: Number of read operations=0  
  166.         FILE: Number of large read operations=0  
  167.         FILE: Number of write operations=0  
  168.     Map-Reduce Framework  
  169.         Map input records=405  
  170.         Map output records=1  
  171.         Map output bytes=17  
  172.         Map output materialized bytes=55  
  173.         Input split bytes=657  
  174.         Combine input records=1  
  175.         Combine output records=1  
  176.         Reduce input groups=1  
  177.         Reduce shuffle bytes=55  
  178.         Reduce input records=1  
  179.         Reduce output records=1  
  180.         Spilled Records=2  
  181.         Shuffled Maps =6  
  182.         Failed Shuffles=0  
  183.         Merged Map outputs=6  
  184.         GC time elapsed (ms)=2359  
  185.         CPU time spent (ms)=0  
  186.         Physical memory (bytes) snapshot=0  
  187.         Virtual memory (bytes) snapshot=0  
  188.         Total committed heap usage (bytes)=1106096128  
  189.     Shuffle Errors  
  190.         BAD_ID=0  
  191.         CONNECTION=0  
  192.         IO_ERROR=0  
  193.         WRONG_LENGTH=0  
  194.         WRONG_MAP=0  
  195.         WRONG_REDUCE=0  
  196.     File Input Format Counters   
  197.         Bytes Read=15649  
  198.     File Output Format Counters   
  199.         Bytes Written=123  
  200. 14/10/08 05:57:51 INFO jvm.JvmMetrics: Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized  
  201. 14/10/08 05:57:51 WARN mapreduce.JobSubmitter: No job jar file set.  User classes may not be found. See Job or Job#setJar(String).  
  202. 14/10/08 05:57:51 INFO input.FileInputFormat: Total input paths to process : 1  
  203. 14/10/08 05:57:51 INFO mapreduce.JobSubmitter: number of splits:1  
  204. 14/10/08 05:57:51 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_local571678604_0002  
  205. 14/10/08 05:57:51 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root571678604/.staging/job_local571678604_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  206. 14/10/08 05:57:51 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/staging/root571678604/.staging/job_local571678604_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  207. 14/10/08 05:57:52 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local571678604_0002/job_local571678604_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.  
  208. 14/10/08 05:57:52 WARN conf.Configuration: file:/tmp/hadoop-root/mapred/local/localRunner/root/job_local571678604_0002/job_local571678604_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.  
  209. 14/10/08 05:57:52 INFO mapreduce.Job: The url to track the job: http://localhost:8080/  
  210. 14/10/08 05:57:52 INFO mapreduce.Job: Running job: job_local571678604_0002  
  211. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: OutputCommitter set in config null  
  212. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: OutputCommitter is org.apache.hadoop.mapreduce.lib.output.FileOutputCommitter  
  213. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Waiting for map tasks  
  214. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Starting task: attempt_local571678604_0002_m_000000_0  
  215. 14/10/08 05:57:52 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  216. 14/10/08 05:57:52 INFO mapred.MapTask: Processing split: file:/opt/hadoop-2.5.1/grep-temp-913340630/part-r-00000:0+111  
  217. 14/10/08 05:57:52 INFO mapred.MapTask: Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer  
  218. 14/10/08 05:57:52 INFO mapred.MapTask: (EQUATOR) 0 kvi 26214396(104857584)  
  219. 14/10/08 05:57:52 INFO mapred.MapTask: mapreduce.task.io.sort.mb: 100  
  220. 14/10/08 05:57:52 INFO mapred.MapTask: soft limit at 83886080  
  221. 14/10/08 05:57:52 INFO mapred.MapTask: bufstart = 0; bufvoid = 104857600  
  222. 14/10/08 05:57:52 INFO mapred.MapTask: kvstart = 26214396; length = 6553600  
  223. 14/10/08 05:57:52 INFO mapred.LocalJobRunner:   
  224. 14/10/08 05:57:52 INFO mapred.MapTask: Starting flush of map output  
  225. 14/10/08 05:57:52 INFO mapred.MapTask: Spilling map output  
  226. 14/10/08 05:57:52 INFO mapred.MapTask: bufstart = 0; bufend = 17; bufvoid = 104857600  
  227. 14/10/08 05:57:52 INFO mapred.MapTask: kvstart = 26214396(104857584); kvend = 26214396(104857584); length = 1/6553600  
  228. 14/10/08 05:57:52 INFO mapred.MapTask: Finished spill 0  
  229. 14/10/08 05:57:52 INFO mapred.Task: Task:attempt_local571678604_0002_m_000000_0 is done. And is in the process of committing  
  230. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: map  
  231. 14/10/08 05:57:52 INFO mapred.Task: Task 'attempt_local571678604_0002_m_000000_0' done.  
  232. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Finishing task: attempt_local571678604_0002_m_000000_0  
  233. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: map task executor complete.  
  234. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Waiting for reduce tasks  
  235. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Starting task: attempt_local571678604_0002_r_000000_0  
  236. 14/10/08 05:57:52 INFO mapred.Task:  Using ResourceCalculatorProcessTree : [ ]  
  237. 14/10/08 05:57:52 INFO mapred.ReduceTask: Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@63ae8b5c  
  238. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: MergerManager: memoryLimit=363285696, maxSingleShuffleLimit=90821424, mergeThreshold=239768576, ioSortFactor=10, memToMemMergeOutputsThreshold=10  
  239. 14/10/08 05:57:52 INFO reduce.EventFetcher: attempt_local571678604_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events  
  240. 14/10/08 05:57:52 INFO reduce.LocalFetcher: localfetcher#2 about to shuffle output of map attempt_local571678604_0002_m_000000_0 decomp: 21 len: 25 to MEMORY  
  241. 14/10/08 05:57:52 INFO reduce.InMemoryMapOutput: Read 21 bytes from map-output for attempt_local571678604_0002_m_000000_0  
  242. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: closeInMemoryFile -> map-output of size: 21, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->21  
  243. 14/10/08 05:57:52 INFO reduce.EventFetcher: EventFetcher is interrupted.. Returning  
  244. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: 1 / 1 copied.  
  245. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs  
  246. 14/10/08 05:57:52 INFO mapred.Merger: Merging 1 sorted segments  
  247. 14/10/08 05:57:52 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 11 bytes  
  248. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: Merged 1 segments, 21 bytes to disk to satisfy reduce memory limit  
  249. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: Merging 1 files, 25 bytes from disk  
  250. 14/10/08 05:57:52 INFO reduce.MergeManagerImpl: Merging 0 segments, 0 bytes from memory into reduce  
  251. 14/10/08 05:57:52 INFO mapred.Merger: Merging 1 sorted segments  
  252. 14/10/08 05:57:52 INFO mapred.Merger: Down to the last merge-pass, with 1 segments left of total size: 11 bytes  
  253. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: 1 / 1 copied.  
  254. 14/10/08 05:57:52 INFO mapred.Task: Task:attempt_local571678604_0002_r_000000_0 is done. And is in the process of committing  
  255. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: 1 / 1 copied.  
  256. 14/10/08 05:57:52 INFO mapred.Task: Task attempt_local571678604_0002_r_000000_0 is allowed to commit now  
  257. 14/10/08 05:57:52 INFO output.FileOutputCommitter: Saved output of task 'attempt_local571678604_0002_r_000000_0' to file:/opt/hadoop-2.5.1/output/_temporary/0/task_local571678604_0002_r_000000  
  258. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: reduce > reduce  
  259. 14/10/08 05:57:52 INFO mapred.Task: Task 'attempt_local571678604_0002_r_000000_0' done.  
  260. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: Finishing task: attempt_local571678604_0002_r_000000_0  
  261. 14/10/08 05:57:52 INFO mapred.LocalJobRunner: reduce task executor complete.  
  262. 14/10/08 05:57:53 INFO mapreduce.Job: Job job_local571678604_0002 running in uber mode : false  
  263. 14/10/08 05:57:53 INFO mapreduce.Job:  map 100% reduce 100%  
  264. 14/10/08 05:57:53 INFO mapreduce.Job: Job job_local571678604_0002 completed successfully  
  265. 14/10/08 05:57:53 INFO mapreduce.Job: Counters: 33  
  266.     File System Counters  
  267.         FILE: Number of bytes read=39892  
  268.         FILE: Number of bytes written=913502  
  269.         FILE: Number of read operations=0  
  270.         FILE: Number of large read operations=0  
  271.         FILE: Number of write operations=0  
  272.     Map-Reduce Framework  
  273.         Map input records=1  
  274.         Map output records=1  
  275.         Map output bytes=17  
  276.         Map output materialized bytes=25  
  277.         Input split bytes=120  
  278.         Combine input records=0  
  279.         Combine output records=0  
  280.         Reduce input groups=1  
  281.         Reduce shuffle bytes=25  
  282.         Reduce input records=1  
  283.         Reduce output records=1  
  284.         Spilled Records=2  
  285.         Shuffled Maps =1  
  286.         Failed Shuffles=0  
  287.         Merged Map outputs=1  
  288.         GC time elapsed (ms)=37  
  289.         CPU time spent (ms)=0  
  290.         Physical memory (bytes) snapshot=0  
  291.         Virtual memory (bytes) snapshot=0  
  292.         Total committed heap usage (bytes)=250560512  
  293.     Shuffle Errors  
  294.         BAD_ID=0  
  295.         CONNECTION=0  
  296.         IO_ERROR=0  
  297.         WRONG_LENGTH=0  
  298.         WRONG_MAP=0  
  299.         WRONG_REDUCE=0  
  300.     File Input Format Counters   
  301.         Bytes Read=123  
  302.     File Output Format Counters   
  303.         Bytes Written=23  

OK,总算对了。


转自:http://blog.csdn.net/testcs_dn/article/details/39853517