You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Ted Yu <yu...@gmail.com> on 2010/03/03 18:57:52 UTC
Re: NotServingRegionException
Previous attempt wasn't delivered.
On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
>
Re: NotServingRegionException
Posted by Ted Yu <yu...@gmail.com>.
I use org.apache.hadoop.hbase.mapreduce.Import to import which is launched
on the same VM.
On Wed, Mar 3, 2010 at 11:37 AM, Jean-Daniel Cryans <jd...@apache.org>wrote:
> 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 <yu...@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 <jdcryans@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 <yu...@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.SelectionKeyImpl@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)
> >> >
> >> > [root@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
> >> > <jd...@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 <yu...@gmail.com> wrote:
> >> >> > Previous attempt wasn't delivered.
> >> >> >
> >> >> > On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
> >> >> >>
> >> >> >
> >> >>
> >> >
> >
> >
>
Re: NotServingRegionException
Posted by Jean-Daniel Cryans <jd...@apache.org>.
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 <yu...@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 <jd...@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 <yu...@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.SelectionKeyImpl@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)
>> >
>> > [root@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
>> > <jd...@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 <yu...@gmail.com> wrote:
>> >> > Previous attempt wasn't delivered.
>> >> >
>> >> > On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
>> >> >>
>> >> >
>> >>
>> >
>
>
Re: NotServingRegionException
Posted by Jean-Daniel Cryans <jd...@apache.org>.
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 <yu...@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.SelectionKeyImpl@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)
>
> [root@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 <jd...@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 <yu...@gmail.com> wrote:
>> > Previous attempt wasn't delivered.
>> >
>> > On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
>> >>
>> >
>>
>
Re: NotServingRegionException
Posted by Ted Yu <yu...@gmail.com>.
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.SelectionKeyImpl@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)
[root@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 <jd...@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 <yu...@gmail.com> wrote:
> > Previous attempt wasn't delivered.
> >
> > On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
> >>
> >
>
Re: NotServingRegionException
Posted by Jean-Daniel Cryans <jd...@apache.org>.
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 <yu...@gmail.com> wrote:
> Previous attempt wasn't delivered.
>
> On Wed, Mar 3, 2010 at 9:30 AM, Ted Yu <yu...@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
>>
>