You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/01/19 23:42:58 UTC
Build failed in Hudson: HBase-Patch #491
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/491/changes
Changes:
[stack] HBASE-1089 Add count of regions on filesystem to master UI; add percentage online as difference between whats open and whats on filesystem
[stack] HBASE-1136 HashFunction inadvertently destroys some randomness
[stack] HBASE-1136 HashFunction inadvertently destroys some randomness
------------------------------------------
[...truncated 22596 lines...]
[junit] 2009-01-19 22:47:33,800 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/733168598/contents/info/4643426119835657378, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 22:47:33,800 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 733168598/contents, max sequence id 2
[junit] 2009-01-19 22:47:33,806 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232405253572 is 3
[junit] 2009-01-19 22:47:33,807 INFO [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232405253572/733168598 available
[junit] 2009-01-19 22:47:33,813 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232405253572: compactions & flushes disabled
[junit] 2009-01-19 22:47:33,814 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:33,814 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:33,814 DEBUG [main] regionserver.HStore(600): closed 733168598/contents
[junit] 2009-01-19 22:47:33,814 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:33,814 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2009-01-19 22:47:33,815 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2009-01-19 22:47:33,815 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-01-19 22:47:33,816 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-01-19 22:47:33,825 INFO [main] util.Merge(190): Merging regions [B@267f18 and [B@1623820 in table [B@152e7a4
[junit] 2009-01-19 22:47:33,828 INFO [main] regionserver.HLog(265): New log writer: /user/hudson/log_1232405253825/hlog.dat.1232405253826
[junit] 2009-01-19 22:47:33,828 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-01-19 22:47:33,828 DEBUG [main] regionserver.HRegion(238): Opening region -ROOT-,,0/70236052
[junit] 2009-01-19 22:47:33,872 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/-ROOT-/70236052/info/info/6990125714247972651, isReference=false, sequence id=1, length=577, majorCompaction=false
[junit] 2009-01-19 22:47:33,873 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2009-01-19 22:47:33,878 DEBUG [main] regionserver.HRegion(299): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-01-19 22:47:33,880 INFO [main] regionserver.HRegion(321): region -ROOT-,,0/70236052 available
[junit] 2009-01-19 22:47:33,880 DEBUG [main] regionserver.HLog(215): changing sequence number from 0 to 2
[junit] 2009-01-19 22:47:33,880 INFO [main] regionserver.HRegion(719): starting compaction on region -ROOT-,,0
[junit] 2009-01-19 22:47:33,882 INFO [main] regionserver.HRegion(734): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-01-19 22:47:33,886 INFO [main] util.Merge(204): Found meta for region1 [B@1e04a35, meta for region2 [B@1e04a35
[junit] 2009-01-19 22:47:33,887 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:33,887 DEBUG [main] regionserver.HRegion(238): Opening region .META.,,1/1028785192
[junit] 2009-01-19 22:47:33,895 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/5518053313516823167, isReference=false, sequence id=13, length=1216, majorCompaction=false
[junit] 2009-01-19 22:47:33,901 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/8338137093753867074, isReference=false, sequence id=5, length=1953, majorCompaction=false
[junit] 2009-01-19 22:47:33,907 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/8955033595752925994, isReference=false, sequence id=17, length=663, majorCompaction=false
[junit] 2009-01-19 22:47:33,908 DEBUG [main] regionserver.HStore(232): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2009-01-19 22:47:33,924 DEBUG [main] regionserver.HRegion(299): Next sequence id for region .META.,,1 is 18
[junit] 2009-01-19 22:47:33,925 INFO [main] regionserver.HRegion(321): region .META.,,1/1028785192 available
[junit] 2009-01-19 22:47:33,925 DEBUG [main] regionserver.HLog(215): changing sequence number from 2 to 18
[junit] 2009-01-19 22:47:33,925 INFO [main] regionserver.HRegion(719): starting compaction on region .META.,,1
[junit] 2009-01-19 22:47:33,926 DEBUG [main] regionserver.HStore(828): 1028785192/historian: no store files to compact
[junit] 2009-01-19 22:47:33,930 DEBUG [main] regionserver.HStore(901): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
[junit] 2009-01-19 22:47:33,943 DEBUG [main] regionserver.HStore(919): Started compaction of 3 file(s) into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3453090977531720711
[junit] 2009-01-19 22:47:33,976 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3453090977531720711 to /user/hudson/.META./1028785192/info/mapfiles/9141717272129397518
[junit] 2009-01-19 22:47:33,990 DEBUG [main] regionserver.HStore(938): Completed compaction of 1028785192/info store size is 3.5k
[junit] 2009-01-19 22:47:34,001 INFO [main] regionserver.HRegion(734): compaction completed on region .META.,,1 in 0sec
[junit] 2009-01-19 22:47:34,002 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1232405253572', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 733168598, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:34,002 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,row_0100,1232405253572/733168598
[junit] 2009-01-19 22:47:34,010 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/733168598/contents/info/4643426119835657378, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 22:47:34,010 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 733168598/contents, max sequence id 2
[junit] 2009-01-19 22:47:34,015 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232405253572 is 3
[junit] 2009-01-19 22:47:34,017 INFO [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232405253572/733168598 available
[junit] 2009-01-19 22:47:34,017 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232405239614', STARTKEY => '', ENDKEY => '', ENCODED => 1560089681, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:34,017 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232405239614/1560089681
[junit] 2009-01-19 22:47:34,025 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1560089681/contents/info/2007150344246414874, isReference=false, sequence id=2, length=204, majorCompaction=false
[junit] 2009-01-19 22:47:34,025 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1560089681/contents, max sequence id 2
[junit] 2009-01-19 22:47:34,030 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232405239614 is 3
[junit] 2009-01-19 22:47:34,031 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232405239614/1560089681 available
[junit] 2009-01-19 22:47:34,032 INFO [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:34,038 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/733168598/contents/mapfiles/7640235846832106099
[junit] 2009-01-19 22:47:34,070 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/733168598/contents/mapfiles/7640235846832106099 to /user/hudson/TestMergeTool/733168598/contents/mapfiles/3858065850591347481
[junit] 2009-01-19 22:47:34,081 DEBUG [main] regionserver.HStore(938): Completed major compaction of 733168598/contents store size is 486.0
[junit] 2009-01-19 22:47:34,083 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,row_0100,1232405253572 in 0sec
[junit] 2009-01-19 22:47:34,083 DEBUG [main] regionserver.HRegion(2457): Files for region: TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:34,083 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents
[junit] 2009-01-19 22:47:34,084 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/info
[junit] 2009-01-19 22:47:34,085 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/info/3858065850591347481 size=11
[junit] 2009-01-19 22:47:34,085 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/mapfiles
[junit] 2009-01-19 22:47:34,086 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/mapfiles/3858065850591347481
[junit] 2009-01-19 22:47:34,086 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/mapfiles/3858065850591347481/data size=486
[junit] 2009-01-19 22:47:34,086 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/733168598/contents/mapfiles/3858065850591347481/index size=227
[junit] 2009-01-19 22:47:34,087 INFO [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,,1232405239614
[junit] 2009-01-19 22:47:34,093 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1560089681/contents/mapfiles/1224382201625465579
[junit] 2009-01-19 22:47:34,111 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1560089681/contents/mapfiles/1224382201625465579 to /user/hudson/TestMergeTool/1560089681/contents/mapfiles/1124428515277213421
[junit] 2009-01-19 22:47:34,149 DEBUG [main] regionserver.HStore(938): Completed major compaction of 1560089681/contents store size is 204.0
[junit] 2009-01-19 22:47:34,150 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232405239614 in 0sec
[junit] 2009-01-19 22:47:34,150 DEBUG [main] regionserver.HRegion(2462): Files for region: TestMergeTool,,1232405239614
[junit] 2009-01-19 22:47:34,151 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents
[junit] 2009-01-19 22:47:34,152 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/info
[junit] 2009-01-19 22:47:34,152 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/info/1124428515277213421 size=11
[junit] 2009-01-19 22:47:34,152 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/mapfiles
[junit] 2009-01-19 22:47:34,153 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/mapfiles/1124428515277213421
[junit] 2009-01-19 22:47:34,154 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/mapfiles/1124428515277213421/data size=204
[junit] 2009-01-19 22:47:34,154 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681/contents/mapfiles/1124428515277213421/index size=227
[junit] 2009-01-19 22:47:34,154 INFO [main] regionserver.HRegion(2486): Creating new region REGION => {NAME => 'TestMergeTool,,1232405254154', STARTKEY => '', ENDKEY => '', ENCODED => 1713721059, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:34,156 INFO [main] regionserver.HRegion(2495): starting merge of regions: TestMergeTool,row_0100,1232405253572 and TestMergeTool,,1232405239614 into new region REGION => {NAME => 'TestMergeTool,,1232405254154', STARTKEY => '', ENDKEY => '', ENCODED => 1713721059, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <[B...@1be0f0a> and end key <[B...@1be0f0a>
[junit] 2009-01-19 22:47:34,156 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232405253572: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,156 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:34,156 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:34,157 DEBUG [main] regionserver.HStore(600): closed 733168598/contents
[junit] 2009-01-19 22:47:34,157 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232405253572
[junit] 2009-01-19 22:47:34,157 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232405239614: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,157 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232405239614
[junit] 2009-01-19 22:47:34,157 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232405239614
[junit] 2009-01-19 22:47:34,157 DEBUG [main] regionserver.HStore(600): closed 1560089681/contents
[junit] 2009-01-19 22:47:34,158 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232405239614
[junit] 2009-01-19 22:47:34,163 DEBUG [main] regionserver.HRegion(2518): Adjusting sequence id of storeFile 1560089681/contents/1124428515277213421 down by one; sequence id A=2, sequence id B=2
[junit] 2009-01-19 22:47:34,170 DEBUG [main] regionserver.HRegion(2529): Renaming 733168598/contents/3858065850591347481 to 1713721059/contents/5257873170148346293
[junit] 2009-01-19 22:47:34,173 DEBUG [main] regionserver.HRegion(2529): Renaming 1560089681/contents/1124428515277213421 to 1713721059/contents/4063212166357777000
[junit] 2009-01-19 22:47:34,177 DEBUG [main] regionserver.HRegion(2535): Files for new region
[junit] 2009-01-19 22:47:34,177 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents
[junit] 2009-01-19 22:47:34,178 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/info
[junit] 2009-01-19 22:47:34,179 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/info/4063212166357777000 size=9
[junit] 2009-01-19 22:47:34,179 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/info/5257873170148346293 size=11
[junit] 2009-01-19 22:47:34,179 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles
[junit] 2009-01-19 22:47:34,180 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/4063212166357777000
[junit] 2009-01-19 22:47:34,181 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/4063212166357777000/data size=204
[junit] 2009-01-19 22:47:34,181 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/4063212166357777000/index size=227
[junit] 2009-01-19 22:47:34,181 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/5257873170148346293
[junit] 2009-01-19 22:47:34,182 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/5257873170148346293/data size=486
[junit] 2009-01-19 22:47:34,182 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/5257873170148346293/index size=227
[junit] 2009-01-19 22:47:34,182 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232405254154/1713721059
[junit] 2009-01-19 22:47:34,190 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1713721059/contents/info/4063212166357777000, isReference=false, sequence id=1, length=204, majorCompaction=false
[junit] 2009-01-19 22:47:34,195 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1713721059/contents/info/5257873170148346293, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 22:47:34,196 DEBUG [main] regionserver.HStore(232): Loaded 2 file(s) in hstore 1713721059/contents, max sequence id 2
[junit] 2009-01-19 22:47:34,205 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232405254154 is 3
[junit] 2009-01-19 22:47:34,206 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232405254154/1713721059 available
[junit] 2009-01-19 22:47:34,206 INFO [main] regionserver.HRegion(719): starting compaction on region TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,209 DEBUG [main] regionserver.HStore(901): Compaction size of 1713721059/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2009-01-19 22:47:34,223 DEBUG [main] regionserver.HStore(919): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/compaction.dir/1713721059/contents/mapfiles/4253358989547874755
[junit] 2009-01-19 22:47:34,247 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1713721059/contents/mapfiles/4253358989547874755 to /user/hudson/TestMergeTool/1713721059/contents/mapfiles/3669435352103511411
[junit] 2009-01-19 22:47:34,268 DEBUG [main] regionserver.HStore(938): Completed compaction of 1713721059/contents store size is 580.0
[junit] 2009-01-19 22:47:34,270 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232405254154 in 0sec
[junit] 2009-01-19 22:47:34,270 DEBUG [main] regionserver.HRegion(2542): Files for new region
[junit] 2009-01-19 22:47:34,271 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents
[junit] 2009-01-19 22:47:34,272 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/info
[junit] 2009-01-19 22:47:34,272 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/info/3669435352103511411 size=9
[junit] 2009-01-19 22:47:34,273 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles
[junit] 2009-01-19 22:47:34,273 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/3669435352103511411
[junit] 2009-01-19 22:47:34,274 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/3669435352103511411/data size=580
[junit] 2009-01-19 22:47:34,274 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:50443/user/hudson/TestMergeTool/1713721059/contents/mapfiles/3669435352103511411/index size=227
[junit] 2009-01-19 22:47:34,274 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:50443/user/hudson/TestMergeTool/733168598
[junit] 2009-01-19 22:47:34,275 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:50443/user/hudson/TestMergeTool/1560089681
[junit] 2009-01-19 22:47:34,276 INFO [main] regionserver.HRegion(2548): merge completed. New region is TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,276 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1232405253572', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 733168598, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-01-19 22:47:34,277 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1232405239614', STARTKEY => '', ENDKEY => '', ENCODED => 1560089681, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-01-19 22:47:34,282 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1232405254154', STARTKEY => '', ENDKEY => '', ENCODED => 1713721059, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:34,282 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232405254154: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,282 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,282 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,283 DEBUG [main] regionserver.HStore(600): closed 1713721059/contents
[junit] 2009-01-19 22:47:34,283 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,283 DEBUG [main] regionserver.HRegion(392): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,283 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-01-19 22:47:34,283 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-01-19 22:47:34,283 DEBUG [main] regionserver.HStore(600): closed 70236052/info
[junit] 2009-01-19 22:47:34,284 INFO [main] regionserver.HRegion(441): Closed -ROOT-,,0
[junit] 2009-01-19 22:47:34,284 DEBUG [main] regionserver.HRegion(392): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,284 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-01-19 22:47:34,284 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region .META.,,1
[junit] 2009-01-19 22:47:34,284 DEBUG [main] regionserver.HRegion(844): Started memcache flush for region .META.,,1. Current region memcache size 906.0
[junit] 2009-01-19 22:47:34,307 DEBUG [main] regionserver.HStore(696): Added /user/hudson/.META./1028785192/info/mapfiles/3681368768616377583 with 3 entries, sequence id 21, data size ~906.0, file size 623.0 to .META.,,1
[junit] 2009-01-19 22:47:34,308 DEBUG [main] regionserver.HRegion(921): Finished memcache flush of ~906.0 for region .META.,,1 in 24ms, sequence id=21, compaction requested=true
[junit] 2009-01-19 22:47:34,308 DEBUG [main] regionserver.HStore(600): closed 1028785192/historian
[junit] 2009-01-19 22:47:34,308 DEBUG [main] regionserver.HStore(600): closed 1028785192/info
[junit] 2009-01-19 22:47:34,308 INFO [main] regionserver.HRegion(441): Closed .META.,,1
[junit] 2009-01-19 22:47:34,314 INFO [main] regionserver.HLog(265): Closed hdfs://localhost:50443/user/hudson/log_1232405253825/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1232405253825/hlog.dat.1232405254313
[junit] 2009-01-19 22:47:34,314 DEBUG [main] regionserver.HLog(272): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-01-19 22:47:34,315 INFO [main] regionserver.HLog(383): removing old log file /user/hudson/log_1232405253825/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-01-19 22:47:34,315 DEBUG [main] regionserver.HLog(419): closing log writer in hdfs://localhost:50443/user/hudson/log_1232405253825
[junit] 2009-01-19 22:47:34,320 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232405254154', STARTKEY => '', ENDKEY => '', ENCODED => 1713721059, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 22:47:34,321 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232405254154/1713721059
[junit] 2009-01-19 22:47:34,328 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1713721059/contents/info/3669435352103511411, isReference=false, sequence id=2, length=580, majorCompaction=false
[junit] 2009-01-19 22:47:34,329 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1713721059/contents, max sequence id 2
[junit] 2009-01-19 22:47:34,333 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232405254154 is 3
[junit] 2009-01-19 22:47:34,334 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232405254154/1713721059 available
[junit] 2009-01-19 22:47:34,343 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232405254154: compactions & flushes disabled
[junit] 2009-01-19 22:47:34,343 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,343 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,344 DEBUG [main] regionserver.HStore(600): closed 1713721059/contents
[junit] 2009-01-19 22:47:34,344 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232405254154
[junit] 2009-01-19 22:47:34,344 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2009-01-19 22:47:34,344 DEBUG [main] regionserver.HLog(419): closing log writer in /tmp/log_1232405241709
[junit] 2009-01-19 22:47:34,349 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2009-01-19 22:47:34,396 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-01-19 22:47:34,397 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=39491]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=39491]
[junit] 2009-01-19 22:47:34,401 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:39491
[junit] 2009-01-19 22:47:34,401 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@903025
[junit] 2009-01-19 22:47:34,487 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 22:47:34,487 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@3a0ab1
[junit] 2009-01-19 22:47:34,546 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 22:47:34,547 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1732ed2
[junit] 2009-01-19 22:47:34,549 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@7b4703] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:47445, storageID=DS-703500783-67.195.138.9-47445-1232405240981, infoPort=39491, ipcPort=42561):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-01-19 22:47:35,548 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=50446]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=50446]
[junit] 2009-01-19 22:47:35,548 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:50446
[junit] 2009-01-19 22:47:35,549 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c70b0d
[junit] 2009-01-19 22:47:35,618 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 22:47:35,618 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@9b6220
[junit] 2009-01-19 22:47:35,671 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 22:47:35,671 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@c6f734
[junit] 2009-01-19 22:47:35,673 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@2f2295] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:47059, storageID=DS-1851762349-67.195.138.9-47059-1232405240764, infoPort=50446, ipcPort=59008):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-01-19 22:47:36,672 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=37620]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=37620]
[junit] 2009-01-19 22:47:36,672 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:37620
[junit] 2009-01-19 22:47:36,673 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@20f443
[junit] 2009-01-19 22:47:36,723 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 22:47:36,723 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1db5ec
[junit] 2009-01-19 22:47:36,772 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 22:47:36,772 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1724a9d
[junit] 2009-01-19 22:47:36,772 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@1cef4f7] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 17.259 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-01-19 22:47:37,091 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:158)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.039 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-01-19 22:47:37,371 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-19 22:47:37,375 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-19 22:47:37,375 INFO [main] test.TestFilter(262): Success!
[junit] 2009-01-19 22:47:37,376 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-01-19 22:47:37,377 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-19 22:47:37,378 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-19 22:47:37,379 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 2, Errors: 0, Time elapsed: 0.046 sec
[junit] Test org.onelab.test.TestFilter FAILED
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :453: Tests failed!
Total time: 26 minutes 23 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Hudson build is back to normal: HBase-Patch #494
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/494/changes
Build failed in Hudson: HBase-Patch #493
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/493/changes
Changes:
[stack] HBASE-1136 HashFunction inadvertently destroys some randomness; REVERTING
------------------------------------------
[...truncated 22964 lines...]
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-01-20 00:47:09,359 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57999]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57999]
[junit] 2009-01-20 00:47:09,359 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:57999
[junit] 2009-01-20 00:47:09,360 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@d9896e
[junit] 2009-01-20 00:47:09,429 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-20 00:47:09,429 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@12e7c6a
[junit] 2009-01-20 00:47:09,483 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-20 00:47:09,483 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1a4c5b4
[junit] 2009-01-20 00:47:09,484 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@3e1bc8] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:51650, storageID=DS-551026190-67.195.138.9-51650-1232412414907, infoPort=57999, ipcPort=44200):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-01-20 00:47:10,484 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=33603]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=33603]
[junit] 2009-01-20 00:47:10,485 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:33603
[junit] 2009-01-20 00:47:10,486 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@5dc994
[junit] 2009-01-20 00:47:10,538 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-20 00:47:10,539 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@b4be3d
[junit] 2009-01-20 00:47:10,588 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-20 00:47:10,588 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@17cec96
[junit] 2009-01-20 00:47:10,589 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@aeea66] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 16.923 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-01-20 00:47:10,879 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:158)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.039 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-01-20 00:47:11,168 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-20 00:47:11,171 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-20 00:47:11,172 INFO [main] test.TestFilter(262): Success!
[junit] 2009-01-20 00:47:11,173 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-01-20 00:47:11,174 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-20 00:47:11,175 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-20 00:47:11,176 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.043 sec
clover.setup:
clover.info:
[echo]
[echo] Clover not found. Code coverage reports disabled.
[echo]
clover:
init:
jspc:
compile:
[javac] Compiling 6 source files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/classes
jar:
[jar] Building jar: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev.jar
javadoc:
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/docs/api
[javadoc] Generating Javadoc
[javadoc] Javadoc execution
[javadoc] Loading source files for package org.apache.hadoop.hbase...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client.tableindexed...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client.transactional...
[javadoc] Loading source files for package org.apache.hadoop.hbase.filter...
[javadoc] Loading source files for package org.apache.hadoop.hbase.io...
[javadoc] Loading source files for package org.apache.hadoop.hbase.ipc...
[javadoc] Loading source files for package org.apache.hadoop.hbase.mapred...
[javadoc] Loading source files for package org.apache.hadoop.hbase.master...
[javadoc] Loading source files for package org.apache.hadoop.hbase.master.metrics...
[javadoc] Loading source files for package org.apache.hadoop.hbase.metrics.file...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.metrics...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.tableindexed...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.transactional...
[javadoc] Loading source files for package org.apache.hadoop.hbase.rest...
[javadoc] Loading source files for package org.apache.hadoop.hbase.thrift...
[javadoc] Loading source files for package org.apache.hadoop.hbase.thrift.generated...
[javadoc] Loading source files for package org.apache.hadoop.hbase.util...
[javadoc] Constructing Javadoc information...
[javadoc] Standard Doclet version 1.6.0_11
[javadoc] Building tree for all the packages and classes...
[javadoc] Building index for all the packages and classes...
[javadoc] Building index for all classes...
compile-test:
[javac] Compiling 1 source file to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/test
[jar] Building jar: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev-test.jar
package:
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev
[copy] Copying 2 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/webapps
[copy] Copying 8 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/webapps
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/lib
[copy] Copying 29 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/lib
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/conf
[copy] Copying 6 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/conf
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/bin
[copy] Copying 12 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/bin
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/docs
[copy] Copying 866 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/docs
[copy] Copied 50 empty directories to 3 empty directories under http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/docs
[copy] Copying 5 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev
[mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/src
[copy] Copying 368 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/src
[copy] Copied 73 empty directories to 2 empty directories under http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/src
clover.setup:
clover.info:
[echo]
[echo] Clover not found. Code coverage reports disabled.
[echo]
clover:
init:
jspc:
compile:
[javac] Compiling 6 source files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/classes
jar:
[jar] Building jar: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev.jar
javadoc:
[javadoc] Generating Javadoc
[javadoc] Javadoc execution
[javadoc] Loading source files for package org.apache.hadoop.hbase...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client.tableindexed...
[javadoc] Loading source files for package org.apache.hadoop.hbase.client.transactional...
[javadoc] Loading source files for package org.apache.hadoop.hbase.filter...
[javadoc] Loading source files for package org.apache.hadoop.hbase.io...
[javadoc] Loading source files for package org.apache.hadoop.hbase.ipc...
[javadoc] Loading source files for package org.apache.hadoop.hbase.mapred...
[javadoc] Loading source files for package org.apache.hadoop.hbase.master...
[javadoc] Loading source files for package org.apache.hadoop.hbase.master.metrics...
[javadoc] Loading source files for package org.apache.hadoop.hbase.metrics.file...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.metrics...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.tableindexed...
[javadoc] Loading source files for package org.apache.hadoop.hbase.regionserver.transactional...
[javadoc] Loading source files for package org.apache.hadoop.hbase.rest...
[javadoc] Loading source files for package org.apache.hadoop.hbase.thrift...
[javadoc] Loading source files for package org.apache.hadoop.hbase.thrift.generated...
[javadoc] Loading source files for package org.apache.hadoop.hbase.util...
[javadoc] Constructing Javadoc information...
[javadoc] Standard Doclet version 1.6.0_11
[javadoc] Building tree for all the packages and classes...
[javadoc] Building index for all the packages and classes...
[javadoc] Building index for all classes...
compile-test:
[javac] Compiling 1 source file to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/test
[jar] Building jar: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev-test.jar
package:
[copy] Copying 1 file to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev
[copy] Copying 799 files to http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/hbase-0.20.0-dev/docs
tar:
[tar] Building tar: http://hudson.zones.apache.org/hudson/job/HBase-Patch/493/artifact/trunk/build/hbase-0.20.0-dev.tar.gz
BUILD SUCCESSFUL
Total time: 26 minutes 13 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
FATAL: Unable to copy coverage from http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/test/clover/reports/ to /export/home/hudson/hudson/jobs/HBase-Patch/clover
hudson.util.IOException2: hudson.util.IOException2: null
stream=
at hudson.FilePath.readFromTar(FilePath.java:1013)
at hudson.FilePath.copyRecursiveTo(FilePath.java:936)
at hudson.FilePath.copyRecursiveTo(FilePath.java:848)
at hudson.plugins.clover.CloverPublisher.perform(CloverPublisher.java:127)
at hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:322)
at hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:310)
at hudson.model.Build$RunnerImpl.post2(Build.java:126)
at hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:295)
at hudson.model.Run.run(Run.java:843)
at hudson.model.Build.run(Build.java:88)
at hudson.model.ResourceController.execute(ResourceController.java:70)
at hudson.model.Executor.run(Executor.java:90)
Caused by: java.io.EOFException
at java.util.zip.GZIPInputStream.readUByte(GZIPInputStream.java:207)
at java.util.zip.GZIPInputStream.readUShort(GZIPInputStream.java:197)
at java.util.zip.GZIPInputStream.readHeader(GZIPInputStream.java:136)
at java.util.zip.GZIPInputStream.<init>(GZIPInputStream.java:58)
at java.util.zip.GZIPInputStream.<init>(GZIPInputStream.java:68)
at hudson.FilePath.readFromTar(FilePath.java:1009)
... 11 more
at hudson.FilePath.copyRecursiveTo(FilePath.java:943)
at hudson.FilePath.copyRecursiveTo(FilePath.java:848)
at hudson.plugins.clover.CloverPublisher.perform(CloverPublisher.java:127)
at hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:322)
at hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:310)
at hudson.model.Build$RunnerImpl.post2(Build.java:126)
at hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:295)
at hudson.model.Run.run(Run.java:843)
at hudson.model.Build.run(Build.java:88)
at hudson.model.ResourceController.execute(ResourceController.java:70)
at hudson.model.Executor.run(Executor.java:90)
Caused by: java.util.concurrent.ExecutionException: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/test/clover/reports not found.
at hudson.remoting.Channel$1.adapt(Channel.java:486)
at hudson.remoting.Channel$1.adapt(Channel.java:481)
at hudson.remoting.FutureAdapter.get(FutureAdapter.java:36)
at hudson.FilePath.copyRecursiveTo(FilePath.java:939)
... 10 more
Caused by: http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build/test/clover/reports not found.
at org.apache.tools.ant.types.AbstractFileSet.getDirectoryScanner(AbstractFileSet.java:422)
at hudson.FilePath.writeToTar(FilePath.java:970)
at hudson.FilePath.access$400(FilePath.java:121)
at hudson.FilePath$25.invoke(FilePath.java:929)
at hudson.FilePath$25.invoke(FilePath.java:926)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:1224)
at hudson.remoting.UserRequest.perform(UserRequest.java:69)
at hudson.remoting.UserRequest.perform(UserRequest.java:23)
at hudson.remoting.Request$2.run(Request.java:213)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Could not find 'trunk/build/test/clover/reports//clover.xml'. Did you generate the XML report for Clover?
Build failed in Hudson: HBase-Patch #492
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/492/changes
Changes:
[stack] HBASE-1140 'ant clean test' fails
[stack] HBASE-1130 PrefixRowFilter
[stack] HBASE-1130 PrefixRowFilter
[stack] HBASE-1136 HashFunction inadvertently destroys some randomness; fixes broken build
------------------------------------------
[...truncated 22735 lines...]
[junit] 2009-01-19 23:49:58,453 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1089417950/contents/info/8411956474837858861, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 23:49:58,454 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1089417950/contents, max sequence id 2
[junit] 2009-01-19 23:49:58,469 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232408998220 is 3
[junit] 2009-01-19 23:49:58,470 INFO [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232408998220/1089417950 available
[junit] 2009-01-19 23:49:58,477 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232408998220: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,477 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,478 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,478 DEBUG [main] regionserver.HStore(600): closed 1089417950/contents
[junit] 2009-01-19 23:49:58,478 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,479 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2009-01-19 23:49:58,479 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2009-01-19 23:49:58,479 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-01-19 23:49:58,480 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-01-19 23:49:58,490 INFO [main] util.Merge(190): Merging regions [B@1890c67 and [B@8d5485 in table [B@a801b0
[junit] 2009-01-19 23:49:58,493 INFO [main] regionserver.HLog(265): New log writer: /user/hudson/log_1232408998490/hlog.dat.1232408998491
[junit] 2009-01-19 23:49:58,493 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,494 DEBUG [main] regionserver.HRegion(238): Opening region -ROOT-,,0/70236052
[junit] 2009-01-19 23:49:58,502 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/-ROOT-/70236052/info/info/1460504288692716986, isReference=false, sequence id=1, length=577, majorCompaction=false
[junit] 2009-01-19 23:49:58,503 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2009-01-19 23:49:58,508 DEBUG [main] regionserver.HRegion(299): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-01-19 23:49:58,509 INFO [main] regionserver.HRegion(321): region -ROOT-,,0/70236052 available
[junit] 2009-01-19 23:49:58,510 DEBUG [main] regionserver.HLog(215): changing sequence number from 0 to 2
[junit] 2009-01-19 23:49:58,510 INFO [main] regionserver.HRegion(719): starting compaction on region -ROOT-,,0
[junit] 2009-01-19 23:49:58,512 INFO [main] regionserver.HRegion(734): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-01-19 23:49:58,517 INFO [main] util.Merge(204): Found meta for region1 [B@1670cc6, meta for region2 [B@1670cc6
[junit] 2009-01-19 23:49:58,517 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,518 DEBUG [main] regionserver.HRegion(238): Opening region .META.,,1/1028785192
[junit] 2009-01-19 23:49:58,558 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/5086974178063355138, isReference=false, sequence id=13, length=1216, majorCompaction=false
[junit] 2009-01-19 23:49:58,565 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/7664620106513457602, isReference=false, sequence id=5, length=1953, majorCompaction=false
[junit] 2009-01-19 23:49:58,571 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/8662318062249755533, isReference=false, sequence id=17, length=663, majorCompaction=false
[junit] 2009-01-19 23:49:58,572 DEBUG [main] regionserver.HStore(232): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2009-01-19 23:49:58,589 DEBUG [main] regionserver.HRegion(299): Next sequence id for region .META.,,1 is 18
[junit] 2009-01-19 23:49:58,590 INFO [main] regionserver.HRegion(321): region .META.,,1/1028785192 available
[junit] 2009-01-19 23:49:58,591 DEBUG [main] regionserver.HLog(215): changing sequence number from 2 to 18
[junit] 2009-01-19 23:49:58,591 INFO [main] regionserver.HRegion(719): starting compaction on region .META.,,1
[junit] 2009-01-19 23:49:58,592 DEBUG [main] regionserver.HStore(828): 1028785192/historian: no store files to compact
[junit] 2009-01-19 23:49:58,595 DEBUG [main] regionserver.HStore(901): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
[junit] 2009-01-19 23:49:58,609 DEBUG [main] regionserver.HStore(919): Started compaction of 3 file(s) into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/2332425580080090586
[junit] 2009-01-19 23:49:58,630 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/2332425580080090586 to /user/hudson/.META./1028785192/info/mapfiles/3729420995566738448
[junit] 2009-01-19 23:49:58,646 DEBUG [main] regionserver.HStore(938): Completed compaction of 1028785192/info store size is 3.5k
[junit] 2009-01-19 23:49:58,647 INFO [main] regionserver.HRegion(734): compaction completed on region .META.,,1 in 0sec
[junit] 2009-01-19 23:49:58,648 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1232408998220', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1089417950, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,649 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,row_0100,1232408998220/1089417950
[junit] 2009-01-19 23:49:58,657 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1089417950/contents/info/8411956474837858861, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 23:49:58,657 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1089417950/contents, max sequence id 2
[junit] 2009-01-19 23:49:58,663 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232408998220 is 3
[junit] 2009-01-19 23:49:58,664 INFO [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232408998220/1089417950 available
[junit] 2009-01-19 23:49:58,664 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232408983700', STARTKEY => '', ENDKEY => '', ENCODED => 748027358, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,665 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232408983700/748027358
[junit] 2009-01-19 23:49:58,673 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/748027358/contents/info/8799768084752262224, isReference=false, sequence id=2, length=204, majorCompaction=false
[junit] 2009-01-19 23:49:58,673 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 748027358/contents, max sequence id 2
[junit] 2009-01-19 23:49:58,679 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232408983700 is 3
[junit] 2009-01-19 23:49:58,680 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232408983700/748027358 available
[junit] 2009-01-19 23:49:58,680 INFO [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,687 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1089417950/contents/mapfiles/7053699614086173009
[junit] 2009-01-19 23:49:58,718 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1089417950/contents/mapfiles/7053699614086173009 to /user/hudson/TestMergeTool/1089417950/contents/mapfiles/1229359209302521514
[junit] 2009-01-19 23:49:58,730 DEBUG [main] regionserver.HStore(938): Completed major compaction of 1089417950/contents store size is 486.0
[junit] 2009-01-19 23:49:58,731 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,row_0100,1232408998220 in 0sec
[junit] 2009-01-19 23:49:58,732 DEBUG [main] regionserver.HRegion(2457): Files for region: TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,733 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents
[junit] 2009-01-19 23:49:58,733 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/info
[junit] 2009-01-19 23:49:58,734 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/info/1229359209302521514 size=11
[junit] 2009-01-19 23:49:58,735 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/mapfiles
[junit] 2009-01-19 23:49:58,735 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/mapfiles/1229359209302521514
[junit] 2009-01-19 23:49:58,736 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/mapfiles/1229359209302521514/data size=486
[junit] 2009-01-19 23:49:58,737 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950/contents/mapfiles/1229359209302521514/index size=227
[junit] 2009-01-19 23:49:58,737 INFO [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,,1232408983700
[junit] 2009-01-19 23:49:58,744 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/748027358/contents/mapfiles/6987560190621393794
[junit] 2009-01-19 23:49:58,764 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/748027358/contents/mapfiles/6987560190621393794 to /user/hudson/TestMergeTool/748027358/contents/mapfiles/6125093991951325474
[junit] 2009-01-19 23:49:58,781 DEBUG [main] regionserver.HStore(938): Completed major compaction of 748027358/contents store size is 204.0
[junit] 2009-01-19 23:49:58,782 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232408983700 in 0sec
[junit] 2009-01-19 23:49:58,783 DEBUG [main] regionserver.HRegion(2462): Files for region: TestMergeTool,,1232408983700
[junit] 2009-01-19 23:49:58,783 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents
[junit] 2009-01-19 23:49:58,784 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/info
[junit] 2009-01-19 23:49:58,785 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/info/6125093991951325474 size=11
[junit] 2009-01-19 23:49:58,785 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/mapfiles
[junit] 2009-01-19 23:49:58,786 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/mapfiles/6125093991951325474
[junit] 2009-01-19 23:49:58,787 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/mapfiles/6125093991951325474/data size=204
[junit] 2009-01-19 23:49:58,787 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/748027358/contents/mapfiles/6125093991951325474/index size=227
[junit] 2009-01-19 23:49:58,788 INFO [main] regionserver.HRegion(2486): Creating new region REGION => {NAME => 'TestMergeTool,,1232408998788', STARTKEY => '', ENDKEY => '', ENCODED => 1785957699, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,789 INFO [main] regionserver.HRegion(2495): starting merge of regions: TestMergeTool,row_0100,1232408998220 and TestMergeTool,,1232408983700 into new region REGION => {NAME => 'TestMergeTool,,1232408998788', STARTKEY => '', ENDKEY => '', ENCODED => 1785957699, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <[B...@9ced8e> and end key <[B...@9ced8e>
[junit] 2009-01-19 23:49:58,790 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232408998220: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,790 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,790 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,791 DEBUG [main] regionserver.HStore(600): closed 1089417950/contents
[junit] 2009-01-19 23:49:58,791 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232408998220
[junit] 2009-01-19 23:49:58,791 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232408983700: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,792 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232408983700
[junit] 2009-01-19 23:49:58,792 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232408983700
[junit] 2009-01-19 23:49:58,792 DEBUG [main] regionserver.HStore(600): closed 748027358/contents
[junit] 2009-01-19 23:49:58,793 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232408983700
[junit] 2009-01-19 23:49:58,798 DEBUG [main] regionserver.HRegion(2518): Adjusting sequence id of storeFile 748027358/contents/6125093991951325474 down by one; sequence id A=2, sequence id B=2
[junit] 2009-01-19 23:49:58,805 DEBUG [main] regionserver.HRegion(2529): Renaming 1089417950/contents/1229359209302521514 to 1785957699/contents/2503147949434126441
[junit] 2009-01-19 23:49:58,809 DEBUG [main] regionserver.HRegion(2529): Renaming 748027358/contents/6125093991951325474 to 1785957699/contents/4604308120620097144
[junit] 2009-01-19 23:49:58,812 DEBUG [main] regionserver.HRegion(2535): Files for new region
[junit] 2009-01-19 23:49:58,813 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents
[junit] 2009-01-19 23:49:58,814 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/info
[junit] 2009-01-19 23:49:58,815 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/info/2503147949434126441 size=11
[junit] 2009-01-19 23:49:58,815 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/info/4604308120620097144 size=9
[junit] 2009-01-19 23:49:58,815 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles
[junit] 2009-01-19 23:49:58,816 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/2503147949434126441
[junit] 2009-01-19 23:49:58,817 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/2503147949434126441/data size=486
[junit] 2009-01-19 23:49:58,817 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/2503147949434126441/index size=227
[junit] 2009-01-19 23:49:58,818 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/4604308120620097144
[junit] 2009-01-19 23:49:58,819 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/4604308120620097144/data size=204
[junit] 2009-01-19 23:49:58,819 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/4604308120620097144/index size=227
[junit] 2009-01-19 23:49:58,819 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232408998788/1785957699
[junit] 2009-01-19 23:49:58,827 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1785957699/contents/info/2503147949434126441, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2009-01-19 23:49:58,833 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1785957699/contents/info/4604308120620097144, isReference=false, sequence id=1, length=204, majorCompaction=false
[junit] 2009-01-19 23:49:58,834 DEBUG [main] regionserver.HStore(232): Loaded 2 file(s) in hstore 1785957699/contents, max sequence id 2
[junit] 2009-01-19 23:49:58,843 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232408998788 is 3
[junit] 2009-01-19 23:49:58,844 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232408998788/1785957699 available
[junit] 2009-01-19 23:49:58,844 INFO [main] regionserver.HRegion(719): starting compaction on region TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:58,847 DEBUG [main] regionserver.HStore(901): Compaction size of 1785957699/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2009-01-19 23:49:58,858 DEBUG [main] regionserver.HStore(919): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/compaction.dir/1785957699/contents/mapfiles/5959439333130750574
[junit] 2009-01-19 23:49:58,878 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1785957699/contents/mapfiles/5959439333130750574 to /user/hudson/TestMergeTool/1785957699/contents/mapfiles/6241666444482847939
[junit] 2009-01-19 23:49:58,918 DEBUG [main] regionserver.HStore(938): Completed compaction of 1785957699/contents store size is 580.0
[junit] 2009-01-19 23:49:58,919 INFO [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232408998788 in 0sec
[junit] 2009-01-19 23:49:58,920 DEBUG [main] regionserver.HRegion(2542): Files for new region
[junit] 2009-01-19 23:49:58,921 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents
[junit] 2009-01-19 23:49:58,922 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/info
[junit] 2009-01-19 23:49:58,923 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/info/6241666444482847939 size=9
[junit] 2009-01-19 23:49:58,923 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles
[junit] 2009-01-19 23:49:58,924 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/6241666444482847939
[junit] 2009-01-19 23:49:58,925 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/6241666444482847939/data size=580
[junit] 2009-01-19 23:49:58,925 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:46988/user/hudson/TestMergeTool/1785957699/contents/mapfiles/6241666444482847939/index size=227
[junit] 2009-01-19 23:49:58,925 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:46988/user/hudson/TestMergeTool/1089417950
[junit] 2009-01-19 23:49:58,926 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:46988/user/hudson/TestMergeTool/748027358
[junit] 2009-01-19 23:49:58,927 INFO [main] regionserver.HRegion(2548): merge completed. New region is TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:58,928 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1232408998220', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1089417950, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-01-19 23:49:58,928 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1232408983700', STARTKEY => '', ENDKEY => '', ENCODED => 748027358, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-01-19 23:49:58,933 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1232408998788', STARTKEY => '', ENDKEY => '', ENCODED => 1785957699, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,934 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232408998788: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,934 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:58,934 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:58,935 DEBUG [main] regionserver.HStore(600): closed 1785957699/contents
[junit] 2009-01-19 23:49:58,935 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:58,935 DEBUG [main] regionserver.HRegion(392): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,936 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-01-19 23:49:58,936 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-01-19 23:49:58,936 DEBUG [main] regionserver.HStore(600): closed 70236052/info
[junit] 2009-01-19 23:49:58,937 INFO [main] regionserver.HRegion(441): Closed -ROOT-,,0
[junit] 2009-01-19 23:49:58,937 DEBUG [main] regionserver.HRegion(392): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-01-19 23:49:58,937 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-01-19 23:49:58,937 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region .META.,,1
[junit] 2009-01-19 23:49:58,938 DEBUG [main] regionserver.HRegion(844): Started memcache flush for region .META.,,1. Current region memcache size 906.0
[junit] 2009-01-19 23:49:58,963 DEBUG [main] regionserver.HStore(696): Added /user/hudson/.META./1028785192/info/mapfiles/8761050992398986885 with 3 entries, sequence id 21, data size ~906.0, file size 623.0 to .META.,,1
[junit] 2009-01-19 23:49:58,964 DEBUG [main] regionserver.HRegion(921): Finished memcache flush of ~906.0 for region .META.,,1 in 26ms, sequence id=21, compaction requested=true
[junit] 2009-01-19 23:49:58,964 DEBUG [main] regionserver.HStore(600): closed 1028785192/historian
[junit] 2009-01-19 23:49:58,965 DEBUG [main] regionserver.HStore(600): closed 1028785192/info
[junit] 2009-01-19 23:49:58,965 INFO [main] regionserver.HRegion(441): Closed .META.,,1
[junit] 2009-01-19 23:49:58,971 INFO [main] regionserver.HLog(265): Closed hdfs://localhost:46988/user/hudson/log_1232408998490/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1232408998490/hlog.dat.1232408998970
[junit] 2009-01-19 23:49:58,971 DEBUG [main] regionserver.HLog(272): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-01-19 23:49:58,972 INFO [main] regionserver.HLog(383): removing old log file /user/hudson/log_1232408998490/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-01-19 23:49:58,972 DEBUG [main] regionserver.HLog(419): closing log writer in hdfs://localhost:46988/user/hudson/log_1232408998490
[junit] 2009-01-19 23:49:58,978 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232408998788', STARTKEY => '', ENDKEY => '', ENCODED => 1785957699, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-01-19 23:49:58,978 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232408998788/1785957699
[junit] 2009-01-19 23:49:58,985 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1785957699/contents/info/6241666444482847939, isReference=false, sequence id=2, length=580, majorCompaction=false
[junit] 2009-01-19 23:49:58,986 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1785957699/contents, max sequence id 2
[junit] 2009-01-19 23:49:58,991 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232408998788 is 3
[junit] 2009-01-19 23:49:58,992 INFO [main] regionserver.HRegion(321): region TestMergeTool,,1232408998788/1785957699 available
[junit] 2009-01-19 23:49:59,001 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232408998788: compactions & flushes disabled
[junit] 2009-01-19 23:49:59,001 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:59,002 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:59,002 DEBUG [main] regionserver.HStore(600): closed 1785957699/contents
[junit] 2009-01-19 23:49:59,002 INFO [main] regionserver.HRegion(441): Closed TestMergeTool,,1232408998788
[junit] 2009-01-19 23:49:59,002 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2009-01-19 23:49:59,003 DEBUG [main] regionserver.HLog(419): closing log writer in /tmp/log_1232408985952
[junit] 2009-01-19 23:49:59,008 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2009-01-19 23:49:59,009 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-01-19 23:49:59,009 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57745]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57745]
[junit] 2009-01-19 23:49:59,012 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:57745
[junit] 2009-01-19 23:49:59,013 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@ad2c30
[junit] 2009-01-19 23:49:59,092 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 23:49:59,092 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@91f005
[junit] 2009-01-19 23:49:59,150 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 23:49:59,151 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1c486f2
[junit] 2009-01-19 23:49:59,152 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@e93999] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:35910, storageID=DS-1185539921-67.195.138.9-35910-1232408985159, infoPort=57745, ipcPort=41612):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-01-19 23:49:59,153 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34897]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34897]
[junit] 2009-01-19 23:49:59,154 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34897
[junit] 2009-01-19 23:49:59,155 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e4bb3c
[junit] 2009-01-19 23:49:59,224 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 23:49:59,225 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1bb9696
[junit] 2009-01-19 23:49:59,276 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 23:49:59,276 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@c16b18
[junit] 2009-01-19 23:49:59,278 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@19f9d2] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:34637, storageID=DS-578663372-67.195.138.9-34637-1232408984927, infoPort=34897, ipcPort=59980):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-01-19 23:50:00,277 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=51383]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=51383]
[junit] 2009-01-19 23:50:00,279 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:51383
[junit] 2009-01-19 23:50:00,280 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@ded0f0
[junit] 2009-01-19 23:50:00,330 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-01-19 23:50:00,331 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@8ae45a
[junit] 2009-01-19 23:50:00,379 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-01-19 23:50:00,379 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@f0b7f8
[junit] 2009-01-19 23:50:00,379 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@b754b2] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 16.779 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-01-19 23:50:00,691 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:158)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.039 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-01-19 23:50:00,981 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-19 23:50:00,984 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-19 23:50:00,984 INFO [main] test.TestFilter(262): Success!
[junit] 2009-01-19 23:50:00,985 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-01-19 23:50:00,986 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-01-19 23:50:00,988 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-01-19 23:50:00,988 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 2, Errors: 0, Time elapsed: 0.046 sec
[junit] Test org.onelab.test.TestFilter FAILED
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :453: Tests failed!
Total time: 28 minutes 47 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results