landyer

浏览: 141953 次
性别:
来自: 上海

最近访客更多访客>>

bill00

hubobocbb

ronggui

笨鸟刃心

博主相关

博客

微博

相册

留言

关于我

文章分类

社区版块

存档分类

Hadoop学习总结：Hadoop的运行痕迹

博客分类：

hadoop

Hadoop JVM Rack Apache log4j

Hadoop 学习总结之一：HDFS简介

Hadoop学习总结之二：HDFS读写过程解析

Hadoop学习总结之三：Map-Reduce入门

Hadoop学习总结之四：Map-Reduce的过程解析

在使用hadoop的时候，可能遇到各种各样的问题，然而由于hadoop的运行机制比较复杂，因而出现了问题的时候比较难于发现问题。

本文欲通过某种方式跟踪Hadoop的运行痕迹，方便出现问题的时候可以通过这些痕迹来解决问题。

一、环境的搭建

为了能够跟踪这些运行的痕迹，我们需要搭建一个特殊的环境，从而可以一步步的查看上一节提到的一些关键步骤所引起的变化。

我们首先搭建一个拥有一个NameNode(namenode:192.168.1.104)，三个 DataNode(datanode01:192.168.1.105, datanode02:192.168.1.106, datanode03:192.168.1.107)的Hadoop环境，其中SecondaryNameNode和NameNode运行在同一台机器上。

对于这四台机器上的Hadoop，我们需要进行如下相同的配置：

NameNode，SeondaryNameNode，JobTracker都应该运行在namenode:192.168.1.104机器上
DataNode，TaskTracker，以及生成的Map和Reduce的Task JVM应该运行在datanode01, datanode02, datanode03上
数据共有三份备份
HDFS以及Map-Reduce运行的数据放在/data/hadoop/dir/tmp文件夹下

<name>fs.default.name</name>

</property>

<name>mapred.job.tracker</name>

</property>

<name>dfs.replication</name>

</property>

<name>hadoop.tmp.dir</name>

<value>/data/hadoopdir/tmp</value>

<description>A base for other temporary directories.</description>

</property>

然而由于Map-Reduce过程相对复杂，为了能够对Map和Reduce的Task JVM进行远程的调试，从而能一步一步观察，因而对NameNode和三个DataNode有一些不同的配置：

对于NameNode:

设置mapred.job.reuse.jvm.num.tasks为-1，使得多个运行于同一个DataNode上的Map和Reduce的Task共用同一个JVM，从而方便对此JVM进行远程调试，并且不会因为多个Task JVM监听同一个远程调试端口而发生冲突
对于mapred.tasktracker.map.tasks.maximum和mapred.tasktracker.reduce.tasks.maximum的配置以DataNode上的为准
设置io.sort.mb为1M(原来为100M)，是为了在Map阶段让内存中的map output尽快的spill到文件中来，从而我们可以观察map的输出
设置mapred.child.java.opts的时候，即设置Task JVM的运行参数，添加远程调试监听端口8333

<property>
    <name>mapred.job.reuse.jvm.num.tasks</name>
    <value>-1</value>
    <description></description>
</property>
<property>
    <name>mapred.tasktracker.map.tasks.maximum</name>
    <value>1</value>
    <description></description>
</property>
<property>
    <name>mapred.tasktracker.reduce.tasks.maximum</name>
    <value>1</value>
    <description></description>
</property>
<property>
    <name>io.sort.mb</name>
    <value>1</value>
    <description></description>
</property>
<property>
    <name>mapred.child.java.opts</name>
    <value>-Xmx200m -agentlib:jdwp=transport=dt_socket,address=8883,server=y,suspend=y</value>
    <description></description>
</property>

<property>
    <name>mapred.job.shuffle.input.buffer.percent</name>
    <value>0.001</value>
    <description></description>
</property>

<property>
    <name>mapred.job.shuffle.merge.percent</name>
    <value>0.001</value>
    <description></description>
    </property>

<property>
    <name>io.sort.factor</name>
    <value>2</value>
    <description></description>
</property>

对于DataNode:

对于datanode01:192.168.1.105，设置同时运行的map task的个数(mapred.tasktracker.map.tasks.maximum)为1，同时运行的reduce task的个数(mapred.tasktracker.reduce.tasks.maximum)为0
对于 datanode02:192.168.1.106，设置同时运行的map task的个数(mapred.tasktracker.map.tasks.maximum)为0，同时运行的reduce task的个数(mapred.tasktracker.reduce.tasks.maximum)为0
对于 datanode02:192.168.1.107，设置同时运行的map task的个数(mapred.tasktracker.map.tasks.maximum)为0，同时运行的reduce task的个数(mapred.tasktracker.reduce.tasks.maximum)为1
之所以这样设置，是因为我们虽然可以控制多个Map task共用同一个JVM，然而我们不能控制Map task和Reduce Task也共用一个JVM。从而当Map task的JVM和Reduce Task的JVM同时在同一台机器上启动的时候，仍然会出现监听远程调用端口冲突的问题。
经过上面的设置，从而datanode01专门负责运行Map Task，datanode03专门负责运行Reduce Task，而datanode02不运行任何的Task，甚至连TaskTracker也不用启动了
对于Reduce Task设置mapred.job.shuffle.input.buffer.percent和 mapred.job.shuffle.merge.percent为0.001，从而使得拷贝，合并阶段的中间结果都因为内存设置过小而写入硬盘，我们能够看到痕迹
设置io.sort.factor为2，使得在map task输出不多的情况下，也能触发合并。

除了对Map task和Reduce Task进行远程调试之外，我们还想对NameNode，SecondaryName，DataNode，JobTracker，TaskTracker进行远程调试，则需要修改一下bin/hadoop文件：

if [ "$COMMAND" = "namenode" ] ; then

CLASS='org.apache.hadoop.hdfs.server.namenode.NameNode'

HADOOP_OPTS="$HADOOP_OPTS $HADOOP_NAMENODE_OPTS -agentlib:jdwp=transport=dt_socket,address=8888,server=y,suspend=n"

elif [ "$COMMAND" = "secondarynamenode" ] ; then

CLASS='org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode'

HADOOP_OPTS="$HADOOP_OPTS $HADOOP_SECONDARYNAMENODE_OPTS -agentlib:jdwp=transport=dt_socket,address=8887,server=y,suspend=n"

elif [ "$COMMAND" = "datanode" ] ; then

CLASS='org.apache.hadoop.hdfs.server.datanode.DataNode'

HADOOP_OPTS="$HADOOP_OPTS $HADOOP_DATANODE_OPTS -agentlib:jdwp=transport=dt_socket,address=8886,server=y,suspend=n"

……

elif [ "$COMMAND" = "jobtracker" ] ; then

CLASS=org.apache.hadoop.mapred.JobTracker

HADOOP_OPTS="$HADOOP_OPTS $HADOOP_JOBTRACKER_OPTS -agentlib:jdwp=transport=dt_socket,address=8885,server=y,suspend=n"

elif [ "$COMMAND" = "tasktracker" ] ; then

CLASS=org.apache.hadoop.mapred.TaskTracker

HADOOP_OPTS="$HADOOP_OPTS $HADOOP_TASKTRACKER_OPTS -agentlib:jdwp=transport=dt_socket,address=8884,server=y,suspend=n"

在进行一切实验之前，我们首先清空/data/hadoopdir/tmp以及logs文件夹。

二、格式化HDFS

格式化HDFS需要运行命令：bin/hadoop namenode –format

于是打印出如下的日志：

10/11/20 19:52:21 INFO namenode.NameNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting NameNode
STARTUP_MSG:   host = namenode/192.168.1.104
STARTUP_MSG:   args = [-format]
STARTUP_MSG:   version = 0.19.2
STARTUP_MSG:   build = https://svn.apache.org/repos/asf/hadoop/common/branches/branch-0.19 -r 789657; compiled by 'root' on Tue Jun 30 12:40:50 EDT 2009
************************************************************/
10/11/20 19:52:21 INFO namenode.FSNamesystem: fsOwner=admin,sambashare
10/11/20 19:52:21 INFO namenode.FSNamesystem: supergroup=supergroup
10/11/20 19:52:21 INFO namenode.FSNamesystem: isPermissionEnabled=true
10/11/20 19:52:21 INFO common.Storage: Image file of size 97 saved in 0 seconds.
10/11/20 19:52:21 INFO common.Storage: Storage directory /data/hadoopdir/tmp/dfs/name has been successfully formatted.
10/11/20 19:52:21 INFO namenode.NameNode: SHUTDOWN_MSG:
/************************************************************
SHUTDOWN_MSG: Shutting down NameNode at namenode/192.168.1.104
************************************************************/

这个时候在NameNode的/data/hadoopdir/tmp下面出现如下的文件树形结构：

+- dfs
       +- name
              +--- current
                         +---- edits
                         +---- fsimage
                         +---- fstime
                         +---- VERSION
              +---image
                         +---- fsimage

这个时候，DataNode的/data/hadoopdir/tmp中还是空的。

二、启动Hadoop

启动Hadoop需要调用命令bin/start-all.sh，输出的日志如下：

starting namenode, logging to logs/hadoop-namenode-namenode.out

192.168.1.106: starting datanode, logging to logs/hadoop-datanode-datanode02.out

192.168.1.105: starting datanode, logging to logs/hadoop-datanode-datanode01.out

192.168.1.107: starting datanode, logging to logs/hadoop-datanode-datanode03.out

192.168.1.104: starting secondarynamenode, logging to logs/hadoop-secondarynamenode-namenode.out

starting jobtracker, logging to logs/hadoop-jobtracker-namenode.out

192.168.1.106: starting tasktracker, logging to logs/hadoop-tasktracker-datanode02.out

192.168.1.105: starting tasktracker, logging to logs/hadoop-tasktracker-datanode01.out

192.168.1.107: starting tasktracker, logging to logs/hadoop-tasktracker-datanode03.out

从日志中我们可以看出，此脚本启动了NameNode, 三个DataNode，SecondaryName，JobTracker以及三个TaskTracker.

下面我们分别从NameNode和三个DataNode中运行jps -l，看看到底运行了那些java程序：

在NameNode中：

22214 org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode

22107 org.apache.hadoop.hdfs.server.namenode.NameNode

22271 org.apache.hadoop.mapred.JobTracker

在datanode01中：

12580 org.apache.hadoop.mapred.TaskTracker

12531 org.apache.hadoop.hdfs.server.datanode.DataNode

在datanode02中：

10548 org.apache.hadoop.hdfs.server.datanode.DataNode

在datanode03中：

12593 org.apache.hadoop.hdfs.server.datanode.DataNode

12644 org.apache.hadoop.mapred.TaskTracker

同我们上面的配置完全符合。

当启动了Hadoop以后，/data/hadoopdir/tmp目录也发生了改变，通过ls -R我们可以看到。

对于NameNode：

在name文件夹中，多了in_use.lock文件，说明NameNode已经启动了
多了nameseondary文件夹，用于存放SecondaryNameNode的数据

dfs

./dfs:

name namesecondary

./dfs/name:

current image in_use.lock

./dfs/name/current:

edits fsimage fstime VERSION

./dfs/name/image:

fsimage

./dfs/namesecondary:

current image in_use.lock

./dfs/namesecondary/current:

edits fsimage fstime VERSION

./dfs/namesecondary/image:

fsimage

对于DataNode:

多了dfs和mapred两个文件夹
dfs文件夹用于存放HDFS的block数据的
mapred用于存放Map-Reduce Task任务执行所需要的数据的。

dfs mapred

./dfs:

data

./dfs/data:

current detach in_use.lock storage tmp

./dfs/data/current:

dncp_block_verification.log.curr VERSION

./dfs/data/detach:

./dfs/data/tmp:

./mapred:

local

./mapred/local:

当然随着Hadoop的启动，logs文件夹下也多个很多的日志：

在NameNode上，日志有：

NameNode的日志：
- hadoop-namenode-namenode.log此为log4j的输出日志
- hadoop-namenode-namenode.out此为stdout和stderr的输出日志
SecondaryNameNode的日志：
- hadoop-secondarynamenode-namenode.log此为log4j的输出日志
- hadoop-secondarynamenode-namenode.out此为stdout和stderr的输出日志
JobTracker的日志：
- hadoop-jobtracker-namenode.log此为log4j的输出日志
- hadoop-jobtracker-namenode.out此为stdout和stderr的输出日志

在DataNode上的日志有(以datanode01为例子)：

DataNode的日志
- hadoop-datanode-datanode01.log此为log4j的输出日志
- hadoop-datanode-datanode01.out此为stdout和stderr的输出日志
TaskTracker的日志
- hadoop-tasktracker-datanode01.log此为log4j的输出日志
- hadoop-tasktracker-datanode01.out此为stdout和stderr的输出日志

下面我们详细查看这些日志中的有重要意义的信息：

在hadoop-namenode-namenode.log文件中，我们可以看到NameNode启动的过程：

Namenode up at: namenode/192.168.1.104:9000

//文件的数量

Number of files = 0

Number of files under construction = 0

//加载fsimage和edits文件形成FSNamesystem

Image file of size 97 loaded in 0 seconds.

Edits file /data/hadoopdir/tmp/dfs/name/current/edits of size 4 edits # 0 loaded in 0 seconds.

Image file of size 97 saved in 0 seconds.

Finished loading FSImage in 12812 msecs

//统计block的数量和状态

Total number of blocks = 0

Number of invalid blocks = 0

Number of under-replicated blocks = 0

Number of over-replicated blocks = 0

//离开safe mode

Leaving safe mode after 12 secs.

//注册DataNode

Adding a new node: /default-rack/192.168.1.106:50010

Adding a new node: /default-rack/192.168.1.105:50010

Adding a new node: /default-rack/192.168.1.107:50010

在hadoop-secondarynamenode-namenode.log文件中，我们可以看到SecondaryNameNode的启动过程：

Secondary Web-server up at: 0.0.0.0:50090

//进行Checkpoint的周期

Checkpoint Period :3600 secs (60 min)

Log Size Trigger :67108864 bytes (65536 KB)

//进行一次checkpoint，从NameNode下载fsimage和edits

Downloaded file fsimage size 97 bytes.

Downloaded file edits size 370 bytes.

//加载edit文件，进行合并，将合并后的fsimage保存，我们可以看到fsimage变大了

Edits file /data/hadoopdir/tmp/dfs/namesecondary/current/edits of size 370 edits # 6 loaded in 0 seconds.

Image file of size 540 saved in 0 seconds.

//此次checkpoint结束

Checkpoint done. New Image Size: 540

在hadoop-jobtracker-namenode.log文件中，我们可以看到JobTracker的启动过程：

JobTracker up at: 9001

JobTracker webserver: 50030

//清除HDFS中的/data/hadoopdir/tmp/mapred/system文件夹，是用于Map-Reduce运行过程中保存数据的

Cleaning up the system directory

//不断的从TaskTracker收到heartbeat，第一次是注册TaskTracker

Got heartbeat from: tracker_datanode01:localhost/127.0.0.1:58297

Adding a new node: /default-rack/datanode01

Got heartbeat from: tracker_datanode03:localhost/127.0.0.1:37546

Adding a new node: /default-rack/datanode03

在hadoop-datanode-datanode01.log中，可以看到DataNode的启动过程：

//格式化DataNode存放block的文件夹

Storage directory /data/hadoopdir/tmp/dfs/data is not formatted.

Formatting ...

//启动DataNode

Opened info server at 50010

Balancing bandwith is 1048576 bytes/s

Initializing JVM Metrics with processName=DataNode, sessionId=null

//向NameNode注册此DataNode

dnRegistration = DatanodeRegistration(datanode01:50010, storageID=, infoPort=50075, ipcPort=50020)

New storage id DS-1042573498-192.168.1.105-50010-1290313555129 is assigned to data-node 192.168.1.105:5001

DatanodeRegistration(192.168.1.105:50010, storageID=DS-1042573498-192.168.1.105-50010-1290313555129, infoPort=50075, ipcPort=50020)In DataNode.run, data = FSDataset{dirpath='/data/hadoopdir/tmp/dfs/data/current'}

//启动block scanner

Starting Periodic block scanner.

在hadoop-tasktracker-datanode01.log中，可以看到TaskTracker的启动过程：

//启动TaskTracker

Initializing JVM Metrics with processName=TaskTracker, sessionId=

TaskTracker up at: localhost/127.0.0.1:58297

Starting tracker tracker_datanode01:localhost/127.0.0.1:58297

//向JobTracker发送heartbeat

Got heartbeatResponse from JobTracker with responseId: 0 and 0 actions

一个特殊的log文件是hadoop-tasktracker-datanode02.log中，因为我们设置的最大Map Task数目和最大Reduce Task数据为0，而报了一个Exception，Can not start task tracker because java.lang.IllegalArgumentException，从而使得datanode02上的TaskTracker没有启动起来。

当Hadoop启动起来以后，在HDFS中也创建了一些文件夹/data/hadoopdir/tmp/mapred/system，用来保存Map-Reduce运行时候的共享资源。

三、向HDFS中放入文件

向HDFS中放入文件，需要使用命令：bin/hadoop fs -put inputdata /data/input

放入文件完毕后，我们查看HDFS：bin/hadoop fs -ls /data/input，结果为：

-rw-r--r-- 3 hadoop supergroup 6119928 2010-11-21 00:47 /data/input/inputdata

这个时候，我们查看DataNode下的/data/hadoopdir/tmp文件夹发生了变化：

在datanode01, datanode02, datanode03上的/data/hadoopdir/tmp/dfs/data/current下面都多了如下的block文件
可见block文件被复制了三份

dfs mapred

./dfs:

data

./dfs/data:

current detach in_use.lock storage tmp

./dfs/data/current:

blk_2672607439166801630 blk_2672607439166801630_1002.meta dncp_block_verification.log.curr VERSION

./dfs/data/detach:

./dfs/data/tmp:

./mapred:

local

./mapred/local:

在放入文件的过程中，我们可以看log如下：

namenode的hadoop-namenode-namenode.log如下:

//创建/data/input/inputdata

ugi=admin,sambashareip=/192.168.1.104 cmd=create src=/data/input/inputdata dst=null perm=hadoop:supergroup:rw-r--r--

//分配block

NameSystem.allocateBlock: /data/input/inputdata. blk_2672607439166801630_1002

NameSystem.addStoredBlock: blockMap updated: 192.168.1.107:50010 is added to blk_2672607439166801630_1002 size 6119928

NameSystem.addStoredBlock: blockMap updated: 192.168.1.105:50010 is added to blk_2672607439166801630_1002 size 6119928

NameSystem.addStoredBlock: blockMap updated: 192.168.1.106:50010 is added to blk_2672607439166801630_1002 size 6119928

datanode01的hadoop-datanode-datanode01.log如下:

//datanode01从客户端接收一个block

Receiving block blk_2672607439166801630_1002 src: /192.168.1.104:41748 dest: /192.168.1.105:50010

src: /192.168.1.104:41748, dest: /192.168.1.105:50010, bytes: 6119928, op: HDFS_WRITE, cliID: DFSClient_-1541812792, srvID: DS-1042573498-192.168.1.105-50010-1290313555129, blockid: blk_2672607439166801630_1002

PacketResponder 2 for block blk_2672607439166801630_1002 terminating

datanode02的hadoop-datanode-datanode02.log如下：

//datanode02从datanode01接收一个block

Receiving block blk_2672607439166801630_1002 src: /192.168.1.105:60266 dest: /192.168.1.106:50010

src: /192.168.1.105:60266, dest: /192.168.1.106:50010, bytes: 6119928, op: HDFS_WRITE, cliID: DFSClient_-1541812792, srvID: DS-1366730865-192.168.1.106-50010-1290313543717, blockid: blk_2672607439166801630_1002

PacketResponder 1 for block blk_2672607439166801630_1002 terminating

datanode03的hadoop-datanode-datanode03.log如下：

//datanode03从datanode02接收一个block

Receiving block blk_2672607439166801630_1002 src: /192.168.1.106:58899 dest: /192.168.1.107:50010

src: /192.168.1.106:58899, dest: /192.168.1.107:50010, bytes: 6119928, op: HDFS_WRITE, cliID: DFSClient_-1541812792, srvID: DS-765014609-192.168.1.107-50010-1290313555841, blockid: blk_2672607439166801630_1002

PacketResponder 0 for block blk_2672607439166801630_1002 terminating

Verification succeeded for blk_2672607439166801630_1002

四、运行一个Map-Reduce程序

运行Map-Reduce函数，需要运行命令：bin/hadoop jar hadoop-0.19.2-examples.jar wordcount /data/input /data/output

为了能够观察Map-Reduce一步步运行的情况，我们首先远程调试JobTracker，将断点设置在JobTracker.submitJob函数中。

按照我们上一篇文章讨论的那样，DFSClient向JobTracker提交任务之前，会将任务运行所需要的三类文件放入HDFS，从而可被JobTracker和TaskTracker得到：

运行的jar文件：job.jar
运行所需要的input split的信息：job.split
运行所需的配置：job.xml

当Map-Reduce程序停在JobTracker.submitJob函数中的时候，让我们查看HDFS中有如下的变化：

bin/hadoop fs -ls /data/hadoopdir/tmp/mapred/system

其中多了一个文件夹job_201011202025_0001，这是当前运行的Job的ID，在这个文件夹中有三个文件：

bin/hadoop fs -ls /data/hadoopdir/tmp/mapred/system/job_201011202025_0001

Found 3 items

-rw-r--r-- /data/hadoopdir/tmp/mapred/system/job_201011202025_0001/job.jar

-rw-r--r-- /data/hadoopdir/tmp/mapred/system/job_201011202025_0001/job.split

-rw-r--r-- /data/hadoopdir/tmp/mapred/system/job_201011202025_0001/job.xml

现在我们可以断开对JobTracker的远程调试。

在JobTracker.submitJob的函数中，会读取这些上传到HDFS的文件，从而将Job拆分成Map Task和Reduce Task。

当 TaskTracker通过heartbeat向JobTracker请求一个Map Task或者Reduce Task来运行，按照我们上面的配置，显然datanode01会请求Map Task来执行，而datanode03会申请Reduce Task来执行。

下面我们首先来看datanode01上Map Task的执行过程：

当TaskTracker得到一个Task的时候，它会调用TaskTracker.localizeJob将job运行的三个文件从HDFS中拷贝到本地文件夹，然后调用TaskInProgress.localizeTask创建Task运行的本地工作目录。

我们来远程调试datanode01上的TaskTracker，分别将断点设在localizeJob和localizeTask函数中，当程序停在做完 localizeTask后，我们来看datanode01上的/data/hadoopdir/tmp/mapred/local /taskTracker/jobcache下多了一个文件夹

job_201011202025_0001，在此文件夹下面有如下的结构：

datanode01:/data/hadoopdir/tmp/mapred/local/taskTracker/jobcache/job_201011202025_0001$ ls -R

att

分享到：

(转)MapReduce源码分析总结 | Hadoop学习总结：Map-Reduce的过程解析

2011-05-03 04:30
浏览 1489
评论(0)
分类:编程语言
查看更多

发表评论

您还没有登录,请您登录后再发表评论

最近访客更多访客>>

博主相关

文章分类

社区版块

存档分类

最新评论

Hadoop学习总结：Hadoop的运行痕迹

一、环境的搭建

二、格式化HDFS

二、启动Hadoop

三、向HDFS中放入文件

四、运行一个Map-Reduce程序

评论

发表评论

相关推荐

最近访客 更多访客>>

博主相关

文章分类

社区版块

存档分类

最新评论

Hadoop学习总结：Hadoop的运行痕迹

一、环境的搭建

二、格式化HDFS

二、启动Hadoop

三、向HDFS中放入文件

四、运行一个Map-Reduce程序

评论

发表评论

相关推荐

thrift安装资料集合

在Ubuntu下编译安装Thrift(支持php和c++)

HBase Thrift 0.5.0 + PHP 5 安裝設定

Hadoop+hbase+thrift H.H.T环境部署

php操作hbase例子

HBase技术介绍

详细讲解Hadoop中的一个简单数据库HBase

hive sql语法解读

Hive 的启动方式

Hive环境搭建与入门

Hbase入门6 -白话MySQL(RDBMS)与HBase之间

Apache Hive入门3–Hive与HBase的整合

Apache Hive入门2

Apache Hive入门1

hbase分布安装部署

使用HBase的一个典型例子，涉及了HBase中很多概念

HBase入门篇4–存储

HBase入门篇3

HBase入门篇2-Java操作HBase例子

HBase入门篇

最近访客更多访客>>