Looks like a connectivity issue, it says:
> 10/03/03 10:45:55 WARN zookeeper.ZooKeeperWrapper: Failed to create /hbase
> -- check quorum servers, currently=tyu-linux:2181
Do what it says to do ;) Also make sure that that client can reach
that address. In my experience using a VM can be troublesome
network-wise.
J-D
On Wed, Mar 3, 2010 at 10:56 AM, Ted Yu <yuzhih...@gmail.com> wrote:
> Hi, J-D:
> I restarted hbase and am not seeing NotServingRegionException now.
>
> I tried to import a table that I exported from hbase 0.20.1 into this 0.20.3
> instance.
> After sometime I got:
> 10/03/03 10:45:55 WARN zookeeper.ZooKeeperWrapper: Failed to create /hbase
> -- check quorum servers, currently=tyu-linux:2181
> org.apache.zookeeper.KeeperException$ConnectionLossException:
> KeeperErrorCode = ConnectionLoss for /hbase
> at
> org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
> 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.ensureExists(ZooKeeperWrapper.java:405)
> at
> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.ensureParentExists(ZooKeeperWrapper.java:428)
> at
> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.checkOutOfSafeMode(ZooKeeperWrapper.java:541)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRootRegion(HConnectionManager.java:957)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:625)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:601)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:675)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:634)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:601)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:675)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:638)
> at
> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:601)
> at org.apache.hadoop.hbase.client.HTable.<init>(HTable.java:128)
> at org.apache.hadoop.hbase.client.HTable.<init>(HTable.java:106)
> at
> org.apache.hadoop.hbase.mapreduce.TableOutputFormat.getRecordWriter(TableOutputFormat.java:116)
> at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:573)
> at org.apache.hadoop.mapred.MapTask.run(MapTask.java:305)
> at
> org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:176)
> 10/03/03 10:45:55 DEBUG client.HConnectionManager$TableServers: Sleeping
> 1000ms, waiting for root region.
> 10/03/03 10:45:56 INFO zookeeper.ClientCnxn: Attempting connection to server
> tyu-linux/10.10.30.104:2181
> 10/03/03 10:45:56 WARN zookeeper.ClientCnxn: Exception closing session
> 0x1272319e9190009 to sun.nio.ch.selectionkeyi...@18856447
> java.net.ConnectException: Connection refused
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:933)
> 10/03/03 10:45:56 WARN zookeeper.ClientCnxn: Ignoring exception during
> shutdown input
> java.nio.channels.ClosedChannelException
> at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> 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)
> 10/03/03 10:45:56 WARN zookeeper.ClientCnxn: Ignoring exception during
> shutdown output
> java.nio.channels.ClosedChannelException
> at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> 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)
>
> [r...@tyu-linux logs]# echo ruok | nc tyu-linux 2181
> imok
>
> Here is from Zookeeper log:
>
> 2010-03-03 10:39:34,674 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0xa zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:34,953 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0xd zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:35,179 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x10 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:35,483 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x13 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:35,717 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x16 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:39,484 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x19 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:39:58,113 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:41:27,840 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x1f zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:42:08,352 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x22 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:43:36,599 WARN [ProcessThread:-1] server.PrepRequestProcessor
> Got exception when processing sessionid:0x1272319e9190009 type:create
> cxid:0x25 zxid:0xfffffffffffffffe txntype:unknown n/a
> org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
> NodeExists
> at
> org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
> at
> org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
> 2010-03-03 10:44:34,989 INFO [NIOServerCxn.Factory:2181]
> server.NIOServerCnxn Connected to /10.10.30.104:37310 lastZxid 0
>
> ------
>
> BTW I don't see error in hbase log:
> 2010-03-03 10:47:31,884 INFO [RegionManager.metaScanner]
> master.BaseScanner(282): Deleting region ruletable,,1260380289385
> (encoded=1470823151) because daughter splits no longer hold references
> 2010-03-03 10:47:31,886 DEBUG [RegionManager.metaScanner]
> regionserver.HRegion(2084): DELETING region
> hdfs://tyu-linux:9000/hbase/ruletable/1470823151
> 2010-03-03 10:47:31,913 INFO [RegionManager.metaScanner]
> master.BaseScanner(224): RegionManager.metaScanner scan of 6 row(s) of meta
> region {server: 10.10.30.104:60020, regionname: .META.,,1, startKey: <>}
> complete
> 2010-03-03 10:47:31,913 INFO [RegionManager.metaScanner]
> master.MetaScanner(132): All 1 .META. region(s) scanned
> 2010-03-03 10:48:29,123 INFO [Thread-10]
> master.ServerManager$ServerMonitor(129): 1 region servers, 0 dead, average
> load 6.0
> 2010-03-03 10:48:29,775 INFO [RegionManager.rootScanner]
> master.BaseScanner(146): RegionManager.rootScanner scanning meta region
> {server: 10.10.30.104:60020, regionname: -ROOT-,,0, startKey: <>}
> 2010-03-03 10:48:29,911 INFO [RegionManager.rootScanner]
> master.BaseScanner(224): RegionManager.rootScanner scan of 1 row(s) of meta
> region {server: 10.10.30.104:60020, regionname: -ROOT-,,0, startKey: <>}
> complete
> 2010-03-03 10:48:31,087 INFO [RegionManager.metaScanner]
> master.BaseScanner(146): RegionManager.metaScanner scanning meta region
> {server: 10.10.30.104:60020, regionname: .META.,,1, startKey: <>}
> 2010-03-03 10:48:31,247 INFO [RegionManager.metaScanner]
> master.BaseScanner(224): RegionManager.metaScanner scan of 4 row(s) of meta
> region {server: 10.10.30.104:60020, regionname: .META.,,1, startKey: <>}
> complete
> 2010-03-03 10:48:31,248 INFO [RegionManager.metaScanner]
> master.MetaScanner(132): All 1 .META. region(s) scanned
>
> 2010-03-03 10:46:59,508 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(753): Started compaction of 1 file(s),
> hasReferences=true, into /hbase/ruletable/compaction.dir/166372898,
> seqid=48520
> 2010-03-03 10:46:59,656 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(760): Completed compaction of lpm_1.0; new storefile is
> hdfs://tyu-linux:9000/hbase/ruletable/166372898/lpm_1.0/1940808286363293239;
> store size is 228.0
> 2010-03-03 10:46:59,666 INFO [regionserver/10.10.30.104:60020.compactor]
> regionserver.HRegion(792): compaction completed on region
> ruletable,com.hoovers.www/company/Ehlhardt_Construction/chxcjcjr-1.html,1267641983544
> in 15sec
> 2010-03-03 10:46:59,666 INFO [regionserver/10.10.30.104:60020.compactor]
> regionserver.HRegion(777): Starting compaction on region
> ruletable,com.hoovers.www/company/Arcadia_Films_Inc/rcryrcrj-1.html,1267641983544
> 2010-03-03 10:46:59,681 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(753): Started compaction of 2 file(s),
> hasReferences=true, into /hbase/ruletable/compaction.dir/1683413945,
> seqid=393092
> 2010-03-03 10:47:13,523 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(760): Completed compaction of exactmatch_1.0; new
> storefile is
> hdfs://tyu-linux:9000/hbase/ruletable/1683413945/exactmatch_1.0/4748550833150014710;
> store size is 157.8m
> 2010-03-03 10:47:13,858 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(753): Started compaction of 1 file(s),
> hasReferences=true, into /hbase/ruletable/compaction.dir/1683413945,
> seqid=48519
> 2010-03-03 10:47:14,452 DEBUG [regionserver/10.10.30.104:60020.compactor]
> regionserver.Store(760): Completed compaction of lpm_1.0; new storefile is
> hdfs://tyu-linux:9000/hbase/ruletable/1683413945/lpm_1.0/6987583517721068169;
> store size is 228.0
> 2010-03-03 10:47:14,717 INFO [regionserver/10.10.30.104:60020.compactor]
> regionserver.HRegion(792): compaction completed on region
> ruletable,com.hoovers.www/company/Arcadia_Films_Inc/rcryrcrj-1.html,1267641983544
> in 15sec
> 2010-03-03 10:47:40,525 DEBUG [pool-1-thread-1] hfile.LruBlockCache(551):
> Cache Stats: Sizes: Total=10.08004MB (10569688), Free=1218.3075MB
> (1277488040), Max=1228.3876MB (1288057728), Counts: Blocks=2, Access=14465,
> Hit=190, Miss=14275, Evictions=0, Evicted=0, Ratios: Hit
> Ratio=1.31351538002491%, Miss Ratio=98.68648648262024%, Evicted/Run=NaN
>
>
> On Wed, Mar 3, 2010 at 10:22 AM, Jean-Daniel Cryans
> <jdcry...@apache.org>wrote:
>
>> Ted,
>>
>> With such a small snippet it's hard to tell ;)
>>
>> Looks like that region server wasn't assigned with .META. but -ROOT-
>> contains that address for that region. Look at the logs for when 1)
>> the master assigns the region and 2) when the region server opens the
>> region. In between I expect you should see some exceptions.
>>
>> You can also put your 2 logs somewhere and post a link here so someone
>> can take a look at it.
>>
>> J-D
>>
>> On Wed, Mar 3, 2010 at 9:57 AM, Ted Yu <yuzhih...@gmail.com> wrote:
>> > Previous attempt wasn't delivered.
>> >
>> > On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yuzhih...@gmail.com> wrote:
>> >
>> >> Hi,
>> >> I started hbase 0.20.3 successfully on my Linux VM. Master and
>> regionserver
>> >> are on the same VM.
>> >> There're two empty tables.
>> >>
>> >> Soon I saw the following in regionserver.log:
>> >> 2010-03-03 09:18:31,643 INFO [regionserver/10.10.30.104:60020]
>> >> regionserver.StoreFile(241): Allocating LruBlockCache with maximum size
>> 1.2g
>> >> 2010-03-03 09:18:58,179 ERROR [IPC Server handler 1 on 60020]
>> >> regionserver.HRegionServer(849): Failed openScanner
>> >> org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
>> >> at
>> >>
>> org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2266)
>> >> at
>> >>
>> org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1845)
>> >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> >> at
>> >>
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>> >> at
>> >>
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>> >> at java.lang.reflect.Method.invoke(Method.java:597)
>> >> at
>> >> org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:657)
>> >> at
>> >>
>> org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
>> >>
>> >> And this in master.log:
>> >> 2010-03-03 09:18:58,196 WARN [RegionManager.metaScanner]
>> >> master.MetaScanner(78): Scan one META region: {server:
>> 10.10.30.104:60020,
>> >> regionname: .META.,,1, startKey: <>}
>> >> org.apache.hadoop.hbase.NotServingRegionException:
>> >> org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
>> >> at
>> >>
>> org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2266)
>> >> at
>> >>
>> org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1845)
>> >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> >> at
>> >>
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>> >> at
>> >>
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>> >> at java.lang.reflect.Method.invoke(Method.java:597)
>> >> at
>> >> org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:657)
>> >> at
>> >>
>> org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
>> >>
>> >> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>> >> Method)
>> >>
>> >> Has anyone experienced similar issue ?
>> >>
>> >> Thanks
>> >>
>> >
>>
>
