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 17:24:03 UTC
Build failed in Hudson: HBase-Patch #430
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
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
>
>