Yes that's one thing, also make sure your client has connectivity...
doesn't seem so.
J-D
On Wed, Mar 3, 2010 at 11:32 AM, Ted Yu <yuzhih...@gmail.com> wrote:
> But querying zookeeper shows:
> lsr /hbase
>
> hbase
> safe-mode
> rs
> 1267640372165
> root-region-server
> master
> shutdown
>
>
> On Wed, Mar 3, 2010 at 10:59 AM, Jean-Daniel Cryans <jdcry...@apache.org>
> wrote:
>>
>> 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
>> >> >>
>> >> >
>> >>
>> >
>
>
