Re: Exceptions when starting hadoop

[Brian Bockelman]

On Sep 27, 2009, at 1:53 AM, Zheng Lv wrote:

Hello Starry,
   Thank you for your reply. As you said, last time we changed the

to startup the hadoop system. Isn't it too long? Before the startup is
finished, if we run "hadoop/bin/hadoop dfs -ls /", it will be waiting

cluster, removing a datanode form the cluster. And today we have built a whole new cluster. But when we ran "start-all.sh", it took several minutes forever. Following is the log on namenode server, is it normal? Thanks.

Hey Zheng,







Brian

Did you try starting up the datanodes by hand? How long does it take to SSH between nodes? Look at your original set of logs - it's almost 2 minutes from the time the namenode java process is launched and the datanode java process is launched. It looks like there's an issue with SSH or some other system issue on your cluster; i.e., doesn't appear to be a Hadoop issue. It also appears that you did not attempt to run ls until 9 minutes after you started up your cluster. It may be that you are typing things into your terminal incorrectly.

   2009-09-27 11:52:38,190 INFO
org.apache.hadoop.hdfs.server.namenode.NameNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting NameNode
STARTUP_MSG:   host = ubuntu6/192.168.33.7
STARTUP_MSG:   args = []
STARTUP_MSG:   version = 0.20.0
STARTUP_MSG:   build =

https://svn.apache.org/repos/asf/hadoop/core/branches/branch-0.20 -r 763504;

compiled by 'ndaley' on Thu Apr  9 05:18:40 UTC 2009
************************************************************/
2009-09-27 11:52:38,284 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
Initializing RPC Metrics with hostName=NameNode, port=9000
2009-09-27 11:52:38,288 INFO

192.168.33.7:9000
2009-09-27 11:52:38,290 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
Initializing JVM Metrics with processName=NameNode, sessionId=null
2009-09-27 11:52:38,291 INFO

NameNodeMeterics using context object:org.apache.had
oop.metrics.spi.NullContext
2009-09-27 11:52:38,373 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
fsOwner=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin
2009-09-27 11:52:38,373 INFO

2009-09-27 11:52:38,373 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
isPermissionEnabled=true
2009-09-27 11:52:38,380 INFO
org.apache.hadoop.hdfs.server.namenode.metrics.FSNamesystemMetrics:
Initializing FSNamesystemMetrics using context object:org.apa
che.hadoop.metrics.spi.NullContext
2009-09-27 11:52:38,381 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Registered
FSNamesystemStatusMBean

Number of files = 1

Number of files under construction = 0

Image file of size 93 loaded in 0 seconds.
2009-09-27 11:52:38,417 INFO

end of edit log Number of transactions found 9

loaded in 0
seconds.

Image file of size 541 saved in 0 seconds.
2009-09-27 11:52:38,587 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Finished loading
FSImage in 269 msecs

mode ON.

Safe mode will be turned off automatically.
2009-09-27 11:52:43,972 INFO org.mortbay.log: Logging to
org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
org.mortbay.log.Slf4jLog

to port 50070
2009-09-27 11:52:44,138 INFO org.mortbay.log: jetty-6.1.14
2009-09-27 11:53:44,318 INFO org.mortbay.log: Started
selectchannelconnec...@0.0.0.0:50070
2009-09-27 11:53:44,319 INFO
org.apache.hadoop.hdfs.server.namenode.NameNode: Web-server up at:
0.0.0.0:50070
2009-09-27 11:53:44,320 INFO org.apache.hadoop.ipc.Server: IPC Server
Responder: starting
2009-09-27 11:53:44,321 INFO org.apache.hadoop.ipc.Server: IPC Server
listener on 9000: starting
2009-09-27 11:53:44,350 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 0 on 9000: starting
2009-09-27 11:53:44,366 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 1 on 9000: starting
2009-09-27 11:53:44,366 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 2 on 9000: starting
2009-09-27 11:53:44,367 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 3 on 9000: starting
2009-09-27 11:53:44,367 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 4 on 9000: starting
2009-09-27 11:53:44,368 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 5 on 9000: starting
2009-09-27 11:53:44,368 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 6 on 9000: starting
2009-09-27 11:53:44,369 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 7 on 9000: starting
2009-09-27 11:53:44,369 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 8 on 9000: starting
2009-09-27 11:53:44,370 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 9 on 9000: starting

NameSystem.registerDatanode: node registration from
192.168.33.6:50010storage DS-3923
30531-192.168.33.6-50010-1254023159672

new node: /default-rack/192.168.33.6:50010

mode extension entered.

mode will be turned off automatically in 29 seconds.

mode ON.

mode will be turned off automatically in 9 seconds.
2009-09-27 11:57:02,092 INFO

= 1
2009-09-27 11:57:02,092 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of invalid
blocks = 0
2009-09-27 11:57:02,092 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
under-replicated blocks = 1
2009-09-27 11:57:02,092 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
over-replicated blocks = 0

Leaving safe mode after 263 secs.

mode is OFF.

Network topology has 1 racks and 1 datanodes

UnderReplicatedBlocks has 1 blocks

NameSystem.registerDatanode: node registration from
192.168.33.8:50010storage DS-1578
942809-192.168.33.8-50010-1254023408249

new node: /default-rack/192.168.33.8:50010

blk_234235
2795116225569_1001 size 4

NameSystem.registerDatanode: node registration from
192.168.33.5:50010storage DS-7945
10456-192.168.33.5-50010-1254023267768

new node: /default-rack/192.168.33.5:50010
2009-09-27 12:00:02,336 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=listStatus  src=/tmp/hadoop-cyd/mapred/system
dst=null        perm=null

of 192.168
.33.6:50010

of 192.168
.33.8:50010
2009-09-27 12:00:02,349 INFO

1 Total time for transactions(ms): 1Number of transa
ctions batched in Syncs: 0 Number of syncs: 0 SyncTimes(ms): 0
2009-09-27 12:00:02,384 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=delete      src=/tmp/hadoop-cyd/mapred/system
dst=null        perm=null
2009-09-27 12:00:02,400 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=mkdirs      src=/tmp/hadoop-cyd/mapred/system
dst=null        perm=cyd:supergroup:rwxr-xr-x
2009-09-27 12:00:02,408 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=setPermission
src=/tmp/hadoop-cyd/mapred/system       dst=null
perm=cyd:supergroup:rwx-wx-wx
2009-09-27 12:00:02,432 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=create      src=/tmp/hadoop-cyd/mapred/system/
jobtracker.info       dst=null        perm=cyd:supergroup:rw-r--r--
2009-09-27 12:00:02,440 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19

jobtracker.info       dst=null        perm=cyd:supergroup:rw-------

blk_-69940863
0358636044_1002

blk_-69940
8630358636044_1002 size 4

blk_-69940
8630358636044_1002 size 4

192.168.33.8:50010 to delete  blk_2342352795116225569_1001

192.168.33.6:50010 to delete  blk_2342352795116225569_1001
2009-09-27 12:03:49,176 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin  ip=/19
2.168.33.7      cmd=listStatus  src=/   dst=null        perm=null



2009/9/26 Starry SHI <starr...@gmail.com>

org.apache.hadoop.hdfs.server.namenode.NameNode: Namenode up at: ubuntu6/ org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics: Initializing org.apache.hadoop.hdfs.server.namenode.FSNamesystem: supergroup=supergroup 2009-09-27 11:52:38,407 INFO org.apache.hadoop.hdfs.server.common.Storage: 2009-09-27 11:52:38,411 INFO org.apache.hadoop.hdfs.server.common.Storage: 2009-09-27 11:52:38,411 INFO org.apache.hadoop.hdfs.server.common.Storage: org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Invalid opcode, reached 2009-09-27 11:52:38,417 INFO org.apache.hadoop.hdfs.server.common.Storage: Edits file /home/cyd/hdfs2/name/current/edits of size 1049092 edits # 9 2009-09-27 11:52:38,462 INFO org.apache.hadoop.hdfs.server.common.Storage: 2009-09-27 11:52:38,602 INFO org.apache.hadoop.hdfs.StateChange: STATE* Safe The ratio of reported blocks 0.0000 has not reached the threshold 0.9990. 2009-09-27 11:52:44,138 INFO org.apache.hadoop.http.HttpServer: Jetty bound 2009-09-27 11:56:32,036 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* 2009-09-27 11:56:32,043 INFO org.apache.hadoop.net.NetworkTopology: Adding a 2009-09-27 11:56:32,086 INFO org.apache.hadoop.hdfs.StateChange: STATE* Safe The ratio of reported blocks 1.0000 has reached the threshold 0.9990. Safe 2009-09-27 11:56:52,090 INFO org.apache.hadoop.hdfs.StateChange: STATE* Safe The ratio of reported blocks 1.0000 has reached the threshold 0.9990. Safe org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Total number of blocks 2009-09-27 11:57:02,093 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-27 11:57:02,093 INFO org.apache.hadoop.hdfs.StateChange: STATE* Safe 2009-09-27 11:57:02,093 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-27 11:57:02,093 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-27 11:59:00,157 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* 2009-09-27 11:59:00,158 INFO org.apache.hadoop.net.NetworkTopology: Adding a 2009-09-27 11:59:00,192 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.33.8:50010 is added to 2009-09-27 11:59:20,745 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* 2009-09-27 11:59:20,746 INFO org.apache.hadoop.net.NetworkTopology: Adding a 2009-09-27 12:00:02,346 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2342352795116225569 is added to invalidSet 2009-09-27 12:00:02,346 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2342352795116225569 is added to invalidSet org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: 2.168.33.7 cmd=setPermission src=/tmp/hadoop-cyd/mapred/ system/ 2009-09-27 12:00:02,445 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/hadoop-cyd/mapred/system/ jobtracker.info. 2009-09-27 12:00:02,593 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.33.6:50010 is added to 2009-09-27 12:00:02,600 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.33.5:50010 is added to 2009-09-27 12:00:02,644 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 2009-09-27 12:00:05,644 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask

Is that the first time you start your cluster? My experience is that, when you start the cluster once, then change the conf (say, add another slave), and restart your cluster, it sometimes generate some IPC issues (like the timeout in the namenode log). This change will cause the filesystem into

safe mode so there will be the exceptions.


then your cluster should be started.

Hope this can help.

Best regards,
Starry

/* Tomorrow is another day. So is today. */

The exception in your NN log is caused when the cluster was trying to add a new node but reached a timeout. If you have changed your cluster conf, you can use "hadoop namenode format" to format the filesystem and then start, On Sat, Sep 26, 2009 at 09:03, Zheng Lv <lvzheng19800...@gmail.com> wrote:

No one can give some suggestions?

2009/9/25 Zheng Lv <lvzheng19800...@gmail.com>

Hello Everyone,

these logs when starting hadoop0.20. Is it normal?
   2009-09-25 10:45:00,616 INFO
org.apache.hadoop.hdfs.server.namenode.NameNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting NameNode
STARTUP_MSG:   host = ubuntu6/192.168.33.7
STARTUP_MSG:   args = []
STARTUP_MSG:   version = 0.20.1-dev
STARTUP_MSG:   build =  -r ; compiled by 'cyd' on 2009?ê 08?? 07??

We have a cluster with one namenode and three datanodes. And we got

??????

15:20:16 CST
************************************************************/

Initializing RPC Metrics with hostName=NameNode, port=9000
2009-09-25 10:45:00,767 INFO
org.apache.hadoop.hdfs.server.namenode.NameNode: Namenode up at:

2009-09-25 10:45:00,721 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:

ubuntu6/

192.168.33.7:9000

Initializing JVM Metrics with processName=NameNode, sessionId=null
2009-09-25 10:45:00,771 INFO
org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics:

2009-09-25 10:45:00,769 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:

Initializing

NameNodeMeterics using context
object:org.apache.hadoop.metrics.spi.NullContext
2009-09-25 10:45:00,835 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
fsOwner=cyd,cyd,adm,dialout,cdrom,plugdev,lpadmin,sambashare,admin
2009-09-25 10:45:00,835 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem:

supergroup=supergroup

2009-09-25 10:45:00,835 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
isPermissionEnabled=true
2009-09-25 10:45:00,842 INFO
org.apache.hadoop.hdfs.server.namenode.metrics.FSNamesystemMetrics:
Initializing FSNamesystemMetrics using context
object:org.apache.hadoop.metrics.spi.NullContext
2009-09-25 10:45:00,843 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Registered
FSNamesystemStatusMBean
2009-09-25 10:45:00,871 INFO

org.apache.hadoop.hdfs.server.common.Storage:

Number of files = 2834
2009-09-25 10:45:01,412 INFO

org.apache.hadoop.hdfs.server.common.Storage:

Number of files under construction = 1
2009-09-25 10:45:01,416 INFO

org.apache.hadoop.hdfs.server.common.Storage:

Image file of size 329240 loaded in 0 seconds.
2009-09-25 10:45:01,417 INFO

org.apache.hadoop.hdfs.server.common.Storage:

Edits file /home/cyd/hdfs2/name/current/edits of size 4 edits # 0

loaded

in

0 seconds.
2009-09-25 10:45:01,683 INFO

org.apache.hadoop.hdfs.server.common.Storage:

Image file of size 329240 saved in 0 seconds.
2009-09-25 10:45:01,805 INFO

FSImage in 1007 msecs

Safe mode ON.
The ratio of reported blocks 0.0000 has not reached the threshold

org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Finished loading 2009-09-25 10:45:01,821 INFO org.apache.hadoop.hdfs.StateChange: STATE*

0.9990.

Safe mode will be turned off automatically.
2009-09-25 10:45:07,162 INFO org.mortbay.log: Logging to
org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
org.mortbay.log.Slf4jLog

2009-09-25 10:45:07,228 INFO org.apache.hadoop.http.HttpServer: Jetty

bound

to port 50070
2009-09-25 10:45:07,229 INFO org.mortbay.log: jetty-6.1.14
2009-09-25 10:47:34,305 INFO org.mortbay.log: Started
selectchannelconnec...@0.0.0.0:50070
2009-09-25 10:47:34,319 INFO
org.apache.hadoop.hdfs.server.namenode.NameNode: Web-server up at:
0.0.0.0:50070

Responder: starting

listener on 9000: starting

handler 0 on 9000: starting

handler 1 on 9000: starting

handler 2 on 9000: starting

handler 3 on 9000: starting

handler 5 on 9000: starting

handler 4 on 9000: starting

handler 6 on 9000: starting

Responder, call

2009-09-25 10:47:34,320 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,321 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,355 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,355 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,356 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,356 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,384 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,397 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,398 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,400 WARN org.apache.hadoop.ipc.Server: IPC Server getProtocolVersion (org.apache.hadoop.hdfs.protocol.ClientProtocol, 41)

from

192.168.33.7:54977: output error

handler 7 on 9000: starting

handler 8 on 9000: starting

handler 9 on 9000: starting

handler 1 on 9000 caught: java.nio.channels.ClosedChannelException
       at

2009-09-25 10:47:34,401 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,402 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,404 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:47:34,433 INFO org.apache.hadoop.ipc.Server: IPC Server

sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java: 126)

       at

sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)

at org.apache.hadoop.ipc.Server.channelWrite(Server.java: 1195)

       at org.apache.hadoop.ipc.Server.access$1900(Server.java:77)
       at

       at
org.apache.hadoop.ipc.Server$Responder.doRespond(Server.java:677)
       at org.apache.hadoop.ipc.Server$Handler.run(Server.java:981)

org.apache.hadoop.ipc.Server$Responder.processResponse (Server.java:613) 2009-09-25 10:48:09,304 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.registerDatanode: node registration from 192.168.33.5:50010

storage

DS-1782592326-192.168.33.5-50010-1253784633678

2009-09-25 10:48:09,311 INFO org.apache.hadoop.net.NetworkTopology:

Adding

a new node: /default-rack/192.168.33.5:50010

Safe mode ON.
The ratio of reported blocks 0.0005 has not reached the threshold

2009-09-25 10:48:09,920 INFO org.apache.hadoop.hdfs.StateChange: STATE*

0.9990.

Safe mode will be turned off automatically.

Safe mode extension entered.

2009-09-25 10:48:09,985 INFO org.apache.hadoop.hdfs.StateChange: STATE* The ratio of reported blocks 0.9990 has reached the threshold 0.9990.

Safe

mode will be turned off automatically in 29 seconds.

Safe mode ON.

2009-09-25 10:48:29,989 INFO org.apache.hadoop.hdfs.StateChange: STATE* The ratio of reported blocks 1.0000 has reached the threshold 0.9990.

Safe

mode will be turned off automatically in 9 seconds.

2009-09-25 10:48:32,412 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.registerDatanode: node registration from 192.168.33.6:50010

storage

DS-119886468-192.168.33.6-50010-1253784635966

2009-09-25 10:48:32,412 INFO org.apache.hadoop.net.NetworkTopology:

Adding

a new node: /default-rack/192.168.33.6:50010
2009-09-25 10:48:40,147 INFO

org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Total number of

blocks

= 2052
2009-09-25 10:48:40,147 INFO

blocks = 0
2009-09-25 10:48:40,147 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
under-replicated blocks = 2051
2009-09-25 10:48:40,147 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
over-replicated blocks = 0

Leaving safe mode after 219 secs.

Safe mode is OFF.

Network topology has 1 racks and 2 datanodes

UnderReplicatedBlocks has 2051 blocks

org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of invalid 2009-09-25 10:48:40,147 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-25 10:48:40,147 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-25 10:48:40,148 INFO org.apache.hadoop.hdfs.StateChange: STATE* 2009-09-25 10:48:40,148 INFO org.apache.hadoop.hdfs.StateChange: STATE* I noticed the exceptions and "org.apache.hadoop.hdfs.StateChange: STATE* Network topology has 1 racks and 2 datanodes".Sometimes it tells

1

datanodes, and sometimes 2, but we have 3.Please give some suggestions,

thank you.



   Following is logs in one of datanodes:
   2009-09-25 10:47:22,110 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: Registered
FSDatasetStatusMBean
2009-09-25 10:47:22,112 INFO

org.apache.hadoop.hdfs.server.datanode.DataNode: Opened info server at

50010

2009-09-25 10:47:22,114 INFO

1048576 bytes/s
2009-09-25 10:47:27,257 INFO org.mortbay.log: Logging to
org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
org.mortbay.log.Slf4jLog

org.apache.hadoop.hdfs.server.datanode.DataNode: Balancing bandwith is 2009-09-25 10:47:27,434 INFO org.apache.hadoop.http.HttpServer: Jetty

bound

to port 50075
2009-09-25 10:47:27,434 INFO org.mortbay.log: jetty-6.1.14
2009-09-25 10:48:14,324 INFO org.mortbay.log: Started
selectchannelconnec...@0.0.0.0:50075

Initializing JVM Metrics with processName=DataNode, sessionId=null

Initializing RPC Metrics with hostName=DataNode, port=50020

Responder: starting

listener on 50020: starting

handler 0 on 50020: starting

handler 1 on 50020: starting

handler 2 on 50020: starting

handler 3 on 50020: starting

handler 4 on 50020: starting

handler 5 on 50020: starting

handler 6 on 50020: starting

handler 7 on 50020: starting

handler 8 on 50020: starting

handler 9 on 50020: starting

handler 10 on 50020: starting

handler 11 on 50020: starting

handler 12 on 50020: starting

handler 13 on 50020: starting

handler 14 on 50020: starting

handler 15 on 50020: starting

handler 16 on 50020: starting

handler 17 on 50020: starting

handler 18 on 50020: starting

handler 19 on 50020: starting

handler 20 on 50020: starting

handler 21 on 50020: starting

handler 22 on 50020: starting

handler 23 on 50020: starting

handler 24 on 50020: starting

handler 25 on 50020: starting

handler 26 on 50020: starting

handler 27 on 50020: starting

handler 28 on 50020: starting

handler 29 on 50020: starting

handler 30 on 50020: starting

handler 31 on 50020: starting
2009-09-25 10:48:19,391 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: dnRegistration =
DatanodeRegistration(ubuntu7:50010,
storageID=DS-119886468-192.168.33.6-50010-1253784635966,

2009-09-25 10:48:14,334 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: 2009-09-25 10:48:19,369 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: 2009-09-25 10:48:19,376 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,376 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,378 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,380 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,380 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,381 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,381 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,381 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,382 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,382 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,382 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,383 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,383 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,383 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,384 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,384 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,385 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,385 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,385 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,386 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,386 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,386 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,387 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,387 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,388 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,388 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,388 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,388 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,389 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,389 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,390 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,390 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,390 INFO org.apache.hadoop.ipc.Server: IPC Server 2009-09-25 10:48:19,391 INFO org.apache.hadoop.ipc.Server: IPC Server

infoPort=50075,

ipcPort=50020)
2009-09-25 10:48:19,434 INFO

192.168.33.6:50010,
storageID=DS-119886468-192.168.33.6-50010-1253784635966,

org.apache.hadoop.hdfs.server.datanode.DataNode: DatanodeRegistration(

infoPort=50075,

ipcPort=50020)In DataNode.run, data =
FSDataset{dirpath='/home/cyd/hdfs2/data/current'}
2009-09-25 10:48:19,456 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: using

BLOCKREPORT_INTERVAL

of 3600000msec Initial delay: 0msec
2009-09-25 10:48:19,950 INFO

org.apache.hadoop.hdfs.server.datanode.DataNode: BlockReport of 2052

blocks

got processed in 458 msecs
2009-09-25 10:48:19,951 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: Starting Periodic

block

scanner.
2009-09-25 10:48:20,601 INFO

succeeded for blk_2990263655324635865_9556
2009-09-25 10:48:58,692 INFO

org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification org.apache.hadoop.hdfs.server.datanode.DataNode: BlockReport of 2052

blocks

got processed in 224 msecs
2009-09-25 10:51:07,955 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block
blk_-1955286602120745744_18039 src: /192.168.33.5:43889 dest: /
192.168.33.6:50010
2009-09-25 10:51:07,982 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: /
192.168.33.5:43889, dest: /192.168.33.6:50010, bytes: 4, op:

HDFS_WRITE,

cliID: DFSClient_2050853952, srvID:
DS-119886468-192.168.33.6-50010-1253784635966, blockid:
blk_-1955286602120745744_18039
2009-09-25 10:51:07,983 INFO

org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for

block

blk_-1955286602120745744_18039 terminating
2009-09-25 10:51:10,742 INFO
org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block
blk_-6733538557527582040_18038 file
/home/cyd/hdfs2/data/current/blk_-6733538557527582040
2009-09-25 10:56:45,523 INFO

succeeded for blk_-8204684875565980176_3413
2009-09-25 11:03:06,572 INFO

succeeded for blk_8093352211012570299_17220
2009-09-25 11:10:28,649 INFO

succeeded for blk_-6978381366409301329_8279

Thanks a lot,
LvZheng

org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification

smime.p7s
Description: S/MIME cryptographic signature