I've attached the log.
One more thing I'll add is that the the stop-hbase.sh script hangs hangs on
the "stopping master..." line so I had to manually kill the Hmaster process
before doing a restart.
On 8/13/10 5:00 PM, "Jean-Daniel Cryans" <[email protected]> wrote:
> A clean log of a full master startup would be really useful, can't
> tell much more by the current info you provided.
>
> J-D
>
> On Fri, Aug 13, 2010 at 4:50 PM, Marchwiak, Patrick D.
> <[email protected]> wrote:
>> I am having issues performing any operations (list/create/put) on my hbase
>> instance once it starts up.
>>
>> The environment:
>> Red Hat 5.5
>> Hadoop 0.20.2
>> HBase 0.20.4
>> java 1.6.0_20
>> 1 running master
>> 23 running regionserver + 3 also running zookeeper
>>
>> When attemting to do a list from the hbase shell it returns this error:
>> NativeException: org.apache.hadoop.hbase.MasterNotRunningException: null
>>
>> When attempting to perform inserts from a hadoop job I see the following
>> error in my application:
>>
>> 2010-08-13 14:03:22.207 INFO [main] JobClient:1317 Task Id :
>> attempt_201006091333_0031_m_000000_0, Status : FAILED
>> org.apache.hadoop.hbase.client.NoServerForRegionException: Timed out trying
>> to locate root region
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRootReg
>> ion(HConnectionManager.java:930)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(
>> HConnectionManager.java:581)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.relocateRegio
>> n(HConnectionManager.java:563)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionI
>> nMeta(HConnectionManager.java:694)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(
>> HConnectionManager.java:590)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.relocateRegio
>> n(HConnectionManager.java:563)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionI
>> nMeta(HConnectionManager.java:694)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(
>> HConnectionManager.java:594)
>> at
>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(
>> HConnectionManager.java:557)
>> at org.apache.hadoop.hbase.client.HTable.<init>(HTable.java:127)
>> ...
>>
>> Now contrary to what the shell is reporting, the HMaster process is
>> definitely running (along with HRegionServer and HQuorumPeer on the
>> appropriate other nodes in the cluster). I do not see any errors in the
>> master log, though interestingly I noticed a log message mentioning only 7
>> region servers - in fact there are more than twice that many in the cluster.
>>
>> 2010-08-13 14:04:32,018 INFO org.apache.hadoop.hbase.master.ServerManager: 7
>> region servers, 0 dead, average load 3.142857142857143
>>
>> The last clue I have is some exceptions in the zookeeper logs:
>>
>> 2010-08-13 13:34:16,041 WARN
>> org.apache.zookeeper.server.PrepRequestProcessor: Got exception when
>> processing sessionid:0x12a6d2847e40000 type:create cxid:0x28
>> zxid:0xfffffffffffffffe txntype:unknown n/a
>> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
>> NodeExists
>> at
>> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcess
>> or.java:245)
>> at
>> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.ja
>> va:114)
>> 2010-08-13 14:05:08,782 INFO org.apache.zookeeper.server.NIOServerCnxn:
>> Connected to /128.115.210.161:35883 lastZxid 0
>> 2010-08-13 14:05:08,782 INFO org.apache.zookeeper.server.NIOServerCnxn:
>> Creating new session 0x12a6d2847e40001
>> 2010-08-13 14:05:08,800 INFO org.apache.zookeeper.server.NIOServerCnxn:
>> Finished init of 0x12a6d2847e40001 valid:true
>> 2010-08-13 14:05:08,802 WARN
>> org.apache.zookeeper.server.PrepRequestProcessor: Got exception when
>> processing sessionid:0x12a6d2847e40001 type:create cxid:0x1
>> zxid:0xfffffffffffffffe txntype:unknown n/a
>> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
>> NodeExists
>> at
>> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcess
>> or.java:245)
>> at
>> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.ja
>> va:114)
>> 2010-08-13 14:05:09,762 WARN org.apache.zookeeper.server.NIOServerCnxn:
>> Exception causing close of session 0x12a6d2847e40001 due to
>> java.io.IOException: Read error
>> 2010-08-13 14:05:09,763 INFO org.apache.zookeeper.server.NIOServerCnxn:
>> closing session:0x12a6d2847e40001 NIOServerCnxn:
>> java.nio.channels.SocketChannel[connected local=/128.115.210.149:2181
>> remote=/128.115.210.161:35883]
>>
>> HBase was running on this cluster a few months ago so I doubt it is a
>> blatant misconfiguration at fault. I've tried restarting everything hbase or
>> hadoop related as well as wiping out the hbase data directory on hdfs to
>> start fresh with no result. Any hints or suggestions as to what the problem
>> might be are greatly appreciated. Thanks!
>>
>>
>>
>>
>>
>>
>>
Fri Aug 13 17:07:23 PDT 2010 Starting master on hnode1
ulimit -n 1024
2010-08-13 17:07:23,417 INFO org.apache.hadoop.hbase.master.HMaster:
vmName=Java HotSpot(TM) 64-Bit Server VM, vmVendor=Sun Microsystems Inc.,
vmVersion=16.3-b01
2010-08-13 17:07:23,418 INFO org.apache.hadoop.hbase.master.HMaster:
vmInputArguments=[-Xmx1000m, -XX:+HeapDumpOnOutOfMemoryError,
-XX:+UseConcMarkSweepGC, -XX:+CMSIncrementalMode,
-Dhbase.log.dir=/apps/hbase-0.20.4/logs,
-Dhbase.log.file=hbase-endeca-master-hnode1.log,
-Dhbase.home.dir=/apps/hbase-0.20.4, -Dhbase.id.str=endeca,
-Dhbase.root.logger=INFO,DRFA,
-Djava.library.path=/apps/hbase-0.20.4/lib/native/Linux-amd64-64]
2010-08-13 17:07:23,458 INFO org.apache.hadoop.hbase.master.HMaster: My address
is hnode1.llnl.gov:60000
2010-08-13 17:07:23,692 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics:
Initializing RPC Metrics with hostName=HMaster, port=60000
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:zookeeper.version=3.2.2-888565, built on 12/08/2009 21:51 GMT
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:host.name=hnode1.llnl.gov
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.version=1.6.0_20
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.vendor=Sun Microsystems Inc.
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.home=/usr/java/jdk1.6.0_20/jre
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.class.path=/apps/hbase-0.20.4/conf:/apps/java/latest/lib/tools.jar:/apps/hbase-0.20.4:/apps/hbase-0.20.4/hbase-0.20.4.jar:/apps/hbase-0.20.4/hbase-0.20.4-test.jar:/apps/hbase-0.20.4/hbase-filters-0.0.1-SNAPSHOT.jar:/apps/hbase-0.20.4/lib/commons-cli-2.0-SNAPSHOT.jar:/apps/hbase-0.20.4/lib/commons-el-from-jetty-5.1.4.jar:/apps/hbase-0.20.4/lib/commons-httpclient-3.0.1.jar:/apps/hbase-0.20.4/lib/commons-logging-1.0.4.jar:/apps/hbase-0.20.4/lib/commons-logging-api-1.0.4.jar:/apps/hbase-0.20.4/lib/commons-math-1.1.jar:/apps/hbase-0.20.4/lib/hadoop-0.20.2-core.jar:/apps/hbase-0.20.4/lib/hadoop-0.20.2-test.jar:/apps/hbase-0.20.4/lib/jasper-compiler-5.5.12.jar:/apps/hbase-0.20.4/lib/jasper-runtime-5.5.12.jar:/apps/hbase-0.20.4/lib/jetty-6.1.14.jar:/apps/hbase-0.20.4/lib/jetty-util-6.1.14.jar:/apps/hbase-0.20.4/lib/jruby-complete-1.2.0.jar:/apps/hbase-0.20.4/lib/junit-3.8.1.jar:/apps/hbase-0.20.4/lib/libthrift-r771587.jar:/apps/hbase-0.20.4/lib/log4j-1.2.15.jar:/apps/hbase-0.20.4/lib/lucene-core-2.2.0.jar:/apps/hbase-0.20.4/lib/servlet-api-2.5-6.1.14.jar:/apps/hbase-0.20.4/lib/xmlenc-0.52.jar:/apps/hbase-0.20.4/lib/zookeeper-3.2.2.jar:/apps/hbase-0.20.4/lib/jsp-2.1/jsp-2.1.jar:/apps/hbase-0.20.4/lib/jsp-2.1/jsp-api-2.1.jar:hbase-filters-0.0.1-SNAPSHOT.jar
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.library.path=/apps/hbase-0.20.4/lib/native/Linux-amd64-64
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.io.tmpdir=/tmp
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.compiler=<NA>
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:os.name=Linux
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:os.arch=amd64
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:os.version=2.6.18-194.3.1.el5
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:user.name=endeca
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:user.home=/home/endeca
2010-08-13 17:07:23,749 INFO org.apache.zookeeper.ZooKeeper: Client
environment:user.dir=/home/endeca
2010-08-13 17:07:23,750 INFO org.apache.zookeeper.ZooKeeper: Initiating client
connection, connectString=hnode30:2181,hnode20:2181,hnode10:2181
sessionTimeout=60000 watcher=Thread[Thread-1,5,main]
2010-08-13 17:07:23,751 INFO org.apache.zookeeper.ClientCnxn:
zookeeper.disableAutoWatchReset is false
2010-08-13 17:07:23,762 INFO org.apache.zookeeper.ClientCnxn: Attempting
connection to server hnode10/128.115.210.45:2181
2010-08-13 17:07:23,763 INFO org.apache.zookeeper.ClientCnxn: Priming
connection to java.nio.channels.SocketChannel[connected
local=/128.115.210.46:43705 remote=hnode10/128.115.210.45:2181]
2010-08-13 17:07:23,768 INFO org.apache.zookeeper.ClientCnxn: Server connection
successful
2010-08-13 17:07:23,771 WARN org.apache.zookeeper.ClientCnxn: Exception closing
session 0x0 to sun.nio.ch.selectionkeyi...@7ee49dcd
java.io.IOException: Read error rc = -1 java.nio.DirectByteBuffer[pos=0 lim=4
cap=4]
at org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:701)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
2010-08-13 17:07:23,772 WARN org.apache.zookeeper.ClientCnxn: Ignoring
exception during shutdown input
java.net.SocketException: Transport endpoint is not connected
at sun.nio.ch.SocketChannelImpl.shutdown(Native Method)
at
sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:640)
at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
at
org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:999)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970)
2010-08-13 17:07:23,772 WARN org.apache.zookeeper.ClientCnxn: Ignoring
exception during shutdown output
java.net.SocketException: Transport endpoint is not connected
at sun.nio.ch.SocketChannelImpl.shutdown(Native Method)
at
sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:651)
at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
at
org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1004)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970)
2010-08-13 17:07:23,782 INFO org.apache.hadoop.hbase.master.RegionManager:
-ROOT- region unset (but not set to be reassigned)
2010-08-13 17:07:23,783 INFO org.apache.hadoop.hbase.master.RegionManager: ROOT
inserted into regionsInTransition
2010-08-13 17:07:23,882 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to read:
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode =
ConnectionLoss for /hbase/master
2010-08-13 17:07:24,779 INFO org.apache.zookeeper.ClientCnxn: Attempting
connection to server hnode30/128.115.210.149:2181
2010-08-13 17:07:24,779 INFO org.apache.zookeeper.ClientCnxn: Priming
connection to java.nio.channels.SocketChannel[connected
local=/128.115.210.46:42148 remote=hnode30/128.115.210.149:2181]
2010-08-13 17:07:24,779 INFO org.apache.zookeeper.ClientCnxn: Server connection
successful
2010-08-13 17:07:24,831 DEBUG org.apache.hadoop.hbase.master.HMaster: Got event
None with path null
2010-08-13 17:07:24,859 WARN
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to write master
address 128.115.210.46:60000 to ZooKeeper
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /hbase/master
at org.apache.zookeeper.KeeperException.create(KeeperException.java:110)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:608)
at
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.writeMasterAddress(ZooKeeperWrapper.java:527)
at
org.apache.hadoop.hbase.master.HMaster.writeAddressToZooKeeper(HMaster.java:260)
at org.apache.hadoop.hbase.master.HMaster.<init>(HMaster.java:242)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at org.apache.hadoop.hbase.master.HMaster.doMain(HMaster.java:1230)
at org.apache.hadoop.hbase.master.HMaster.main(HMaster.java:1271)
2010-08-13 17:07:24,864 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode /hbase/master
got 128.115.210.46:60000
2010-08-13 17:07:24,864 DEBUG
org.apache.hadoop.hbase.master.ZKMasterAddressWatcher: Waiting for master
address ZNode to be deleted and watching the cluster state node
2010-08-13 17:08:04,014 DEBUG
org.apache.hadoop.hbase.master.ZKMasterAddressWatcher: Got event NodeDeleted
with path /hbase/master
2010-08-13 17:08:04,014 DEBUG
org.apache.hadoop.hbase.master.ZKMasterAddressWatcher: Master address ZNode
deleted, notifying waiting masters
2010-08-13 17:08:04,015 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to read:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
for /hbase/master
2010-08-13 17:08:04,025 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Wrote master address
128.115.210.46:60000 to ZooKeeper
2010-08-13 17:08:04,029 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: State node exists.
2010-08-13 17:08:04,030 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode /hbase/master
got 128.115.210.46:60000
2010-08-13 17:08:04,030 INFO org.apache.hadoop.hbase.master.HMaster: HMaster
initialized on 128.115.210.46:60000
2010-08-13 17:08:04,031 DEBUG org.apache.hadoop.hbase.master.HMaster: Checking
cluster state...
2010-08-13 17:08:04,032 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/root-region-server got 128.115.210.142:60020
2010-08-13 17:08:04,038 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781567 got 128.115.210.45:60020
2010-08-13 17:08:04,038 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781587 got 128.115.210.116:60020
2010-08-13 17:08:04,039 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781568 got 128.115.210.49:60020
2010-08-13 17:08:04,040 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781529 got 128.115.210.52:60020
2010-08-13 17:08:04,041 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781528 got 128.115.210.48:60020
2010-08-13 17:08:04,042 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781586 got 128.115.210.142:60020
2010-08-13 17:08:04,043 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode
/hbase/rs/1281567781561 got 128.115.210.42:60020
2010-08-13 17:08:04,043 INFO org.apache.hadoop.hbase.master.HMaster: This is a
failover, ZK inspection begins...
2010-08-13 17:08:04,074 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode10.llnl.gov
2010-08-13 17:08:04,084 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781567 with data 128.115.210.45:60020
2010-08-13 17:08:04,090 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode21.llnl.gov
2010-08-13 17:08:04,095 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781587 with data 128.115.210.116:60020
2010-08-13 17:08:04,102 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode3.llnl.gov
2010-08-13 17:08:04,107 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781568 with data 128.115.210.49:60020
2010-08-13 17:08:04,111 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode5.llnl.gov
2010-08-13 17:08:04,119 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781529 with data 128.115.210.52:60020
2010-08-13 17:08:04,125 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode2.llnl.gov
2010-08-13 17:08:04,131 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781528 with data 128.115.210.48:60020
2010-08-13 17:08:04,136 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode24.llnl.gov
2010-08-13 17:08:04,143 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781586 with data 128.115.210.142:60020
2010-08-13 17:08:04,154 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: SetData of ZNode
/hbase/root-region-server with 128.115.210.142:60020
2010-08-13 17:08:04,157 DEBUG org.apache.hadoop.hbase.master.HMaster:
Inspection found server hnode7.llnl.gov
2010-08-13 17:08:04,161 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
/hbase/rs/1281567781561 with data 128.115.210.42:60020
2010-08-13 17:08:04,163 INFO org.apache.hadoop.hbase.master.HMaster: Inspection
found 22 regions, with -ROOT-
2010-08-13 17:08:04,166 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode10.llnl.gov,60020,1281567781567
2010-08-13 17:08:04,166 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,166 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode2.llnl.gov,60020,1281567781528
2010-08-13 17:08:04,166 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,166 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode21.llnl.gov,60020,1281567781587
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode24.llnl.gov,60020,1281567781586
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode3.llnl.gov,60020,1281567781568
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode5.llnl.gov,60020,1281567781529
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Found log
folder : hnode7.llnl.gov,60020,1281567781561
2010-08-13 17:08:04,167 INFO org.apache.hadoop.hbase.master.HMaster: Log folder
belongs to an existing region server
2010-08-13 17:08:04,169 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
Initializing JVM Metrics with processName=Master, sessionId=HMaster
2010-08-13 17:08:04,170 INFO
org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized
2010-08-13 17:08:04,171 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scanning meta region {server: 128.115.210.142:60020,
regionname: -ROOT-,,0, startKey: <>}
2010-08-13 17:08:04,178 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.45:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:08:04,181 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.45:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:08:04,234 DEBUG org.apache.hadoop.hbase.master.BaseScanner:
Current assignment of .META.,,1 is not valid;
serverAddress=128.115.210.48:60020, startCode=1281567781528 unknown.
2010-08-13 17:08:04,236 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
128.115.210.142:60020, regionname: -ROOT-,,0, startKey: <>} complete
2010-08-13 17:08:04,308 INFO org.apache.hadoop.http.HttpServer: Port returned
by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the
listener on 60010
2010-08-13 17:08:04,308 INFO org.apache.hadoop.http.HttpServer:
listener.getLocalPort() returned 60010
webServer.getConnectors()[0].getLocalPort() returned 60010
2010-08-13 17:08:04,308 INFO org.apache.hadoop.http.HttpServer: Jetty bound to
port 60010
2010-08-13 17:08:04,623 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 0 on 60000: starting
2010-08-13 17:08:04,623 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
listener on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 1 on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 2 on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 3 on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 4 on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 5 on 60000: starting
2010-08-13 17:08:04,624 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 6 on 60000: starting
2010-08-13 17:08:04,626 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
Responder: starting
2010-08-13 17:08:04,626 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 7 on 60000: starting
2010-08-13 17:08:04,626 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 8 on 60000: starting
2010-08-13 17:08:04,626 DEBUG org.apache.hadoop.hbase.master.HMaster: Started
service threads
2010-08-13 17:08:04,626 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 9 on 60000: starting
2010-08-13 17:08:04,638 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: 128.115.210.116:60020, startcode: 1281567781587, load:
(requests=0, regions=3, usedHeap=29, maxHeap=993): total nregions to assign=1,
nregions to reach balance=0, isMetaAssign=true
2010-08-13 17:08:04,638 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Doing for address: 128.115.210.116:60020, startcode: 1281567781587, load:
(requests=0, regions=3, usedHeap=29, maxHeap=993) nregions: 1 and
nRegionsToAssign: 1
2010-08-13 17:08:04,638 INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region .META.,,1 to hnode21.llnl.gov,60020,1281567781587
2010-08-13 17:08:04,638 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,639 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,640 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,642 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,643 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,644 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,644 INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: .META.,,1 from
hnode21.llnl.gov,60020,1281567781587; 1 of 1
2010-08-13 17:08:04,646 INFO org.apache.hadoop.hbase.master.RegionManager: in
safe mode
2010-08-13 17:08:04,647 DEBUG org.apache.hadoop.hbase.master.HMaster:
Processing todo: PendingOpenOperation from hnode21.llnl.gov,60020,1281567781587
2010-08-13 17:08:04,647 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: .META.,,1 open on
128.115.210.116:60020
2010-08-13 17:08:04,648 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: Updated row .META.,,1 in
region -ROOT-,,0 with startcode=1281567781587, server=128.115.210.116:60020
2010-08-13 17:08:04,649 DEBUG
org.apache.hadoop.hbase.master.RegionServerOperation: Adding to
onlineMetaRegions: {server: 128.115.210.116:60020, regionname: .META.,,1,
startKey: <>}
2010-08-13 17:08:04,649 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.116:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:08:04,654 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.116:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:08:04,654 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1
.META. region(s) scanned
2010-08-13 17:08:07,671 WARN
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to create out of
safe mode in ZooKeeper:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /hbase/safe-mode
2010-08-13 17:08:07,671 INFO
org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Node exists; just move on
2010-08-13 17:08:07,671 INFO org.apache.hadoop.hbase.master.RegionManager:
exiting safe mode
2010-08-13 17:08:23,779 INFO org.apache.hadoop.hbase.master.ServerManager: 7
region servers, 0 dead, average load 3.142857142857143
2010-08-13 17:09:04,182 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scanning meta region {server: 128.115.210.142:60020,
regionname: -ROOT-,,0, startKey: <>}
2010-08-13 17:09:04,192 DEBUG org.apache.hadoop.hbase.master.BaseScanner:
Current assignment of .META.,,1 is not valid;
serverAddress=128.115.210.116:60020, startCode=1281567781587 unknown.
2010-08-13 17:09:04,194 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
128.115.210.142:60020, regionname: -ROOT-,,0, startKey: <>} complete
2010-08-13 17:09:04,659 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.116:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:09:04,666 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.116:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:09:04,666 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1
.META. region(s) scanned
2010-08-13 17:09:04,750 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: 128.115.210.45:60020, startcode: 1281567781567, load:
(requests=0, regions=3, usedHeap=29, maxHeap=991): total nregions to assign=1,
nregions to reach balance=0, isMetaAssign=true
2010-08-13 17:09:04,750 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Doing for address: 128.115.210.45:60020, startcode: 1281567781567, load:
(requests=0, regions=3, usedHeap=29, maxHeap=991) nregions: 1 and
nRegionsToAssign: 1
2010-08-13 17:09:04,750 INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region .META.,,1 to hnode10.llnl.gov,60020,1281567781567
2010-08-13 17:09:04,753 INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: .META.,,1 from
hnode10.llnl.gov,60020,1281567781567; 1 of 1
2010-08-13 17:09:04,753 DEBUG org.apache.hadoop.hbase.master.HMaster:
Processing todo: PendingOpenOperation from hnode10.llnl.gov,60020,1281567781567
2010-08-13 17:09:04,753 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: .META.,,1 open on
128.115.210.45:60020
2010-08-13 17:09:04,757 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: Updated row .META.,,1 in
region -ROOT-,,0 with startcode=1281567781567, server=128.115.210.45:60020
2010-08-13 17:09:04,757 DEBUG
org.apache.hadoop.hbase.master.RegionServerOperation: Adding to
onlineMetaRegions: {server: 128.115.210.45:60020, regionname: .META.,,1,
startKey: <>}
2010-08-13 17:09:04,757 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.45:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:09:04,761 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.45:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:09:04,761 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1
.META. region(s) scanned
2010-08-13 17:09:23,790 INFO org.apache.hadoop.hbase.master.ServerManager: 7
region servers, 0 dead, average load 3.142857142857143
2010-08-13 17:10:04,192 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scanning meta region {server: 128.115.210.142:60020,
regionname: -ROOT-,,0, startKey: <>}
2010-08-13 17:10:04,202 DEBUG org.apache.hadoop.hbase.master.BaseScanner:
Current assignment of .META.,,1 is not valid;
serverAddress=128.115.210.45:60020, startCode=1281567781567 unknown.
2010-08-13 17:10:04,204 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
128.115.210.142:60020, regionname: -ROOT-,,0, startKey: <>} complete
2010-08-13 17:10:04,768 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.45:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:10:04,772 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.45:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:10:04,772 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1
.META. region(s) scanned
2010-08-13 17:10:04,823 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: 128.115.210.49:60020, startcode: 1281567781568, load:
(requests=0, regions=3, usedHeap=35, maxHeap=991): total nregions to assign=1,
nregions to reach balance=0, isMetaAssign=true
2010-08-13 17:10:04,823 DEBUG org.apache.hadoop.hbase.master.RegionManager:
Doing for address: 128.115.210.49:60020, startcode: 1281567781568, load:
(requests=0, regions=3, usedHeap=35, maxHeap=991) nregions: 1 and
nRegionsToAssign: 1
2010-08-13 17:10:04,823 INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region .META.,,1 to hnode3.llnl.gov,60020,1281567781568
2010-08-13 17:10:04,825 INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: .META.,,1 from hnode3.llnl.gov,60020,1281567781568;
1 of 1
2010-08-13 17:10:04,825 DEBUG org.apache.hadoop.hbase.master.HMaster:
Processing todo: PendingOpenOperation from hnode3.llnl.gov,60020,1281567781568
2010-08-13 17:10:04,825 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: .META.,,1 open on
128.115.210.49:60020
2010-08-13 17:10:04,827 INFO
org.apache.hadoop.hbase.master.RegionServerOperation: Updated row .META.,,1 in
region -ROOT-,,0 with startcode=1281567781568, server=128.115.210.49:60020
2010-08-13 17:10:04,827 DEBUG
org.apache.hadoop.hbase.master.RegionServerOperation: Adding to
onlineMetaRegions: {server: 128.115.210.49:60020, regionname: .META.,,1,
startKey: <>}
2010-08-13 17:10:04,827 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 128.115.210.49:60020,
regionname: .META.,,1, startKey: <>}
2010-08-13 17:10:04,830 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 0 row(s) of meta region {server:
128.115.210.49:60020, regionname: .META.,,1, startKey: <>} complete
2010-08-13 17:10:04,830 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1
.META. region(s) scanned
2010-08-13 17:10:23,801 INFO org.apache.hadoop.hbase.master.ServerManager: 7
region servers, 0 dead, average load 3.142857142857143
