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 2008/11/28 11:52:53 UTC
Build failed in Hudson: HBase-Patch #428
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/428/changes
Changes:
[apurtell] HBASE-902 Add force compaction and force split operations to UI and Admin; force compactions before split, added test case
[apurtell] HBASE-1028 If key does not exist, return null in getRow rather than an empty RowResult
------------------------------------------
[...truncated 21806 lines...]
[junit] 2008-11-28 10:52:39,009 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 10:52:39,009 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 10:52:39,009 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 10:52:39,009 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 510.0
[junit] 2008-11-28 10:52:39,380 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/2713938823549262694 with 3 entries, sequence id 17, data size 510.0, file size 662.0 to .META.,,1
[junit] 2008-11-28 10:52:39,380 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 371ms, sequence id=17, compaction requested=true
[junit] 2008-11-28 10:52:39,380 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 10:52:39,380 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 10:52:39,381 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 10:52:39,471 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:34771/user/hudson/log_1227869555171/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227869555171/hlog.dat.1227869559428
[junit] 2008-11-28 10:52:39,472 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 10:52:39,472 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227869555171/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2008-11-28 10:52:39,473 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:34771/user/hudson/log_1227869555171
[junit] 2008-11-28 10:52:39,555 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227869557516', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 582274869, 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 => 'true'}]}}
[junit] 2008-11-28 10:52:39,556 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227869557516/582274869
[junit] 2008-11-28 10:52:39,565 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/582274869/contents/info/5495287867511386883, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 10:52:39,566 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 582274869/contents, max sequence id 2
[junit] 2008-11-28 10:52:39,573 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227869557516 is 3
[junit] 2008-11-28 10:52:39,575 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227869557516/582274869 available
[junit] 2008-11-28 10:52:39,576 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227869557516: compactions & flushes disabled
[junit] 2008-11-28 10:52:39,577 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:39,577 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:39,577 DEBUG [main] regionserver.HStore(597): closed 582274869/contents
[junit] 2008-11-28 10:52:39,578 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:39,578 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2008-11-28 10:52:39,578 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2008-11-28 10:52:39,579 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2008-11-28 10:52:39,580 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2008-11-28 10:52:39,592 INFO [main] util.Merge(190): Merging regions [B@1672313 and [B@2fe032 in table [B@1282707
[junit] 2008-11-28 10:52:39,672 INFO [main] regionserver.HLog(255): New log writer: /user/hudson/log_1227869559593/hlog.dat.1227869559620
[junit] 2008-11-28 10:52:39,672 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}]}}
[junit] 2008-11-28 10:52:39,673 DEBUG [main] regionserver.HRegion(232): Opening region -ROOT-,,0/70236052
[junit] 2008-11-28 10:52:39,683 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/-ROOT-/70236052/info/info/1693764755287687971, isReference=false, sequence id=1, length=578, majorCompaction=false
[junit] 2008-11-28 10:52:39,684 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2008-11-28 10:52:39,692 DEBUG [main] regionserver.HRegion(293): Next sequence id for region -ROOT-,,0 is 2
[junit] 2008-11-28 10:52:39,693 INFO [main] regionserver.HRegion(315): region -ROOT-,,0/70236052 available
[junit] 2008-11-28 10:52:39,694 DEBUG [main] regionserver.HLog(208): changing sequence number from 0 to 2
[junit] 2008-11-28 10:52:39,694 INFO [main] regionserver.HRegion(703): starting compaction on region -ROOT-,,0
[junit] 2008-11-28 10:52:39,696 INFO [main] regionserver.HRegion(717): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2008-11-28 10:52:39,704 INFO [main] util.Merge(204): Found meta for region1 [B@f757b9, meta for region2 [B@f757b9
[junit] 2008-11-28 10:52:39,704 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 10:52:39,705 DEBUG [main] regionserver.HRegion(232): Opening region .META.,,1/1028785192
[junit] 2008-11-28 10:52:39,714 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/2208576166049732628, isReference=false, sequence id=5, length=1948, majorCompaction=false
[junit] 2008-11-28 10:52:39,721 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/2713938823549262694, isReference=false, sequence id=17, length=662, majorCompaction=false
[junit] 2008-11-28 10:52:39,728 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/7596577787713649645, isReference=false, sequence id=13, length=1214, majorCompaction=false
[junit] 2008-11-28 10:52:39,729 DEBUG [main] regionserver.HStore(229): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2008-11-28 10:52:39,752 DEBUG [main] regionserver.HRegion(293): Next sequence id for region .META.,,1 is 18
[junit] 2008-11-28 10:52:39,754 INFO [main] regionserver.HRegion(315): region .META.,,1/1028785192 available
[junit] 2008-11-28 10:52:39,754 DEBUG [main] regionserver.HLog(208): changing sequence number from 2 to 18
[junit] 2008-11-28 10:52:39,754 INFO [main] regionserver.HRegion(703): starting compaction on region .META.,,1
[junit] 2008-11-28 10:52:39,755 DEBUG [main] regionserver.HStore(826): no store files to compact
[junit] 2008-11-28 10:52:39,759 DEBUG [main] regionserver.HStore(893): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 10:52:39,797 DEBUG [main] regionserver.HStore(911): Started compaction of 3 file(s) into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/413385276093438713
[junit] 2008-11-28 10:52:40,127 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/413385276093438713 to /user/hudson/.META./1028785192/info/mapfiles/4397516047905649590
[junit] 2008-11-28 10:52:40,555 DEBUG [main] regionserver.HStore(930): Completed compaction of 1028785192/info store size is 3.5k
[junit] 2008-11-28 10:52:40,591 INFO [main] regionserver.HRegion(717): compaction completed on region .META.,,1 in 0sec
[junit] 2008-11-28 10:52:40,594 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227869557516', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 582274869, 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 => 'true'}]}}
[junit] 2008-11-28 10:52:40,595 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227869557516/582274869
[junit] 2008-11-28 10:52:40,612 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/582274869/contents/info/5495287867511386883, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 10:52:40,613 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 582274869/contents, max sequence id 2
[junit] 2008-11-28 10:52:40,623 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227869557516 is 3
[junit] 2008-11-28 10:52:40,625 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227869557516/582274869 available
[junit] 2008-11-28 10:52:40,625 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227869521305', STARTKEY => '', ENDKEY => '', ENCODED => 1160410525, 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 => 'true'}]}}
[junit] 2008-11-28 10:52:40,626 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227869521305/1160410525
[junit] 2008-11-28 10:52:40,639 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1160410525/contents/info/4984429374202338010, isReference=false, sequence id=2, length=204, majorCompaction=false
[junit] 2008-11-28 10:52:40,640 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1160410525/contents, max sequence id 2
[junit] 2008-11-28 10:52:40,656 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227869521305 is 3
[junit] 2008-11-28 10:52:40,657 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227869521305/1160410525 available
[junit] 2008-11-28 10:52:40,657 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:40,666 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/582274869/contents/mapfiles/1907276498132428779
[junit] 2008-11-28 10:52:41,000 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/582274869/contents/mapfiles/1907276498132428779 to /user/hudson/TestMergeTool/582274869/contents/mapfiles/9113768017509848579
[junit] 2008-11-28 10:52:41,162 DEBUG [main] regionserver.HStore(930): Completed major compaction of 582274869/contents store size is 486.0
[junit] 2008-11-28 10:52:41,224 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,row_0100,1227869557516 in 0sec
[junit] 2008-11-28 10:52:41,224 DEBUG [main] regionserver.HRegion(2294): Files for region: TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:41,225 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents
[junit] 2008-11-28 10:52:41,226 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/info
[junit] 2008-11-28 10:52:41,227 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/info/9113768017509848579 size=11
[junit] 2008-11-28 10:52:41,227 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/mapfiles
[junit] 2008-11-28 10:52:41,228 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/mapfiles/9113768017509848579
[junit] 2008-11-28 10:52:41,230 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/mapfiles/9113768017509848579/data size=486
[junit] 2008-11-28 10:52:41,230 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/582274869/contents/mapfiles/9113768017509848579/index size=227
[junit] 2008-11-28 10:52:41,230 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227869521305
[junit] 2008-11-28 10:52:41,240 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1160410525/contents/mapfiles/7468965129125612421
[junit] 2008-11-28 10:52:43,283 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1160410525/contents/mapfiles/7468965129125612421 to /user/hudson/TestMergeTool/1160410525/contents/mapfiles/5550980816449569531
[junit] 2008-11-28 10:52:43,509 DEBUG [main] regionserver.HStore(930): Completed major compaction of 1160410525/contents store size is 204.0
[junit] 2008-11-28 10:52:43,533 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227869521305 in 2sec
[junit] 2008-11-28 10:52:43,533 DEBUG [main] regionserver.HRegion(2299): Files for region: TestMergeTool,,1227869521305
[junit] 2008-11-28 10:52:43,534 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents
[junit] 2008-11-28 10:52:43,535 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/info
[junit] 2008-11-28 10:52:43,536 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/info/5550980816449569531 size=11
[junit] 2008-11-28 10:52:43,536 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/mapfiles
[junit] 2008-11-28 10:52:43,537 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/mapfiles/5550980816449569531
[junit] 2008-11-28 10:52:43,538 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/mapfiles/5550980816449569531/data size=204
[junit] 2008-11-28 10:52:43,538 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525/contents/mapfiles/5550980816449569531/index size=227
[junit] 2008-11-28 10:52:43,538 INFO [main] regionserver.HRegion(2323): Creating new region REGION => {NAME => 'TestMergeTool,,1227869563538', STARTKEY => '', ENDKEY => '', ENCODED => 2044739718, 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 => 'true'}]}}
[junit] 2008-11-28 10:52:43,559 INFO [main] regionserver.HRegion(2332): starting merge of regions: TestMergeTool,row_0100,1227869557516 and TestMergeTool,,1227869521305 into new region REGION => {NAME => 'TestMergeTool,,1227869563538', STARTKEY => '', ENDKEY => '', ENCODED => 2044739718, 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 => 'true'}]}} with start key <[B...@3e89c3> and end key <[B...@3e89c3>
[junit] 2008-11-28 10:52:43,559 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227869557516: compactions & flushes disabled
[junit] 2008-11-28 10:52:43,559 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:43,560 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:43,560 DEBUG [main] regionserver.HStore(597): closed 582274869/contents
[junit] 2008-11-28 10:52:43,560 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227869557516
[junit] 2008-11-28 10:52:43,560 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227869521305: compactions & flushes disabled
[junit] 2008-11-28 10:52:43,560 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227869521305
[junit] 2008-11-28 10:52:43,560 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227869521305
[junit] 2008-11-28 10:52:43,561 DEBUG [main] regionserver.HStore(597): closed 1160410525/contents
[junit] 2008-11-28 10:52:43,561 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227869521305
[junit] 2008-11-28 10:52:43,608 DEBUG [main] regionserver.HRegion(2355): Adjusting sequence id of storeFile 1160410525/contents/5550980816449569531 down by one; sequence id A=2, sequence id B=2
[junit] 2008-11-28 10:52:43,690 DEBUG [main] regionserver.HRegion(2366): Renaming 582274869/contents/9113768017509848579 to 2044739718/contents/2512475088695106927
[junit] 2008-11-28 10:52:43,782 DEBUG [main] regionserver.HRegion(2366): Renaming 1160410525/contents/5550980816449569531 to 2044739718/contents/7049594830633374001
[junit] 2008-11-28 10:52:43,840 DEBUG [main] regionserver.HRegion(2372): Files for new region
[junit] 2008-11-28 10:52:43,841 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents
[junit] 2008-11-28 10:52:43,842 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/info
[junit] 2008-11-28 10:52:43,843 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/info/2512475088695106927 size=11
[junit] 2008-11-28 10:52:43,843 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/info/7049594830633374001 size=9
[junit] 2008-11-28 10:52:43,843 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles
[junit] 2008-11-28 10:52:43,844 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2512475088695106927
[junit] 2008-11-28 10:52:43,845 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2512475088695106927/data size=486
[junit] 2008-11-28 10:52:43,845 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2512475088695106927/index size=227
[junit] 2008-11-28 10:52:43,845 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/7049594830633374001
[junit] 2008-11-28 10:52:43,846 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/7049594830633374001/data size=204
[junit] 2008-11-28 10:52:43,846 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/7049594830633374001/index size=227
[junit] 2008-11-28 10:52:43,846 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227869563538/2044739718
[junit] 2008-11-28 10:52:43,855 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/2044739718/contents/info/2512475088695106927, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 10:52:43,864 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/2044739718/contents/info/7049594830633374001, isReference=false, sequence id=1, length=204, majorCompaction=false
[junit] 2008-11-28 10:52:43,864 DEBUG [main] regionserver.HStore(229): Loaded 2 file(s) in hstore 2044739718/contents, max sequence id 2
[junit] 2008-11-28 10:52:43,882 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227869563538 is 3
[junit] 2008-11-28 10:52:43,883 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227869563538/2044739718 available
[junit] 2008-11-28 10:52:43,883 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:43,886 DEBUG [main] regionserver.HStore(893): Compaction size of 2044739718/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 10:52:43,904 DEBUG [main] regionserver.HStore(911): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/compaction.dir/2044739718/contents/mapfiles/1794455120763118519
[junit] 2008-11-28 10:52:44,137 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/2044739718/contents/mapfiles/1794455120763118519 to /user/hudson/TestMergeTool/2044739718/contents/mapfiles/2997100478479928817
[junit] 2008-11-28 10:52:44,308 DEBUG [main] regionserver.HStore(930): Completed compaction of 2044739718/contents store size is 580.0
[junit] 2008-11-28 10:52:44,351 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227869563538 in 0sec
[junit] 2008-11-28 10:52:44,353 DEBUG [main] regionserver.HRegion(2379): Files for new region
[junit] 2008-11-28 10:52:44,354 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents
[junit] 2008-11-28 10:52:44,355 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/info
[junit] 2008-11-28 10:52:44,356 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/info/2997100478479928817 size=9
[junit] 2008-11-28 10:52:44,357 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles
[junit] 2008-11-28 10:52:44,357 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2997100478479928817
[junit] 2008-11-28 10:52:44,358 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2997100478479928817/data size=580
[junit] 2008-11-28 10:52:44,359 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:34771/user/hudson/TestMergeTool/2044739718/contents/mapfiles/2997100478479928817/index size=227
[junit] 2008-11-28 10:52:44,359 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:34771/user/hudson/TestMergeTool/582274869
[junit] 2008-11-28 10:52:44,384 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:34771/user/hudson/TestMergeTool/1160410525
[junit] 2008-11-28 10:52:44,423 INFO [main] regionserver.HRegion(2385): merge completed. New region is TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:44,423 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1227869557516', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 582274869, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 10:52:44,425 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1227869521305', STARTKEY => '', ENDKEY => '', ENCODED => 1160410525, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 10:52:44,439 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1227869563538', STARTKEY => '', ENDKEY => '', ENCODED => 2044739718, 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 => 'true'}]}} 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 10:52:44,439 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227869563538: compactions & flushes disabled
[junit] 2008-11-28 10:52:44,439 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:44,440 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:44,440 DEBUG [main] regionserver.HStore(597): closed 2044739718/contents
[junit] 2008-11-28 10:52:44,440 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:44,440 DEBUG [main] regionserver.HRegion(386): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2008-11-28 10:52:44,440 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2008-11-28 10:52:44,440 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-28 10:52:44,441 DEBUG [main] regionserver.HStore(597): closed 70236052/info
[junit] 2008-11-28 10:52:44,441 INFO [main] regionserver.HRegion(435): Closed -ROOT-,,0
[junit] 2008-11-28 10:52:44,441 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 10:52:44,441 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 10:52:44,441 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 10:52:44,441 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 470.0
[junit] 2008-11-28 10:52:45,574 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/2804792911307881456 with 3 entries, sequence id 21, data size 470.0, file size 622.0 to .META.,,1
[junit] 2008-11-28 10:52:45,574 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 1133ms, sequence id=21, compaction requested=true
[junit] 2008-11-28 10:52:45,574 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 10:52:45,574 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 10:52:45,575 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 10:52:45,635 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:34771/user/hudson/log_1227869559593/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227869559593/hlog.dat.1227869565603
[junit] 2008-11-28 10:52:45,635 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 10:52:45,635 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227869559593/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2008-11-28 10:52:45,636 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:34771/user/hudson/log_1227869559593
[junit] 2008-11-28 10:52:45,690 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227869563538', STARTKEY => '', ENDKEY => '', ENCODED => 2044739718, 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 => 'true'}]}}
[junit] 2008-11-28 10:52:45,690 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227869563538/2044739718
[junit] 2008-11-28 10:52:45,700 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/2044739718/contents/info/2997100478479928817, isReference=false, sequence id=2, length=580, majorCompaction=false
[junit] 2008-11-28 10:52:45,701 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 2044739718/contents, max sequence id 2
[junit] 2008-11-28 10:52:45,709 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227869563538 is 3
[junit] 2008-11-28 10:52:45,711 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227869563538/2044739718 available
[junit] 2008-11-28 10:52:45,712 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227869563538: compactions & flushes disabled
[junit] 2008-11-28 10:52:45,713 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:45,713 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:45,713 DEBUG [main] regionserver.HStore(597): closed 2044739718/contents
[junit] 2008-11-28 10:52:45,714 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227869563538
[junit] 2008-11-28 10:52:45,714 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2008-11-28 10:52:45,714 DEBUG [main] regionserver.HLog(386): closing log writer in /tmp/log_1227869534895
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2008-11-28 10:52:45,775 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2008-11-28 10:52:45,776 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] 2008-11-28 10:52:45,777 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34797]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34797]
[junit] 2008-11-28 10:52:45,784 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34797
[junit] 2008-11-28 10:52:45,785 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@160bf50
[junit] 2008-11-28 10:52:45,967 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 10:52:45,968 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@9b688e
[junit] 2008-11-28 10:52:46,050 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 10:52:46,051 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@135f44e
[junit] Shutting down DataNode 0
[junit] 2008-11-28 10:52:47,133 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34789]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34789]
[junit] 2008-11-28 10:52:47,134 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34789
[junit] 2008-11-28 10:52:47,136 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@15e92d7
[junit] 2008-11-28 10:52:47,243 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 10:52:47,243 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c8769b
[junit] 2008-11-28 10:52:47,533 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 10:52:47,534 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@17cf6b6
[junit] 2008-11-28 10:52:48,660 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34778]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34778]
[junit] 2008-11-28 10:52:48,661 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34778
[junit] 2008-11-28 10:52:48,743 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e183e9
[junit] 2008-11-28 10:52:48,818 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 10:52:48,818 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1980630
[junit] 2008-11-28 10:52:48,892 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 10:52:48,893 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1b62aab
[junit] 2008-11-28 10:52:48,893 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@ba5bdb] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 47.885 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2008-11-28 10:52:50,446 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.063 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2008-11-28 10:52:52,121 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 10:52:52,125 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 10:52:52,126 INFO [main] test.TestFilter(262): Success!
[junit] 2008-11-28 10:52:52,127 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2008-11-28 10:52:52,128 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 10:52:52,130 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 10:52:52,131 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.067 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453: Tests failed!
Total time: 46 minutes 56 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 #431
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/431/changes
Re: Build failed in Hudson: HBase-Patch #430
Posted by Jean-Daniel Cryans <jd...@apache.org>.
For some reason the Region Server was too slow to shut down and was hanging
waiting for the master (which was already down). At least 1036 is fixed.
J-D
On Fri, Nov 28, 2008 at 11:24 AM, Apache Hudson Server <
hudson@hudson.zones.apache.org> wrote:
> See http://hudson.zones.apache.org/hudson/job/HBase-Patch/430/changes
>
> Changes:
>
> [jdcryans] HABSE-1036 HBASE-1028 broke Thrift
>
> ------------------------------------------
> [...truncated 21887 lines...]
> [junit] 2008-11-28 16:23:53,447 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region -ROOT-,,0
> [junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HStore(597):
> closed 70236052/info
> [junit] 2008-11-28 16:23:53,448 INFO [main] regionserver.HRegion(435):
> Closed -ROOT-,,0
> [junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HRegion(386):
> Closing .META.,,1: compactions & flushes disabled
> [junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on .META.,,1
> [junit] 2008-11-28 16:23:53,449 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region .META.,,1
> [junit] 2008-11-28 16:23:53,449 DEBUG [main] regionserver.HRegion(827):
> Started memcache flush for region .META.,,1. Current region memcache size
> 510.0
> [junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HStore(692):
> Added /user/hudson/.META./1028785192/info/mapfiles/852468849594726661 with 3
> entries, sequence id 17, data size 510.0, file size 662.0 to .META.,,1
> [junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HRegion(901):
> Finished memcache flush for region .META.,,1 in 863ms, sequence id=17,
> compaction requested=true
> [junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HStore(597):
> closed 1028785192/historian
> [junit] 2008-11-28 16:23:54,313 DEBUG [main] regionserver.HStore(597):
> closed 1028785192/info
> [junit] 2008-11-28 16:23:54,313 INFO [main] regionserver.HRegion(435):
> Closed .META.,,1
> [junit] 2008-11-28 16:23:54,373 INFO [main] regionserver.HLog(255):
> Closed hdfs://localhost:38252/user/hudson/log_1227889430358/hlog.dat.0,
> entries=4. New log writer:
> /user/hudson/log_1227889430358/hlog.dat.1227889434348
> [junit] 2008-11-28 16:23:54,373 DEBUG [main] regionserver.HLog(262):
> Last sequence written is empty. Deleting all old hlogs
> [junit] 2008-11-28 16:23:54,373 INFO [main] regionserver.HLog(350):
> removing old log file /user/hudson/log_1227889430358/hlog.dat.0 whose
> highest sequence/edit id is 17
> [junit] 2008-11-28 16:23:54,374 DEBUG [main] regionserver.HLog(386):
> closing log writer in hdfs://localhost:38252/user/hudson/log_1227889430358
> [junit] 2008-11-28 16:23:54,423 DEBUG [main] regionserver.HRegion(2074):
> Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391',
> STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}}
> [junit] 2008-11-28 16:23:54,424 DEBUG [main] regionserver.HRegion(232):
> Opening region TestMergeTool,row_0100,1227889432391/862025725
> [junit] 2008-11-28 16:23:54,432 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/862025725/contents/info/3439039739016574008,
> isReference=false, sequence id=2, length=486, majorCompaction=false
> [junit] 2008-11-28 16:23:54,433 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 862025725/contents, max sequence id 2
> [junit] 2008-11-28 16:23:54,439 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region TestMergeTool,row_0100,1227889432391 is 3
> [junit] 2008-11-28 16:23:54,440 INFO [main] regionserver.HRegion(315):
> region TestMergeTool,row_0100,1227889432391/862025725 available
> [junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(386):
> Closing TestMergeTool,row_0100,1227889432391: compactions & flushes disabled
> [junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HStore(597):
> closed 862025725/contents
> [junit] 2008-11-28 16:23:54,442 INFO [main] regionserver.HRegion(435):
> Closed TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:54,442 INFO [main] util.TestMergeTool(171):
> Verified merging regions 0+1+2 and 3
> [junit] 2008-11-28 16:23:54,442 INFO [main] util.TestMergeTool(158):
> merging regions 0+1+2+3 and 4
> [junit] 2008-11-28 16:23:54,443 INFO [main] util.Merge(80): Verifying
> that file system is available...
> [junit] 2008-11-28 16:23:54,444 INFO [main] util.Merge(89): Verifying
> that HBase is not running...
> [junit] 2008-11-28 16:23:54,456 INFO [main] util.Merge(190): Merging
> regions [B@1bd06bf and [B@1061299 in table [B@1af1915
> [junit] 2008-11-28 16:23:54,498 INFO [main] regionserver.HLog(255): New
> log writer: /user/hudson/log_1227889434456/hlog.dat.1227889434473
> [junit] 2008-11-28 16:23:54,499 DEBUG [main] regionserver.HRegion(2074):
> 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 => 'false'}]}}
> [junit] 2008-11-28 16:23:54,499 DEBUG [main] regionserver.HRegion(232):
> Opening region -ROOT-,,0/70236052
> [junit] 2008-11-28 16:23:54,507 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/-ROOT-/70236052/info/info/3772439809902929981,
> isReference=false, sequence id=1, length=578, majorCompaction=false
> [junit] 2008-11-28 16:23:54,508 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
> [junit] 2008-11-28 16:23:54,514 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region -ROOT-,,0 is 2
> [junit] 2008-11-28 16:23:54,515 INFO [main] regionserver.HRegion(315):
> region -ROOT-,,0/70236052 available
> [junit] 2008-11-28 16:23:54,515 DEBUG [main] regionserver.HLog(208):
> changing sequence number from 0 to 2
> [junit] 2008-11-28 16:23:54,515 INFO [main] regionserver.HRegion(703):
> starting compaction on region -ROOT-,,0
> [junit] 2008-11-28 16:23:54,517 INFO [main] regionserver.HRegion(717):
> compaction completed on region -ROOT-,,0 in 0sec
> [junit] 2008-11-28 16:23:54,522 INFO [main] util.Merge(204): Found meta
> for region1 [B@d5163a, meta for region2 [B@d5163a
> [junit] 2008-11-28 16:23:54,523 DEBUG [main] regionserver.HRegion(2074):
> 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 => 'false'}, {NAME => 'historian',
> BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE',
> LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE =>
> 'false'}]}}
> [junit] 2008-11-28 16:23:54,523 DEBUG [main] regionserver.HRegion(232):
> Opening region .META.,,1/1028785192
> [junit] 2008-11-28 16:23:54,531 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/2987696775101159451,
> isReference=false, sequence id=5, length=1948, majorCompaction=false
> [junit] 2008-11-28 16:23:54,538 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/7128235772467530096,
> isReference=false, sequence id=13, length=1214, majorCompaction=false
> [junit] 2008-11-28 16:23:54,544 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/852468849594726661,
> isReference=false, sequence id=17, length=662, majorCompaction=false
> [junit] 2008-11-28 16:23:54,545 DEBUG [main] regionserver.HStore(229):
> Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
> [junit] 2008-11-28 16:23:54,563 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region .META.,,1 is 18
> [junit] 2008-11-28 16:23:54,564 INFO [main] regionserver.HRegion(315):
> region .META.,,1/1028785192 available
> [junit] 2008-11-28 16:23:54,564 DEBUG [main] regionserver.HLog(208):
> changing sequence number from 2 to 18
> [junit] 2008-11-28 16:23:54,565 INFO [main] regionserver.HRegion(703):
> starting compaction on region .META.,,1
> [junit] 2008-11-28 16:23:54,565 DEBUG [main] regionserver.HStore(826):
> no store files to compact
> [junit] 2008-11-28 16:23:54,569 DEBUG [main] regionserver.HStore(893):
> Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
> [junit] 2008-11-28 16:23:54,619 DEBUG [main] regionserver.HStore(911):
> Started compaction of 3 file(s) into
> /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/1959897562482008641
> [junit] 2008-11-28 16:23:54,868 DEBUG [main] regionserver.HStore(1232):
> moving
> /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/1959897562482008641
> to /user/hudson/.META./1028785192/info/mapfiles/8428569232980126168
> [junit] 2008-11-28 16:23:55,105 DEBUG [main] regionserver.HStore(930):
> Completed compaction of 1028785192/info store size is 3.5k
> [junit] 2008-11-28 16:23:55,137 INFO [main] regionserver.HRegion(717):
> compaction completed on region .META.,,1 in 0sec
> [junit] 2008-11-28 16:23:55,139 DEBUG [main] regionserver.HRegion(2074):
> Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391',
> STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}}
> [junit] 2008-11-28 16:23:55,139 DEBUG [main] regionserver.HRegion(232):
> Opening region TestMergeTool,row_0100,1227889432391/862025725
> [junit] 2008-11-28 16:23:55,148 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/862025725/contents/info/3439039739016574008,
> isReference=false, sequence id=2, length=486, majorCompaction=false
> [junit] 2008-11-28 16:23:55,149 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 862025725/contents, max sequence id 2
> [junit] 2008-11-28 16:23:55,155 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region TestMergeTool,row_0100,1227889432391 is 3
> [junit] 2008-11-28 16:23:55,157 INFO [main] regionserver.HRegion(315):
> region TestMergeTool,row_0100,1227889432391/862025725 available
> [junit] 2008-11-28 16:23:55,157 DEBUG [main] regionserver.HRegion(2074):
> Opening region: REGION => {NAME => 'TestMergeTool,,1227889400030', STARTKEY
> => '', ENDKEY => '', ENCODED => 1571829044, 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 => 'true'}]}}
> [junit] 2008-11-28 16:23:55,158 DEBUG [main] regionserver.HRegion(232):
> Opening region TestMergeTool,,1227889400030/1571829044
> [junit] 2008-11-28 16:23:55,166 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1571829044/contents/info/8006302450357688722,
> isReference=false, sequence id=2, length=204, majorCompaction=false
> [junit] 2008-11-28 16:23:55,167 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 1571829044/contents, max sequence id 2
> [junit] 2008-11-28 16:23:55,173 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region TestMergeTool,,1227889400030 is 3
> [junit] 2008-11-28 16:23:55,174 INFO [main] regionserver.HRegion(315):
> region TestMergeTool,,1227889400030/1571829044 available
> [junit] 2008-11-28 16:23:55,174 INFO [main] regionserver.HRegion(703):
> starting compaction on region TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:55,182 DEBUG [main] regionserver.HStore(911):
> Started compaction of 1 file(s) into
> /user/hudson/TestMergeTool/compaction.dir/862025725/contents/mapfiles/3056506830065991960
> [junit] 2008-11-28 16:23:55,423 DEBUG [main] regionserver.HStore(1232):
> moving
> /user/hudson/TestMergeTool/compaction.dir/862025725/contents/mapfiles/3056506830065991960
> to
> /user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964
> [junit] 2008-11-28 16:23:55,558 DEBUG [main] regionserver.HStore(930):
> Completed major compaction of 862025725/contents store size is 486.0
> [junit] 2008-11-28 16:23:55,591 INFO [main] regionserver.HRegion(717):
> compaction completed on region TestMergeTool,row_0100,1227889432391 in 0sec
> [junit] 2008-11-28 16:23:55,591 DEBUG [main] regionserver.HRegion(2294):
> Files for region: TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:55,592 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents
> [junit] 2008-11-28 16:23:55,593 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/info
> [junit] 2008-11-28 16:23:55,594 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/info/8270492496144383964
> size=11
> [junit] 2008-11-28 16:23:55,594 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles
> [junit] 2008-11-28 16:23:55,595 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964
> [junit] 2008-11-28 16:23:55,596 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964/data
> size=486
> [junit] 2008-11-28 16:23:55,596 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964/index
> size=227
> [junit] 2008-11-28 16:23:55,596 INFO [main] regionserver.HRegion(703):
> starting compaction on region TestMergeTool,,1227889400030
> [junit] 2008-11-28 16:23:55,604 DEBUG [main] regionserver.HStore(911):
> Started compaction of 1 file(s) into
> /user/hudson/TestMergeTool/compaction.dir/1571829044/contents/mapfiles/8041728386331972518
> [junit] 2008-11-28 16:23:55,817 DEBUG [main] regionserver.HStore(1232):
> moving
> /user/hudson/TestMergeTool/compaction.dir/1571829044/contents/mapfiles/8041728386331972518
> to
> /user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769
> [junit] 2008-11-28 16:23:55,954 DEBUG [main] regionserver.HStore(930):
> Completed major compaction of 1571829044/contents store size is 204.0
> [junit] 2008-11-28 16:23:55,987 INFO [main] regionserver.HRegion(717):
> compaction completed on region TestMergeTool,,1227889400030 in 0sec
> [junit] 2008-11-28 16:23:55,987 DEBUG [main] regionserver.HRegion(2299):
> Files for region: TestMergeTool,,1227889400030
> [junit] 2008-11-28 16:23:55,988 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents
> [junit] 2008-11-28 16:23:55,988 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/info
> [junit] 2008-11-28 16:23:55,989 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/info/7161127353416989769
> size=11
> [junit] 2008-11-28 16:23:55,989 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles
> [junit] 2008-11-28 16:23:55,990 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769
> [junit] 2008-11-28 16:23:55,991 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769/data
> size=204
> [junit] 2008-11-28 16:23:55,991 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769/index
> size=227
> [junit] 2008-11-28 16:23:55,991 INFO [main] regionserver.HRegion(2323):
> Creating new region REGION => {NAME => 'TestMergeTool,,1227889435991',
> STARTKEY => '', ENDKEY => '', ENCODED => 1200610943, 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
> => 'true'}]}}
> [junit] 2008-11-28 16:23:56,016 INFO [main] regionserver.HRegion(2332):
> starting merge of regions: TestMergeTool,row_0100,1227889432391 and
> TestMergeTool,,1227889400030 into new region REGION => {NAME =>
> 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY => '', ENCODED =>
> 1200610943, 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 => 'true'}]}} with start key <[B...@3e89c3>
> and end key <[B...@3e89c3>
> [junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(386):
> Closing TestMergeTool,row_0100,1227889432391: compactions & flushes disabled
> [junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HStore(597):
> closed 862025725/contents
> [junit] 2008-11-28 16:23:56,017 INFO [main] regionserver.HRegion(435):
> Closed TestMergeTool,row_0100,1227889432391
> [junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(386):
> Closing TestMergeTool,,1227889400030: compactions & flushes disabled
> [junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,,1227889400030
> [junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region TestMergeTool,,1227889400030
> [junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HStore(597):
> closed 1571829044/contents
> [junit] 2008-11-28 16:23:56,018 INFO [main] regionserver.HRegion(435):
> Closed TestMergeTool,,1227889400030
> [junit] 2008-11-28 16:23:56,086 DEBUG [main] regionserver.HRegion(2355):
> Adjusting sequence id of storeFile 1571829044/contents/7161127353416989769
> down by one; sequence id A=2, sequence id B=2
> [junit] 2008-11-28 16:23:56,195 DEBUG [main] regionserver.HRegion(2366):
> Renaming 862025725/contents/8270492496144383964 to
> 1200610943/contents/191100720503070040
> [junit] 2008-11-28 16:23:56,281 DEBUG [main] regionserver.HRegion(2366):
> Renaming 1571829044/contents/7161127353416989769 to
> 1200610943/contents/188450657983040496
> [junit] 2008-11-28 16:23:56,350 DEBUG [main] regionserver.HRegion(2372):
> Files for new region
> [junit] 2008-11-28 16:23:56,351 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents
> [junit] 2008-11-28 16:23:56,352 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info
> [junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/188450657983040496
> size=9
> [junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/191100720503070040
> size=11
> [junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles
> [junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496
> [junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496/data
> size=204
> [junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496/index
> size=227
> [junit] 2008-11-28 16:23:56,355 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040
> [junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040/data
> size=486
> [junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040/index
> size=227
> [junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(232):
> Opening region TestMergeTool,,1227889435991/1200610943
> [junit] 2008-11-28 16:23:56,363 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1200610943/contents/info/188450657983040496,
> isReference=false, sequence id=1, length=204, majorCompaction=false
> [junit] 2008-11-28 16:23:56,369 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1200610943/contents/info/191100720503070040,
> isReference=false, sequence id=2, length=486, majorCompaction=false
> [junit] 2008-11-28 16:23:56,371 DEBUG [main] regionserver.HStore(229):
> Loaded 2 file(s) in hstore 1200610943/contents, max sequence id 2
> [junit] 2008-11-28 16:23:56,382 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region TestMergeTool,,1227889435991 is 3
> [junit] 2008-11-28 16:23:56,384 INFO [main] regionserver.HRegion(315):
> region TestMergeTool,,1227889435991/1200610943 available
> [junit] 2008-11-28 16:23:56,384 INFO [main] regionserver.HRegion(703):
> starting compaction on region TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:56,387 DEBUG [main] regionserver.HStore(893):
> Compaction size of 1200610943/contents: 1.1k; Skipped 0 file(s), size: 0
> [junit] 2008-11-28 16:23:56,398 DEBUG [main] regionserver.HStore(911):
> Started compaction of 2 file(s) into
> /user/hudson/TestMergeTool/compaction.dir/1200610943/contents/mapfiles/1036022825091209637
> [junit] 2008-11-28 16:23:56,676 DEBUG [main] regionserver.HStore(1232):
> moving
> /user/hudson/TestMergeTool/compaction.dir/1200610943/contents/mapfiles/1036022825091209637
> to
> /user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011
> [junit] 2008-11-28 16:23:56,937 DEBUG [main] regionserver.HStore(930):
> Completed compaction of 1200610943/contents store size is 580.0
> [junit] 2008-11-28 16:23:57,013 INFO [main] regionserver.HRegion(717):
> compaction completed on region TestMergeTool,,1227889435991 in 0sec
> [junit] 2008-11-28 16:23:57,016 DEBUG [main] regionserver.HRegion(2379):
> Files for new region
> [junit] 2008-11-28 16:23:57,017 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents
> [junit] 2008-11-28 16:23:57,017 DEBUG [main] regionserver.HRegion(2445):
> d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info
> [junit] 2008-11-28 16:23:57,018 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/3765205542815023011
> size=9
> [junit] 2008-11-28 16:23:57,018 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles
> [junit] 2008-11-28 16:23:57,022 DEBUG [main] regionserver.HRegion(2445):
> d
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011
> [junit] 2008-11-28 16:23:57,023 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011/data
> size=580
> [junit] 2008-11-28 16:23:57,024 DEBUG [main] regionserver.HRegion(2448):
> f
> hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011/index
> size=227
> [junit] 2008-11-28 16:23:57,024 DEBUG [main] regionserver.HRegion(2173):
> DELETING region hdfs://localhost:38252/user/hudson/TestMergeTool/862025725
> [junit] 2008-11-28 16:23:57,094 DEBUG [main] regionserver.HRegion(2173):
> DELETING region hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044
> [junit] 2008-11-28 16:23:57,169 INFO [main] regionserver.HRegion(2385):
> merge completed. New region is TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:57,170 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391', STARTKEY
> => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}} from .META.,,1
> [junit] 2008-11-28 16:23:57,172 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,,1227889400030', STARTKEY => '',
> ENDKEY => '', ENCODED => 1571829044, 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 => 'true'}]}}
> from .META.,,1
> [junit] 2008-11-28 16:23:57,180 INFO [main] util.Merge(244): Adding
> REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY =>
> '', ENCODED => 1200610943, 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 => 'true'}]}} 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false',
> VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL
> => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
> [junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(386):
> Closing TestMergeTool,,1227889435991: compactions & flushes disabled
> [junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HStore(597):
> closed 1200610943/contents
> [junit] 2008-11-28 16:23:57,181 INFO [main] regionserver.HRegion(435):
> Closed TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(386):
> Closing -ROOT-,,0: compactions & flushes disabled
> [junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on -ROOT-,,0
> [junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region -ROOT-,,0
> [junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HStore(597):
> closed 70236052/info
> [junit] 2008-11-28 16:23:57,183 INFO [main] regionserver.HRegion(435):
> Closed -ROOT-,,0
> [junit] 2008-11-28 16:23:57,183 DEBUG [main] regionserver.HRegion(386):
> Closing .META.,,1: compactions & flushes disabled
> [junit] 2008-11-28 16:23:57,183 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on .META.,,1
> [junit] 2008-11-28 16:23:57,184 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region .META.,,1
> [junit] 2008-11-28 16:23:57,184 DEBUG [main] regionserver.HRegion(827):
> Started memcache flush for region .META.,,1. Current region memcache size
> 470.0
> [junit] 2008-11-28 16:23:57,732 DEBUG [main] regionserver.HStore(692):
> Added /user/hudson/.META./1028785192/info/mapfiles/4041481935336757798 with
> 3 entries, sequence id 21, data size 470.0, file size 622.0 to .META.,,1
> [junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HRegion(901):
> Finished memcache flush for region .META.,,1 in 549ms, sequence id=21,
> compaction requested=true
> [junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HStore(597):
> closed 1028785192/historian
> [junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HStore(597):
> closed 1028785192/info
> [junit] 2008-11-28 16:23:57,733 INFO [main] regionserver.HRegion(435):
> Closed .META.,,1
> [junit] 2008-11-28 16:23:57,888 INFO [main] regionserver.HLog(255):
> Closed hdfs://localhost:38252/user/hudson/log_1227889434456/hlog.dat.0,
> entries=4. New log writer:
> /user/hudson/log_1227889434456/hlog.dat.1227889437832
> [junit] 2008-11-28 16:23:57,888 DEBUG [main] regionserver.HLog(262):
> Last sequence written is empty. Deleting all old hlogs
> [junit] 2008-11-28 16:23:57,889 INFO [main] regionserver.HLog(350):
> removing old log file /user/hudson/log_1227889434456/hlog.dat.0 whose
> highest sequence/edit id is 21
> [junit] 2008-11-28 16:23:57,889 DEBUG [main] regionserver.HLog(386):
> closing log writer in hdfs://localhost:38252/user/hudson/log_1227889434456
> [junit] 2008-11-28 16:23:57,988 DEBUG [main] regionserver.HRegion(2074):
> Opening region: REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY
> => '', ENDKEY => '', ENCODED => 1200610943, 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
> => 'true'}]}}
> [junit] 2008-11-28 16:23:57,989 DEBUG [main] regionserver.HRegion(232):
> Opening region TestMergeTool,,1227889435991/1200610943
> [junit] 2008-11-28 16:23:57,996 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1200610943/contents/info/3765205542815023011,
> isReference=false, sequence id=2, length=580, majorCompaction=false
> [junit] 2008-11-28 16:23:57,997 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 1200610943/contents, max sequence id 2
> [junit] 2008-11-28 16:23:58,003 DEBUG [main] regionserver.HRegion(293):
> Next sequence id for region TestMergeTool,,1227889435991 is 3
> [junit] 2008-11-28 16:23:58,004 INFO [main] regionserver.HRegion(315):
> region TestMergeTool,,1227889435991/1200610943 available
> [junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(386):
> Closing TestMergeTool,,1227889435991: compactions & flushes disabled
> [junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(416):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(423):
> No more row locks outstanding on region TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:58,006 DEBUG [main] regionserver.HStore(597):
> closed 1200610943/contents
> [junit] 2008-11-28 16:23:58,006 INFO [main] regionserver.HRegion(435):
> Closed TestMergeTool,,1227889435991
> [junit] 2008-11-28 16:23:58,006 INFO [main] util.TestMergeTool(171):
> Verified merging regions 0+1+2+3 and 4
> [junit] 2008-11-28 16:23:58,006 DEBUG [main] regionserver.HLog(386):
> closing log writer in /tmp/log_1227889414465
> [junit] 2008-11-28 16:23:58,065 INFO [main] hbase.HBaseTestCase(600):
> Shutting down FileSystem
> [junit] 2008-11-28 16:23:58,066 INFO [main] hbase.HBaseTestCase(607):
> Shutting down Mini DFS
> [junit] Shutting down the Mini HDFS Cluster
> [junit] Shutting down DataNode 1
> [junit] 2008-11-28 16:23:58,072 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:38263
> [junit] 2008-11-28 16:23:58,073 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@160bf50
> [junit] 2008-11-28 16:23:58,238 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2008-11-28 16:23:58,238 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@16fdac
> [junit] 2008-11-28 16:23:58,318 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-28 16:23:58,319 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@135f44e
> [junit] Shutting down DataNode 0
> [junit] 2008-11-28 16:23:59,327 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:38257
> [junit] 2008-11-28 16:23:59,328 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1fa681c
> [junit] 2008-11-28 16:23:59,434 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2008-11-28 16:23:59,434 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c8769b
> [junit] 2008-11-28 16:23:59,509 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-28 16:23:59,509 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@17cf6b6
> [junit] 2008-11-28 16:24:00,626 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:38253
> [junit] 2008-11-28 16:24:00,627 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e183e9
> [junit] 2008-11-28 16:24:00,699 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2008-11-28 16:24:00,700 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1980630
> [junit] 2008-11-28 16:24:00,776 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-28 16:24:00,776 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@1b62aab
> [junit] 2008-11-28 16:24:00,777 WARN
> [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@ba5bdb]
> namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread
> received InterruptedException.java.lang.InterruptedException: sleep
> interrupted
> [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 40.946 sec
> [junit] Running org.apache.hadoop.hbase.util.TestRootPath
> [junit] 2008-11-28 16:24:01,618 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.058 sec
> [junit] Running org.onelab.test.TestFilter
> [junit] 2008-11-28 16:24:02,406 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2008-11-28 16:24:02,411 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2008-11-28 16:24:02,411 INFO [main] test.TestFilter(262):
> Success!
> [junit] 2008-11-28 16:24:02,412 INFO [main] test.TestFilter(226):
> Checking serialization/deserialization
> [junit] 2008-11-28 16:24:02,414 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2008-11-28 16:24:02,416 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2008-11-28 16:24:02,417 INFO [main] test.TestFilter(262):
> Success!
> [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.064 sec
>
> BUILD FAILED
> /zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453:
> Tests failed!
>
> Total time: 55 minutes 50 seconds
> [locks-and-latches] Releasing all the locks
> [locks-and-latches] All the locks released
> Recording test results
>
>
Build failed in Hudson: HBase-Patch #430
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/430/changes
Changes:
[jdcryans] HABSE-1036 HBASE-1028 broke Thrift
------------------------------------------
[...truncated 21887 lines...]
[junit] 2008-11-28 16:23:53,447 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HStore(597): closed 70236052/info
[junit] 2008-11-28 16:23:53,448 INFO [main] regionserver.HRegion(435): Closed -ROOT-,,0
[junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 16:23:53,448 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 16:23:53,449 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 16:23:53,449 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 510.0
[junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/852468849594726661 with 3 entries, sequence id 17, data size 510.0, file size 662.0 to .META.,,1
[junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 863ms, sequence id=17, compaction requested=true
[junit] 2008-11-28 16:23:54,312 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 16:23:54,313 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 16:23:54,313 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 16:23:54,373 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:38252/user/hudson/log_1227889430358/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227889430358/hlog.dat.1227889434348
[junit] 2008-11-28 16:23:54,373 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 16:23:54,373 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227889430358/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2008-11-28 16:23:54,374 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:38252/user/hudson/log_1227889430358
[junit] 2008-11-28 16:23:54,423 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}}
[junit] 2008-11-28 16:23:54,424 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227889432391/862025725
[junit] 2008-11-28 16:23:54,432 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/862025725/contents/info/3439039739016574008, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 16:23:54,433 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 862025725/contents, max sequence id 2
[junit] 2008-11-28 16:23:54,439 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227889432391 is 3
[junit] 2008-11-28 16:23:54,440 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227889432391/862025725 available
[junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227889432391: compactions & flushes disabled
[junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:54,442 DEBUG [main] regionserver.HStore(597): closed 862025725/contents
[junit] 2008-11-28 16:23:54,442 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:54,442 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2008-11-28 16:23:54,442 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2008-11-28 16:23:54,443 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2008-11-28 16:23:54,444 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2008-11-28 16:23:54,456 INFO [main] util.Merge(190): Merging regions [B@1bd06bf and [B@1061299 in table [B@1af1915
[junit] 2008-11-28 16:23:54,498 INFO [main] regionserver.HLog(255): New log writer: /user/hudson/log_1227889434456/hlog.dat.1227889434473
[junit] 2008-11-28 16:23:54,499 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}]}}
[junit] 2008-11-28 16:23:54,499 DEBUG [main] regionserver.HRegion(232): Opening region -ROOT-,,0/70236052
[junit] 2008-11-28 16:23:54,507 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/-ROOT-/70236052/info/info/3772439809902929981, isReference=false, sequence id=1, length=578, majorCompaction=false
[junit] 2008-11-28 16:23:54,508 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2008-11-28 16:23:54,514 DEBUG [main] regionserver.HRegion(293): Next sequence id for region -ROOT-,,0 is 2
[junit] 2008-11-28 16:23:54,515 INFO [main] regionserver.HRegion(315): region -ROOT-,,0/70236052 available
[junit] 2008-11-28 16:23:54,515 DEBUG [main] regionserver.HLog(208): changing sequence number from 0 to 2
[junit] 2008-11-28 16:23:54,515 INFO [main] regionserver.HRegion(703): starting compaction on region -ROOT-,,0
[junit] 2008-11-28 16:23:54,517 INFO [main] regionserver.HRegion(717): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2008-11-28 16:23:54,522 INFO [main] util.Merge(204): Found meta for region1 [B@d5163a, meta for region2 [B@d5163a
[junit] 2008-11-28 16:23:54,523 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 16:23:54,523 DEBUG [main] regionserver.HRegion(232): Opening region .META.,,1/1028785192
[junit] 2008-11-28 16:23:54,531 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/2987696775101159451, isReference=false, sequence id=5, length=1948, majorCompaction=false
[junit] 2008-11-28 16:23:54,538 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/7128235772467530096, isReference=false, sequence id=13, length=1214, majorCompaction=false
[junit] 2008-11-28 16:23:54,544 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/852468849594726661, isReference=false, sequence id=17, length=662, majorCompaction=false
[junit] 2008-11-28 16:23:54,545 DEBUG [main] regionserver.HStore(229): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2008-11-28 16:23:54,563 DEBUG [main] regionserver.HRegion(293): Next sequence id for region .META.,,1 is 18
[junit] 2008-11-28 16:23:54,564 INFO [main] regionserver.HRegion(315): region .META.,,1/1028785192 available
[junit] 2008-11-28 16:23:54,564 DEBUG [main] regionserver.HLog(208): changing sequence number from 2 to 18
[junit] 2008-11-28 16:23:54,565 INFO [main] regionserver.HRegion(703): starting compaction on region .META.,,1
[junit] 2008-11-28 16:23:54,565 DEBUG [main] regionserver.HStore(826): no store files to compact
[junit] 2008-11-28 16:23:54,569 DEBUG [main] regionserver.HStore(893): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 16:23:54,619 DEBUG [main] regionserver.HStore(911): Started compaction of 3 file(s) into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/1959897562482008641
[junit] 2008-11-28 16:23:54,868 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/1959897562482008641 to /user/hudson/.META./1028785192/info/mapfiles/8428569232980126168
[junit] 2008-11-28 16:23:55,105 DEBUG [main] regionserver.HStore(930): Completed compaction of 1028785192/info store size is 3.5k
[junit] 2008-11-28 16:23:55,137 INFO [main] regionserver.HRegion(717): compaction completed on region .META.,,1 in 0sec
[junit] 2008-11-28 16:23:55,139 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}}
[junit] 2008-11-28 16:23:55,139 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227889432391/862025725
[junit] 2008-11-28 16:23:55,148 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/862025725/contents/info/3439039739016574008, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 16:23:55,149 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 862025725/contents, max sequence id 2
[junit] 2008-11-28 16:23:55,155 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227889432391 is 3
[junit] 2008-11-28 16:23:55,157 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227889432391/862025725 available
[junit] 2008-11-28 16:23:55,157 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227889400030', STARTKEY => '', ENDKEY => '', ENCODED => 1571829044, 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 => 'true'}]}}
[junit] 2008-11-28 16:23:55,158 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227889400030/1571829044
[junit] 2008-11-28 16:23:55,166 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1571829044/contents/info/8006302450357688722, isReference=false, sequence id=2, length=204, majorCompaction=false
[junit] 2008-11-28 16:23:55,167 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1571829044/contents, max sequence id 2
[junit] 2008-11-28 16:23:55,173 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227889400030 is 3
[junit] 2008-11-28 16:23:55,174 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227889400030/1571829044 available
[junit] 2008-11-28 16:23:55,174 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:55,182 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/862025725/contents/mapfiles/3056506830065991960
[junit] 2008-11-28 16:23:55,423 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/862025725/contents/mapfiles/3056506830065991960 to /user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964
[junit] 2008-11-28 16:23:55,558 DEBUG [main] regionserver.HStore(930): Completed major compaction of 862025725/contents store size is 486.0
[junit] 2008-11-28 16:23:55,591 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,row_0100,1227889432391 in 0sec
[junit] 2008-11-28 16:23:55,591 DEBUG [main] regionserver.HRegion(2294): Files for region: TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:55,592 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents
[junit] 2008-11-28 16:23:55,593 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/info
[junit] 2008-11-28 16:23:55,594 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/info/8270492496144383964 size=11
[junit] 2008-11-28 16:23:55,594 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles
[junit] 2008-11-28 16:23:55,595 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964
[junit] 2008-11-28 16:23:55,596 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964/data size=486
[junit] 2008-11-28 16:23:55,596 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/862025725/contents/mapfiles/8270492496144383964/index size=227
[junit] 2008-11-28 16:23:55,596 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227889400030
[junit] 2008-11-28 16:23:55,604 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1571829044/contents/mapfiles/8041728386331972518
[junit] 2008-11-28 16:23:55,817 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1571829044/contents/mapfiles/8041728386331972518 to /user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769
[junit] 2008-11-28 16:23:55,954 DEBUG [main] regionserver.HStore(930): Completed major compaction of 1571829044/contents store size is 204.0
[junit] 2008-11-28 16:23:55,987 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227889400030 in 0sec
[junit] 2008-11-28 16:23:55,987 DEBUG [main] regionserver.HRegion(2299): Files for region: TestMergeTool,,1227889400030
[junit] 2008-11-28 16:23:55,988 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents
[junit] 2008-11-28 16:23:55,988 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/info
[junit] 2008-11-28 16:23:55,989 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/info/7161127353416989769 size=11
[junit] 2008-11-28 16:23:55,989 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles
[junit] 2008-11-28 16:23:55,990 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769
[junit] 2008-11-28 16:23:55,991 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769/data size=204
[junit] 2008-11-28 16:23:55,991 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044/contents/mapfiles/7161127353416989769/index size=227
[junit] 2008-11-28 16:23:55,991 INFO [main] regionserver.HRegion(2323): Creating new region REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY => '', ENCODED => 1200610943, 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 => 'true'}]}}
[junit] 2008-11-28 16:23:56,016 INFO [main] regionserver.HRegion(2332): starting merge of regions: TestMergeTool,row_0100,1227889432391 and TestMergeTool,,1227889400030 into new region REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY => '', ENCODED => 1200610943, 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 => 'true'}]}} with start key <[B...@3e89c3> and end key <[B...@3e89c3>
[junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227889432391: compactions & flushes disabled
[junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HStore(597): closed 862025725/contents
[junit] 2008-11-28 16:23:56,017 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227889432391
[junit] 2008-11-28 16:23:56,017 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227889400030: compactions & flushes disabled
[junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227889400030
[junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227889400030
[junit] 2008-11-28 16:23:56,018 DEBUG [main] regionserver.HStore(597): closed 1571829044/contents
[junit] 2008-11-28 16:23:56,018 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227889400030
[junit] 2008-11-28 16:23:56,086 DEBUG [main] regionserver.HRegion(2355): Adjusting sequence id of storeFile 1571829044/contents/7161127353416989769 down by one; sequence id A=2, sequence id B=2
[junit] 2008-11-28 16:23:56,195 DEBUG [main] regionserver.HRegion(2366): Renaming 862025725/contents/8270492496144383964 to 1200610943/contents/191100720503070040
[junit] 2008-11-28 16:23:56,281 DEBUG [main] regionserver.HRegion(2366): Renaming 1571829044/contents/7161127353416989769 to 1200610943/contents/188450657983040496
[junit] 2008-11-28 16:23:56,350 DEBUG [main] regionserver.HRegion(2372): Files for new region
[junit] 2008-11-28 16:23:56,351 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents
[junit] 2008-11-28 16:23:56,352 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info
[junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/188450657983040496 size=9
[junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/191100720503070040 size=11
[junit] 2008-11-28 16:23:56,353 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles
[junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496
[junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496/data size=204
[junit] 2008-11-28 16:23:56,354 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/188450657983040496/index size=227
[junit] 2008-11-28 16:23:56,355 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040
[junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040/data size=486
[junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/191100720503070040/index size=227
[junit] 2008-11-28 16:23:56,356 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227889435991/1200610943
[junit] 2008-11-28 16:23:56,363 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1200610943/contents/info/188450657983040496, isReference=false, sequence id=1, length=204, majorCompaction=false
[junit] 2008-11-28 16:23:56,369 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1200610943/contents/info/191100720503070040, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 16:23:56,371 DEBUG [main] regionserver.HStore(229): Loaded 2 file(s) in hstore 1200610943/contents, max sequence id 2
[junit] 2008-11-28 16:23:56,382 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227889435991 is 3
[junit] 2008-11-28 16:23:56,384 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227889435991/1200610943 available
[junit] 2008-11-28 16:23:56,384 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:56,387 DEBUG [main] regionserver.HStore(893): Compaction size of 1200610943/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 16:23:56,398 DEBUG [main] regionserver.HStore(911): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/compaction.dir/1200610943/contents/mapfiles/1036022825091209637
[junit] 2008-11-28 16:23:56,676 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1200610943/contents/mapfiles/1036022825091209637 to /user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011
[junit] 2008-11-28 16:23:56,937 DEBUG [main] regionserver.HStore(930): Completed compaction of 1200610943/contents store size is 580.0
[junit] 2008-11-28 16:23:57,013 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227889435991 in 0sec
[junit] 2008-11-28 16:23:57,016 DEBUG [main] regionserver.HRegion(2379): Files for new region
[junit] 2008-11-28 16:23:57,017 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents
[junit] 2008-11-28 16:23:57,017 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info
[junit] 2008-11-28 16:23:57,018 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/info/3765205542815023011 size=9
[junit] 2008-11-28 16:23:57,018 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles
[junit] 2008-11-28 16:23:57,022 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011
[junit] 2008-11-28 16:23:57,023 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011/data size=580
[junit] 2008-11-28 16:23:57,024 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:38252/user/hudson/TestMergeTool/1200610943/contents/mapfiles/3765205542815023011/index size=227
[junit] 2008-11-28 16:23:57,024 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:38252/user/hudson/TestMergeTool/862025725
[junit] 2008-11-28 16:23:57,094 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:38252/user/hudson/TestMergeTool/1571829044
[junit] 2008-11-28 16:23:57,169 INFO [main] regionserver.HRegion(2385): merge completed. New region is TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:57,170 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1227889432391', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 862025725, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 16:23:57,172 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1227889400030', STARTKEY => '', ENDKEY => '', ENCODED => 1571829044, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 16:23:57,180 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY => '', ENCODED => 1200610943, 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 => 'true'}]}} 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227889435991: compactions & flushes disabled
[junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:57,181 DEBUG [main] regionserver.HStore(597): closed 1200610943/contents
[junit] 2008-11-28 16:23:57,181 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(386): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-28 16:23:57,182 DEBUG [main] regionserver.HStore(597): closed 70236052/info
[junit] 2008-11-28 16:23:57,183 INFO [main] regionserver.HRegion(435): Closed -ROOT-,,0
[junit] 2008-11-28 16:23:57,183 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 16:23:57,183 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 16:23:57,184 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 16:23:57,184 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 470.0
[junit] 2008-11-28 16:23:57,732 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/4041481935336757798 with 3 entries, sequence id 21, data size 470.0, file size 622.0 to .META.,,1
[junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 549ms, sequence id=21, compaction requested=true
[junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 16:23:57,733 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 16:23:57,733 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 16:23:57,888 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:38252/user/hudson/log_1227889434456/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227889434456/hlog.dat.1227889437832
[junit] 2008-11-28 16:23:57,888 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 16:23:57,889 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227889434456/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2008-11-28 16:23:57,889 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:38252/user/hudson/log_1227889434456
[junit] 2008-11-28 16:23:57,988 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227889435991', STARTKEY => '', ENDKEY => '', ENCODED => 1200610943, 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 => 'true'}]}}
[junit] 2008-11-28 16:23:57,989 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227889435991/1200610943
[junit] 2008-11-28 16:23:57,996 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1200610943/contents/info/3765205542815023011, isReference=false, sequence id=2, length=580, majorCompaction=false
[junit] 2008-11-28 16:23:57,997 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1200610943/contents, max sequence id 2
[junit] 2008-11-28 16:23:58,003 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227889435991 is 3
[junit] 2008-11-28 16:23:58,004 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227889435991/1200610943 available
[junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227889435991: compactions & flushes disabled
[junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:58,005 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:58,006 DEBUG [main] regionserver.HStore(597): closed 1200610943/contents
[junit] 2008-11-28 16:23:58,006 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227889435991
[junit] 2008-11-28 16:23:58,006 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2008-11-28 16:23:58,006 DEBUG [main] regionserver.HLog(386): closing log writer in /tmp/log_1227889414465
[junit] 2008-11-28 16:23:58,065 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2008-11-28 16:23:58,066 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2008-11-28 16:23:58,072 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:38263
[junit] 2008-11-28 16:23:58,073 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@160bf50
[junit] 2008-11-28 16:23:58,238 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 16:23:58,238 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@16fdac
[junit] 2008-11-28 16:23:58,318 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 16:23:58,319 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@135f44e
[junit] Shutting down DataNode 0
[junit] 2008-11-28 16:23:59,327 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:38257
[junit] 2008-11-28 16:23:59,328 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1fa681c
[junit] 2008-11-28 16:23:59,434 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 16:23:59,434 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c8769b
[junit] 2008-11-28 16:23:59,509 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 16:23:59,509 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@17cf6b6
[junit] 2008-11-28 16:24:00,626 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:38253
[junit] 2008-11-28 16:24:00,627 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e183e9
[junit] 2008-11-28 16:24:00,699 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 16:24:00,700 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1980630
[junit] 2008-11-28 16:24:00,776 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 16:24:00,776 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1b62aab
[junit] 2008-11-28 16:24:00,777 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@ba5bdb] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 40.946 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2008-11-28 16:24:01,618 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.058 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2008-11-28 16:24:02,406 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 16:24:02,411 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 16:24:02,411 INFO [main] test.TestFilter(262): Success!
[junit] 2008-11-28 16:24:02,412 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2008-11-28 16:24:02,414 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 16:24:02,416 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 16:24:02,417 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.064 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453: Tests failed!
Total time: 55 minutes 50 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Build failed in Hudson: HBase-Patch #429
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/429/changes
Changes:
[apurtell] HBASE-1034 Remove useless TestToString unit test
------------------------------------------
[...truncated 20859 lines...]
[junit] 2008-11-28 12:59:43,729 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-28 12:59:43,729 DEBUG [main] regionserver.HStore(597): closed 70236052/info
[junit] 2008-11-28 12:59:43,730 INFO [main] regionserver.HRegion(435): Closed -ROOT-,,0
[junit] 2008-11-28 12:59:43,730 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 12:59:43,730 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 12:59:43,730 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 12:59:43,730 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 510.0
[junit] 2008-11-28 12:59:44,128 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/3247966983290981823 with 3 entries, sequence id 17, data size 510.0, file size 662.0 to .META.,,1
[junit] 2008-11-28 12:59:44,128 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 398ms, sequence id=17, compaction requested=true
[junit] 2008-11-28 12:59:44,129 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 12:59:44,129 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 12:59:44,129 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 12:59:44,238 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:50500/user/hudson/log_1227877175678/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227877175678/hlog.dat.1227877184190
[junit] 2008-11-28 12:59:44,239 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 12:59:44,239 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227877175678/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2008-11-28 12:59:44,240 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:50500/user/hudson/log_1227877175678
[junit] 2008-11-28 12:59:44,602 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227877180771', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1537382760, 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 => 'true'}]}}
[junit] 2008-11-28 12:59:44,602 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227877180771/1537382760
[junit] 2008-11-28 12:59:44,611 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1537382760/contents/info/2521294513939225600, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 12:59:44,612 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1537382760/contents, max sequence id 2
[junit] 2008-11-28 12:59:44,619 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227877180771 is 3
[junit] 2008-11-28 12:59:44,620 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227877180771/1537382760 available
[junit] 2008-11-28 12:59:44,621 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227877180771: compactions & flushes disabled
[junit] 2008-11-28 12:59:44,621 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:44,621 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:44,622 DEBUG [main] regionserver.HStore(597): closed 1537382760/contents
[junit] 2008-11-28 12:59:44,622 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:44,622 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2008-11-28 12:59:44,622 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2008-11-28 12:59:44,622 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2008-11-28 12:59:44,623 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2008-11-28 12:59:44,635 INFO [main] util.Merge(190): Merging regions [B@d5163a and [B@1a66c87 in table [B@11f1d25
[junit] 2008-11-28 12:59:44,748 INFO [main] regionserver.HLog(255): New log writer: /user/hudson/log_1227877184636/hlog.dat.1227877184691
[junit] 2008-11-28 12:59:44,749 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}]}}
[junit] 2008-11-28 12:59:44,749 DEBUG [main] regionserver.HRegion(232): Opening region -ROOT-,,0/70236052
[junit] 2008-11-28 12:59:44,758 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/-ROOT-/70236052/info/info/2168232324089195444, isReference=false, sequence id=1, length=578, majorCompaction=false
[junit] 2008-11-28 12:59:44,759 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2008-11-28 12:59:44,765 DEBUG [main] regionserver.HRegion(293): Next sequence id for region -ROOT-,,0 is 2
[junit] 2008-11-28 12:59:44,766 INFO [main] regionserver.HRegion(315): region -ROOT-,,0/70236052 available
[junit] 2008-11-28 12:59:44,766 DEBUG [main] regionserver.HLog(208): changing sequence number from 0 to 2
[junit] 2008-11-28 12:59:44,766 INFO [main] regionserver.HRegion(703): starting compaction on region -ROOT-,,0
[junit] 2008-11-28 12:59:44,768 INFO [main] regionserver.HRegion(717): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2008-11-28 12:59:44,774 INFO [main] util.Merge(204): Found meta for region1 [B@67f797, meta for region2 [B@67f797
[junit] 2008-11-28 12:59:44,774 DEBUG [main] regionserver.HRegion(2074): 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 12:59:44,775 DEBUG [main] regionserver.HRegion(232): Opening region .META.,,1/1028785192
[junit] 2008-11-28 12:59:44,784 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/249466541231374867, isReference=false, sequence id=13, length=1214, majorCompaction=false
[junit] 2008-11-28 12:59:44,791 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/3247966983290981823, isReference=false, sequence id=17, length=662, majorCompaction=false
[junit] 2008-11-28 12:59:44,797 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/8342701354414203436, isReference=false, sequence id=5, length=1948, majorCompaction=false
[junit] 2008-11-28 12:59:44,799 DEBUG [main] regionserver.HStore(229): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2008-11-28 12:59:44,819 DEBUG [main] regionserver.HRegion(293): Next sequence id for region .META.,,1 is 18
[junit] 2008-11-28 12:59:44,821 INFO [main] regionserver.HRegion(315): region .META.,,1/1028785192 available
[junit] 2008-11-28 12:59:44,821 DEBUG [main] regionserver.HLog(208): changing sequence number from 2 to 18
[junit] 2008-11-28 12:59:44,822 INFO [main] regionserver.HRegion(703): starting compaction on region .META.,,1
[junit] 2008-11-28 12:59:44,823 DEBUG [main] regionserver.HStore(826): no store files to compact
[junit] 2008-11-28 12:59:44,827 DEBUG [main] regionserver.HStore(893): Compaction size of 1028785192/info: 4.5k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 12:59:44,845 DEBUG [main] regionserver.HStore(911): Started compaction of 3 file(s) into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/9160599404713712577
[junit] 2008-11-28 12:59:45,791 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/9160599404713712577 to /user/hudson/.META./1028785192/info/mapfiles/748003666131607033
[junit] 2008-11-28 12:59:46,131 DEBUG [main] regionserver.HStore(930): Completed compaction of 1028785192/info store size is 3.5k
[junit] 2008-11-28 12:59:46,289 INFO [main] regionserver.HRegion(717): compaction completed on region .META.,,1 in 1sec
[junit] 2008-11-28 12:59:46,291 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1227877180771', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1537382760, 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 => 'true'}]}}
[junit] 2008-11-28 12:59:46,292 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,row_0100,1227877180771/1537382760
[junit] 2008-11-28 12:59:46,423 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1537382760/contents/info/2521294513939225600, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 12:59:46,424 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1537382760/contents, max sequence id 2
[junit] 2008-11-28 12:59:46,433 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,row_0100,1227877180771 is 3
[junit] 2008-11-28 12:59:46,434 INFO [main] regionserver.HRegion(315): region TestMergeTool,row_0100,1227877180771/1537382760 available
[junit] 2008-11-28 12:59:46,434 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227877127177', STARTKEY => '', ENDKEY => '', ENCODED => 1557394781, 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 => 'true'}]}}
[junit] 2008-11-28 12:59:46,435 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227877127177/1557394781
[junit] 2008-11-28 12:59:46,443 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1557394781/contents/info/1055615904034326575, isReference=false, sequence id=2, length=204, majorCompaction=false
[junit] 2008-11-28 12:59:46,444 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1557394781/contents, max sequence id 2
[junit] 2008-11-28 12:59:46,450 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227877127177 is 3
[junit] 2008-11-28 12:59:46,451 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227877127177/1557394781 available
[junit] 2008-11-28 12:59:46,451 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:46,459 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1537382760/contents/mapfiles/827486621571161296
[junit] 2008-11-28 12:59:48,639 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1537382760/contents/mapfiles/827486621571161296 to /user/hudson/TestMergeTool/1537382760/contents/mapfiles/7298701706037364643
[junit] 2008-11-28 12:59:49,148 DEBUG [main] regionserver.HStore(930): Completed major compaction of 1537382760/contents store size is 486.0
[junit] 2008-11-28 12:59:49,488 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,row_0100,1227877180771 in 3sec
[junit] 2008-11-28 12:59:49,488 DEBUG [main] regionserver.HRegion(2294): Files for region: TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:49,489 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents
[junit] 2008-11-28 12:59:49,490 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/info
[junit] 2008-11-28 12:59:49,491 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/info/7298701706037364643 size=11
[junit] 2008-11-28 12:59:49,491 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/mapfiles
[junit] 2008-11-28 12:59:49,491 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/mapfiles/7298701706037364643
[junit] 2008-11-28 12:59:49,492 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/mapfiles/7298701706037364643/data size=486
[junit] 2008-11-28 12:59:49,492 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760/contents/mapfiles/7298701706037364643/index size=227
[junit] 2008-11-28 12:59:49,493 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227877127177
[junit] 2008-11-28 12:59:49,500 DEBUG [main] regionserver.HStore(911): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/compaction.dir/1557394781/contents/mapfiles/8919050604132517469
[junit] 2008-11-28 12:59:49,814 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1557394781/contents/mapfiles/8919050604132517469 to /user/hudson/TestMergeTool/1557394781/contents/mapfiles/6461565683507524969
[junit] 2008-11-28 12:59:50,193 DEBUG [main] regionserver.HStore(930): Completed major compaction of 1557394781/contents store size is 204.0
[junit] 2008-11-28 12:59:50,233 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227877127177 in 0sec
[junit] 2008-11-28 12:59:50,234 DEBUG [main] regionserver.HRegion(2299): Files for region: TestMergeTool,,1227877127177
[junit] 2008-11-28 12:59:50,234 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents
[junit] 2008-11-28 12:59:50,235 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/info
[junit] 2008-11-28 12:59:50,236 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/info/6461565683507524969 size=11
[junit] 2008-11-28 12:59:50,237 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/mapfiles
[junit] 2008-11-28 12:59:50,237 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/mapfiles/6461565683507524969
[junit] 2008-11-28 12:59:50,238 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/mapfiles/6461565683507524969/data size=204
[junit] 2008-11-28 12:59:50,239 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781/contents/mapfiles/6461565683507524969/index size=227
[junit] 2008-11-28 12:59:50,239 INFO [main] regionserver.HRegion(2323): Creating new region REGION => {NAME => 'TestMergeTool,,1227877190239', STARTKEY => '', ENDKEY => '', ENCODED => 1647601374, 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 => 'true'}]}}
[junit] 2008-11-28 12:59:50,282 INFO [main] regionserver.HRegion(2332): starting merge of regions: TestMergeTool,row_0100,1227877180771 and TestMergeTool,,1227877127177 into new region REGION => {NAME => 'TestMergeTool,,1227877190239', STARTKEY => '', ENDKEY => '', ENCODED => 1647601374, 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 => 'true'}]}} with start key <[B...@3e89c3> and end key <[B...@3e89c3>
[junit] 2008-11-28 12:59:50,282 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,row_0100,1227877180771: compactions & flushes disabled
[junit] 2008-11-28 12:59:50,282 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:50,282 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:50,282 DEBUG [main] regionserver.HStore(597): closed 1537382760/contents
[junit] 2008-11-28 12:59:50,283 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,row_0100,1227877180771
[junit] 2008-11-28 12:59:50,283 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227877127177: compactions & flushes disabled
[junit] 2008-11-28 12:59:50,283 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227877127177
[junit] 2008-11-28 12:59:50,283 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227877127177
[junit] 2008-11-28 12:59:50,283 DEBUG [main] regionserver.HStore(597): closed 1557394781/contents
[junit] 2008-11-28 12:59:50,283 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227877127177
[junit] 2008-11-28 12:59:50,389 DEBUG [main] regionserver.HRegion(2355): Adjusting sequence id of storeFile 1557394781/contents/6461565683507524969 down by one; sequence id A=2, sequence id B=2
[junit] 2008-11-28 12:59:51,040 DEBUG [main] regionserver.HRegion(2366): Renaming 1537382760/contents/7298701706037364643 to 1647601374/contents/5535164937082440161
[junit] 2008-11-28 12:59:51,557 DEBUG [main] regionserver.HRegion(2366): Renaming 1557394781/contents/6461565683507524969 to 1647601374/contents/329465739852492879
[junit] 2008-11-28 12:59:52,460 DEBUG [main] regionserver.HRegion(2372): Files for new region
[junit] 2008-11-28 12:59:52,462 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents
[junit] 2008-11-28 12:59:52,463 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/info
[junit] 2008-11-28 12:59:52,464 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/info/329465739852492879 size=9
[junit] 2008-11-28 12:59:52,464 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/info/5535164937082440161 size=11
[junit] 2008-11-28 12:59:52,464 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles
[junit] 2008-11-28 12:59:52,465 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/329465739852492879
[junit] 2008-11-28 12:59:52,466 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/329465739852492879/data size=204
[junit] 2008-11-28 12:59:52,466 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/329465739852492879/index size=227
[junit] 2008-11-28 12:59:52,466 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/5535164937082440161
[junit] 2008-11-28 12:59:52,467 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/5535164937082440161/data size=486
[junit] 2008-11-28 12:59:52,467 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/5535164937082440161/index size=227
[junit] 2008-11-28 12:59:52,468 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227877190239/1647601374
[junit] 2008-11-28 12:59:52,476 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1647601374/contents/info/329465739852492879, isReference=false, sequence id=1, length=204, majorCompaction=false
[junit] 2008-11-28 12:59:52,482 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1647601374/contents/info/5535164937082440161, isReference=false, sequence id=2, length=486, majorCompaction=false
[junit] 2008-11-28 12:59:52,483 DEBUG [main] regionserver.HStore(229): Loaded 2 file(s) in hstore 1647601374/contents, max sequence id 2
[junit] 2008-11-28 12:59:52,499 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227877190239 is 3
[junit] 2008-11-28 12:59:52,500 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227877190239/1647601374 available
[junit] 2008-11-28 12:59:52,500 INFO [main] regionserver.HRegion(703): starting compaction on region TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:52,503 DEBUG [main] regionserver.HStore(893): Compaction size of 1647601374/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2008-11-28 12:59:52,514 DEBUG [main] regionserver.HStore(911): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/compaction.dir/1647601374/contents/mapfiles/6002782090789029846
[junit] 2008-11-28 12:59:53,122 DEBUG [main] regionserver.HStore(1232): moving /user/hudson/TestMergeTool/compaction.dir/1647601374/contents/mapfiles/6002782090789029846 to /user/hudson/TestMergeTool/1647601374/contents/mapfiles/8508296063664343642
[junit] 2008-11-28 12:59:53,684 DEBUG [main] regionserver.HStore(930): Completed compaction of 1647601374/contents store size is 580.0
[junit] 2008-11-28 12:59:53,712 INFO [main] regionserver.HRegion(717): compaction completed on region TestMergeTool,,1227877190239 in 1sec
[junit] 2008-11-28 12:59:53,713 DEBUG [main] regionserver.HRegion(2379): Files for new region
[junit] 2008-11-28 12:59:53,714 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents
[junit] 2008-11-28 12:59:53,715 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/info
[junit] 2008-11-28 12:59:53,716 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/info/8508296063664343642 size=9
[junit] 2008-11-28 12:59:53,716 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles
[junit] 2008-11-28 12:59:53,717 DEBUG [main] regionserver.HRegion(2445): d hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/8508296063664343642
[junit] 2008-11-28 12:59:53,717 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/8508296063664343642/data size=580
[junit] 2008-11-28 12:59:53,717 DEBUG [main] regionserver.HRegion(2448): f hdfs://localhost:50500/user/hudson/TestMergeTool/1647601374/contents/mapfiles/8508296063664343642/index size=227
[junit] 2008-11-28 12:59:53,718 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:50500/user/hudson/TestMergeTool/1537382760
[junit] 2008-11-28 12:59:53,745 DEBUG [main] regionserver.HRegion(2173): DELETING region hdfs://localhost:50500/user/hudson/TestMergeTool/1557394781
[junit] 2008-11-28 12:59:53,809 INFO [main] regionserver.HRegion(2385): merge completed. New region is TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:53,809 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1227877180771', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1537382760, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 12:59:53,811 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1227877127177', STARTKEY => '', ENDKEY => '', ENCODED => 1557394781, 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 => 'true'}]}} from .META.,,1
[junit] 2008-11-28 12:59:53,818 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1227877190239', STARTKEY => '', ENDKEY => '', ENCODED => 1647601374, 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 => 'true'}]}} 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 => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-28 12:59:53,819 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227877190239: compactions & flushes disabled
[junit] 2008-11-28 12:59:53,819 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:53,819 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:53,819 DEBUG [main] regionserver.HStore(597): closed 1647601374/contents
[junit] 2008-11-28 12:59:53,819 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:53,820 DEBUG [main] regionserver.HRegion(386): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2008-11-28 12:59:53,820 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2008-11-28 12:59:53,820 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-28 12:59:53,820 DEBUG [main] regionserver.HStore(597): closed 70236052/info
[junit] 2008-11-28 12:59:53,821 INFO [main] regionserver.HRegion(435): Closed -ROOT-,,0
[junit] 2008-11-28 12:59:53,821 DEBUG [main] regionserver.HRegion(386): Closing .META.,,1: compactions & flushes disabled
[junit] 2008-11-28 12:59:53,821 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2008-11-28 12:59:53,821 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region .META.,,1
[junit] 2008-11-28 12:59:53,821 DEBUG [main] regionserver.HRegion(827): Started memcache flush for region .META.,,1. Current region memcache size 470.0
[junit] 2008-11-28 12:59:54,360 DEBUG [main] regionserver.HStore(692): Added /user/hudson/.META./1028785192/info/mapfiles/3277182644338381422 with 3 entries, sequence id 21, data size 470.0, file size 622.0 to .META.,,1
[junit] 2008-11-28 12:59:54,360 DEBUG [main] regionserver.HRegion(901): Finished memcache flush for region .META.,,1 in 539ms, sequence id=21, compaction requested=true
[junit] 2008-11-28 12:59:54,360 DEBUG [main] regionserver.HStore(597): closed 1028785192/historian
[junit] 2008-11-28 12:59:54,361 DEBUG [main] regionserver.HStore(597): closed 1028785192/info
[junit] 2008-11-28 12:59:54,361 INFO [main] regionserver.HRegion(435): Closed .META.,,1
[junit] 2008-11-28 12:59:54,493 INFO [main] regionserver.HLog(255): Closed hdfs://localhost:50500/user/hudson/log_1227877184636/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1227877184636/hlog.dat.1227877194447
[junit] 2008-11-28 12:59:54,494 DEBUG [main] regionserver.HLog(262): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-28 12:59:54,494 INFO [main] regionserver.HLog(350): removing old log file /user/hudson/log_1227877184636/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2008-11-28 12:59:54,494 DEBUG [main] regionserver.HLog(386): closing log writer in hdfs://localhost:50500/user/hudson/log_1227877184636
[junit] 2008-11-28 12:59:54,639 DEBUG [main] regionserver.HRegion(2074): Opening region: REGION => {NAME => 'TestMergeTool,,1227877190239', STARTKEY => '', ENDKEY => '', ENCODED => 1647601374, 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 => 'true'}]}}
[junit] 2008-11-28 12:59:54,640 DEBUG [main] regionserver.HRegion(232): Opening region TestMergeTool,,1227877190239/1647601374
[junit] 2008-11-28 12:59:54,647 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1647601374/contents/info/8508296063664343642, isReference=false, sequence id=2, length=580, majorCompaction=false
[junit] 2008-11-28 12:59:54,648 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1647601374/contents, max sequence id 2
[junit] 2008-11-28 12:59:54,654 DEBUG [main] regionserver.HRegion(293): Next sequence id for region TestMergeTool,,1227877190239 is 3
[junit] 2008-11-28 12:59:54,655 INFO [main] regionserver.HRegion(315): region TestMergeTool,,1227877190239/1647601374 available
[junit] 2008-11-28 12:59:54,657 DEBUG [main] regionserver.HRegion(386): Closing TestMergeTool,,1227877190239: compactions & flushes disabled
[junit] 2008-11-28 12:59:54,657 DEBUG [main] regionserver.HRegion(416): Updates disabled for region, no outstanding scanners on TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:54,657 DEBUG [main] regionserver.HRegion(423): No more row locks outstanding on region TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:54,657 DEBUG [main] regionserver.HStore(597): closed 1647601374/contents
[junit] 2008-11-28 12:59:54,657 INFO [main] regionserver.HRegion(435): Closed TestMergeTool,,1227877190239
[junit] 2008-11-28 12:59:54,657 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2008-11-28 12:59:54,658 DEBUG [main] regionserver.HLog(386): closing log writer in /tmp/log_1227877151511
[junit] 2008-11-28 12:59:54,798 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2008-11-28 12:59:54,798 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2008-11-28 12:59:54,802 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:50508
[junit] 2008-11-28 12:59:54,803 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e5f46e
[junit] 2008-11-28 12:59:54,889 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 12:59:54,889 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@813bc1
[junit] 2008-11-28 12:59:55,006 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 12:59:55,179 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@19d12cc
[junit] Shutting down DataNode 0
[junit] 2008-11-28 12:59:56,214 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:50505
[junit] 2008-11-28 12:59:56,217 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1a7f9dc
[junit] 2008-11-28 12:59:56,384 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 12:59:56,384 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@d12eea
[junit] 2008-11-28 12:59:56,464 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 12:59:56,464 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1700391
[junit] 2008-11-28 12:59:57,579 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:50501
[junit] 2008-11-28 12:59:57,580 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e183e9
[junit] 2008-11-28 12:59:57,658 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2008-11-28 12:59:57,658 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1be4777
[junit] 2008-11-28 12:59:57,739 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-28 12:59:57,740 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1b62aab
[junit] 2008-11-28 12:59:57,740 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@ba5bdb] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 71.678 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2008-11-28 12:59:59,713 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.061 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2008-11-28 13:00:00,624 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 13:00:00,629 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 13:00:00,630 INFO [main] test.TestFilter(262): Success!
[junit] 2008-11-28 13:00:00,631 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2008-11-28 13:00:00,633 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-28 13:00:00,635 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-28 13:00:00,636 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.067 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453: Tests failed!
Total time: 32 minutes 55 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results