上一篇 通过单机的Hadoop伪分布式运行理解Hadoop运行过程 中已经对WordCount这个工具例子的运行过程进行了追踪。这里,主要通过查看日志,了解一下执行那样一个任务的一些细节信息,做一个总结。
其实,分析日志也是一个不错的方式。
启动Hadoop进程之后,即执行命令:
就已经针对各个进程的启动状态,生成了日志信息(位于G:\hadoop-0.16.4\logs目录下)。
下面,基本基于5个进程的启动的时间顺序来分析日志,以5个进程为标题,并围绕这5个进程来进行阐述。
一、NameNode启动
先看NameNode的日志文件hadoop-SHIYANJUN-namenode-cbbd2ce9428e48b.log信息如下:
2008-09-21 18:10:27,812 INFO org.apache.hadoop.dfs.NameNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting NameNode
STARTUP_MSG: host = cbbd2ce9428e48b/192.168.151.201
STARTUP_MSG: args = []
STARTUP_MSG: version = 0.16.4
STARTUP_MSG: build = -r 652614; compiled by 'hadoopqa' on Fri May 2 00:18:12 UTC 2008
************************************************************/
2008-09-21 18:10:28,375 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Initializing RPC Metrics with hostName=NameNode, port=9000
2008-09-21 18:10:28,421 INFO org.apache.hadoop.dfs.NameNode: Namenode up at: localhost/127.0.0.1:9000
2008-09-21 18:10:28,437 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=NameNode, sessionId=null
2008-09-21 18:10:28,640 INFO org.apache.hadoop.dfs.NameNodeMetrics: Initializing NameNodeMeterics using context object:org.apache.hadoop.metrics.spi.NullContext
2008-09-21 18:10:30,828 INFO org.apache.hadoop.fs.FSNamesystem: fsOwner=SHIYANJUN,None,root,Administrators,Users
2008-09-21 18:10:30,828 INFO org.apache.hadoop.fs.FSNamesystem: supergroup=supergroup
2008-09-21 18:10:30,828 INFO org.apache.hadoop.fs.FSNamesystem: isPermissionEnabled=true
2008-09-21 18:10:31,062 INFO org.apache.hadoop.fs.FSNamesystem: Finished loading FSImage in 2266 msecs
2008-09-21 18:10:31,078 INFO org.apache.hadoop.fs.FSNamesystem: Leaving safemode after 2282 msecs
2008-09-21 18:10:31,078 INFO org.apache.hadoop.dfs.StateChange: STATE* Network topology has 0 racks and 0 datanodes
2008-09-21 18:10:31,078 INFO org.apache.hadoop.dfs.StateChange: STATE* UnderReplicatedBlocks has 0 blocks
2008-09-21 18:10:31,093 INFO org.apache.hadoop.fs.FSNamesystem: Registered FSNamesystemStatusMBean
2008-09-21 18:10:31,359 INFO org.mortbay.util.Credential: Checking Resource aliases
2008-09-21 18:10:31,546 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-21 18:10:31,546 INFO org.mortbay.util.Container: Started HttpContext[/static,/static]
2008-09-21 18:10:31,546 INFO org.mortbay.util.Container: Started HttpContext[/logs,/logs]
2008-09-21 18:10:33,015 INFO org.mortbay.util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@94cb8b
2008-09-21 18:10:33,281 INFO org.mortbay.util.Container: Started WebApplicationContext[/,/]
2008-09-21 18:10:33,296 INFO org.mortbay.http.SocketListener: Started SocketListener on 0.0.0.0:50070
2008-09-21 18:10:33,296 INFO org.mortbay.util.Container: Started org.mortbay.jetty.Server@15c62bc
2008-09-21 18:10:33,296 INFO org.apache.hadoop.fs.FSNamesystem: Web-server up at: 0.0.0.0:50070
2008-09-21 18:10:33,359 INFO org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2008-09-21 18:10:33,390 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 0 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 1 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 3 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 4 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 9000: starting
2008-09-21 18:10:33,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 9000: starting
2008-09-21 18:10:33,781 INFO org.apache.hadoop.ipc.Server: IPC Server handler 7 on 9000: starting
2008-09-21 18:10:33,968 INFO org.apache.hadoop.ipc.Server: IPC Server handler 8 on 9000: starting
2008-09-21 18:10:33,968 INFO org.apache.hadoop.ipc.Server: IPC Server handler 9 on 9000: starting
通过日志分析,可以看到在这个过程中NameNode做了如下工作:
1、启动NameNode结点:Names结点在本机(具体为:localhost/127.0.0.1:9000)上启动。在真实分布式环境中NameNode与DaraNode不能在同一主机上,但是NameNode可以同JobTracer在同一主机上。
2、完成NameNode启动之后,需要做很多初始化工作:在本地文件系统FS中加载FSImage文件,可以在tmp\hadoop-SHIYANJUN\dfs\name\image下看到。
3、记录HDFS的状态:通过使用org.apache.hadoop.dfs.StateChange来实现HDFS状态的获取。
4、本机FS注册,并启动HDFS容器及其初始化上下文。同时在本机启动Web-server,建立Socket并进行监听(0.0.0.0:50070)。因为本机上设置了NameNode结点,在处理任务过程中需要接收DataNode结点的必要信息。
5、建立IPC(Internet Process Connection),为了让进程间通信而开放的命名管道,可以通过验证在远程管理计算机和查看计算机的共享资源时使用。其中,利用IPC可以与目标主机建立一个空的连接(无需用户名与密码)。NameNode结点需要与DataNode结点所在主机相互通讯,DataNode所在主机在执行数据处理任务而进行注册的时候,必须建立IPC连接。NameNode监听localhost/127.0.0.1:9000:9000端口,这个端口是我们在hadoop-site.xml中配置的:
<property>
<name>fs.default.name</name>
<value>localhost:9000</value>
</property>
属性fs.default.name对应的就是NameNode。
二、启动DataNode
当IPC建立完成以后,开始启动DataNode结点了,可以查看到DataNode的日志,在hadoop-SHIYANJUN-datanode-cbbd2ce9428e48b.log日志中的信息:
2008-09-21 18:10:52,453 INFO org.apache.hadoop.dfs.DataNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting DataNode
STARTUP_MSG: host = cbbd2ce9428e48b/192.168.151.201
STARTUP_MSG: args = []
STARTUP_MSG: version = 0.16.4
STARTUP_MSG: build = -r 652614; compiled by 'hadoopqa' on Fri May 2 00:18:12 UTC 2008
************************************************************/
2008-09-21 18:10:53,718 INFO org.apache.hadoop.dfs.Storage: Storage directory \tmp\hadoop-SYSTEM\dfs\data is not formatted.
2008-09-21 18:10:53,718 INFO org.apache.hadoop.dfs.Storage: Formatting ...
2008-09-21 18:10:54,328 INFO org.apache.hadoop.dfs.DataNode: Registered FSDatasetStatusMBean
2008-09-21 18:10:54,328 INFO org.apache.hadoop.dfs.DataNode: Opened server at 50010
2008-09-21 18:10:54,343 INFO org.apache.hadoop.dfs.DataNode: Balancing bandwith is 1048576 bytes/s
2008-09-21 18:10:54,671 INFO org.mortbay.util.Credential: Checking Resource aliases
2008-09-21 18:10:54,875 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-21 18:10:54,906 INFO org.mortbay.util.Container: Started HttpContext[/static,/static]
2008-09-21 18:10:54,906 INFO org.mortbay.util.Container: Started HttpContext[/logs,/logs]
2008-09-21 18:10:56,125 INFO org.mortbay.util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@1f0aecc
2008-09-21 18:10:56,390 INFO org.mortbay.util.Container: Started WebApplicationContext[/,/]
2008-09-21 18:10:56,421 INFO org.mortbay.http.SocketListener: Started SocketListener on 0.0.0.0:50075
2008-09-21 18:10:56,421 INFO org.mortbay.util.Container: Started org.mortbay.jetty.Server@5ddb6e
2008-09-21 18:10:57,343 INFO org.apache.hadoop.dfs.DataNode: New storage id DS-1069829945-192.168.151.201-50010-1221991857296 is assigned to data-node 127.0.0.1:50010
2008-09-21 18:10:57,375 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=DataNode, sessionId=null
2008-09-21 18:10:57,609 INFO org.apache.hadoop.dfs.DataNode: 127.0.0.1:50010In DataNode.run, data = FSDataset{dirpath='g:\tmp\hadoop-SYSTEM\dfs\data\current'}
2008-09-21 18:10:57,609 INFO org.apache.hadoop.dfs.DataNode: using BLOCKREPORT_INTERVAL of 3401027msec Initial delay: 60000msec
DataNode启动过程中做了如下工作:
1、启动DataNode结点之前,可以从启动信息中查看,与NameNode很相似。
2、格式化DataNode的文件系统,即tmp\hadoop-SYSTEM\dfs\data,这里,DataNode对应tmp\hadoop-SYSTEM\dfs目录下的data目录,而NameNode结点对应于tmp\hadoop-SHIYANJUN\dfs\name目录,真实分布式计算环境中,它们不是在同一主机上,这里模拟通过使用hadoop-SHIYANJUN和hadoop-SYSTEM来分离。
3、注册,启动Server,初始化上下文,建立Socket并进行监听(0.0.0.0:50075)。
4、启动DataNode,初始化其文件系统目录信息FSDataset{dirpath='g:\tmp\hadoop-SYSTEM\dfs\data\current'}。
在DataNode注册的过程中,他会向NameNode发送请求,同时等待NameNode回应,可以在NameNode的日志文件hadoop-SHIYANJUN-namenode-cbbd2ce9428e48b.log中根据时间线索信息查看到:
2008-09-21 18:10:57,312 INFO org.apache.hadoop.dfs.StateChange: BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:50010 storage DS-1069829945-192.168.151.201-50010-1221991857296
2008-09-21 18:10:57,328 INFO org.apache.hadoop.net.NetworkTopology: Adding a new node: /default-rack/127.0.0.1:50010
也就是上面DataNode启动了而且要注册,来自127.0.0.1:50010的注册请求信息就是指这个DataNode,同时,NameNode向默认机架( /default-rack/127.0.0.1:50010)添加一个新的结点。
之后,DataNode会即使向NameNode提交实时报告信息,可以查看DataNode的日志,依据时间线索信息在hadoop-SHIYANJUN-datanode-cbbd2ce9428e48b.log日志中的信息:
2008-09-21 18:10:58,718 INFO org.apache.hadoop.dfs.DataNode: BlockReport of 0 blocks got processed in 15 msecs
2008-09-21 18:39:20,000 INFO org.apache.hadoop.dfs.DataNode: BlockReport of 0 blocks got processed in 16 msecs
进行了两次报告,表示没有获取到要处理的数据块(Block)。
三、启动SecondaryNameNode
在DataNode启动完成时候,通过SecondaryNameNode的日志,可以在hadoop-SHIYANJUN-secondarynamenode-cbbd2ce9428e48b.log日志文件中看到:
2008-09-21 18:11:23,312 INFO org.apache.hadoop.dfs.NameNode.Secondary: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting SecondaryNameNode
STARTUP_MSG: host = cbbd2ce9428e48b/192.168.151.201
STARTUP_MSG: args = []
STARTUP_MSG: version = 0.16.4
STARTUP_MSG: build = -r 652614; compiled by 'hadoopqa' on Fri May 2 00:18:12 UTC 2008
************************************************************/
2008-09-21 18:11:23,765 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=SecondaryNameNode, sessionId=null
2008-09-21 18:11:24,906 INFO org.mortbay.util.Credential: Checking Resource aliases
2008-09-21 18:11:25,312 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-21 18:11:25,312 INFO org.mortbay.util.Container: Started HttpContext[/static,/static]
2008-09-21 18:11:25,312 INFO org.mortbay.util.Container: Started HttpContext[/logs,/logs]
2008-09-21 18:11:26,765 INFO org.mortbay.util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@16ea269
2008-09-21 18:11:27,234 INFO org.mortbay.util.Container: Started WebApplicationContext[/,/]
2008-09-21 18:11:27,312 INFO org.mortbay.http.SocketListener: Started SocketListener on 0.0.0.0:50090
2008-09-21 18:11:27,312 INFO org.mortbay.util.Container: Started org.mortbay.jetty.Server@b754b2
2008-09-21 18:11:27,312 INFO org.apache.hadoop.dfs.NameNode.Secondary: Secondary Web-server up at: 0.0.0.0:50090
2008-09-21 18:11:27,328 WARN org.apache.hadoop.dfs.NameNode.Secondary: Checkpoint Directory:\tmp\hadoop-SYSTEM\dfs\namesecondary
2008-09-21 18:11:27,328 WARN org.apache.hadoop.dfs.NameNode.Secondary: Checkpoint Period :3600 secs (60 min)
2008-09-21 18:11:27,328 WARN org.apache.hadoop.dfs.NameNode.Secondary: Log Size Trigger :67108864 bytes (65536 KB)
SecondaryNameNode启动过程中所做的工作如下:
1、启动SecondaryNameNode之前,处理一些基本信息,可以查看日志中STARTUP_MSG。
2、建立IPC连接,初始化上下文,建立Socket连接,并进行监听(0.0.0.0:50090)。
3、建立Checkpoint Directory:\tmp\hadoop-SYSTEM\dfs\namesecondary,创建org.apache.hadoop.dfs.NameNode.Secondary: Log Size Trigger。
四、启动JobTracer
然后,JobTracer要启动了,可以分析其对应的日志信息,在hadoop-SHIYANJUN-jobtracker-cbbd2ce9428e48b.log日志文件中可以看到:
2008-09-21 18:11:40,890 INFO org.apache.hadoop.mapred.JobTracker: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting JobTracker
STARTUP_MSG: host = cbbd2ce9428e48b/192.168.151.201
STARTUP_MSG: args = []
STARTUP_MSG: version = 0.16.4
STARTUP_MSG: build = -r 652614; compiled by 'hadoopqa' on Fri May 2 00:18:12 UTC 2008
************************************************************/
2008-09-21 18:11:41,515 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Initializing RPC Metrics with hostName=JobTracker, port=9001
2008-09-21 18:11:41,578 INFO org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2008-09-21 18:11:41,578 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 9001: starting
2008-09-21 18:11:41,578 INFO org.apache.hadoop.ipc.Server: IPC Server handler 0 on 9001: starting
2008-09-21 18:11:41,578 INFO org.apache.hadoop.ipc.Server: IPC Server handler 1 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 3 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 4 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 7 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 8 on 9001: starting
2008-09-21 18:11:41,593 INFO org.apache.hadoop.ipc.Server: IPC Server handler 9 on 9001: starting
2008-09-21 18:11:41,875 INFO org.mortbay.util.Credential: Checking Resource aliases
2008-09-21 18:11:42,031 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-21 18:11:42,031 INFO org.mortbay.util.Container: Started HttpContext[/static,/static]
2008-09-21 18:11:42,031 INFO org.mortbay.util.Container: Started HttpContext[/logs,/logs]
2008-09-21 18:11:43,265 INFO org.mortbay.util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@b4be3d
2008-09-21 18:11:43,640 INFO org.mortbay.util.Container: Started WebApplicationContext[/,/]
2008-09-21 18:11:43,718 INFO org.mortbay.http.SocketListener: Started SocketListener on 0.0.0.0:50030
2008-09-21 18:11:43,718 INFO org.mortbay.util.Container: Started org.mortbay.jetty.Server@90832e
2008-09-21 18:11:43,718 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=JobTracker, sessionId=
2008-09-21 18:11:44,218 INFO org.apache.hadoop.mapred.JobTracker: JobTracker up at: 9001
2008-09-21 18:11:44,218 INFO org.apache.hadoop.mapred.JobTracker: JobTracker webserver: 50030
2008-09-21 18:11:47,390 INFO org.apache.hadoop.mapred.JobTracker: Starting RUNNING
JobTracer启动过程中所做的工作如下:
1、启动JobTracer之前,处理一些基本信息,可以查看日志中STARTUP_MSG。
2、建立IPC连接,初始化上下文,建立Socket连接,并进行监听(0.0.0.0:50030)。JobTracker设置的是本地9001端口,这个端口号我们在hadoop-site.xml中配置的:
<property>
<name>mapred.job.tracker</name>
<value>localhost:9001</value>
</property>
3、启动并运行JobTracer。
JobTracer建立了IPC连接,此时NameNode结点主机已经接收到这个信息,同时给予响应,可以看NameNode的日志文件hadoop-SHIYANJUN-namenode-cbbd2ce9428e48b.log,根据时间线索信息:
2008-09-21 18:11:47,250 WARN org.apache.hadoop.dfs.StateChange: DIR* FSDirectory.unprotectedDelete: failed to remove /tmp/hadoop-SHIYANJUN/mapred/system because it does not exist
2008-09-21 18:11:47,250 INFO org.apache.hadoop.fs.FSNamesystem: Number of transactions: 0 Total time for transactions(ms): 0 Number of syncs: 0 SyncTimes(ms): 0
因为启动了JobTracer,可以进行任务的分配和调度了,NameNode将HDFS的状态变化信息登录到日志。这里,JobTracer和NameNode是在同一主机上配置的,可以在tmp\hadoop-SHIYANJUN\mapred\local目录中看到建立的JobTracer目录。
五、启动TaskTracker
接着,TaskTracer就要启动了。可以查看TaskTracer的日志文件,可以在hadoop-SHIYANJUN-tasktracker-cbbd2ce9428e48b.log文件中查看到:
2008-09-21 18:11:58,718 INFO org.apache.hadoop.mapred.TaskTracker: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting TaskTracker
STARTUP_MSG: host = cbbd2ce9428e48b/192.168.151.201
STARTUP_MSG: args = []
STARTUP_MSG: version = 0.16.4
STARTUP_MSG: build = -r 652614; compiled by 'hadoopqa' on Fri May 2 00:18:12 UTC 2008
************************************************************/
2008-09-21 18:11:59,625 INFO org.mortbay.util.Credential: Checking Resource aliases
2008-09-21 18:12:00,890 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-21 18:12:00,906 INFO org.mortbay.util.Container: Started HttpContext[/static,/static]
2008-09-21 18:12:00,906 INFO org.mortbay.util.Container: Started HttpContext[/logs,/logs]
2008-09-21 18:12:01,984 INFO org.mortbay.util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@b754b2
2008-09-21 18:12:02,187 INFO org.mortbay.util.Container: Started WebApplicationContext[/,/]
2008-09-21 18:12:02,203 INFO org.mortbay.http.SocketListener: Started SocketListener on 0.0.0.0:50060
2008-09-21 18:12:02,203 INFO org.mortbay.util.Container: Started org.mortbay.jetty.Server@1e3118a
2008-09-21 18:12:02,281 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=TaskTracker, sessionId=
2008-09-21 18:12:02,515 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Initializing RPC Metrics with hostName=TaskTracker, port=4881
2008-09-21 18:12:02,718 INFO org.apache.hadoop.ipc.Server: IPC Server Responder: starting
2008-09-21 18:12:02,718 INFO org.apache.hadoop.mapred.TaskTracker: TaskTracker up at: localhost/127.0.0.1:4881
2008-09-21 18:12:02,718 INFO org.apache.hadoop.mapred.TaskTracker: Starting tracker tracker_cbbd2ce9428e48b:localhost/127.0.0.1:4881
2008-09-21 18:12:02,718 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 4881: starting
2008-09-21 18:12:02,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 0 on 4881: starting
2008-09-21 18:12:02,718 INFO org.apache.hadoop.ipc.Server: IPC Server handler 1 on 4881: starting
2008-09-21 18:12:02,937 INFO org.apache.hadoop.mapred.TaskTracker: Starting thread: Map-events fetcher for all reduce tasks on tracker_cbbd2ce9428e48b:localhost/127.0.0.1:4881
TaskTracer启动过程中所做的工作如下:
1、启动TaskTracer之前,处理一些基本信息,可以查看日志中STARTUP_MSG。
2、建立IPC连接,初始化上下文,建立Socket连接,并进行监听(0.0.0.0:50060)。TaskTracer设置的是localhost/127.0.0.1:4881。
3、启动并运行TaskTracer:TaskTracer启动了用于进行Map任务的线程,准备对待处理数据进行Map任务处理工作。
空闲状态
到目前为止,所有的进行任务的进程都已经处于就绪状态,只要Master执行任务的分配和调度,各个进程就开始进行工作了。
查看NameNode的日志文件,在hadoop-SHIYANJUN-namenode-cbbd2ce9428e48b.log文件中,根据时间线索信息,可以看到:
2008-09-21 18:16:27,640 INFO org.apache.hadoop.fs.FSNamesystem: Roll Edit Log from 127.0.0.1
2008-09-21 18:16:27,640 INFO org.apache.hadoop.fs.FSNamesystem: Number of transactions: 5 Total time for transactions(ms): 0 Number of syncs: 3 SyncTimes(ms): 62
当前Hadoop系统所处的状态,NameNode实时检测。
这时,SecondaryNameNode已经处于运作状态了,通过SecondaryNameNode的日志,可以在hadoop-SHIYANJUN-secondarynamenode-cbbd2ce9428e48b.log日志文件中,根据时间线索信息,看到:
2008-09-21 18:16:28,546 INFO org.apache.hadoop.dfs.NameNode.Secondary: Downloaded file \tmp\hadoop-SYSTEM\dfs\namesecondary\srcimage.tmp size 16 bytes.
2008-09-21 18:16:28,609 INFO org.apache.hadoop.dfs.NameNode.Secondary: Downloaded file \tmp\hadoop-SYSTEM\dfs\namesecondary\edits.tmp size 312 bytes.
2008-09-21 18:16:29,640 INFO org.apache.hadoop.fs.FSNamesystem: fsOwner=SHIYANJUN,None,root,Administrators,Users
2008-09-21 18:16:29,656 INFO org.apache.hadoop.fs.FSNamesystem: supergroup=supergroup
2008-09-21 18:16:29,656 INFO org.apache.hadoop.fs.FSNamesystem: isPermissionEnabled=true
2008-09-21 18:16:29,765 INFO org.apache.hadoop.dfs.NameNode.Secondary: Posted URL 0.0.0.0:50070putimage=1&port=50090&machine=192.168.151.201&token=1221992188000
2008-09-21 18:16:30,031 INFO org.apache.hadoop.dfs.NameNode.Secondary: New Image \tmp\hadoop-SYSTEM\dfs\namesecondary\destimage.tmp retrieved by Namenode.
2008-09-21 18:16:30,328 WARN org.apache.hadoop.dfs.NameNode.Secondary: Checkpoint done. Image Size:16 Edit Size:312 New Image Size:292
从上面可以看到,SecondaryNameNode进程执行下载任务,下载了2个文件:tmp\hadoop-SYSTEM\dfs\namesecondary\srcimage.tmp和tmp\hadoop-SYSTEM\dfs\namesecondary\edits.tmp,可以到本地文件系统中查看到的。
因为在真实的分布式计算环境中,SecondaryNameNode和NameNode不在同一个主机上,例如在WordCount这个工具的例子中,SecondaryNameNode是在DataNode所在的主机上,它在请求下载文件的时候,与NameNode所在主机多次进行通信,在通讯过程中需要处理认证问题的。
NameNode进程继续检测Hadoop系统状态:
2008-09-21 18:16:30,171 INFO org.apache.hadoop.fs.FSNamesystem: Roll FSImage from 127.0.0.1
2008-09-21 18:16:30,171 INFO org.apache.hadoop.fs.FSNamesystem: Number of transactions: 0 Total time for transactions(ms): 0 Number of syncs: 0 SyncTimes(ms): 0
现在,可以输入命令开始执行任务(比如复制任务)了。