You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by "stack (JIRA)" <ji...@apache.org> on 2008/12/29 00:06:44 UTC
[jira] Created: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
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
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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "Andrew Purtell (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659828#action_12659828 ]
Andrew Purtell commented on HBASE-1092:
---------------------------------------
I'm getting FNF on indexes on my cluster. I deployed the above change locally.
> 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
> Assignee: 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12660003#action_12660003 ]
stack commented on HBASE-1092:
------------------------------
The above commit broke the build. I want to figure why before backing it out. I'd like to keep the patch in if I can.
> 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
> Assignee: stack
>
> 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.
[jira] Assigned: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack reassigned HBASE-1092:
----------------------------
Assignee: stack
> 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
> Assignee: 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12660127#action_12660127 ]
stack commented on HBASE-1092:
------------------------------
This is different but logging it here because 'weird' FNFE issue:
{code}
2008-12-31 02:18:35,119 [regionserver/0:0:0:0:0:0:0:0:60020.worker] DEBUG org.apache.hadoop.hbase.regionserver.HRegion: waiting for compaction to complete for region TestTable,0000515246,1230688952892
2008-12-31 02:18:35,119 [regionserver/0:0:0:0:0:0:0:0:60020.cacheFlusher] FATAL org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Replay of hlog required. Forcing server shutdown
org.apache.hadoop.hbase.DroppedSnapshotException: region: TestTable,0000515246,1230688952892
at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:880)
at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:773)
at org.apache.hadoop.hbase.regionserver.MemcacheFlusher.flushRegion(MemcacheFlusher.java:227)
at org.apache.hadoop.hbase.regionserver.MemcacheFlusher.run(MemcacheFlusher.java:137)
Caused by: java.io.FileNotFoundException: File does not exist: hdfs://aa0-000-12.u.powerset.com:9000/hbasetrunk2/TestTable/1485814348/info/mapfiles/7021491802461813204/data
at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:394)
at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:679)
at org.apache.hadoop.hbase.io.SequenceFile$Reader.<init>(SequenceFile.java:1431)
at org.apache.hadoop.hbase.io.SequenceFile$Reader.<init>(SequenceFile.java:1426)
at org.apache.hadoop.hbase.io.HBaseMapFile$HBaseReader$1.<init>(HBaseMapFile.java:100)
at org.apache.hadoop.hbase.io.HBaseMapFile$HBaseReader.createDataFileReader(HBaseMapFile.java:100)
at org.apache.hadoop.hbase.io.MapFile$Reader.open(MapFile.java:292)
at org.apache.hadoop.hbase.io.HBaseMapFile$HBaseReader.<init>(HBaseMapFile.java:79)
at org.apache.hadoop.hbase.io.BloomFilterMapFile$Reader.<init>(BloomFilterMapFile.java:65)
at org.apache.hadoop.hbase.regionserver.HStoreFile.getReader(HStoreFile.java:443)
at org.apache.hadoop.hbase.regionserver.HStore.updateReaders(HStore.java:719)
at org.apache.hadoop.hbase.regionserver.HStore.internalFlushCache(HStore.java:693)
at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:629)
at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:865)
{code}
Above was trunk. Didn't have the change to isEmptyFile in place. Above is saying the file we just wrote flushing doesn't exist when we go to open a Reader on it.
> 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
> Assignee: stack
>
> 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659859#action_12659859 ]
stack commented on HBASE-1092:
------------------------------
Can I see one of the stack traces Andrew?
> 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
> Assignee: 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "Andrew Purtell (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12660130#action_12660130 ]
Andrew Purtell commented on HBASE-1092:
---------------------------------------
Are you seeing anything like this in the master log?
2008-12-30 05:21:20,673 INFO org.apache.hadoop.fs.FSNamesystem: Recovering lease=[Lease. Holder: DFSClient_85822244, pendingcreates: 2], src=/data/hbase/content/1486100541/content/mapfiles/6488314919128681661/data
2008-12-30 05:21:20,673 WARN org.apache.hadoop.dfs.StateChange: BLOCK* internalReleaseLease: No blocks found, lease removed.
> 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
> Assignee: stack
>
> 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.
[jira] Updated: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack updated HBASE-1092:
-------------------------
Fix Version/s: (was: 0.19.0)
Committed the change in empty file symantecs. Should flag missing files earlier.
Moving this issue out of 0.19.0. We should address fact that failure in metrics causes HRS to do nothing else but the root of this issue is an HDFS issue. That we're addressing in other issues in 0.19.0 and elsewhere.
> 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
> Assignee: stack
>
> 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.
[jira] Updated: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack updated HBASE-1092:
-------------------------
Fix Version/s: 0.19.0
This metrics exception goes on and on in the logs; at a minium, should just keep going w/o metric. Not end of world if can't get a metric.
Looking more, this is serious. Getting metric is at head of the HRS#run loop. Means that the HRS does nothing else but this exception.
Bringing into 0.19.0.
> 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12660157#action_12660157 ]
stack commented on HBASE-1092:
------------------------------
Amended committed patch; don't check for empty file if reference:
{code}
Index: src/java/org/apache/hadoop/hbase/regionserver/HStore.java
===================================================================
--- src/java/org/apache/hadoop/hbase/regionserver/HStore.java (revision 730325)
+++ src/java/org/apache/hadoop/hbase/regionserver/HStore.java (working copy)
@@ -457,14 +457,15 @@
"Cleaned up info file. Continuing...Probable DATA LOSS!!!");
continue;
}
- if (isEmptyDataFile(mapfile)) {
+ // References don't have data or index components under mapfile.
+ if (!isReference && isEmptyDataFile(mapfile)) {
curfile.delete();
// We can have empty data file if data loss in hdfs.
LOG.warn("Mapfile " + mapfile.toString() + " has empty data. " +
"Deleting. Continuing...Probable DATA LOSS!!! See HBASE-646.");
continue;
}
- if (isEmptyIndexFile(mapfile)) {
+ if (!isReference && isEmptyIndexFile(mapfile)) {
try {
// Try fixing this file.. if we can. Use the hbase version of fix.
// Need to remove the old index file first else fix won't go ahead.
{code}
> 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
> Assignee: stack
>
> 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.
[jira] Resolved: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack resolved HBASE-1092.
--------------------------
Resolution: Cannot Reproduce
Haven't seen since. Resolving.
> 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
> Assignee: stack
>
> 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ 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.
[jira] Commented: (HBASE-1092) FileNotFoundException trying to get
index file size for metrics
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1092?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12660131#action_12660131 ]
stack commented on HBASE-1092:
------------------------------
No. Not seeing that. Still looking...
> 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
> Assignee: stack
>
> 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.