You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by bijieshan <bi...@huawei.com> on 2012/01/25 05:55:43 UTC
Closed parent region present in Hlog.lastSeqWritten
Hi all,
We found so many hlogs in our cluster, after some analysis, we also found one splitted region occurred in HLog.lastSeqWritten. For this region had been closed, it can't be flushed again. So blocking all the other logs removing to ".oldlogs" directory.
05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s): 2acaf8e3acfd2e8a5825a1f6f0aca4a8
05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s): 2acaf8e3acfd2e8a5825a1f6f0aca4a8
05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s): 2acaf8e3acfd2e8a5825a1f6f0aca4a8
05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s): 2acaf8e3acfd2e8a5825a1f6f0aca4a8
05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
Let's see what happened to the region of "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~129.5m for region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in 13299ms, sequenceid=20311822, compaction requested=true
00:30:49,242 DEBUG org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested for Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. because User-triggered split; priority=1, compaction queue size=5840
00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815 to hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815 to hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
00:30:59,614 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123, entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~133.5m for region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in 21816ms, sequenceid=20312223, compaction requested=true
00:30:59,787 DEBUG org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested for Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. because regionserver20020.cacheFlusher; priority=0, compaction queue size=5840
00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting compaction on region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed compaction on region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. after 0sec
00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction: Starting split of region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.: disabling compactions & flushes
00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates disabled for region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined parent region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in META
------
00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312223, majorCompaction=false
00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread: Region split, META updated, and report to master. Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8., new regions: Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e., Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a.. Split took 29sec
// At this time, found this region again in HLog#lastSeqWritten.
00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1 hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224 from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
Our HBase version is "0.90.5+" when we found this issue.
So after splitting and closing, how this region come into HLog.lastSeqWritten?
We analyze all the related code, it seems impossible. Because after a region be closed, it has no chance to add this region into HLog.lastSeqWritten again.
So I want to get some insight here from someone who is intimately familiar with this or has encountered the similar problem.
Thanks and Regards,
Jieshan
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by bijieshan <bi...@huawei.com>.
Ted:
Below is the search info for "20312224" "20312223" "20312225". We also analyzed this but got nothing:(
[20312224]
00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
00:31:42,541 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.; next sequenceid=20312224
00:31:42,595 INFO org.apache.hadoop.hbase.regionserver.Store: Started compaction of 10 file(s) in cf=value, hasReferences=true, into hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/.tmp, seqid=20312224, totalSize=1.6g
00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1 hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224 from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
01:39:14,494 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/1634833527842694834, isReference=false, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
01:55:15,293 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/1634833527842694834, isReference=false, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
[20312223]
00:30:59,614 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123, entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~133.5m for region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in 21816ms, sequenceid=20312223, compaction requested=true
00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312223, majorCompaction=false
[20312225]
00:31:42,531 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a.; next sequenceid=20312225
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 14:33
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Jieshan:
Can you search the region server log for seq id: 20312224 ?
Thanks
2012/1/24 Ramkrishna.S.Vasudevan <ra...@huawei.com>
> HBASE-5225 was merged for different purpose. But this issue does not seem
> to be because of HBASE-5225.
> Because in HBASE-5225 we tried to fix the case where the seq id is missed.
> Here it is not missed it is still there in lastSeqWritten without getting
> flushed.
>
> Regards
> Ram
>
> -----Original Message-----
> From: bijieshan [mailto:bijieshan@huawei.com]
> Sent: Wednesday, January 25, 2012 10:59 AM
> To: user@hbase.apache.org; dev@hbase.apache.org
> Cc: Chenjian
> Subject: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
> this.
> Thanks.
> Jieshan
>
> -----邮件原件-----
> 发件人: Ted Yu [mailto:yuzhihong@gmail.com]
> 发送时间: 2012年1月25日 13:18
> 收件人: dev@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Can you provide more detail on this 0.90.5 +, please ?
>
> Did it include HBASE-5225 ?
>
> Thanks
>
> On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
>
> > Hi all,
> > We found so many hlogs in our cluster, after some analysis, we also found
> > one splitted region occurred in HLog.lastSeqWritten. For this region had
> > been closed, it can't be flushed again. So blocking all the other logs
> > removing to ".oldlogs" directory.
> >
> > 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> >
> > Let's see what happened to the region of
> > "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
> >
> > 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~129.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 13299ms, sequenceid=20311822, compaction requested=true
> > 00:30:49,242 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because User-triggered split; priority=1, compaction queue size=5840
> > 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> > flushed file at hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:55,214<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:59,614<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> ,
> > entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> > 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~133.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 21816ms, sequenceid=20312223, compaction requested=true
> > 00:30:59,787 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because regionserver20020.cacheFlusher; priority=0, compaction queue
> > size=5840
> > 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> after
> > 0sec
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> > Starting split of region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> > disabling compactions & flushes
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> > disabled for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> > parent region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > META
> > ------
> > 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312224,
> > majorCompaction=false
> > 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312223,
> > majorCompaction=false
> > 00:31:42,575 INFO
> org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> > Region split, META updated, and report to master.
> >
>
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> ,
> > new regions:
> > Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> >
>
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
> 76bbca29cee84a..
> > Split took 29sec
> > // At this time, found this region again in HLog#lastSeqWritten.
> > 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> > hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> > from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> >
> > Our HBase version is "0.90.5+" when we found this issue.
> >
> > So after splitting and closing, how this region come into
> > HLog.lastSeqWritten?
> >
> > We analyze all the related code, it seems impossible. Because after a
> > region be closed, it has no chance to add this region into
> > HLog.lastSeqWritten again.
> >
> > So I want to get some insight here from someone who is intimately
> familiar
> > with this or has encountered the similar problem.
> >
> > Thanks and Regards,
> > Jieshan
> >
>
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by bijieshan <bi...@huawei.com>.
Ted:
Below is the search info for "20312224" "20312223" "20312225". We also analyzed this but got nothing:(
[20312224]
00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
00:31:42,541 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.; next sequenceid=20312224
00:31:42,595 INFO org.apache.hadoop.hbase.regionserver.Store: Started compaction of 10 file(s) in cf=value, hasReferences=true, into hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/.tmp, seqid=20312224, totalSize=1.6g
00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1 hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224 from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
01:39:14,494 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/1634833527842694834, isReference=false, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
01:55:15,293 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/1634833527842694834, isReference=false, isBulkLoadResult=false, seqid=20312224, majorCompaction=false
[20312223]
00:30:59,614 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123, entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~133.5m for region Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in 21816ms, sequenceid=20312223, compaction requested=true
00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8, isReference=true, isBulkLoadResult=false, seqid=20312223, majorCompaction=false
[20312225]
00:31:42,531 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a.; next sequenceid=20312225
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 14:33
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Jieshan:
Can you search the region server log for seq id: 20312224 ?
Thanks
2012/1/24 Ramkrishna.S.Vasudevan <ra...@huawei.com>
> HBASE-5225 was merged for different purpose. But this issue does not seem
> to be because of HBASE-5225.
> Because in HBASE-5225 we tried to fix the case where the seq id is missed.
> Here it is not missed it is still there in lastSeqWritten without getting
> flushed.
>
> Regards
> Ram
>
> -----Original Message-----
> From: bijieshan [mailto:bijieshan@huawei.com]
> Sent: Wednesday, January 25, 2012 10:59 AM
> To: user@hbase.apache.org; dev@hbase.apache.org
> Cc: Chenjian
> Subject: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
> this.
> Thanks.
> Jieshan
>
> -----邮件原件-----
> 发件人: Ted Yu [mailto:yuzhihong@gmail.com]
> 发送时间: 2012年1月25日 13:18
> 收件人: dev@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Can you provide more detail on this 0.90.5 +, please ?
>
> Did it include HBASE-5225 ?
>
> Thanks
>
> On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
>
> > Hi all,
> > We found so many hlogs in our cluster, after some analysis, we also found
> > one splitted region occurred in HLog.lastSeqWritten. For this region had
> > been closed, it can't be flushed again. So blocking all the other logs
> > removing to ".oldlogs" directory.
> >
> > 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> >
> > Let's see what happened to the region of
> > "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
> >
> > 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~129.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 13299ms, sequenceid=20311822, compaction requested=true
> > 00:30:49,242 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because User-triggered split; priority=1, compaction queue size=5840
> > 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> > flushed file at hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:55,214<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:59,614<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> ,
> > entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> > 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~133.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 21816ms, sequenceid=20312223, compaction requested=true
> > 00:30:59,787 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because regionserver20020.cacheFlusher; priority=0, compaction queue
> > size=5840
> > 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> after
> > 0sec
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> > Starting split of region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> > disabling compactions & flushes
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> > disabled for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> > parent region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > META
> > ------
> > 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312224,
> > majorCompaction=false
> > 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312223,
> > majorCompaction=false
> > 00:31:42,575 INFO
> org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> > Region split, META updated, and report to master.
> >
>
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> ,
> > new regions:
> > Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> >
>
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
> 76bbca29cee84a..
> > Split took 29sec
> > // At this time, found this region again in HLog#lastSeqWritten.
> > 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> > hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> > from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> >
> > Our HBase version is "0.90.5+" when we found this issue.
> >
> > So after splitting and closing, how this region come into
> > HLog.lastSeqWritten?
> >
> > We analyze all the related code, it seems impossible. Because after a
> > region be closed, it has no chance to add this region into
> > HLog.lastSeqWritten again.
> >
> > So I want to get some insight here from someone who is intimately
> familiar
> > with this or has encountered the similar problem.
> >
> > Thanks and Regards,
> > Jieshan
> >
>
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by Ted Yu <yu...@gmail.com>.
Jieshan:
Can you search the region server log for seq id: 20312224 ?
Thanks
2012/1/24 Ramkrishna.S.Vasudevan <ra...@huawei.com>
> HBASE-5225 was merged for different purpose. But this issue does not seem
> to be because of HBASE-5225.
> Because in HBASE-5225 we tried to fix the case where the seq id is missed.
> Here it is not missed it is still there in lastSeqWritten without getting
> flushed.
>
> Regards
> Ram
>
> -----Original Message-----
> From: bijieshan [mailto:bijieshan@huawei.com]
> Sent: Wednesday, January 25, 2012 10:59 AM
> To: user@hbase.apache.org; dev@hbase.apache.org
> Cc: Chenjian
> Subject: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
> this.
> Thanks.
> Jieshan
>
> -----邮件原件-----
> 发件人: Ted Yu [mailto:yuzhihong@gmail.com]
> 发送时间: 2012年1月25日 13:18
> 收件人: dev@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Can you provide more detail on this 0.90.5 +, please ?
>
> Did it include HBASE-5225 ?
>
> Thanks
>
> On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
>
> > Hi all,
> > We found so many hlogs in our cluster, after some analysis, we also found
> > one splitted region occurred in HLog.lastSeqWritten. For this region had
> > been closed, it can't be flushed again. So blocking all the other logs
> > removing to ".oldlogs" directory.
> >
> > 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> >
> > Let's see what happened to the region of
> > "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
> >
> > 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~129.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 13299ms, sequenceid=20311822, compaction requested=true
> > 00:30:49,242 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because User-triggered split; priority=1, compaction queue size=5840
> > 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> > flushed file at hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:55,214<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:59,614<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> ,
> > entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> > 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~133.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 21816ms, sequenceid=20312223, compaction requested=true
> > 00:30:59,787 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because regionserver20020.cacheFlusher; priority=0, compaction queue
> > size=5840
> > 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> after
> > 0sec
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> > Starting split of region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> > disabling compactions & flushes
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> > disabled for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> > parent region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > META
> > ------
> > 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312224,
> > majorCompaction=false
> > 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312223,
> > majorCompaction=false
> > 00:31:42,575 INFO
> org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> > Region split, META updated, and report to master.
> >
>
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> ,
> > new regions:
> > Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> >
>
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
> 76bbca29cee84a..
> > Split took 29sec
> > // At this time, found this region again in HLog#lastSeqWritten.
> > 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> > hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> > from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> >
> > Our HBase version is "0.90.5+" when we found this issue.
> >
> > So after splitting and closing, how this region come into
> > HLog.lastSeqWritten?
> >
> > We analyze all the related code, it seems impossible. Because after a
> > region be closed, it has no chance to add this region into
> > HLog.lastSeqWritten again.
> >
> > So I want to get some insight here from someone who is intimately
> familiar
> > with this or has encountered the similar problem.
> >
> > Thanks and Regards,
> > Jieshan
> >
>
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by Ted Yu <yu...@gmail.com>.
Jieshan:
Can you search the region server log for seq id: 20312224 ?
Thanks
2012/1/24 Ramkrishna.S.Vasudevan <ra...@huawei.com>
> HBASE-5225 was merged for different purpose. But this issue does not seem
> to be because of HBASE-5225.
> Because in HBASE-5225 we tried to fix the case where the seq id is missed.
> Here it is not missed it is still there in lastSeqWritten without getting
> flushed.
>
> Regards
> Ram
>
> -----Original Message-----
> From: bijieshan [mailto:bijieshan@huawei.com]
> Sent: Wednesday, January 25, 2012 10:59 AM
> To: user@hbase.apache.org; dev@hbase.apache.org
> Cc: Chenjian
> Subject: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
> this.
> Thanks.
> Jieshan
>
> -----邮件原件-----
> 发件人: Ted Yu [mailto:yuzhihong@gmail.com]
> 发送时间: 2012年1月25日 13:18
> 收件人: dev@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Closed parent region present in Hlog.lastSeqWritten
>
> Can you provide more detail on this 0.90.5 +, please ?
>
> Did it include HBASE-5225 ?
>
> Thanks
>
> On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
>
> > Hi all,
> > We found so many hlogs in our cluster, after some analysis, we also found
> > one splitted region occurred in HLog.lastSeqWritten. For this region had
> > been closed, it can't be flushed again. So blocking all the other logs
> > removing to ".oldlogs" directory.
> >
> > 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> > 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> > hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> > 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> > 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> > to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
> requester=null
> >
> > Let's see what happened to the region of
> > "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
> >
> > 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~129.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 13299ms, sequenceid=20311822, compaction requested=true
> > 00:30:49,242 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because User-triggered split; priority=1, compaction queue size=5840
> > 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> > flushed file at hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:55,214<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
> mp/1755862026714756815to<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t%0Amp/1755862026714756815to>hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> >
> 00:30:59,614<
> http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
> a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8%0Aa5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>
> >INFO
> org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
> lue/973789709483406123<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va%0Alue/973789709483406123>
> ,
> > entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> > 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> > memstore flush of ~133.5m for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > 21816ms, sequenceid=20312223, compaction requested=true
> > 00:30:59,787 DEBUG
> > org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> > requested for
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > because regionserver20020.cacheFlusher; priority=0, compaction queue
> > size=5840
> > 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> > compaction on region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> after
> > 0sec
> > 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> > Starting split of region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> > disabling compactions & flushes
> > 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> > disabled for region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> > 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> > parent region
> > Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> > META
> > ------
> > 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312224,
> > majorCompaction=false
> > 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> > hdfs://
> >
>
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
> lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8<http://192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va%0Alue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8>
> ,
> > isReference=true, isBulkLoadResult=false, seqid=20312223,
> > majorCompaction=false
> > 00:31:42,575 INFO
> org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> > Region split, META updated, and report to master.
> >
>
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> ,
> > new regions:
> > Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> >
>
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
> 76bbca29cee84a..
> > Split took 29sec
> > // At this time, found this region again in HLog#lastSeqWritten.
> > 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> > hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> > from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> >
> > Our HBase version is "0.90.5+" when we found this issue.
> >
> > So after splitting and closing, how this region come into
> > HLog.lastSeqWritten?
> >
> > We analyze all the related code, it seems impossible. Because after a
> > region be closed, it has no chance to add this region into
> > HLog.lastSeqWritten again.
> >
> > So I want to get some insight here from someone who is intimately
> familiar
> > with this or has encountered the similar problem.
> >
> > Thanks and Regards,
> > Jieshan
> >
>
>
RE: Closed parent region present in Hlog.lastSeqWritten
Posted by "Ramkrishna.S.Vasudevan" <ra...@huawei.com>.
HBASE-5225 was merged for different purpose. But this issue does not seem
to be because of HBASE-5225.
Because in HBASE-5225 we tried to fix the case where the seq id is missed.
Here it is not missed it is still there in lastSeqWritten without getting
flushed.
Regards
Ram
-----Original Message-----
From: bijieshan [mailto:bijieshan@huawei.com]
Sent: Wednesday, January 25, 2012 10:59 AM
To: user@hbase.apache.org; dev@hbase.apache.org
Cc: Chenjian
Subject: Re: Closed parent region present in Hlog.lastSeqWritten
Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
this.
Thanks.
Jieshan
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 13:18
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
mp/1755862026714756815to hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123
>
00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO
org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
mp/1755862026714756815to hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123
>
00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO
org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
>
Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
>
Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
76bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>
RE: Closed parent region present in Hlog.lastSeqWritten
Posted by "Ramkrishna.S.Vasudevan" <ra...@huawei.com>.
HBASE-5225 was merged for different purpose. But this issue does not seem
to be because of HBASE-5225.
Because in HBASE-5225 we tried to fix the case where the seq id is missed.
Here it is not missed it is still there in lastSeqWritten without getting
flushed.
Regards
Ram
-----Original Message-----
From: bijieshan [mailto:bijieshan@huawei.com]
Sent: Wednesday, January 25, 2012 10:59 AM
To: user@hbase.apache.org; dev@hbase.apache.org
Cc: Chenjian
Subject: Re: Closed parent region present in Hlog.lastSeqWritten
Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with
this.
Thanks.
Jieshan
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 13:18
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null,
requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
mp/1755862026714756815to hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123
>
00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO
org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.t
mp/1755862026714756815to hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123
>
00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8
a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO
org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/va
lue/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/va
lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
>
192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/va
lue/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
>
Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
>
Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e03378
76bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by bijieshan <bi...@huawei.com>.
Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with this.
Thanks.
Jieshan
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 13:18
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by bijieshan <bi...@huawei.com>.
Not including HBASE-5225(before 0.90.6.rc0). I think no relationship with this.
Thanks.
Jieshan
-----邮件原件-----
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2012年1月25日 13:18
收件人: dev@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Closed parent region present in Hlog.lastSeqWritten
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by Ted Yu <yu...@gmail.com>.
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>
Re: Closed parent region present in Hlog.lastSeqWritten
Posted by Ted Yu <yu...@gmail.com>.
Can you provide more detail on this 0.90.5 +, please ?
Did it include HBASE-5225 ?
Thanks
On Tue, Jan 24, 2012 at 8:55 PM, bijieshan <bi...@huawei.com> wrote:
> Hi all,
> We found so many hlogs in our cluster, after some analysis, we also found
> one splitted region occurred in HLog.lastSeqWritten. For this region had
> been closed, it can't be flushed again. So blocking all the other logs
> removing to ".oldlogs" directory.
>
> 05:06:44,422 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=122, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:06:44,422 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:10:48,666 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=123, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:10:48,666 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:14:46,075 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=124, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:14:46,075 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
> 05:15:41,584 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too many
> hlogs: logs=125, maxlogs=32; forcing flush of 1 regions(s):
> 2acaf8e3acfd2e8a5825a1f6f0aca4a8
> 05:15:41,584 WARN org.apache.hadoop.hbase.regionserver.LogRoller: Failed
> to schedule flush of 2acaf8e3acfd2e8a5825a1f6f0aca4a8r=null, requester=null
>
> Let's see what happened to the region of
> "2acaf8e3acfd2e8a5825a1f6f0aca4a8r":
>
> 00:30:49,242 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~129.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 13299ms, sequenceid=20311822, compaction requested=true
> 00:30:49,242 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because User-triggered split; priority=1, compaction queue size=5840
> 00:30:55,214 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming
> flushed file at hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:55,214<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:55,214>INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/.tmp/1755862026714756815to hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123
> 00:30:59,614<http://192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123%0A00:30:59,614>INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/2acaf8e3acfd2e8a5825a1f6f0aca4a8/value/973789709483406123,
> entries=7537, sequenceid=20312223, memsize=4.2m, filesize=2.9m
> 00:30:59,787 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished
> memstore flush of ~133.5m for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> 21816ms, sequenceid=20312223, compaction requested=true
> 00:30:59,787 DEBUG
> org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
> requested for
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> because regionserver20020.cacheFlusher; priority=0, compaction queue
> size=5840
> 00:31:12,605 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.HRegion: completed
> compaction on region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. after
> 0sec
> 00:31:12,607 INFO org.apache.hadoop.hbase.regionserver.SplitTransaction:
> Starting split of region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.:
> disabling compactions & flushes
> 00:31:13,694 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates
> disabled for region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:13,718 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.
> 00:31:39,552 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Offlined
> parent region
> Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8. in
> META
> ------
> 00:31:42,529 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/52ff3c7c6df6e0337876bbca29cee84a/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312224,
> majorCompaction=false
> 00:31:42,532 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded
> hdfs://
> 192.168.1.103:9000/hbase/Htable_UFDR_031/259d0c620c9105928e52713f4a5a252e/value/973789709483406123.2acaf8e3acfd2e8a5825a1f6f0aca4a8,
> isReference=true, isBulkLoadResult=false, seqid=20312223,
> majorCompaction=false
> 00:31:42,575 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread:
> Region split, META updated, and report to master.
> Parent=Htable_UFDR_031,00332,1325808823997.2acaf8e3acfd2e8a5825a1f6f0aca4a8.,
> new regions:
> Htable_UFDR_031,00332,1325809872607.259d0c620c9105928e52713f4a5a252e.,
> Htable_UFDR_031,003732800093168-03594291912,1325809872607.52ff3c7c6df6e0337876bbca29cee84a..
> Split took 29sec
> // At this time, found this region again in HLog#lastSeqWritten.
> 00:34:48,061 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 1
> hlogs to remove out of total 4; oldest outstanding sequenceid is 20312224
> from region 2acaf8e3acfd2e8a5825a1f6f0aca4a8
>
> Our HBase version is "0.90.5+" when we found this issue.
>
> So after splitting and closing, how this region come into
> HLog.lastSeqWritten?
>
> We analyze all the related code, it seems impossible. Because after a
> region be closed, it has no chance to add this region into
> HLog.lastSeqWritten again.
>
> So I want to get some insight here from someone who is intimately familiar
> with this or has encountered the similar problem.
>
> Thanks and Regards,
> Jieshan
>