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/02/08 20:46:48 UTC

Build failed in Hudson: HBase-Patch #519

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

Changes:

[jdcryans] Corrected the "via" stuff in CHANGES

[jdcryans] HBASE-1191  ZooKeeper ensureParentExists calls fail 
               on absolute path (via Nitay Joffe)
HBASE-1187  After disabling/enabling a table, the regions seems to
               be assigned to only 1-2 region servers

------------------------------------------
[...truncated 28924 lines...]
    [junit] 2009-02-08 19:53:45,719 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/826767145/contents/info/1314689609779994351, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-02-08 19:53:45,719 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 826767145/contents, max sequence id 2
    [junit] 2009-02-08 19:53:45,724 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1234122825489 is 3
    [junit] 2009-02-08 19:53:45,725 INFO  [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1234122825489/826767145 available
    [junit] 2009-02-08 19:53:45,732 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1234122825489: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:45,733 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:45,733 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:45,733 DEBUG [main] regionserver.HStore(600): closed 826767145/contents
    [junit] 2009-02-08 19:53:45,733 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:45,733 INFO  [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
    [junit] 2009-02-08 19:53:45,733 INFO  [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
    [junit] 2009-02-08 19:53:45,734 INFO  [main] util.Merge(80): Verifying that file system is available...
    [junit] 2009-02-08 19:53:45,734 INFO  [main] util.Merge(89): Verifying that HBase is not running...
    [junit] 2009-02-08 19:53:45,744 INFO  [main] util.Merge(190): Merging regions [B@5bfbd8 and [B@f33280 in table [B@78ae82
    [junit] 2009-02-08 19:53:45,746 INFO  [main] regionserver.HLog(275): New log writer: /user/hudson/log_1234122825744/hlog.dat.1234122825745
    [junit] 2009-02-08 19:53:45,747 DEBUG [main] regionserver.HRegion(2219): 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-02-08 19:53:45,747 DEBUG [main] regionserver.HRegion(238): Opening region -ROOT-,,0/70236052
    [junit] 2009-02-08 19:53:45,794 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/-ROOT-/70236052/info/info/8713207863142797305, isReference=false, sequence id=1, length=577, majorCompaction=false
    [junit] 2009-02-08 19:53:45,794 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
    [junit] 2009-02-08 19:53:45,800 DEBUG [main] regionserver.HRegion(299): Next sequence id for region -ROOT-,,0 is 2
    [junit] 2009-02-08 19:53:45,801 INFO  [main] regionserver.HRegion(321): region -ROOT-,,0/70236052 available
    [junit] 2009-02-08 19:53:45,801 DEBUG [main] regionserver.HLog(219): changing sequence number from 0 to 2
    [junit] 2009-02-08 19:53:45,801 INFO  [main] regionserver.HRegion(719): starting  compaction on region -ROOT-,,0
    [junit] 2009-02-08 19:53:45,847 INFO  [main] regionserver.HRegion(734): compaction completed on region -ROOT-,,0 in 0sec
    [junit] 2009-02-08 19:53:45,853 INFO  [main] util.Merge(204): Found meta for region1 [B@545646, meta for region2 [B@545646
    [junit] 2009-02-08 19:53:45,853 DEBUG [main] regionserver.HRegion(2219): 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-02-08 19:53:45,853 DEBUG [main] regionserver.HRegion(238): Opening region .META.,,1/1028785192
    [junit] 2009-02-08 19:53:45,860 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/4037706583060095958, isReference=false, sequence id=13, length=1216, majorCompaction=false
    [junit] 2009-02-08 19:53:45,866 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/6730296993759538178, isReference=false, sequence id=5, length=1953, majorCompaction=false
    [junit] 2009-02-08 19:53:45,871 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/.META./1028785192/info/info/9073615428450161699, isReference=false, sequence id=17, length=663, majorCompaction=false
    [junit] 2009-02-08 19:53:45,872 DEBUG [main] regionserver.HStore(232): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
    [junit] 2009-02-08 19:53:45,886 DEBUG [main] regionserver.HRegion(299): Next sequence id for region .META.,,1 is 18
    [junit] 2009-02-08 19:53:45,887 INFO  [main] regionserver.HRegion(321): region .META.,,1/1028785192 available
    [junit] 2009-02-08 19:53:45,887 DEBUG [main] regionserver.HLog(219): changing sequence number from 2 to 18
    [junit] 2009-02-08 19:53:45,887 INFO  [main] regionserver.HRegion(719): starting  compaction on region .META.,,1
    [junit] 2009-02-08 19:53:45,888 DEBUG [main] regionserver.HStore(828): 1028785192/historian: no store files to compact
    [junit] 2009-02-08 19:53:45,891 DEBUG [main] regionserver.HStore(901): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
    [junit] 2009-02-08 19:53:45,911 DEBUG [main] regionserver.HStore(919): Started compaction of 3 file(s)  into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/6011825625948484435
    [junit] 2009-02-08 19:53:45,931 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/6011825625948484435 to /user/hudson/.META./1028785192/info/mapfiles/7761129536297720392
    [junit] 2009-02-08 19:53:45,944 DEBUG [main] regionserver.HStore(938): Completed  compaction of 1028785192/info store size is 3.5k
    [junit] 2009-02-08 19:53:45,946 INFO  [main] regionserver.HRegion(734): compaction completed on region .META.,,1 in 0sec
    [junit] 2009-02-08 19:53:45,946 DEBUG [main] regionserver.HRegion(2219): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1234122825489', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 826767145, 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-02-08 19:53:45,947 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,row_0100,1234122825489/826767145
    [junit] 2009-02-08 19:53:45,954 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/826767145/contents/info/1314689609779994351, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-02-08 19:53:45,954 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 826767145/contents, max sequence id 2
    [junit] 2009-02-08 19:53:45,959 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,row_0100,1234122825489 is 3
    [junit] 2009-02-08 19:53:45,960 INFO  [main] regionserver.HRegion(321): region TestMergeTool,row_0100,1234122825489/826767145 available
    [junit] 2009-02-08 19:53:45,960 DEBUG [main] regionserver.HRegion(2219): Opening region: REGION => {NAME => 'TestMergeTool,,1234122811071', STARTKEY => '', ENDKEY => '', ENCODED => 1836451988, 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-02-08 19:53:45,961 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1234122811071/1836451988
    [junit] 2009-02-08 19:53:45,967 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/1836451988/contents/info/7418236033824053899, isReference=false, sequence id=2, length=204, majorCompaction=false
    [junit] 2009-02-08 19:53:45,968 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 1836451988/contents, max sequence id 2
    [junit] 2009-02-08 19:53:45,973 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1234122811071 is 3
    [junit] 2009-02-08 19:53:45,973 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1234122811071/1836451988 available
    [junit] 2009-02-08 19:53:45,974 INFO  [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:45,980 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s)  into /user/hudson/TestMergeTool/compaction.dir/826767145/contents/mapfiles/8953600553852087519
    [junit] 2009-02-08 19:53:46,018 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/826767145/contents/mapfiles/8953600553852087519 to /user/hudson/TestMergeTool/826767145/contents/mapfiles/3497179031482886186
    [junit] 2009-02-08 19:53:46,029 DEBUG [main] regionserver.HStore(938): Completed major compaction of 826767145/contents store size is 486.0
    [junit] 2009-02-08 19:53:46,030 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,row_0100,1234122825489 in 0sec
    [junit] 2009-02-08 19:53:46,030 DEBUG [main] regionserver.HRegion(2458): Files for region: TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:46,031 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents
    [junit] 2009-02-08 19:53:46,032 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/info
    [junit] 2009-02-08 19:53:46,032 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/info/3497179031482886186 size=11
    [junit] 2009-02-08 19:53:46,033 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/mapfiles
    [junit] 2009-02-08 19:53:46,033 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/mapfiles/3497179031482886186
    [junit] 2009-02-08 19:53:46,034 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/mapfiles/3497179031482886186/data size=486
    [junit] 2009-02-08 19:53:46,034 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/826767145/contents/mapfiles/3497179031482886186/index size=227
    [junit] 2009-02-08 19:53:46,034 INFO  [main] regionserver.HRegion(719): starting major compaction on region TestMergeTool,,1234122811071
    [junit] 2009-02-08 19:53:46,042 DEBUG [main] regionserver.HStore(919): Started compaction of 1 file(s)  into /user/hudson/TestMergeTool/compaction.dir/1836451988/contents/mapfiles/4027858275558337178
    [junit] 2009-02-08 19:53:46,061 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/1836451988/contents/mapfiles/4027858275558337178 to /user/hudson/TestMergeTool/1836451988/contents/mapfiles/4749148735645035359
    [junit] 2009-02-08 19:53:46,089 DEBUG [main] regionserver.HStore(938): Completed major compaction of 1836451988/contents store size is 204.0
    [junit] 2009-02-08 19:53:46,091 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1234122811071 in 0sec
    [junit] 2009-02-08 19:53:46,091 DEBUG [main] regionserver.HRegion(2463): Files for region: TestMergeTool,,1234122811071
    [junit] 2009-02-08 19:53:46,092 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents
    [junit] 2009-02-08 19:53:46,092 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/info
    [junit] 2009-02-08 19:53:46,093 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/info/4749148735645035359 size=11
    [junit] 2009-02-08 19:53:46,093 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/mapfiles
    [junit] 2009-02-08 19:53:46,094 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/mapfiles/4749148735645035359
    [junit] 2009-02-08 19:53:46,095 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/mapfiles/4749148735645035359/data size=204
    [junit] 2009-02-08 19:53:46,095 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988/contents/mapfiles/4749148735645035359/index size=227
    [junit] 2009-02-08 19:53:46,095 INFO  [main] regionserver.HRegion(2487): Creating new region REGION => {NAME => 'TestMergeTool,,1234122826095', STARTKEY => '', ENDKEY => '', ENCODED => 2109398542, 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-02-08 19:53:46,097 INFO  [main] regionserver.HRegion(2496): starting merge of regions: TestMergeTool,row_0100,1234122825489 and TestMergeTool,,1234122811071 into new region REGION => {NAME => 'TestMergeTool,,1234122826095', STARTKEY => '', ENDKEY => '', ENCODED => 2109398542, 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...@172e449> and end key <[B...@172e449>
    [junit] 2009-02-08 19:53:46,097 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,row_0100,1234122825489: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,097 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:46,097 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:46,097 DEBUG [main] regionserver.HStore(600): closed 826767145/contents
    [junit] 2009-02-08 19:53:46,098 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,row_0100,1234122825489
    [junit] 2009-02-08 19:53:46,098 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1234122811071: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,098 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1234122811071
    [junit] 2009-02-08 19:53:46,098 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1234122811071
    [junit] 2009-02-08 19:53:46,098 DEBUG [main] regionserver.HStore(600): closed 1836451988/contents
    [junit] 2009-02-08 19:53:46,099 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1234122811071
    [junit] 2009-02-08 19:53:46,104 DEBUG [main] regionserver.HRegion(2519): Adjusting sequence id of storeFile 1836451988/contents/4749148735645035359 down by one; sequence id A=2, sequence id B=2
    [junit] 2009-02-08 19:53:46,150 DEBUG [main] regionserver.HRegion(2530): Renaming 826767145/contents/3497179031482886186 to 2109398542/contents/7889498413468477930
    [junit] 2009-02-08 19:53:46,154 DEBUG [main] regionserver.HRegion(2530): Renaming 1836451988/contents/4749148735645035359 to 2109398542/contents/6812075488252268386
    [junit] 2009-02-08 19:53:46,157 DEBUG [main] regionserver.HRegion(2536): Files for new region
    [junit] 2009-02-08 19:53:46,157 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents
    [junit] 2009-02-08 19:53:46,158 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/info
    [junit] 2009-02-08 19:53:46,159 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/info/6812075488252268386 size=9
    [junit] 2009-02-08 19:53:46,159 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/info/7889498413468477930 size=11
    [junit] 2009-02-08 19:53:46,159 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles
    [junit] 2009-02-08 19:53:46,160 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/6812075488252268386
    [junit] 2009-02-08 19:53:46,160 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/6812075488252268386/data size=204
    [junit] 2009-02-08 19:53:46,161 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/6812075488252268386/index size=227
    [junit] 2009-02-08 19:53:46,161 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/7889498413468477930
    [junit] 2009-02-08 19:53:46,161 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/7889498413468477930/data size=486
    [junit] 2009-02-08 19:53:46,162 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/7889498413468477930/index size=227
    [junit] 2009-02-08 19:53:46,162 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1234122826095/2109398542
    [junit] 2009-02-08 19:53:46,169 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/2109398542/contents/info/6812075488252268386, isReference=false, sequence id=1, length=204, majorCompaction=false
    [junit] 2009-02-08 19:53:46,174 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/2109398542/contents/info/7889498413468477930, isReference=false, sequence id=2, length=486, majorCompaction=false
    [junit] 2009-02-08 19:53:46,175 DEBUG [main] regionserver.HStore(232): Loaded 2 file(s) in hstore 2109398542/contents, max sequence id 2
    [junit] 2009-02-08 19:53:46,183 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1234122826095 is 3
    [junit] 2009-02-08 19:53:46,184 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1234122826095/2109398542 available
    [junit] 2009-02-08 19:53:46,184 INFO  [main] regionserver.HRegion(719): starting  compaction on region TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,187 DEBUG [main] regionserver.HStore(901): Compaction size of 2109398542/contents: 1.1k; Skipped 0 file(s), size: 0
    [junit] 2009-02-08 19:53:46,195 DEBUG [main] regionserver.HStore(919): Started compaction of 2 file(s)  into /user/hudson/TestMergeTool/compaction.dir/2109398542/contents/mapfiles/7890036721473571888
    [junit] 2009-02-08 19:53:46,227 DEBUG [main] regionserver.HStore(1244): moving /user/hudson/TestMergeTool/compaction.dir/2109398542/contents/mapfiles/7890036721473571888 to /user/hudson/TestMergeTool/2109398542/contents/mapfiles/5282597266571656461
    [junit] 2009-02-08 19:53:46,258 DEBUG [main] regionserver.HStore(938): Completed  compaction of 2109398542/contents store size is 580.0
    [junit] 2009-02-08 19:53:46,260 INFO  [main] regionserver.HRegion(734): compaction completed on region TestMergeTool,,1234122826095 in 0sec
    [junit] 2009-02-08 19:53:46,261 DEBUG [main] regionserver.HRegion(2543): Files for new region
    [junit] 2009-02-08 19:53:46,261 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents
    [junit] 2009-02-08 19:53:46,262 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/info
    [junit] 2009-02-08 19:53:46,263 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/info/5282597266571656461 size=9
    [junit] 2009-02-08 19:53:46,263 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles
    [junit] 2009-02-08 19:53:46,263 DEBUG [main] regionserver.HRegion(2609): d hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/5282597266571656461
    [junit] 2009-02-08 19:53:46,264 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/5282597266571656461/data size=580
    [junit] 2009-02-08 19:53:46,264 DEBUG [main] regionserver.HRegion(2612): f hdfs://localhost:51264/user/hudson/TestMergeTool/2109398542/contents/mapfiles/5282597266571656461/index size=227
    [junit] 2009-02-08 19:53:46,264 DEBUG [main] regionserver.HRegion(2337): DELETING region hdfs://localhost:51264/user/hudson/TestMergeTool/826767145
    [junit] 2009-02-08 19:53:46,265 DEBUG [main] regionserver.HRegion(2337): DELETING region hdfs://localhost:51264/user/hudson/TestMergeTool/1836451988
    [junit] 2009-02-08 19:53:46,266 INFO  [main] regionserver.HRegion(2549): merge completed. New region is TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,266 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1234122825489', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 826767145, 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-02-08 19:53:46,267 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1234122811071', STARTKEY => '', ENDKEY => '', ENCODED => 1836451988, 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-02-08 19:53:46,272 INFO  [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1234122826095', STARTKEY => '', ENDKEY => '', ENCODED => 2109398542, 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-02-08 19:53:46,272 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1234122826095: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,272 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HStore(600): closed 2109398542/contents
    [junit] 2009-02-08 19:53:46,273 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HRegion(392): Closing -ROOT-,,0: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on -ROOT-,,0
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region -ROOT-,,0
    [junit] 2009-02-08 19:53:46,273 DEBUG [main] regionserver.HStore(600): closed 70236052/info
    [junit] 2009-02-08 19:53:46,274 INFO  [main] regionserver.HRegion(441): Closed -ROOT-,,0
    [junit] 2009-02-08 19:53:46,274 DEBUG [main] regionserver.HRegion(392): Closing .META.,,1: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,274 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on .META.,,1
    [junit] 2009-02-08 19:53:46,274 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region .META.,,1
    [junit] 2009-02-08 19:53:46,274 DEBUG [main] regionserver.HRegion(844): Started memcache flush for region .META.,,1. Current region memcache size 906.0
    [junit] 2009-02-08 19:53:46,299 DEBUG [main] regionserver.HStore(696): Added /user/hudson/.META./1028785192/info/mapfiles/6316740816798462166 with 3 entries, sequence id 21, data size ~906.0, file size 623.0 to .META.,,1
    [junit] 2009-02-08 19:53:46,301 DEBUG [main] regionserver.HRegion(921): Finished memcache flush of ~906.0 for region .META.,,1 in 27ms, sequence id=21, compaction requested=true
    [junit] 2009-02-08 19:53:46,303 DEBUG [main] regionserver.HStore(600): closed 1028785192/historian
    [junit] 2009-02-08 19:53:46,304 DEBUG [main] regionserver.HStore(600): closed 1028785192/info
    [junit] 2009-02-08 19:53:46,306 INFO  [main] regionserver.HRegion(441): Closed .META.,,1
    [junit] 2009-02-08 19:53:46,312 INFO  [main] regionserver.HLog(275): Closed hdfs://localhost:51264/user/hudson/log_1234122825744/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1234122825744/hlog.dat.1234122826311
    [junit] 2009-02-08 19:53:46,314 DEBUG [main] regionserver.HLog(282): Last sequence written is empty. Deleting all old hlogs
    [junit] 2009-02-08 19:53:46,315 INFO  [main] regionserver.HLog(393): removing old log file /user/hudson/log_1234122825744/hlog.dat.0 whose highest sequence/edit id is 21
    [junit] 2009-02-08 19:53:46,317 DEBUG [main] regionserver.HLog(429): closing log writer in hdfs://localhost:51264/user/hudson/log_1234122825744
    [junit] 2009-02-08 19:53:46,323 DEBUG [main] regionserver.HRegion(2219): Opening region: REGION => {NAME => 'TestMergeTool,,1234122826095', STARTKEY => '', ENDKEY => '', ENCODED => 2109398542, 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-02-08 19:53:46,325 DEBUG [main] regionserver.HRegion(238): Opening region TestMergeTool,,1234122826095/2109398542
    [junit] 2009-02-08 19:53:46,333 DEBUG [main] regionserver.HStore(494): loaded /user/hudson/TestMergeTool/2109398542/contents/info/5282597266571656461, isReference=false, sequence id=2, length=580, majorCompaction=false
    [junit] 2009-02-08 19:53:46,335 DEBUG [main] regionserver.HStore(232): Loaded 1 file(s) in hstore 2109398542/contents, max sequence id 2
    [junit] 2009-02-08 19:53:46,341 DEBUG [main] regionserver.HRegion(299): Next sequence id for region TestMergeTool,,1234122826095 is 3
    [junit] 2009-02-08 19:53:46,344 INFO  [main] regionserver.HRegion(321): region TestMergeTool,,1234122826095/2109398542 available
    [junit] 2009-02-08 19:53:46,354 DEBUG [main] regionserver.HRegion(392): Closing TestMergeTool,,1234122826095: compactions & flushes disabled 
    [junit] 2009-02-08 19:53:46,355 DEBUG [main] regionserver.HRegion(422): Updates disabled for region, no outstanding scanners on TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,357 DEBUG [main] regionserver.HRegion(429): No more row locks outstanding on region TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,358 DEBUG [main] regionserver.HStore(600): closed 2109398542/contents
    [junit] 2009-02-08 19:53:46,359 INFO  [main] regionserver.HRegion(441): Closed TestMergeTool,,1234122826095
    [junit] 2009-02-08 19:53:46,361 INFO  [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
    [junit] 2009-02-08 19:53:46,362 DEBUG [main] regionserver.HLog(429): closing log writer in /tmp/log_1234122813272
    [junit] 2009-02-08 19:53:46,368 INFO  [main] hbase.HBaseTestCase(600): Shutting down FileSystem
    [junit] 2009-02-08 19:53:46,370 INFO  [main] hbase.HBaseTestCase(607): Shutting down Mini DFS 
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 1
    [junit] 2009-02-08 19:53:46,374 INFO  [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=50174]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=50174]
    [junit] 2009-02-08 19:53:46,377 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:50174
    [junit] 2009-02-08 19:53:46,378 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@913dc1
    [junit] 2009-02-08 19:53:46,454 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-02-08 19:53:46,457 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@fd66a5
    [junit] 2009-02-08 19:53:46,518 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-02-08 19:53:46,519 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@9c82f4
    [junit] 2009-02-08 19:53:46,521 WARN  [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@1bfa3d3] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:41044, storageID=DS-1343272207-67.195.138.9-41044-1234122812513, infoPort=50174, ipcPort=38568):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-02-08 19:53:47,522 INFO  [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=41763]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=41763]
    [junit] 2009-02-08 19:53:47,522 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:41763
    [junit] 2009-02-08 19:53:47,524 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@497904
    [junit] 2009-02-08 19:53:47,595 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-02-08 19:53:47,595 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1f9338f
    [junit] 2009-02-08 19:53:47,648 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-02-08 19:53:47,649 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@1700391
    [junit] 2009-02-08 19:53:47,650 WARN  [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@137d4a4] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:51422, storageID=DS-1588450383-67.195.138.9-51422-1234122812285, infoPort=41763, ipcPort=58318):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-02-08 19:53:48,750 INFO  [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57619]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57619]
    [junit] 2009-02-08 19:53:48,750 INFO  [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:57619
    [junit] 2009-02-08 19:53:48,751 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1264eab
    [junit] 2009-02-08 19:53:48,803 INFO  [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
    [junit] 2009-02-08 19:53:48,804 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c4d04d
    [junit] 2009-02-08 19:53:48,853 INFO  [main] util.Container(156): Stopped WebApplicationContext[/,/]
    [junit] 2009-02-08 19:53:48,854 INFO  [main] util.Container(156): Stopped org.mortbay.jetty.Server@d17ec3
    [junit] 2009-02-08 19:53:48,854 WARN  [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@fb6354] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 17.884 sec
    [junit] Running org.apache.hadoop.hbase.util.TestRootPath
    [junit] 2009-02-08 19:53:49,210 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.062 sec
    [junit] Running org.onelab.test.TestFilter
    [junit] 2009-02-08 19:53:49,546 INFO  [main] test.TestFilter(244): Checking for false negatives
    [junit] 2009-02-08 19:53:49,550 INFO  [main] test.TestFilter(255): Checking for false positives
    [junit] 2009-02-08 19:53:49,554 INFO  [main] test.TestFilter(262): Success!
    [junit] 2009-02-08 19:53:49,555 INFO  [main] test.TestFilter(226): Checking serialization/deserialization
    [junit] 2009-02-08 19:53:49,556 INFO  [main] test.TestFilter(244): Checking for false negatives
    [junit] 2009-02-08 19:53:49,558 INFO  [main] test.TestFilter(255): Checking for false positives
    [junit] 2009-02-08 19:53:49,559 INFO  [main] test.TestFilter(262): Success!
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.078 sec

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :457: Tests failed!

Total time: 30 minutes 22 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...


Hudson build is back to normal: HBase-Patch #520

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