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.
