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/16 21:52:14 UTC

Build failed in Hudson: HBase-Patch #486

See http://hudson.zones.apache.org/hudson/job/HBase-Patch/486/changes

Changes:

[stack] HBASE-1116 generated web.xml and svn don't play nice together

[stack] HBASE-1127 OOME running randomRead PE

------------------------------------------
[...truncated 22247 lines...]
    [junit] 2009-01-16 20:52:06,226 DEBUG [main] regionserver.HStore(600): closed 70236052/info
    [junit] 2009-01-16 20:52:06,227 INFO  [main] regionserver.HRegion(441): Closed -ROOT-,,0
    [junit] 2009-01-16 20:52:06,227 DEBUG [main] regionserver.HRegion(392): Closing .META.,,1: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:06,227 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on .META.,,1
    [junit] 2009-01-16 20:52:06,227 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region .META.,,1
    [junit] 2009-01-16 20:52:06,227 DEBUG [main] regionserver.HRegion(844): Started memcache flush for region .META.,,1. Current region memcache size 946.0
    [junit] 2009-01-16 20:52:06,528 DEBUG [main] regionserver.HStore(696): Added /user/hudson/.META./1028785192/info/mapfiles/1460257057891805666 with 3 entries, sequence id 17, data size ~946.0, file size 663.0 to .META.,,1
    [junit] 2009-01-16 20:52:06,528 DEBUG [main] regionserver.HRegion(921): Finished memcache flush of ~946.0 for region .META.,,1 in 301ms, sequence id=17, compaction requested=true
    [junit] 2009-01-16 20:52:06,529 DEBUG [main] regionserver.HStore(600): closed 1028785192/historian
    [junit] 2009-01-16 20:52:06,529 DEBUG [main] regionserver.HStore(600): closed 1028785192/info
    [junit] 2009-01-16 20:52:06,529 INFO  [main] regionserver.HRegion(441): Closed .META.,,1
    [junit] 2009-01-16 20:52:06,598 INFO  [main] regionserver.HLog(265): Closed hdfs://localhost:44011/user/hudson/log_1232139123152/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1232139123152/hlog.dat.1232139126561
    [junit] 2009-01-16 20:52:06,599 DEBUG [main] regionserver.HLog(272): Last sequence written is empty. Deleting all old hlogs
    [junit] 2009-01-16 20:52:06,599 INFO  [main] regionserver.HLog(383): removing old log file /user/hudson/log_1232139123152/hlog.dat.0 whose highest sequence/edit id is 17
    [junit] 2009-01-16 20:52:06,599 DEBUG [main] regionserver.HLog(419): closing log writer in hdfs://localhost:44011/user/hudson/log_1232139123152
    [junit] 2009-01-16 20:52:06,688 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1232139125231', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 403090138, 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-16 20:52:06,689 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,row_0100,1232139125231/403090138
    [junit] 2009-01-16 20:52:06,697 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/403090138/contents/info/2610374656133294113, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-01-16 20:52:06,698 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 403090138/contents, max sequence id 2
    [junit] 2009-01-16 20:52:06,704 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232139125231 is 3
    [junit] 2009-01-16 20:52:06,705 INFO  [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232139125231/403090138 available
    [junit] 2009-01-16 20:52:06,712 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232139125231: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:06,713 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:06,713 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:06,713 DEBUG [main] regionserver.HStore(600): closed 403090138/contents
    [junit] 2009-01-16 20:52:06,713 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:06,713 INFO  [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
    [junit] 2009-01-16 20:52:06,713 INFO  [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
    [junit] 2009-01-16 20:52:06,714 INFO  [main] util.Merge(80): Verifying that file system is available...
    [junit] 2009-01-16 20:52:06,714 INFO  [main] util.Merge(89): Verifying that HBase is not running...
    [junit] 2009-01-16 20:52:06,726 INFO  [main] util.Merge(190): Merging regions [B@176d662 and [B@f4da6d in table [B@130671e
    [junit] 2009-01-16 20:52:06,787 INFO  [main] regionserver.HLog(265): New log writer: /user/hudson/log_1232139126726/hlog.dat.1232139126753
    [junit] 2009-01-16 20:52:06,788 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-16 20:52:06,788 DEBUG [main] regionserver.HRegion(238): Opening region -ROOT-,,0/70236052
    [junit] 2009-01-16 20:52:06,796 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/-ROOT-/70236052/info/info/476861889685039556, isReference=false, sequence id=1, length=577, majorCompaction=false
    [junit] 2009-01-16 20:52:06,797 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
    [junit] 2009-01-16 20:52:06,802 DEBUG [main] regionserver.HRegion(299): Next sequence id for region -ROOT-,,0 is 2
    [junit] 2009-01-16 20:52:06,804 INFO  [main] regionserver.HRegion(321): region -ROOT-,,0/70236052 available
    [junit] 2009-01-16 20:52:06,804 DEBUG [main] regionserver.HLog(215): changing sequence number from 0 to 2
    [junit] 2009-01-16 20:52:06,804 INFO  [main] regionserver.HRegion(719): starting  compaction on region -ROOT-,,0
    [junit] 2009-01-16 20:52:06,805 INFO  [main] regionserver.HRegion(734): compaction completed on region -ROOT-,,0 in 0sec
    [junit] 2009-01-16 20:52:06,812 INFO  [main] util.Merge(204): Found meta for region1 [B@1ab9dac, meta for region2 [B@1ab9dac
    [junit] 2009-01-16 20:52:06,813 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-16 20:52:06,813 DEBUG [main] regionserver.HRegion(238): Opening region .META.,,1/1028785192
    [junit] 2009-01-16 20:52:06,821 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/106413110356872121, isReference=false, sequence id=5, length=1953, majorCompaction=false
    [junit] 2009-01-16 20:52:06,827 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/1460257057891805666, isReference=false, sequence id=17, length=663, majorCompaction=false
    [junit] 2009-01-16 20:52:06,844 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/9161028788433708277, isReference=false, sequence id=13, length=1216, majorCompaction=false
    [junit] 2009-01-16 20:52:06,847 DEBUG [main] regionserver.HStore(232): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
    [junit] 2009-01-16 20:52:06,881 DEBUG [main] regionserver.HRegion(299): Next sequence id for region .META.,,1 is 18
    [junit] 2009-01-16 20:52:06,882 INFO  [main] regionserver.HRegion(321): region .META.,,1/1028785192 available
    [junit] 2009-01-16 20:52:06,882 DEBUG [main] regionserver.HLog(215): changing sequence number from 2 to 18
    [junit] 2009-01-16 20:52:06,882 INFO  [main] regionserver.HRegion(719): starting  compaction on region .META.,,1
    [junit] 2009-01-16 20:52:06,883 DEBUG [main] regionserver.HStore(828): 1028785192/historian: no store files to compact
    [junit] 2009-01-16 20:52:06,887 DEBUG [main] regionserver.HStore(901): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
    [junit] 2009-01-16 20:52:06,911 DEBUG [main] regionserver.HStore(919): Started compaction of 3 file(s)  into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/8715676549628087875
    [junit] 2009-01-16 20:52:08,114 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/8715676549628087875 to /user/hudson/.META./1028785192/info/mapfiles/6337552003605716005
    [junit] 2009-01-16 20:52:08,358 DEBUG [main] regionserver.HStore(938): Completed  compaction of 1028785192/info store size is 3.5k
    [junit] 2009-01-16 20:52:08,388 INFO  [main] regionserver.HRegion(734): compaction completed on region .META.,,1 in 1sec
    [junit] 2009-01-16 20:52:08,389 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1232139125231', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 403090138, 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-16 20:52:08,389 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,row_0100,1232139125231/403090138
    [junit] 2009-01-16 20:52:08,397 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/403090138/contents/info/2610374656133294113, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-01-16 20:52:08,397 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 403090138/contents, max sequence id 2
    [junit] 2009-01-16 20:52:08,403 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1232139125231 is 3
    [junit] 2009-01-16 20:52:08,404 INFO  [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1232139125231/403090138 available
    [junit] 2009-01-16 20:52:08,404 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232139099515', STARTKEY => '', ENDKEY => '', ENCODED => 1651928880, 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-16 20:52:08,404 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232139099515/1651928880
    [junit] 2009-01-16 20:52:08,411 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1651928880/contents/info/7791825861969553556, isReference=false, sequence id=2, length=204, majorCompaction=false
    [junit] 2009-01-16 20:52:08,412 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1651928880/contents, max sequence id 2
    [junit] 2009-01-16 20:52:08,418 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232139099515 is 3
    [junit] 2009-01-16 20:52:08,419 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1232139099515/1651928880 available
    [junit] 2009-01-16 20:52:08,419 INFO  [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:08,426 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s)  into /user/hudson/TestMergeTool/compaction.dir/403090138/contents/mapfiles/5900158088476830747
    [junit] 2009-01-16 20:52:08,819 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/403090138/contents/mapfiles/5900158088476830747 to /user/hudson/TestMergeTool/403090138/contents/mapfiles/8365883484816433292
    [junit] 2009-01-16 20:52:08,914 DEBUG [main] regionserver.HStore(938): Completed major compaction of 403090138/contents store size is 486.0
    [junit] 2009-01-16 20:52:08,938 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,row_0100,1232139125231 in 0sec
    [junit] 2009-01-16 20:52:08,939 DEBUG [main] regionserver.HRegion(2457): Files for region: TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:08,940 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents
    [junit] 2009-01-16 20:52:08,940 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/info
    [junit] 2009-01-16 20:52:08,941 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/info/8365883484816433292 size=11
    [junit] 2009-01-16 20:52:08,941 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/mapfiles
    [junit] 2009-01-16 20:52:08,941 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/mapfiles/8365883484816433292
    [junit] 2009-01-16 20:52:08,942 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/mapfiles/8365883484816433292/data size=486
    [junit] 2009-01-16 20:52:08,942 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/403090138/contents/mapfiles/8365883484816433292/index size=227
    [junit] 2009-01-16 20:52:08,943 INFO  [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,,1232139099515
    [junit] 2009-01-16 20:52:08,949 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s)  into /user/hudson/TestMergeTool/compaction.dir/1651928880/contents/mapfiles/8211009536814513099
    [junit] 2009-01-16 20:52:09,193 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1651928880/contents/mapfiles/8211009536814513099 to /user/hudson/TestMergeTool/1651928880/contents/mapfiles/6083469289564728645
    [junit] 2009-01-16 20:52:09,317 DEBUG [main] regionserver.HStore(938): Completed major compaction of 1651928880/contents store size is 204.0
    [junit] 2009-01-16 20:52:09,375 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232139099515 in 0sec
    [junit] 2009-01-16 20:52:09,375 DEBUG [main] regionserver.HRegion(2462): Files for region: TestMergeTool,,1232139099515
    [junit] 2009-01-16 20:52:09,376 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents
    [junit] 2009-01-16 20:52:09,376 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/info
    [junit] 2009-01-16 20:52:09,377 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/info/6083469289564728645 size=11
    [junit] 2009-01-16 20:52:09,377 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/mapfiles
    [junit] 2009-01-16 20:52:09,378 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/mapfiles/6083469289564728645
    [junit] 2009-01-16 20:52:09,378 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/mapfiles/6083469289564728645/data size=204
    [junit] 2009-01-16 20:52:09,378 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880/contents/mapfiles/6083469289564728645/index size=227
    [junit] 2009-01-16 20:52:09,379 INFO  [main] regionserver.HRegion(2486): Creating new region REGION => {NAME => 'TestMergeTool,,1232139129379', STARTKEY => '', ENDKEY => '', ENCODED => 656508476, 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-16 20:52:09,414 INFO  [main] regionserver.HRegion(2495): starting merge of regions: TestMergeTool,row_0100,1232139125231 and TestMergeTool,,1232139099515 into new region REGION => {NAME => 'TestMergeTool,,1232139129379', STARTKEY => '', ENDKEY => '', ENCODED => 656508476, 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...@3e89c3> and end key <[B...@3e89c3>
    [junit] 2009-01-16 20:52:09,414 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1232139125231: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:09,414 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:09,414 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:09,415 DEBUG [main] regionserver.HStore(600): closed 403090138/contents
    [junit] 2009-01-16 20:52:09,415 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1232139125231
    [junit] 2009-01-16 20:52:09,415 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232139099515: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:09,415 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232139099515
    [junit] 2009-01-16 20:52:09,415 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232139099515
    [junit] 2009-01-16 20:52:09,415 DEBUG [main] regionserver.HStore(600): closed 1651928880/contents
    [junit] 2009-01-16 20:52:09,416 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1232139099515
    [junit] 2009-01-16 20:52:09,484 DEBUG [main] regionserver.HRegion(2518): Adjusting sequence id of storeFile 1651928880/contents/6083469289564728645 down by one; sequence id A=2, sequence id B=2
    [junit] 2009-01-16 20:52:09,579 DEBUG [main] regionserver.HRegion(2529): Renaming 403090138/contents/8365883484816433292 to 656508476/contents/5200361242646897106
    [junit] 2009-01-16 20:52:09,639 DEBUG [main] regionserver.HRegion(2529): Renaming 1651928880/contents/6083469289564728645 to 656508476/contents/5312578428551982063
    [junit] 2009-01-16 20:52:09,702 DEBUG [main] regionserver.HRegion(2535): Files for new region
    [junit] 2009-01-16 20:52:09,702 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents
    [junit] 2009-01-16 20:52:09,703 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/info
    [junit] 2009-01-16 20:52:09,704 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/info/5200361242646897106 size=11
    [junit] 2009-01-16 20:52:09,704 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/info/5312578428551982063 size=9
    [junit] 2009-01-16 20:52:09,704 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles
    [junit] 2009-01-16 20:52:09,705 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5200361242646897106
    [junit] 2009-01-16 20:52:09,706 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5200361242646897106/data size=486
    [junit] 2009-01-16 20:52:09,706 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5200361242646897106/index size=227
    [junit] 2009-01-16 20:52:09,706 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5312578428551982063
    [junit] 2009-01-16 20:52:09,707 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5312578428551982063/data size=204
    [junit] 2009-01-16 20:52:09,707 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/5312578428551982063/index size=227
    [junit] 2009-01-16 20:52:09,707 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232139129379/656508476
    [junit] 2009-01-16 20:52:09,718 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/656508476/contents/info/5200361242646897106, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-01-16 20:52:09,724 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/656508476/contents/info/5312578428551982063, isReference=false, sequence id=1, length=204, majorCompaction=false
    [junit] 2009-01-16 20:52:09,724 DEBUG [main] regionserver.HStore(232): Loaded 2 file(s) in hstore 656508476/contents, max sequence id 2
    [junit] 2009-01-16 20:52:09,733 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232139129379 is 3
    [junit] 2009-01-16 20:52:09,734 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1232139129379/656508476 available
    [junit] 2009-01-16 20:52:09,734 INFO  [main] regionserver.HRegion(719): starting  compaction on region TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:09,737 DEBUG [main] regionserver.HStore(901): Compaction size of 656508476/contents: 1.1k; Skipped 0 file(s), size: 0
    [junit] 2009-01-16 20:52:09,749 DEBUG [main] regionserver.HStore(919): Started compaction of 2 file(s)  into /user/hudson/TestMergeTool/compaction.dir/656508476/contents/mapfiles/2494325713762001031
    [junit] 2009-01-16 20:52:10,013 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/656508476/contents/mapfiles/2494325713762001031 to /user/hudson/TestMergeTool/656508476/contents/mapfiles/8469249743599706410
    [junit] 2009-01-16 20:52:10,208 DEBUG [main] regionserver.HStore(938): Completed  compaction of 656508476/contents store size is 580.0
    [junit] 2009-01-16 20:52:10,235 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1232139129379 in 0sec
    [junit] 2009-01-16 20:52:10,236 DEBUG [main] regionserver.HRegion(2542): Files for new region
    [junit] 2009-01-16 20:52:10,237 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents
    [junit] 2009-01-16 20:52:10,238 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/info
    [junit] 2009-01-16 20:52:10,239 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/info/8469249743599706410 size=9
    [junit] 2009-01-16 20:52:10,239 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles
    [junit] 2009-01-16 20:52:10,240 DEBUG [main] regionserver.HRegion(2608): d hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/8469249743599706410
    [junit] 2009-01-16 20:52:10,241 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/8469249743599706410/data size=580
    [junit] 2009-01-16 20:52:10,241 DEBUG [main] regionserver.HRegion(2611): f hdfs://localhost:44011/user/hudson/TestMergeTool/656508476/contents/mapfiles/8469249743599706410/index size=227
    [junit] 2009-01-16 20:52:10,241 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:44011/user/hudson/TestMergeTool/403090138
    [junit] 2009-01-16 20:52:10,266 DEBUG [main] regionserver.HRegion(2336): DELETING region hdfs://localhost:44011/user/hudson/TestMergeTool/1651928880
    [junit] 2009-01-16 20:52:10,300 INFO  [main] regionserver.HRegion(2548): merge completed. New region is TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,301 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1232139125231', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 403090138, 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-16 20:52:10,301 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1232139099515', STARTKEY => '', ENDKEY => '', ENCODED => 1651928880, 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-16 20:52:10,308 INFO  [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1232139129379', STARTKEY => '', ENDKEY => '', ENCODED => 656508476, 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-16 20:52:10,308 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232139129379: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:10,309 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,309 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,309 DEBUG [main] regionserver.HStore(600): closed 656508476/contents
    [junit] 2009-01-16 20:52:10,310 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,310 DEBUG [main] regionserver.HRegion(392): Closing -ROOT-,,0: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:10,310 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on -ROOT-,,0
    [junit] 2009-01-16 20:52:10,310 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region -ROOT-,,0
    [junit] 2009-01-16 20:52:10,310 DEBUG [main] regionserver.HStore(600): closed 70236052/info
    [junit] 2009-01-16 20:52:10,311 INFO  [main] regionserver.HRegion(441): Closed -ROOT-,,0
    [junit] 2009-01-16 20:52:10,312 DEBUG [main] regionserver.HRegion(392): Closing .META.,,1: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:10,312 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on .META.,,1
    [junit] 2009-01-16 20:52:10,312 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region .META.,,1
    [junit] 2009-01-16 20:52:10,312 DEBUG [main] regionserver.HRegion(844): Started memcache flush for region .META.,,1. Current region memcache size 906.0
    [junit] 2009-01-16 20:52:10,561 DEBUG [main] regionserver.HStore(696): Added /user/hudson/.META./1028785192/info/mapfiles/7505973618422846369 with 3 entries, sequence id 21, data size ~906.0, file size 623.0 to .META.,,1
    [junit] 2009-01-16 20:52:10,561 DEBUG [main] regionserver.HRegion(921): Finished memcache flush of ~906.0 for region .META.,,1 in 249ms, sequence id=21, compaction requested=true
    [junit] 2009-01-16 20:52:10,561 DEBUG [main] regionserver.HStore(600): closed 1028785192/historian
    [junit] 2009-01-16 20:52:10,561 DEBUG [main] regionserver.HStore(600): closed 1028785192/info
    [junit] 2009-01-16 20:52:10,562 INFO  [main] regionserver.HRegion(441): Closed .META.,,1
    [junit] 2009-01-16 20:52:10,623 INFO  [main] regionserver.HLog(265): Closed hdfs://localhost:44011/user/hudson/log_1232139126726/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1232139126726/hlog.dat.1232139130597
    [junit] 2009-01-16 20:52:10,623 DEBUG [main] regionserver.HLog(272): Last sequence written is empty. Deleting all old hlogs
    [junit] 2009-01-16 20:52:10,623 INFO  [main] regionserver.HLog(383): removing old log file /user/hudson/log_1232139126726/hlog.dat.0 whose highest sequence/edit id is 21
    [junit] 2009-01-16 20:52:10,624 DEBUG [main] regionserver.HLog(419): closing log writer in hdfs://localhost:44011/user/hudson/log_1232139126726
    [junit] 2009-01-16 20:52:10,674 DEBUG [main] regionserver.HRegion(2218): Opening region: REGION => {NAME => 'TestMergeTool,,1232139129379', STARTKEY => '', ENDKEY => '', ENCODED => 656508476, 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-16 20:52:10,675 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1232139129379/656508476
    [junit] 2009-01-16 20:52:10,682 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/656508476/contents/info/8469249743599706410, isReference=false, sequence id=2, length=580, majorCompaction=false
    [junit] 2009-01-16 20:52:10,682 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 656508476/contents, max sequence id 2
    [junit] 2009-01-16 20:52:10,688 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1232139129379 is 3
    [junit] 2009-01-16 20:52:10,689 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1232139129379/656508476 available
    [junit] 2009-01-16 20:52:10,698 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1232139129379: compactions & flushes disabled 
    [junit] 2009-01-16 20:52:10,698 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,698 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,699 DEBUG [main] regionserver.HStore(600): closed 656508476/contents
    [junit] 2009-01-16 20:52:10,699 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1232139129379
    [junit] 2009-01-16 20:52:10,699 INFO  [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
    [junit] 2009-01-16 20:52:10,699 DEBUG [main] regionserver.HLog(419): closing log writer in /tmp/log_1232139106501
    [junit] 2009-01-16 20:52:10,775 INFO  [main] hbase.HBaseTestCase(600): Shutting down FileSystem
    [junit] 2009-01-16 20:52:10,775 INFO  [main] hbase.HBaseTestCase(607): Shutting down Mini DFS 
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 1
    [junit] 2009-01-16 20:52:10,780 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:44019
    [junit] 2009-01-16 20:52:10,780 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@a6af6e
    [junit] 2009-01-16 20:52:10,861 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-01-16 20:52:10,861 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@9260ee
    [junit] 2009-01-16 20:52:10,957 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-01-16 20:52:10,958 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@d58ce2
    [junit] Shutting down DataNode 0
    [junit] 2009-01-16 20:52:11,967 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:44016
    [junit] 2009-01-16 20:52:11,967 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c92507
    [junit] 2009-01-16 20:52:12,039 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-01-16 20:52:12,040 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e2ecc7
    [junit] 2009-01-16 20:52:12,110 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-01-16 20:52:12,110 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@17cf6b6
    [junit] 2009-01-16 20:52:13,116 INFO  [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=44012]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=44012]
    [junit] 2009-01-16 20:52:13,116 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:44012
    [junit] 2009-01-16 20:52:13,117 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1f78b68
    [junit] 2009-01-16 20:52:13,186 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-01-16 20:52:13,186 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1be4777
    [junit] 2009-01-16 20:52:13,254 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-01-16 20:52:13,254 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@ab54eb
    [junit] 2009-01-16 20:52:13,255 WARN  [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@e49dcd] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 33.906 sec
    [junit] Running org.apache.hadoop.hbase.util.TestRootPath
    [junit] 2009-01-16 20:52:13,727 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.051 sec
    [junit] Running org.onelab.test.TestFilter
    [junit] 2009-01-16 20:52:14,123 INFO  [main] test.TestFilter(244): Checking for false negatives
    [junit] 2009-01-16 20:52:14,127 INFO  [main] test.TestFilter(255): Checking for false positives
    [junit] 2009-01-16 20:52:14,128 INFO  [main] test.TestFilter(262): Success!
    [junit] 2009-01-16 20:52:14,128 INFO  [main] test.TestFilter(226): Checking serialization/deserialization
    [junit] 2009-01-16 20:52:14,130 INFO  [main] test.TestFilter(244): Checking for false negatives
    [junit] 2009-01-16 20:52:14,132 INFO  [main] test.TestFilter(255): Checking for false positives
    [junit] 2009-01-16 20:52:14,132 INFO  [main] test.TestFilter(262): Success!
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.057 sec

BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453: Tests failed!

Total time: 35 minutes 36 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 #487

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/487/changes