HBase
  1. HBase
  2. HBASE-766

FileNotFoundException trying to load HStoreFile 'data'

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.2.0
    • Component/s: None
    • Labels:
      None

      Description

      From Renaud Delbru up on the list:

      Hi,
      
      after our issues ("Replay of HLog required", in a precious thread) with HBase, it seems that HBase has corrupted regions.
      We have, on the three region servers, errors stating that HBase cannot open certain regions because some map files on hdfs are missing (see the log attached).
      
      Do you have any ideas how to fix this ?
      
      Thanks.
      
      java.io.FileNotFoundException: File does not exist: hdfs://hadoop1.sindice.net:54310/hbase/page-repository/1105668475/field/mapfiles/5122893264992435570/data
        at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:369)
        at org.apache.hadoop.hbase.regionserver.HStoreFile.length(HStoreFile.java:464)
        at org.apache.hadoop.hbase.regionserver.HStore.loadHStoreFiles(HStore.java:409)
        at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:236)
        at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:1575)
        at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:451)
        at org.apache.hadoop.hbase.regionserver.HRegionServer.instantiateRegion(HRegionServer.java:901)
        at org.apache.hadoop.hbase.regionserver.HRegionServer.openRegion(HRegionServer.java:876)
        at org.apache.hadoop.hbase.regionserver.HRegionServer$Worker.run(HRegionServer.java:816)
        at java.lang.Thread.run(Thread.java:619)
      
      

      I'd thought we'd added handling of this kind of event post HDFS crashings but looking in code, it seems that TRUNK may not have been fixed up properly.

      1. hs.patch
        0.7 kB
        stack
      2. 766.patch
        0.7 kB
        stack

        Activity

        Hide
        stack added a comment -

        Move the getting of file length to AFTER test of file existance.

        Show
        stack added a comment - Move the getting of file length to AFTER test of file existance.
        Hide
        stack added a comment -

        I committed this after running tests up on cluster to confirm doesn't break anything.

        Show
        stack added a comment - I committed this after running tests up on cluster to confirm doesn't break anything.
        Hide
        stack added a comment -

        Jon Gray can reliably reproduce. Looks like we are trying to split regions that still hold references.

        Show
        stack added a comment - Jon Gray can reliably reproduce. Looks like we are trying to split regions that still hold references.
        Hide
        stack added a comment -

        We dropped check for references; we need to always compact if references.

        Show
        stack added a comment - We dropped check for references; we need to always compact if references.
        Hide
        Jonathan Gray added a comment -

        stack, please confirm if i need to apply both patches or just hs.patch.

        Have actually tested with both patches, neither seems to change behavior at all.

        Again, happens during the second split of the problem table:

        2008-07-29 15:11:51,677 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Completed compaction of 426199566/content store size is 378.0m
        2008-07-29 15:11:51,684 INFO org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 in 7sec
        2008-07-29 15:11:51,686 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting split of region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Compactions and cache flushes disabled for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates and scanners disabled for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more active scanners for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384. Current region memcache size 1.9m
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/426199566/content/mapfiles/7100309375208596278 with 10296 entries, sequence id 2537536, data size 1.9m, file size 2.1m
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 in 92ms, sequence id=2537536, compaction requested=true
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/uclusters
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/covisit
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/content
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/clusters
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/readby
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/cfrecs
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/blooms
        2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/ranked
        2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/savedby
        2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/sentby
        2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/receivedby
        2008-07-29 15:11:51,782 INFO org.apache.hadoop.hbase.regionserver.HRegion: closed items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        2008-07-29 15:11:52,033 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369511688/509041795
        2008-07-29 15:11:52,049 INFO org.apache.hadoop.hbase.regionserver.HStore: HSTORE_LOGINFOFILE 509041795/savedby/4080673342751735986-426199566/8532274243649733439/bottom does not contain a sequence number - ignoring
        2008-07-29 15:11:52,052 ERROR org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction failed for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384
        java.io.FileNotFoundException: File does not exist: hdfs://mb0:9000/hbase/items/426199566/savedby/mapfiles/8532274243649733439/data
        at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:369)
        at org.apache.hadoop.hbase.regionserver.HStoreFile.length(HStoreFile.java:444)
        at org.apache.hadoop.hbase.regionserver.HStore.loadHStoreFiles(HStore.java:437)
        at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:219)
        at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:1618)
        at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:466)
        at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:405)
        at org.apache.hadoop.hbase.regionserver.HRegion.splitRegion(HRegion.java:800)
        at org.apache.hadoop.hbase.regionserver.CompactSplitThread.split(CompactSplitThread.java:133)
        at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:86)

        Show
        Jonathan Gray added a comment - stack, please confirm if i need to apply both patches or just hs.patch. Have actually tested with both patches, neither seems to change behavior at all. Again, happens during the second split of the problem table: 2008-07-29 15:11:51,677 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Completed compaction of 426199566/content store size is 378.0m 2008-07-29 15:11:51,684 INFO org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 in 7sec 2008-07-29 15:11:51,686 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting split of region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Compactions and cache flushes disabled for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates and scanners disabled for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more active scanners for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:51,689 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384. Current region memcache size 1.9m 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/426199566/content/mapfiles/7100309375208596278 with 10296 entries, sequence id 2537536, data size 1.9m, file size 2.1m 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 in 92ms, sequence id=2537536, compaction requested=true 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/uclusters 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/covisit 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/content 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/clusters 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/readby 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/cfrecs 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/blooms 2008-07-29 15:11:51,781 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/ranked 2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/savedby 2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/sentby 2008-07-29 15:11:51,782 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 426199566/receivedby 2008-07-29 15:11:51,782 INFO org.apache.hadoop.hbase.regionserver.HRegion: closed items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 2008-07-29 15:11:52,033 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369511688/509041795 2008-07-29 15:11:52,049 INFO org.apache.hadoop.hbase.regionserver.HStore: HSTORE_LOGINFOFILE 509041795/savedby/4080673342751735986-426199566/8532274243649733439/bottom does not contain a sequence number - ignoring 2008-07-29 15:11:52,052 ERROR org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction failed for region items,0050dab2-a057-43d9-8e99-0a41a3e6bdbb,1217369332384 java.io.FileNotFoundException: File does not exist: hdfs://mb0:9000/hbase/items/426199566/savedby/mapfiles/8532274243649733439/data at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:369) at org.apache.hadoop.hbase.regionserver.HStoreFile.length(HStoreFile.java:444) at org.apache.hadoop.hbase.regionserver.HStore.loadHStoreFiles(HStore.java:437) at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:219) at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:1618) at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:466) at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:405) at org.apache.hadoop.hbase.regionserver.HRegion.splitRegion(HRegion.java:800) at org.apache.hadoop.hbase.regionserver.CompactSplitThread.split(CompactSplitThread.java:133) at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:86)
        Hide
        stack added a comment -

        Patch 766.patch has already been committed. See comment above at 'stack - 23/Jul/08 03:10 PM'. That patch was about something else. hs.patch is latest (JIRA has date if you hover over it).

        I took a look up on your cluster. Looking at hb0 or in mb0, src doesn't show my patch in place. Where'd you build the jar?

        Show
        stack added a comment - Patch 766.patch has already been committed. See comment above at 'stack - 23/Jul/08 03:10 PM'. That patch was about something else. hs.patch is latest (JIRA has date if you hover over it). I took a look up on your cluster. Looking at hb0 or in mb0, src doesn't show my patch in place. Where'd you build the jar?
        Hide
        Jonathan Gray added a comment -

        Stack,

        I used the jar you built, confirmed across the cluster it was the one being used, and ran the test... I don't see any additional logging. Check out the region logs on hb5 (where items table was located).

        Here is the error again:

        2008-07-30 17:41:58,970 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950. Current region memcache size 64.0m
        2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/1211238171/content/mapfiles/793072914512989834 with 323136 entries, sequence id 2527714, data size 64.0m, file size 68.8m
        2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 1454ms, sequence id=2527714, compaction requested=true
        2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested for region: items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:00,424 INFO org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:00,428 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Compaction size 396611811, skipped 1, 252131417
        2008-07-30 17:42:00,454 DEBUG org.apache.hadoop.hbase.regionserver.HStore: started compaction of 2 files into /hbase/items/compaction.dir/1211238171/content/mapfiles/4240641699209031496
        2008-07-30 17:42:08,256 DEBUG org.apache.hadoop.hbase.regionserver.HStore: moving /hbase/items/compaction.dir/1211238171/content/mapfiles/4240641699209031496 to /hbase/items/1211238171/content/mapfiles/8894612533024691980
        2008-07-30 17:42:08,293 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Completed compaction of 1211238171/content store size is 377.8m
        2008-07-30 17:42:08,299 INFO org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 7sec
        2008-07-30 17:42:08,301 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting split of region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Compactions and cache flushes disabled for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates and scanners disabled for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more active scanners for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,305 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,305 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950. Current region memcache size 1.9m
        2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/1211238171/content/mapfiles/2539623802632323222 with 10032 entries, sequence id 2537747, data size 1.9m, file size 2.0m
        2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 101ms, sequence id=2537747, compaction requested=true
        2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/uclusters
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/covisit
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/content
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/clusters
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/readby
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/cfrecs
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/blooms
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/ranked
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/savedby
        2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/sentby
        2008-07-30 17:42:08,408 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/receivedby
        2008-07-30 17:42:08,408 INFO org.apache.hadoop.hbase.regionserver.HRegion: closed items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        2008-07-30 17:42:08,638 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464928303/2132462761
        2008-07-30 17:42:08,650 INFO org.apache.hadoop.hbase.regionserver.HStore: HSTORE_LOGINFOFILE 2132462761/readby/8482419619225016670-1211238171/6573863319629365608/bottom does not contain a sequence number - ignoring
        2008-07-30 17:42:08,653 ERROR org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction failed for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950
        java.io.FileNotFoundException: File does not exist: hdfs://mb0:9000/hbase/items/1211238171/readby/mapfiles/6573863319629365608/data
        at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:369)
        at org.apache.hadoop.hbase.regionserver.HStoreFile.length(HStoreFile.java:444)
        at org.apache.hadoop.hbase.regionserver.HStore.loadHStoreFiles(HStore.java:437)
        at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:219)
        at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:1618)
        at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:466)
        at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:405)
        at org.apache.hadoop.hbase.regionserver.HRegion.splitRegion(HRegion.java:800)
        at org.apache.hadoop.hbase.regionserver.CompactSplitThread.split(CompactSplitThread.java:133)
        at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:86)

        Show
        Jonathan Gray added a comment - Stack, I used the jar you built, confirmed across the cluster it was the one being used, and ran the test... I don't see any additional logging. Check out the region logs on hb5 (where items table was located). Here is the error again: 2008-07-30 17:41:58,970 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950. Current region memcache size 64.0m 2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/1211238171/content/mapfiles/793072914512989834 with 323136 entries, sequence id 2527714, data size 64.0m, file size 68.8m 2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 1454ms, sequence id=2527714, compaction requested=true 2008-07-30 17:42:00,424 DEBUG org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested for region: items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:00,424 INFO org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:00,428 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Compaction size 396611811, skipped 1, 252131417 2008-07-30 17:42:00,454 DEBUG org.apache.hadoop.hbase.regionserver.HStore: started compaction of 2 files into /hbase/items/compaction.dir/1211238171/content/mapfiles/4240641699209031496 2008-07-30 17:42:08,256 DEBUG org.apache.hadoop.hbase.regionserver.HStore: moving /hbase/items/compaction.dir/1211238171/content/mapfiles/4240641699209031496 to /hbase/items/1211238171/content/mapfiles/8894612533024691980 2008-07-30 17:42:08,293 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Completed compaction of 1211238171/content store size is 377.8m 2008-07-30 17:42:08,299 INFO org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 7sec 2008-07-30 17:42:08,301 INFO org.apache.hadoop.hbase.regionserver.HRegion: Starting split of region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Compactions and cache flushes disabled for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates and scanners disabled for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,304 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more active scanners for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,305 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,305 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950. Current region memcache size 1.9m 2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HStore: Added /hbase/items/1211238171/content/mapfiles/2539623802632323222 with 10032 entries, sequence id 2537747, data size 1.9m, file size 2.0m 2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 in 101ms, sequence id=2537747, compaction requested=true 2008-07-30 17:42:08,406 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/uclusters 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/covisit 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/content 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/clusters 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/readby 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/cfrecs 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/blooms 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/ranked 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/savedby 2008-07-30 17:42:08,407 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/sentby 2008-07-30 17:42:08,408 DEBUG org.apache.hadoop.hbase.regionserver.HStore: closed 1211238171/receivedby 2008-07-30 17:42:08,408 INFO org.apache.hadoop.hbase.regionserver.HRegion: closed items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 2008-07-30 17:42:08,638 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464928303/2132462761 2008-07-30 17:42:08,650 INFO org.apache.hadoop.hbase.regionserver.HStore: HSTORE_LOGINFOFILE 2132462761/readby/8482419619225016670-1211238171/6573863319629365608/bottom does not contain a sequence number - ignoring 2008-07-30 17:42:08,653 ERROR org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction failed for region items,0050a173-36b8-45a4-a991-2bab7f5c3cd6,1217464581950 java.io.FileNotFoundException: File does not exist: hdfs://mb0:9000/hbase/items/1211238171/readby/mapfiles/6573863319629365608/data at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:369) at org.apache.hadoop.hbase.regionserver.HStoreFile.length(HStoreFile.java:444) at org.apache.hadoop.hbase.regionserver.HStore.loadHStoreFiles(HStore.java:437) at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:219) at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:1618) at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:466) at org.apache.hadoop.hbase.regionserver.HRegion.<init>(HRegion.java:405) at org.apache.hadoop.hbase.regionserver.HRegion.splitRegion(HRegion.java:800) at org.apache.hadoop.hbase.regionserver.CompactSplitThread.split(CompactSplitThread.java:133) at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:86)
        Hide
        stack added a comment -

        Reopening. FNFE out on jgray's cluser.

        Show
        stack added a comment - Reopening. FNFE out on jgray's cluser.
        Hide
        Jonathan Gray added a comment -

        +1, exact same import that recreated the error every time now succeeds

        Show
        Jonathan Gray added a comment - +1, exact same import that recreated the error every time now succeeds
        Hide
        stack added a comment -

        Resolving. JGray says it works.

        Looks like I committed this fix already as part of another patch:

        ------------------------------------------------------------------------
        r680910 | stack | 2008-07-29 21:37:06 -0700 (Tue, 29 Jul 2008) | 1 line

        HBASE-783 For single row, single family retrieval, getRow() works half as fast as getScanner().next()

        Show
        stack added a comment - Resolving. JGray says it works. Looks like I committed this fix already as part of another patch: ------------------------------------------------------------------------ r680910 | stack | 2008-07-29 21:37:06 -0700 (Tue, 29 Jul 2008) | 1 line HBASE-783 For single row, single family retrieval, getRow() works half as fast as getScanner().next()
        Hide
        Jonathan Gray added a comment -

        Re-confirmed that this is fixed on trunk

        Show
        Jonathan Gray added a comment - Re-confirmed that this is fixed on trunk

          People

          • Assignee:
            stack
            Reporter:
            stack
          • Votes:
            1 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development