On Wed, Jun 2, 2010 at 9:55 AM, Stack <st...@duboce.net> wrote:
> On Wed, Jun 2, 2010 at 9:39 AM, Jacob Isaac <ja...@ebrary.com> wrote:
> > That's right sha-1 is my set identifier.
> > and yes I scan since I know the start-row and end-row - I create a Scan
> > object with startRow and stopRow.
> >
> >
>
> Good.
>
> >>
> >> > The Failed openScanner messages seems to suggest some region name
> cache
> >> is
> >> > getting stale with so many splits taking place.
> >> >
> >>
> >> Paste the exception.
> >>
> >>
> > 2010-05-26 20:37:57,161 ERROR [IPC Server handler 20 on 60020]
> > regionserver.HRegionServer(864): Failed openScanner
> > org.apache.hadoop.hbase.NotServingRegionException:
> >
> XXXXX-table-name-XXXXX,249B69DED2DB14DCFD894C7F4A01F282DAAA87D6:00114,1274912608415
> > at
> >
> org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2278)
> > at
> >
> org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1857)
> > at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
> > 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)
> > 2010-05-26 20:37:57,408 ERROR [IPC Server handler 4 on 60020]
> > regionserver.HRegionServer(864): Failed openScanner
> > org.apache.hadoop.hbase.NotServingRegionException:
> >
> XXXXX-table-name-XXXXX,D70FDA6553BE1A63EF62A7CA0585344A9819CA43:00190,1274914545783
> > at
> >
> org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2278)
> > at
> >
> org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1857)
> > at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
> > 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)
> >
>
> Does it recover eventually? In other words, after a while you can
> successfully fetch the startkey from above region? Its been deployed?
>
>
I don't see any application level errors - It's from
the RegionManager.metaScanner as the log snippets below indicate.
> If you track history of this region, can you see what is going on?
> Grep it in master log. What is happening around the time of the above
> message? This is 0.20.4 right, so you should be getting the benefit
> of smarter close where we'll only but up the barriers that provoke the
> NSRE after we've done flushing of the bullk of memory where before
> we'd put it up around the flush and close.
>
> Otherwise, could up the retries.
>
>
Result of a grep for region which eventually NSRE
on Master-
-----------------
hadoop$>grep '46B0876B87DB493034FB353C67FB267B0C4342D0:00270'
/hadoop/hbase/logs/hbase-hadoop-master-node-13.log.2010-05-27
2010-05-27 02:16:22,307 INFO [IPC Server handler 14 on 60000]
master.ServerManager(441): Processing MSG_REPORT_SPLIT_INCLUDES_DAUGHTERS:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046:
Daughters;
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247,
XXXXX-table-name-1-XXXXX,47567C9D81CDF3898C78B641B829272A2755BE31:00013,1274951772247
from XXXXX-node-20-XXXXX,60020,1274934804792; 1 of 1
2010-05-27 02:16:22,468 INFO [IPC Server handler 19 on 60000]
master.RegionManager(337): Assigning region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
to XXXXX-node-20-XXXXX,60020,1274934804792
2010-05-27 02:16:23,327 INFO [IPC Server handler 4 on 60000]
master.ServerManager(441): Processing MSG_REPORT_OPEN:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
from XXXXX-node-20-XXXXX,60020,1274934804792; 1 of 1
2010-05-27 02:16:23,327 INFO [HMaster] master.ProcessRegionOpen(70):
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
open on 10.10.24.35:60020
2010-05-27 02:16:23,328 INFO [HMaster] master.ProcessRegionOpen(80):
Updated row
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
in region .META.,,1 with startcode=1274934804792, server=10.10.24.35:60020
2010-05-27 02:17:34,060 DEBUG [RegionManager.metaScanner]
master.BaseScanner(465):
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247/1680882591
no longer has references to
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:17:34,061 DEBUG [RegionManager.metaScanner]
master.BaseScanner(465):
XXXXX-table-name-1-XXXXX,47567C9D81CDF3898C78B641B829272A2755BE31:00013,1274951772247/1767038200
no longer has references to
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:17:34,062 INFO [RegionManager.metaScanner]
master.BaseScanner(304): Deleting region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
(encoded=771830170) because daughter splits no longer hold references
and on the regionserver
------------------------------------
hadoop$>grep '46B0876B87DB493034FB353C67FB267B0C4342D0:00270'
/hadoop/hbase/logs/hbase-hadoop-regionserver-XXXXX-node-20-XXXXX.log.2010-05-27
2010-05-27 02:16:07,218 INFO [IPC Server handler 15 on 60020]
regionserver.MemStoreFlusher(376): Forced flushing of
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
because global memstore limit of 1.6g exceeded; currently 1.5g and flushing
till 1.4g
2010-05-27 02:16:07,218 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(950): Started memstore flush for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046.
Current region memstore size 58.4m
2010-05-27 02:16:09,167 DEBUG [IPC Server handler 15 on 60020]
regionserver.Store(562): Added
hdfs://XXXXX-node-11-XXXXX:9000/hbase/XXXXX-table-name-1-XXXXX/771830170/strings/945578516995050481,
entries=24097, sequenceid=23152831, memsize=58.4m, filesize=55.4m to
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:09,167 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1074): Finished memstore flush of ~58.4m for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
in 1949ms, sequence id=23152831, compaction requested=false
2010-05-27 02:16:09,951 DEBUG [IPC Server handler 15 on 60020]
regionserver.CompactSplitThread(145): Compaction requested for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046/771830170
because: regionserver/10.10.24.35:60020.cacheFlusher
2010-05-27 02:16:12,224 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(826): Starting compaction on region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:12,227 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(841): compaction completed on region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
in 0sec
2010-05-27 02:16:12,227 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(656): Starting split of region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:12,264 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(485): Closing
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046:
disabling compactions & flushes
2010-05-27 02:16:12,264 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(510): Updates disabled for region, no outstanding
scanners on
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:12,264 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(517): No more row locks outstanding on region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:12,264 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(950): Started memstore flush for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046.
Current region memstore size 525.9k
2010-05-27 02:16:12,458 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.Store(562): Added
hdfs://XXXXX-node-11-XXXXX:9000/hbase/XXXXX-table-name-1-XXXXX/771830170/strings/4368665739067899026,
entries=305, sequenceid=23166410, memsize=525.9k, filesize=487.8k to
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:12,458 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(1074): Finished memstore flush of ~525.9k for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
in 194ms, sequence id=23166410, compaction requested=true
2010-05-27 02:16:12,459 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(529): Closed
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:13,501 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(283): Creating region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247,
encoded=1680882591
2010-05-27 02:16:13,536 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.CompactSplitThread(222): region split, META updated, and report
to master all successful. Old region=REGION => {NAME =>
'XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046',
STARTKEY => '46B0876B87DB493034FB353C67FB267B0C4342D0:00270', ENDKEY =>
'47FB1442E2D78FCBE7E54C64B742EABD78117C28:00098', ENCODED => 771830170,
OFFLINE => true, SPLIT => true, TABLE => {{NAME =>
'XXXXX-table-name-1-XXXXX', FAMILIES => [{NAME => 'strings', COMPRESSION =>
'NONE', VERSIONS => '2', TTL => '2147483647', BLOCKSIZE => '65536',
IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, new regions:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247,
XXXXX-table-name-1-XXXXX,47567C9D81CDF3898C78B641B829272A2755BE31:00013,1274951772247.
Split took 1sec
2010-05-27 02:16:13,707 INFO [regionserver/10.10.24.35:60020]
regionserver.HRegionServer(499): MSG_REGION_OPEN:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
2010-05-27 02:16:13,707 INFO [regionserver/10.10.24.35:60020.worker]
regionserver.HRegionServer$Worker(1440): Worker: MSG_REGION_OPEN:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
2010-05-27 02:16:13,708 DEBUG [regionserver/10.10.24.35:60020.worker]
regionserver.HRegion(283): Creating region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247,
encoded=1680882591
2010-05-27 02:16:14,555 INFO [regionserver/10.10.24.35:60020.worker]
regionserver.HRegion(359): region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247/1680882591
available; sequence id is 23166411
2010-05-27 02:16:14,555 DEBUG [regionserver/10.10.24.35:60020.worker]
regionserver.CompactSplitThread(145): Compaction requested for region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247/1680882591
because: Region has references on open
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:16:29,690 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(826): Starting compaction on region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
2010-05-27 02:16:38,730 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(841): compaction completed on region
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274951772247
in 9sec
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
2010-05-27 02:42:32,462 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.CompactSplitThread(222): region split, META updated, and report
to master all successful. Old region=REGION => {NAME =>
'XXXXX-table-name-1-XXXXX,45806D884F26B1171D43A5E896DDC0453A6D9D58:00207,1274944232908',
STARTKEY => '45806D884F26B1171D43A5E896DDC0453A6D9D58:00207', ENDKEY =>
'46B0876B87DB493034FB353C67FB267B0C4342D0:00270', ENCODED => 464708700,
OFFLINE => true, SPLIT => true, TABLE => {{NAME =>
'XXXXX-table-name-1-XXXXX', FAMILIES => [{NAME => 'strings', COMPRESSION =>
'NONE', VERSIONS => '2', TTL => '2147483647', BLOCKSIZE => '65536',
IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, new regions:
XXXXX-table-name-1-XXXXX,45806D884F26B1171D43A5E896DDC0453A6D9D58:00207,1274953351249,
XXXXX-table-name-1-XXXXX,460D057080572C211DBB7B8C6E3EEA6F2BFDB510:00156,1274953351249.
Split took 1sec
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
org.apache.hadoop.hbase.NotServingRegionException:
XXXXX-table-name-1-XXXXX,46B0876B87DB493034FB353C67FB267B0C4342D0:00270,1274943417046
> >
> >
> >>
> >> > Do see 'Forced flushing of XXXX because global memstore limit of 1.6g
> >> ...."
> >> > every 3-4 min
> >> >
> >> Do these periods last a while or are they short?
> >>
> >>
> > hbase.regionserver.global.memstore.upperLimit=0.40
> > hbase.regionserver.global.memstore.lowerLimit=0.35
> > Hence the forced flushing only lasts typically between 10-30 secs taking
> > the global.memstore from 1.6g (0.40) to 1.4g (0.35)
>
> 10-30 seconds is a pretty long time. Seems like hbase is struggling
> to clear its memstores promptly enough. Is that how you'd read the
> logs?
>
>
>
Most of them are in the 3-10sec range and there are some in the above
mentioned(10-30sec) range
for e.g the following snippet is for a ~6sec flush
352 2010-05-27 00:09:07,501 INFO [IPC Server handler 15 on 60020]
regionserver.MemStoreFlusher(376): Forced flushing of
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421
because global memstore limit of 1.6g exceeded; currently 1.6g and flus
hing till 1.4g
353 2010-05-27 00:09:07,501 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(950): Started memstore flush for region
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421.
Current region memstore size 95.6m
354 2010-05-27 00:09:07,502 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(994): Finished snapshotting, commencing flushing stores
355 2010-05-27 00:09:09,838 DEBUG [IPC Server handler 15 on 60020]
regionserver.Store(562): Added
hdfs://XXXXX-node-11-XXXXX:9000/hbase/XXXXX-table-name-1-XXXXX/1324599186/strings/101116420345322824,
entries=38358, sequenceid=14303944, memsize=95.6m, filesize=90.9m to
XXXXX-table-name-1-XXXXX
,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421
356 2010-05-27 00:09:09,838 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1011): Caches flushed, doing commit now (which includes
update scanners)
357 2010-05-27 00:09:09,838 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1074): Finished memstore flush of ~95.6m for region
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421
in 2337ms, sequence id=14303944, compaction requeste d=false
358 2010-05-27 00:09:09,839 INFO [IPC Server handler 15 on 60020]
regionserver.MemStoreFlusher(376): Forced flushing of
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661
because global memstore limit of 1.6g exceeded; currently 1.5g and flu
shing till 1.4g
359 2010-05-27 00:09:09,839 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(950): Started memstore flush for region
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661.
Current region memstore size 95.3m
360 2010-05-27 00:09:09,839 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(994): Finished snapshotting, commencing flushing stores
361 2010-05-27 00:09:11,563 DEBUG [IPC Server handler 15 on 60020]
regionserver.Store(562): Added
hdfs://XXXXX-node-11-XXXXX:9000/hbase/XXXXX-table-name-2-XXXXX/1223123688/bytes/6426934402369169765,
entries=42741, sequenceid=14303945, memsize=95.3m, filesize=90.1m to
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661
362 2010-05-27 00:09:11,564 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1011): Caches flushed, doing commit now (which includes
update scanners)
363 2010-05-27 00:09:11,564 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1074): Finished memstore flush of ~95.3m for region
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661
in 1725ms, sequence id=14303945, compaction request ed=false
364 2010-05-27 00:09:11,564 INFO [IPC Server handler 15 on 60020]
regionserver.MemStoreFlusher(376): Forced flushing of
XXXXX-table-name-2-XXXXX,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159
because global memstore limit of 1.6g exceeded; currently 1.4g and flu
shing till 1.4g
365 2010-05-27 00:09:11,565 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(950): Started memstore flush for region
XXXXX-table-name-2-XXXXX,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159.
Current region memstore size 95.0m
366 2010-05-27 00:09:11,565 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(994): Finished snapshotting, commencing flushing stores
367 2010-05-27 00:09:13,932 DEBUG [IPC Server handler 15 on 60020]
regionserver.Store(562): Added
hdfs://XXXXX-node-11-XXXXX:9000/hbase/XXXXX-table-name-2-XXXXX/363024297/bytes/7498515656489548668,
entries=40338, sequenceid=14303946, memsize=95.0m, filesize=90.1m to
XXXXX-table-name-2-XXXXX
,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159
368 2010-05-27 00:09:13,932 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1011): Caches flushed, doing commit now (which includes
update scanners)
369 2010-05-27 00:09:13,933 DEBUG [IPC Server handler 15 on 60020]
regionserver.HRegion(1074): Finished memstore flush of ~95.0m for region
XXXXX-table-name-2-XXXXX,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159
in 2367ms, sequence id=14303946, compaction request ed=true
370 2010-05-27 00:09:13,933 DEBUG [IPC Server handler 15 on 60020]
regionserver.CompactSplitThread(145): Compaction requested for region
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421/1324599186
because: regionserver/10.10.24.35:60020.cach eFlusher
371 2010-05-27 00:09:13,933 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(826): Starting compaction on region
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421
372 2010-05-27 00:09:13,934 DEBUG [IPC Server handler 15 on 60020]
regionserver.CompactSplitThread(145): Compaction requested for region
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661/1223123688
because: regionserver/10.10.24.35:60020.cac heFlusher
373 2010-05-27 00:09:13,934 DEBUG [IPC Server handler 15 on 60020]
regionserver.CompactSplitThread(145): Compaction requested for region
XXXXX-table-name-2-XXXXX,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159/363024297
because: regionserver/10.10.24.35:60020.cach eFlusher
374 2010-05-27 00:09:13,937 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(841): compaction completed on region
XXXXX-table-name-1-XXXXX,100DE5707ABD151B18FA3EAA9EAB77410B1BBF36:00020,1274940643421
in 0sec
375 2010-05-27 00:09:13,937 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(826): Starting compaction on region
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661
376 2010-05-27 00:09:13,940 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(841): compaction completed on region
XXXXX-table-name-2-XXXXX,CC0B82D073E2BE78E400FD6B2A39F0EA0FCDC343:00177,1274941678661
in 0sec
377 2010-05-27 00:09:13,940 INFO [regionserver/10.10.24.35:60020.compactor]
regionserver.HRegion(826): Starting compaction on region
XXXXX-table-name-2-XXXXX,F60DC9357155DAA9115A11734752215A830711BC:00152,1274939816159
378 2010-05-27 00:09:13,975 DEBUG [regionserver/10.10.24.35:60020.compactor]
regionserver.Store(754): Compaction size of bytes: 552.9m; Skipped 1
file(s), size: 295459036
> The above NSRE might be because close is held up by a flush that is
> behind others that are going on inside the regionserver at the time.
>
> St.Ack
>
