[
https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659763#action_12659763
]
stack commented on HBASE-1092:
------------------------------
Looking more, the log would seem to say the index file was present when we
opened the Store but looking at the code, it might not have been; our check a
file is empty says file is empty IF FILE EXISTS. I'm changing the check for
empty file to say file is empty if doesn't exist (especially as if it comes
back that the index file is not present, we can actually effect a repair).
{code}
Index: src/java/org/apache/hadoop/hbase/regionserver/HStore.java
===================================================================
--- src/java/org/apache/hadoop/hbase/regionserver/HStore.java (revision
730056)
+++ src/java/org/apache/hadoop/hbase/regionserver/HStore.java (working copy)
@@ -558,8 +558,7 @@
*/
private boolean isEmptyFile(final Path f)
throws IOException {
- return this.fs.exists(f) &&
- this.fs.getFileStatus(f).getLen() == 0;
+ return !this.fs.exists(f) || this.fs.getFileStatus(f).getLen() == 0;
}
/**
{code}
Need to test the above doesn't break 'normal' operation.
I think that regards this issue, something had happened earlier in hdfs. This
stuck in metrics is just a symptom. Regions should just not deploy if can't
have an index on store file; i.e. fail earlier.
> FileNotFoundException trying to get index file size for metrics
> ---------------------------------------------------------------
>
> Key: HBASE-1092
> URL: https://issues.apache.org/jira/browse/HBASE-1092
> Project: Hadoop HBase
> Issue Type: Bug
> Environment: apurtell cluster; trunk on hadoop 0.18.1.
> Reporter: stack
> Fix For: 0.19.0
>
>
> This is an odd one. We open a region and load up its store files. Part of
> loading store files is confirming presence of MapFile index files
> (reconstituting them even if missing). The below log is of region open and
> then seconds later, failing to find the index files when we go to look at
> them for sake of metrics:
> {code}
> 2008-12-28 00:06:19,330 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: MSG_REGION_OPEN:
> content,10a1c144cf729885001e71a5ff5108dc,1230416158498
> 2008-12-28 00:06:19,330 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region
> content,10a1c144cf729885001e71a5ff5108dc,1230416158498/2030495720
> 2008-12-28 00:06:19,337 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/url/info/4139998553412763261,
> isReference=false, sequence id=13310628, length=54275, majorCompaction=false
> 2008-12-28 00:06:19,368 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/url/info/4467064002967944271,
> isReference=false, sequence id=9760762, length=432827, majorCompaction=false
> 2008-12-28 00:06:19,373 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/url/info/5563124412728188459,
> isReference=false, sequence id=12406630, length=22596, majorCompaction=false
> 2008-12-28 00:06:19,379 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/url/info/7040855870376599550,
> isReference=false, sequence id=12795530, length=4163, majorCompaction=false
> 2008-12-28 00:06:19,379 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Loaded 4 file(s) in hstore 2030495720/url, max sequence id 13310628
> 2008-12-28 00:06:19,496 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Applied 0, skipped 2078 because sequence id <= 13310628
> 2008-12-28 00:06:19,687 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/info/info/4076087643455354411,
> isReference=false, sequence id=9760762, length=1491212, majorCompaction=false
> 2008-12-28 00:06:19,691 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/info/info/4178444212265859440,
> isReference=false, sequence id=13310628, length=156148, majorCompaction=false
> 2008-12-28 00:06:19,697 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/info/info/7223110203696352566,
> isReference=false, sequence id=12406630, length=84614, majorCompaction=false
> 2008-12-28 00:06:19,703 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/info/info/8629305049543986640,
> isReference=false, sequence id=12795530, length=9293, majorCompaction=false
> 2008-12-28 00:06:19,704 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Loaded 4 file(s) in hstore 2030495720/info, max sequence id 13310628
> 2008-12-28 00:06:19,773 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> moving
> /data/hbase/content/compaction.dir/888098363/content/mapfiles/3159110292991346789
> to /data/hbase/content/888098363/content/mapfiles/6086595812879433437
> 2008-12-28 00:06:19,787 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Completed compaction of 888098363/content store size is 172.4m
> 2008-12-28 00:06:19,791 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Compaction size of 888098363/info: 1.4m; Skipped 2 file(s), size: 1221094
> 2008-12-28 00:06:19,801 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Started compaction of 2 file(s) into
> /data/hbase/content/compaction.dir/888098363/info/mapfiles/2317624608256855622
> 2008-12-28 00:06:19,821 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Applied 0, skipped 2078 because sequence id <= 13310628
> 2008-12-28 00:06:19,879 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> moving
> /data/hbase/content/compaction.dir/888098363/info/mapfiles/2317624608256855622
> to /data/hbase/content/888098363/info/mapfiles/2738033219360665217
> 2008-12-28 00:06:19,883 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/content/info/2253403598042963153,
> isReference=false, sequence id=13310628, length=12491312,
> majorCompaction=false
> 2008-12-28 00:06:19,887 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/content/info/4596284995168293361,
> isReference=false, sequence id=9760762, length=158138153,
> majorCompaction=false
> 2008-12-28 00:06:19,896 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Completed compaction of 888098363/info store size is 1.4m
> 2008-12-28 00:06:19,898 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Compaction size of 888098363/url: 405.9k; Skipped 2 file(s), size: 339984
> 2008-12-28 00:06:19,904 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Started compaction of 2 file(s) into
> /data/hbase/content/compaction.dir/888098363/url/mapfiles/1108952767537472093
> 2008-12-28 00:06:19,924 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/content/info/7464468628166271570,
> isReference=false, sequence id=12406630, length=11058492,
> majorCompaction=false
> 2008-12-28 00:06:19,930 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> loaded /data/hbase/content/2030495720/content/info/7703689073557380324,
> isReference=false, sequence id=12795530, length=183695, majorCompaction=false
> 2008-12-28 00:06:19,931 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Loaded 4 file(s) in hstore 2030495720/content, max sequence id 13310628
> 2008-12-28 00:06:19,958 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> moving
> /data/hbase/content/compaction.dir/888098363/url/mapfiles/1108952767537472093
> to /data/hbase/content/888098363/url/mapfiles/4113677425818108069
> 2008-12-28 00:06:19,976 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Completed compaction of 888098363/url store size is 403.6k
> 2008-12-28 00:06:19,978 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> compaction completed on region
> content,846510f382e9a0ae5655f03cb772830d,1230384248550 in 0sec
> 2008-12-28 00:06:19,979 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> starting compaction on region
> content,e2f10daf46269ad3cc25766aa3bf48c4,1230416165744
> 2008-12-28 00:06:19,981 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Compaction size of 2100409777/content: 170.2m; Skipped 1 file(s), size:
> 144757669
> 2008-12-28 00:06:19,996 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Started compaction of 2 file(s) into
> /data/hbase/content/compaction.dir/2100409777/content/mapfiles/7166480659109830957
> 2008-12-28 00:06:20,033 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Applied 0, skipped 2078 because sequence id <= 13310628
> 2008-12-28 00:06:20,127 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Deleting old log file:
> hdfs://sjdc-atr-dc-1.atr.trendmicro.com:50000/data/hbase/content/2030495720/oldlogfile.log
> 2008-12-28 00:06:20,137 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Next sequence id for region
> content,10a1c144cf729885001e71a5ff5108dc,1230416158498 is 13310629
> 2008-12-28 00:06:20,138 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> region content,10a1c144cf729885001e71a5ff5108dc,1230416158498/2030495720
> available
> ....
> 2008-12-28 00:06:21,008 DEBUG org.apache.hadoop.hbase.regionserver.HStore:
> Started compaction of 2 file(s) into
> /data/hbase/content/compaction.dir/2100409777/url/mapfiles/744229794307693860
> 2008-12-28 00:06:21,030 WARN
> org.apache.hadoop.hbase.regionserver.HRegionServer: error getting store file
> index size for 2030495720/content: java.io.FileNotFoundException: File does
> not exist:
> hdfs://sjdc-atr-dc-1.atr.trendmicro.com:50000/data/hbase/content/2030495720/content/mapfiles/7703689073557380324/index
> at
> org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:394)
> at
> org.apache.hadoop.hbase.regionserver.HStoreFile.indexLength(HStoreFile.java:488)
> at
> org.apache.hadoop.hbase.regionserver.HStore.getStorefilesIndexSize(HStore.java:2174)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.doMetrics(HRegionServer.java:936)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:333)
> at java.lang.Thread.run(Thread.java:619)
> 2008-12-28 00:06:21,032 WARN
> org.apache.hadoop.hbase.regionserver.HRegionServer: error getting store file
> index size for 2030495720/info: java.io.FileNotFoundException: File does not
> exist:
> hdfs://sjdc-atr-dc-1.atr.trendmicro.com:50000/data/hbase/content/2030495720/info/mapfiles/8629305049543986640/index
> at
> org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:394)
> at
> org.apache.hadoop.hbase.regionserver.HStoreFile.indexLength(HStoreFile.java:488)
> at
> org.apache.hadoop.hbase.regionserver.HStore.getStorefilesIndexSize(HStore.java:2174)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.doMetrics(HRegionServer.java:936)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:333)
>
> at java.lang.Thread.run(Thread.java:619)
> 2008-12-28 00:06:21,053 WARN
> org.apache.hadoop.hbase.regionserver.HRegionServer: error getting store file
> index size for 2030495720/url: java.io.FileNotFoundException: File does not
> exist:
> hdfs://sjdc-atr-dc-1.atr.trendmicro.com:50000/data/hbase/content/2030495720/url/mapfiles/7040855870376599550/index
> at
> org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:394)
> at
> org.apache.hadoop.hbase.regionserver.HStoreFile.indexLength(HStoreFile.java:488)
> at
> org.apache.hadoop.hbase.regionserver.HStore.getStorefilesIndexSize(HStore.java:2174)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.doMetrics(HRegionServer.java:936)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:333)
> at java.lang.Thread.run(Thread.java:619)
> ...
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
