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/10 01:53:51 UTC
Build failed in Hudson: HBase-Patch #396
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/396/changes
Changes:
[jdcryans] HBASE-964 Startup stuck "waiting for root region"
------------------------------------------
[...truncated 18502 lines...]
[junit] 2008-11-10 00:53:38,372 INFO [main] regionserver.HLog(272): New log writer created at /user/hudson/log_1226278410331/hlog.dat.1226278418291
[junit] 2008-11-10 00:53:38,373 DEBUG [main] regionserver.HLog(277): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-10 00:53:38,373 INFO [main] regionserver.HLog(329): removing old log file /user/hudson/log_1226278410331/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2008-11-10 00:53:38,373 DEBUG [main] regionserver.HLog(365): closing log writer in hdfs://localhost:34988/user/hudson/log_1226278410331
[junit] 2008-11-10 00:53:38,597 DEBUG [main] regionserver.HRegion(2258): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:38,597 DEBUG [main] regionserver.HRegion(433): Opening region TestMergeTool,row_0100,1226278415342/1721306299
[junit] 2008-11-10 00:53:38,606 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1721306299/contents/info/8278144264292143646, isReference=false, sequence id=2, length=486
[junit] 2008-11-10 00:53:38,606 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1721306299/contents, max sequence id 2
[junit] 2008-11-10 00:53:38,613 DEBUG [main] regionserver.HRegion(494): Next sequence id for region TestMergeTool,row_0100,1226278415342 is 3
[junit] 2008-11-10 00:53:38,614 INFO [main] regionserver.HRegion(516): region TestMergeTool,row_0100,1226278415342/1721306299 available
[junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(609): No more active scanners for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(611): Updates disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,616 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,616 DEBUG [main] regionserver.HStore(595): closed 1721306299/contents
[junit] 2008-11-10 00:53:38,616 INFO [main] regionserver.HRegion(630): closed TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:38,616 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2 and 3
[junit] 2008-11-10 00:53:38,616 INFO [main] util.TestMergeTool(158): merging regions 0+1+2+3 and 4
[junit] 2008-11-10 00:53:38,617 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2008-11-10 00:53:38,617 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2008-11-10 00:53:38,630 INFO [main] util.Merge(190): Merging regions [B@19c873d and [B@172bab9 in table [B@140c973
[junit] 2008-11-10 00:53:38,791 INFO [main] regionserver.HLog(272): New log writer created at /user/hudson/log_1226278418630/hlog.dat.1226278418705
[junit] 2008-11-10 00:53:38,792 DEBUG [main] regionserver.HRegion(2258): 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 => '1', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-10 00:53:38,792 DEBUG [main] regionserver.HRegion(433): Opening region -ROOT-,,0/70236052
[junit] 2008-11-10 00:53:38,800 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/-ROOT-/70236052/info/info/3826198435386252829, isReference=false, sequence id=1, length=569
[junit] 2008-11-10 00:53:38,801 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
[junit] 2008-11-10 00:53:38,808 DEBUG [main] regionserver.HRegion(494): Next sequence id for region -ROOT-,,0 is 2
[junit] 2008-11-10 00:53:38,809 INFO [main] regionserver.HRegion(516): region -ROOT-,,0/70236052 available
[junit] 2008-11-10 00:53:38,809 DEBUG [main] regionserver.HLog(205): changing sequence number from 0 to 2
[junit] 2008-11-10 00:53:38,809 INFO [main] regionserver.HRegion(899): starting compaction on region -ROOT-,,0
[junit] 2008-11-10 00:53:38,811 INFO [main] regionserver.HRegion(913): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2008-11-10 00:53:38,817 INFO [main] util.Merge(204): Found meta for region1 [B@197507c, meta for region2 [B@197507c
[junit] 2008-11-10 00:53:38,818 DEBUG [main] regionserver.HRegion(2258): 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 => '1', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-10 00:53:38,818 DEBUG [main] regionserver.HRegion(433): Opening region .META.,,1/1028785192
[junit] 2008-11-10 00:53:38,826 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/597168401597830125, isReference=false, sequence id=17, length=658
[junit] 2008-11-10 00:53:38,833 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/8274487517488866077, isReference=false, sequence id=13, length=1206
[junit] 2008-11-10 00:53:38,839 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/.META./1028785192/info/info/8886405319793594306, isReference=false, sequence id=5, length=1928
[junit] 2008-11-10 00:53:38,840 DEBUG [main] regionserver.HStore(229): Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
[junit] 2008-11-10 00:53:38,863 DEBUG [main] regionserver.HRegion(494): Next sequence id for region .META.,,1 is 18
[junit] 2008-11-10 00:53:38,865 INFO [main] regionserver.HRegion(516): region .META.,,1/1028785192 available
[junit] 2008-11-10 00:53:38,866 DEBUG [main] regionserver.HLog(205): changing sequence number from 2 to 18
[junit] 2008-11-10 00:53:38,866 INFO [main] regionserver.HRegion(899): starting compaction on region .META.,,1
[junit] 2008-11-10 00:53:38,872 DEBUG [main] regionserver.HStore(889): Compaction size of 1028785192/info: 4.5k; Skipped 0 files , size: 0
[junit] 2008-11-10 00:53:38,893 DEBUG [main] regionserver.HStore(907): started compaction of 3 files into /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3805311149848711689
[junit] 2008-11-10 00:53:39,980 DEBUG [main] regionserver.HStore(1165): moving /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3805311149848711689 to /user/hudson/.META./1028785192/info/mapfiles/6662607905013016013
[junit] 2008-11-10 00:53:40,712 DEBUG [main] regionserver.HStore(925): Completed compaction of 1028785192/info store size is 3.5k; time since last major compaction: 0 seconds
[junit] 2008-11-10 00:53:40,789 INFO [main] regionserver.HRegion(913): compaction completed on region .META.,,1 in 1sec
[junit] 2008-11-10 00:53:40,791 DEBUG [main] regionserver.HRegion(2258): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:40,792 DEBUG [main] regionserver.HRegion(433): Opening region TestMergeTool,row_0100,1226278415342/1721306299
[junit] 2008-11-10 00:53:40,801 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1721306299/contents/info/8278144264292143646, isReference=false, sequence id=2, length=486
[junit] 2008-11-10 00:53:40,802 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1721306299/contents, max sequence id 2
[junit] 2008-11-10 00:53:40,808 DEBUG [main] regionserver.HRegion(494): Next sequence id for region TestMergeTool,row_0100,1226278415342 is 3
[junit] 2008-11-10 00:53:40,810 INFO [main] regionserver.HRegion(516): region TestMergeTool,row_0100,1226278415342/1721306299 available
[junit] 2008-11-10 00:53:40,810 DEBUG [main] regionserver.HRegion(2258): Opening region: REGION => {NAME => 'TestMergeTool,,1226278374488', STARTKEY => '', ENDKEY => '', ENCODED => 941143000, 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-10 00:53:40,811 DEBUG [main] regionserver.HRegion(433): Opening region TestMergeTool,,1226278374488/941143000
[junit] 2008-11-10 00:53:40,855 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/941143000/contents/info/7848333118125034455, isReference=false, sequence id=2, length=204
[junit] 2008-11-10 00:53:40,856 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 941143000/contents, max sequence id 2
[junit] 2008-11-10 00:53:40,863 DEBUG [main] regionserver.HRegion(494): Next sequence id for region TestMergeTool,,1226278374488 is 3
[junit] 2008-11-10 00:53:40,865 INFO [main] regionserver.HRegion(516): region TestMergeTool,,1226278374488/941143000 available
[junit] 2008-11-10 00:53:40,865 INFO [main] regionserver.HRegion(899): starting compaction on region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:40,874 DEBUG [main] regionserver.HStore(907): started compaction of 1 files into /user/hudson/TestMergeTool/compaction.dir/1721306299/contents/mapfiles/9222501372853478946
[junit] 2008-11-10 00:53:41,461 DEBUG [main] regionserver.HStore(1165): moving /user/hudson/TestMergeTool/compaction.dir/1721306299/contents/mapfiles/9222501372853478946 to /user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814
[junit] 2008-11-10 00:53:41,827 DEBUG [main] regionserver.HStore(925): Completed compaction of 1721306299/contents store size is 486.0
[junit] 2008-11-10 00:53:41,899 INFO [main] regionserver.HRegion(913): compaction completed on region TestMergeTool,row_0100,1226278415342 in 1sec
[junit] 2008-11-10 00:53:41,899 DEBUG [main] regionserver.HRegion(175): Files for region: TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:41,900 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents
[junit] 2008-11-10 00:53:41,901 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/info
[junit] 2008-11-10 00:53:41,901 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/info/469208122528650814 size=9
[junit] 2008-11-10 00:53:41,902 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles
[junit] 2008-11-10 00:53:41,902 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814
[junit] 2008-11-10 00:53:41,903 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814/data size=486
[junit] 2008-11-10 00:53:41,903 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814/index size=227
[junit] 2008-11-10 00:53:41,903 INFO [main] regionserver.HRegion(899): starting compaction on region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:41,910 DEBUG [main] regionserver.HStore(907): started compaction of 1 files into /user/hudson/TestMergeTool/compaction.dir/941143000/contents/mapfiles/3174101678615308442
[junit] 2008-11-10 00:53:42,519 DEBUG [main] regionserver.HStore(1165): moving /user/hudson/TestMergeTool/compaction.dir/941143000/contents/mapfiles/3174101678615308442 to /user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893
[junit] 2008-11-10 00:53:42,849 DEBUG [main] regionserver.HStore(925): Completed compaction of 941143000/contents store size is 204.0
[junit] 2008-11-10 00:53:42,908 INFO [main] regionserver.HRegion(913): compaction completed on region TestMergeTool,,1226278374488 in 1sec
[junit] 2008-11-10 00:53:42,909 DEBUG [main] regionserver.HRegion(180): Files for region: TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:42,910 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents
[junit] 2008-11-10 00:53:42,911 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/info
[junit] 2008-11-10 00:53:42,911 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/info/1163906313873296893 size=9
[junit] 2008-11-10 00:53:42,912 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles
[junit] 2008-11-10 00:53:42,912 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893
[junit] 2008-11-10 00:53:42,913 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893/data size=204
[junit] 2008-11-10 00:53:42,914 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893/index size=227
[junit] 2008-11-10 00:53:42,914 INFO [main] regionserver.HRegion(204): Creating new region REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY => '', ENCODED => 1379193769, 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-10 00:53:43,011 INFO [main] regionserver.HRegion(213): starting merge of regions: TestMergeTool,row_0100,1226278415342 and TestMergeTool,,1226278374488 into new region REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY => '', ENCODED => 1379193769, 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...@1ea0252> and end key <[B...@1ea0252>
[junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(609): No more active scanners for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(611): Updates disabled for region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HStore(595): closed 1721306299/contents
[junit] 2008-11-10 00:53:43,012 INFO [main] regionserver.HRegion(630): closed TestMergeTool,row_0100,1226278415342
[junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(609): No more active scanners for region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(611): Updates disabled for region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,013 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,013 DEBUG [main] regionserver.HStore(595): closed 941143000/contents
[junit] 2008-11-10 00:53:43,013 INFO [main] regionserver.HRegion(630): closed TestMergeTool,,1226278374488
[junit] 2008-11-10 00:53:43,100 DEBUG [main] regionserver.HRegion(236): Adjusting sequence id of storeFile 941143000/contents/1163906313873296893 down by one; sequence id A=2, sequence id B=2
[junit] 2008-11-10 00:53:43,259 DEBUG [main] regionserver.HRegion(247): Renaming 1721306299/contents/469208122528650814 to 1379193769/contents/8357857439596116794
[junit] 2008-11-10 00:53:43,456 DEBUG [main] regionserver.HRegion(247): Renaming 941143000/contents/1163906313873296893 to 1379193769/contents/1511610577137846810
[junit] 2008-11-10 00:53:43,626 DEBUG [main] regionserver.HRegion(253): Files for new region
[junit] 2008-11-10 00:53:43,628 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents
[junit] 2008-11-10 00:53:43,628 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info
[junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/1511610577137846810 size=9
[junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/8357857439596116794 size=9
[junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles
[junit] 2008-11-10 00:53:43,630 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810
[junit] 2008-11-10 00:53:43,631 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810/data size=204
[junit] 2008-11-10 00:53:43,632 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810/index size=227
[junit] 2008-11-10 00:53:43,632 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794
[junit] 2008-11-10 00:53:43,633 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794/data size=486
[junit] 2008-11-10 00:53:43,633 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794/index size=227
[junit] 2008-11-10 00:53:43,634 DEBUG [main] regionserver.HRegion(433): Opening region TestMergeTool,,1226278422914/1379193769
[junit] 2008-11-10 00:53:43,641 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1379193769/contents/info/1511610577137846810, isReference=false, sequence id=1, length=204
[junit] 2008-11-10 00:53:43,647 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1379193769/contents/info/8357857439596116794, isReference=false, sequence id=2, length=486
[junit] 2008-11-10 00:53:43,648 DEBUG [main] regionserver.HStore(229): Loaded 2 file(s) in hstore 1379193769/contents, max sequence id 2
[junit] 2008-11-10 00:53:43,662 DEBUG [main] regionserver.HRegion(494): Next sequence id for region TestMergeTool,,1226278422914 is 3
[junit] 2008-11-10 00:53:43,664 INFO [main] regionserver.HRegion(516): region TestMergeTool,,1226278422914/1379193769 available
[junit] 2008-11-10 00:53:43,664 INFO [main] regionserver.HRegion(899): starting compaction on region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:43,668 DEBUG [main] regionserver.HStore(889): Compaction size of 1379193769/contents: 1.1k; Skipped 0 files , size: 0
[junit] 2008-11-10 00:53:43,681 DEBUG [main] regionserver.HStore(907): started compaction of 2 files into /user/hudson/TestMergeTool/compaction.dir/1379193769/contents/mapfiles/5472175154486337476
[junit] 2008-11-10 00:53:44,852 DEBUG [main] regionserver.HStore(1165): moving /user/hudson/TestMergeTool/compaction.dir/1379193769/contents/mapfiles/5472175154486337476 to /user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276
[junit] 2008-11-10 00:53:45,315 DEBUG [main] regionserver.HStore(925): Completed compaction of 1379193769/contents store size is 580.0; time since last major compaction: 0 seconds
[junit] 2008-11-10 00:53:45,409 INFO [main] regionserver.HRegion(913): compaction completed on region TestMergeTool,,1226278422914 in 1sec
[junit] 2008-11-10 00:53:45,410 DEBUG [main] regionserver.HRegion(260): Files for new region
[junit] 2008-11-10 00:53:45,411 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents
[junit] 2008-11-10 00:53:45,413 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info
[junit] 2008-11-10 00:53:45,414 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/5581900472901382276 size=9
[junit] 2008-11-10 00:53:45,414 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles
[junit] 2008-11-10 00:53:45,415 DEBUG [main] regionserver.HRegion(313): d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276
[junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276/data size=580
[junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(316): f hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276/index size=227
[junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(2355): DELETING region hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299
[junit] 2008-11-10 00:53:45,495 DEBUG [main] regionserver.HRegion(2355): DELETING region hdfs://localhost:34988/user/hudson/TestMergeTool/941143000
[junit] 2008-11-10 00:53:45,567 INFO [main] regionserver.HRegion(266): merge completed. New region is TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,567 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:45,569 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1226278374488', STARTKEY => '', ENDKEY => '', ENCODED => 941143000, 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-10 00:53:45,577 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY => '', ENCODED => 1379193769, 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 => '1', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
[junit] 2008-11-10 00:53:45,577 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,577 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(609): No more active scanners for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(611): Updates disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HStore(595): closed 1379193769/contents
[junit] 2008-11-10 00:53:45,578 INFO [main] regionserver.HRegion(630): closed TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region -ROOT-,,0
[junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region -ROOT-,,0
[junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(609): No more active scanners for region -ROOT-,,0
[junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(611): Updates disabled for region -ROOT-,,0
[junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region -ROOT-,,0
[junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HStore(595): closed 70236052/info
[junit] 2008-11-10 00:53:45,579 INFO [main] regionserver.HRegion(630): closed -ROOT-,,0
[junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region .META.,,1
[junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region .META.,,1
[junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(609): No more active scanners for region .META.,,1
[junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(611): Updates disabled for region .META.,,1
[junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region .META.,,1
[junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(1024): Started memcache flush for region .META.,,1. Current region memcache size 466.0
[junit] 2008-11-10 00:53:46,165 DEBUG [main] regionserver.HStore(690): Added /user/hudson/.META./1028785192/info/mapfiles/5550820802377771249 with 3 entries, sequence id 21, data size 466.0, file size 618.0
[junit] 2008-11-10 00:53:46,165 DEBUG [main] regionserver.HRegion(1098): Finished memcache flush for region .META.,,1 in 585ms, sequence id=21, compaction requested=true
[junit] 2008-11-10 00:53:46,166 DEBUG [main] regionserver.HStore(595): closed 1028785192/historian
[junit] 2008-11-10 00:53:46,166 DEBUG [main] regionserver.HStore(595): closed 1028785192/info
[junit] 2008-11-10 00:53:46,167 INFO [main] regionserver.HRegion(630): closed .META.,,1
[junit] 2008-11-10 00:53:46,277 DEBUG [main] regionserver.HLog(259): Closing current log writer /user/hudson/log_1226278418630/hlog.dat.0
[junit] 2008-11-10 00:53:46,344 INFO [main] regionserver.HLog(272): New log writer created at /user/hudson/log_1226278418630/hlog.dat.1226278426278
[junit] 2008-11-10 00:53:46,344 DEBUG [main] regionserver.HLog(277): Last sequence written is empty. Deleting all old hlogs
[junit] 2008-11-10 00:53:46,344 INFO [main] regionserver.HLog(329): removing old log file /user/hudson/log_1226278418630/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2008-11-10 00:53:46,345 DEBUG [main] regionserver.HLog(365): closing log writer in hdfs://localhost:34988/user/hudson/log_1226278418630
[junit] 2008-11-10 00:53:46,487 DEBUG [main] regionserver.HRegion(2258): Opening region: REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY => '', ENCODED => 1379193769, 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-10 00:53:46,487 DEBUG [main] regionserver.HRegion(433): Opening region TestMergeTool,,1226278422914/1379193769
[junit] 2008-11-10 00:53:46,494 DEBUG [main] regionserver.HStore(490): loaded /user/hudson/TestMergeTool/1379193769/contents/info/5581900472901382276, isReference=false, sequence id=2, length=580
[junit] 2008-11-10 00:53:46,495 DEBUG [main] regionserver.HStore(229): Loaded 1 file(s) in hstore 1379193769/contents, max sequence id 2
[junit] 2008-11-10 00:53:46,501 DEBUG [main] regionserver.HRegion(494): Next sequence id for region TestMergeTool,,1226278422914 is 3
[junit] 2008-11-10 00:53:46,502 INFO [main] regionserver.HRegion(516): region TestMergeTool,,1226278422914/1379193769 available
[junit] 2008-11-10 00:53:46,503 DEBUG [main] regionserver.HRegion(579): Compactions and cache flushes disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(594): Scanners disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(609): No more active scanners for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(611): Updates disabled for region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(617): No more row locks outstanding on region TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HStore(595): closed 1379193769/contents
[junit] 2008-11-10 00:53:46,504 INFO [main] regionserver.HRegion(630): closed TestMergeTool,,1226278422914
[junit] 2008-11-10 00:53:46,505 INFO [main] util.TestMergeTool(171): Verified merging regions 0+1+2+3 and 4
[junit] 2008-11-10 00:53:46,505 DEBUG [main] regionserver.HLog(365): closing log writer in /tmp/log_1226278387070
[junit] 2008-11-10 00:53:46,654 INFO [main] hbase.HBaseTestCase(600): Shutting down FileSystem
[junit] 2008-11-10 00:53:46,654 INFO [main] hbase.HBaseTestCase(607): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2008-11-10 00:53:46,662 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34996
[junit] 2008-11-10 00:53:46,787 INFO [main] util.Container(156): Stopped HttpContext[/static,/static]
[junit] 2008-11-10 00:53:46,788 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@4a5c78
[junit] 2008-11-10 00:53:46,862 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-10 00:53:46,862 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@17c2891
[junit] Shutting down DataNode 0
[junit] 2008-11-10 00:53:47,873 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34993]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34993]
[junit] 2008-11-10 00:53:47,874 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34993
[junit] 2008-11-10 00:53:47,975 INFO [main] util.Container(156): Stopped HttpContext[/static,/static]
[junit] 2008-11-10 00:53:47,976 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@4d2af2
[junit] 2008-11-10 00:53:48,048 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-10 00:53:48,048 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1579a30
[junit] 2008-11-10 00:53:49,053 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34989
[junit] 2008-11-10 00:53:49,122 INFO [main] util.Container(156): Stopped HttpContext[/static,/static]
[junit] 2008-11-10 00:53:49,123 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@d5eb7
[junit] 2008-11-10 00:53:49,190 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2008-11-10 00:53:49,190 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@19113f8
[junit] 2008-11-10 00:53:49,191 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@401369] namenode.FSNamesystem$ReplicationMonitor(2280): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 55.181 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2008-11-10 00:53:50,123 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.06 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2008-11-10 00:53:50,637 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-10 00:53:50,642 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-10 00:53:50,643 INFO [main] test.TestFilter(262): Success!
[junit] 2008-11-10 00:53:50,643 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2008-11-10 00:53:50,645 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2008-11-10 00:53:50,647 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2008-11-10 00:53:50,648 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.068 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453: Tests failed!
Total time: 36 minutes 43 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Re: Build failed in Hudson: HBase-Patch #396
Posted by Jean-Daniel Cryans <jd...@apache.org>.
Weird it passes fine on my laptop...
J-D
On Sun, Nov 9, 2008 at 7:53 PM, Apache Hudson Server <
hudson@hudson.zones.apache.org> wrote:
> See http://hudson.zones.apache.org/hudson/job/HBase-Patch/396/changes
>
> Changes:
>
> [jdcryans] HBASE-964 Startup stuck "waiting for root region"
>
> ------------------------------------------
> [...truncated 18502 lines...]
> [junit] 2008-11-10 00:53:38,372 INFO [main] regionserver.HLog(272): New
> log writer created at /user/hudson/log_1226278410331/hlog.dat.1226278418291
> [junit] 2008-11-10 00:53:38,373 DEBUG [main] regionserver.HLog(277):
> Last sequence written is empty. Deleting all old hlogs
> [junit] 2008-11-10 00:53:38,373 INFO [main] regionserver.HLog(329):
> removing old log file /user/hudson/log_1226278410331/hlog.dat.0 whose
> highest sequence/edit id is 17
> [junit] 2008-11-10 00:53:38,373 DEBUG [main] regionserver.HLog(365):
> closing log writer in hdfs://localhost:34988/user/hudson/log_1226278410331
> [junit] 2008-11-10 00:53:38,597 DEBUG [main] regionserver.HRegion(2258):
> Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342',
> STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:38,597 DEBUG [main] regionserver.HRegion(433):
> Opening region TestMergeTool,row_0100,1226278415342/1721306299
> [junit] 2008-11-10 00:53:38,606 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1721306299/contents/info/8278144264292143646,
> isReference=false, sequence id=2, length=486
> [junit] 2008-11-10 00:53:38,606 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 1721306299/contents, max sequence id 2
> [junit] 2008-11-10 00:53:38,613 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region TestMergeTool,row_0100,1226278415342 is 3
> [junit] 2008-11-10 00:53:38,614 INFO [main] regionserver.HRegion(516):
> region TestMergeTool,row_0100,1226278415342/1721306299 available
> [junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region
> TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,615 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,616 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,616 DEBUG [main] regionserver.HStore(595):
> closed 1721306299/contents
> [junit] 2008-11-10 00:53:38,616 INFO [main] regionserver.HRegion(630):
> closed TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:38,616 INFO [main] util.TestMergeTool(171):
> Verified merging regions 0+1+2 and 3
> [junit] 2008-11-10 00:53:38,616 INFO [main] util.TestMergeTool(158):
> merging regions 0+1+2+3 and 4
> [junit] 2008-11-10 00:53:38,617 INFO [main] util.Merge(80): Verifying
> that file system is available...
> [junit] 2008-11-10 00:53:38,617 INFO [main] util.Merge(89): Verifying
> that HBase is not running...
> [junit] 2008-11-10 00:53:38,630 INFO [main] util.Merge(190): Merging
> regions [B@19c873d and [B@172bab9 in table [B@140c973
> [junit] 2008-11-10 00:53:38,791 INFO [main] regionserver.HLog(272): New
> log writer created at /user/hudson/log_1226278418630/hlog.dat.1226278418705
> [junit] 2008-11-10 00:53:38,792 DEBUG [main] regionserver.HRegion(2258):
> 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 => '1', LENGTH => '2147483647', TTL => '-1',
> IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
> [junit] 2008-11-10 00:53:38,792 DEBUG [main] regionserver.HRegion(433):
> Opening region -ROOT-,,0/70236052
> [junit] 2008-11-10 00:53:38,800 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/-ROOT-/70236052/info/info/3826198435386252829,
> isReference=false, sequence id=1, length=569
> [junit] 2008-11-10 00:53:38,801 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 70236052/info, max sequence id 1
> [junit] 2008-11-10 00:53:38,808 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region -ROOT-,,0 is 2
> [junit] 2008-11-10 00:53:38,809 INFO [main] regionserver.HRegion(516):
> region -ROOT-,,0/70236052 available
> [junit] 2008-11-10 00:53:38,809 DEBUG [main] regionserver.HLog(205):
> changing sequence number from 0 to 2
> [junit] 2008-11-10 00:53:38,809 INFO [main] regionserver.HRegion(899):
> starting compaction on region -ROOT-,,0
> [junit] 2008-11-10 00:53:38,811 INFO [main] regionserver.HRegion(913):
> compaction completed on region -ROOT-,,0 in 0sec
> [junit] 2008-11-10 00:53:38,817 INFO [main] util.Merge(204): Found meta
> for region1 [B@197507c, meta for region2 [B@197507c
> [junit] 2008-11-10 00:53:38,818 DEBUG [main] regionserver.HRegion(2258):
> 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 => '1', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1',
> IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'historian',
> BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE',
> LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false', BLOCKCACHE =>
> 'false'}]}}
> [junit] 2008-11-10 00:53:38,818 DEBUG [main] regionserver.HRegion(433):
> Opening region .META.,,1/1028785192
> [junit] 2008-11-10 00:53:38,826 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/597168401597830125,
> isReference=false, sequence id=17, length=658
> [junit] 2008-11-10 00:53:38,833 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/8274487517488866077,
> isReference=false, sequence id=13, length=1206
> [junit] 2008-11-10 00:53:38,839 DEBUG [main] regionserver.HStore(490):
> loaded /user/hudson/.META./1028785192/info/info/8886405319793594306,
> isReference=false, sequence id=5, length=1928
> [junit] 2008-11-10 00:53:38,840 DEBUG [main] regionserver.HStore(229):
> Loaded 3 file(s) in hstore 1028785192/info, max sequence id 17
> [junit] 2008-11-10 00:53:38,863 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region .META.,,1 is 18
> [junit] 2008-11-10 00:53:38,865 INFO [main] regionserver.HRegion(516):
> region .META.,,1/1028785192 available
> [junit] 2008-11-10 00:53:38,866 DEBUG [main] regionserver.HLog(205):
> changing sequence number from 2 to 18
> [junit] 2008-11-10 00:53:38,866 INFO [main] regionserver.HRegion(899):
> starting compaction on region .META.,,1
> [junit] 2008-11-10 00:53:38,872 DEBUG [main] regionserver.HStore(889):
> Compaction size of 1028785192/info: 4.5k; Skipped 0 files , size: 0
> [junit] 2008-11-10 00:53:38,893 DEBUG [main] regionserver.HStore(907):
> started compaction of 3 files into
> /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3805311149848711689
> [junit] 2008-11-10 00:53:39,980 DEBUG [main] regionserver.HStore(1165):
> moving
> /user/hudson/.META./compaction.dir/1028785192/info/mapfiles/3805311149848711689
> to /user/hudson/.META./1028785192/info/mapfiles/6662607905013016013
> [junit] 2008-11-10 00:53:40,712 DEBUG [main] regionserver.HStore(925):
> Completed compaction of 1028785192/info store size is 3.5k; time since last
> major compaction: 0 seconds
> [junit] 2008-11-10 00:53:40,789 INFO [main] regionserver.HRegion(913):
> compaction completed on region .META.,,1 in 1sec
> [junit] 2008-11-10 00:53:40,791 DEBUG [main] regionserver.HRegion(2258):
> Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342',
> STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:40,792 DEBUG [main] regionserver.HRegion(433):
> Opening region TestMergeTool,row_0100,1226278415342/1721306299
> [junit] 2008-11-10 00:53:40,801 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1721306299/contents/info/8278144264292143646,
> isReference=false, sequence id=2, length=486
> [junit] 2008-11-10 00:53:40,802 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 1721306299/contents, max sequence id 2
> [junit] 2008-11-10 00:53:40,808 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region TestMergeTool,row_0100,1226278415342 is 3
> [junit] 2008-11-10 00:53:40,810 INFO [main] regionserver.HRegion(516):
> region TestMergeTool,row_0100,1226278415342/1721306299 available
> [junit] 2008-11-10 00:53:40,810 DEBUG [main] regionserver.HRegion(2258):
> Opening region: REGION => {NAME => 'TestMergeTool,,1226278374488', STARTKEY
> => '', ENDKEY => '', ENCODED => 941143000, 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-10 00:53:40,811 DEBUG [main] regionserver.HRegion(433):
> Opening region TestMergeTool,,1226278374488/941143000
> [junit] 2008-11-10 00:53:40,855 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/941143000/contents/info/7848333118125034455,
> isReference=false, sequence id=2, length=204
> [junit] 2008-11-10 00:53:40,856 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 941143000/contents, max sequence id 2
> [junit] 2008-11-10 00:53:40,863 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region TestMergeTool,,1226278374488 is 3
> [junit] 2008-11-10 00:53:40,865 INFO [main] regionserver.HRegion(516):
> region TestMergeTool,,1226278374488/941143000 available
> [junit] 2008-11-10 00:53:40,865 INFO [main] regionserver.HRegion(899):
> starting compaction on region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:40,874 DEBUG [main] regionserver.HStore(907):
> started compaction of 1 files into
> /user/hudson/TestMergeTool/compaction.dir/1721306299/contents/mapfiles/9222501372853478946
> [junit] 2008-11-10 00:53:41,461 DEBUG [main] regionserver.HStore(1165):
> moving
> /user/hudson/TestMergeTool/compaction.dir/1721306299/contents/mapfiles/9222501372853478946
> to
> /user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814
> [junit] 2008-11-10 00:53:41,827 DEBUG [main] regionserver.HStore(925):
> Completed compaction of 1721306299/contents store size is 486.0
> [junit] 2008-11-10 00:53:41,899 INFO [main] regionserver.HRegion(913):
> compaction completed on region TestMergeTool,row_0100,1226278415342 in 1sec
> [junit] 2008-11-10 00:53:41,899 DEBUG [main] regionserver.HRegion(175):
> Files for region: TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:41,900 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents
> [junit] 2008-11-10 00:53:41,901 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/info
> [junit] 2008-11-10 00:53:41,901 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/info/469208122528650814
> size=9
> [junit] 2008-11-10 00:53:41,902 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles
> [junit] 2008-11-10 00:53:41,902 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814
> [junit] 2008-11-10 00:53:41,903 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814/data
> size=486
> [junit] 2008-11-10 00:53:41,903 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299/contents/mapfiles/469208122528650814/index
> size=227
> [junit] 2008-11-10 00:53:41,903 INFO [main] regionserver.HRegion(899):
> starting compaction on region TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:41,910 DEBUG [main] regionserver.HStore(907):
> started compaction of 1 files into
> /user/hudson/TestMergeTool/compaction.dir/941143000/contents/mapfiles/3174101678615308442
> [junit] 2008-11-10 00:53:42,519 DEBUG [main] regionserver.HStore(1165):
> moving
> /user/hudson/TestMergeTool/compaction.dir/941143000/contents/mapfiles/3174101678615308442
> to
> /user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893
> [junit] 2008-11-10 00:53:42,849 DEBUG [main] regionserver.HStore(925):
> Completed compaction of 941143000/contents store size is 204.0
> [junit] 2008-11-10 00:53:42,908 INFO [main] regionserver.HRegion(913):
> compaction completed on region TestMergeTool,,1226278374488 in 1sec
> [junit] 2008-11-10 00:53:42,909 DEBUG [main] regionserver.HRegion(180):
> Files for region: TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:42,910 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents
> [junit] 2008-11-10 00:53:42,911 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/info
> [junit] 2008-11-10 00:53:42,911 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/info/1163906313873296893
> size=9
> [junit] 2008-11-10 00:53:42,912 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles
> [junit] 2008-11-10 00:53:42,912 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893
> [junit] 2008-11-10 00:53:42,913 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893/data
> size=204
> [junit] 2008-11-10 00:53:42,914 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/941143000/contents/mapfiles/1163906313873296893/index
> size=227
> [junit] 2008-11-10 00:53:42,914 INFO [main] regionserver.HRegion(204):
> Creating new region REGION => {NAME => 'TestMergeTool,,1226278422914',
> STARTKEY => '', ENDKEY => '', ENCODED => 1379193769, 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-10 00:53:43,011 INFO [main] regionserver.HRegion(213):
> starting merge of regions: TestMergeTool,row_0100,1226278415342 and
> TestMergeTool,,1226278374488 into new region REGION => {NAME =>
> 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY => '', ENCODED =>
> 1379193769, 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...@1ea0252>
> and end key <[B...@1ea0252>
> [junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region
> TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,011 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HStore(595):
> closed 1721306299/contents
> [junit] 2008-11-10 00:53:43,012 INFO [main] regionserver.HRegion(630):
> closed TestMergeTool,row_0100,1226278415342
> [junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region
> TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,012 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,013 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,013 DEBUG [main] regionserver.HStore(595):
> closed 941143000/contents
> [junit] 2008-11-10 00:53:43,013 INFO [main] regionserver.HRegion(630):
> closed TestMergeTool,,1226278374488
> [junit] 2008-11-10 00:53:43,100 DEBUG [main] regionserver.HRegion(236):
> Adjusting sequence id of storeFile 941143000/contents/1163906313873296893
> down by one; sequence id A=2, sequence id B=2
> [junit] 2008-11-10 00:53:43,259 DEBUG [main] regionserver.HRegion(247):
> Renaming 1721306299/contents/469208122528650814 to
> 1379193769/contents/8357857439596116794
> [junit] 2008-11-10 00:53:43,456 DEBUG [main] regionserver.HRegion(247):
> Renaming 941143000/contents/1163906313873296893 to
> 1379193769/contents/1511610577137846810
> [junit] 2008-11-10 00:53:43,626 DEBUG [main] regionserver.HRegion(253):
> Files for new region
> [junit] 2008-11-10 00:53:43,628 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents
> [junit] 2008-11-10 00:53:43,628 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info
> [junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/1511610577137846810
> size=9
> [junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/8357857439596116794
> size=9
> [junit] 2008-11-10 00:53:43,629 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles
> [junit] 2008-11-10 00:53:43,630 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810
> [junit] 2008-11-10 00:53:43,631 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810/data
> size=204
> [junit] 2008-11-10 00:53:43,632 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/1511610577137846810/index
> size=227
> [junit] 2008-11-10 00:53:43,632 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794
> [junit] 2008-11-10 00:53:43,633 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794/data
> size=486
> [junit] 2008-11-10 00:53:43,633 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/8357857439596116794/index
> size=227
> [junit] 2008-11-10 00:53:43,634 DEBUG [main] regionserver.HRegion(433):
> Opening region TestMergeTool,,1226278422914/1379193769
> [junit] 2008-11-10 00:53:43,641 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1379193769/contents/info/1511610577137846810,
> isReference=false, sequence id=1, length=204
> [junit] 2008-11-10 00:53:43,647 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1379193769/contents/info/8357857439596116794,
> isReference=false, sequence id=2, length=486
> [junit] 2008-11-10 00:53:43,648 DEBUG [main] regionserver.HStore(229):
> Loaded 2 file(s) in hstore 1379193769/contents, max sequence id 2
> [junit] 2008-11-10 00:53:43,662 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region TestMergeTool,,1226278422914 is 3
> [junit] 2008-11-10 00:53:43,664 INFO [main] regionserver.HRegion(516):
> region TestMergeTool,,1226278422914/1379193769 available
> [junit] 2008-11-10 00:53:43,664 INFO [main] regionserver.HRegion(899):
> starting compaction on region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:43,668 DEBUG [main] regionserver.HStore(889):
> Compaction size of 1379193769/contents: 1.1k; Skipped 0 files , size: 0
> [junit] 2008-11-10 00:53:43,681 DEBUG [main] regionserver.HStore(907):
> started compaction of 2 files into
> /user/hudson/TestMergeTool/compaction.dir/1379193769/contents/mapfiles/5472175154486337476
> [junit] 2008-11-10 00:53:44,852 DEBUG [main] regionserver.HStore(1165):
> moving
> /user/hudson/TestMergeTool/compaction.dir/1379193769/contents/mapfiles/5472175154486337476
> to
> /user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276
> [junit] 2008-11-10 00:53:45,315 DEBUG [main] regionserver.HStore(925):
> Completed compaction of 1379193769/contents store size is 580.0; time since
> last major compaction: 0 seconds
> [junit] 2008-11-10 00:53:45,409 INFO [main] regionserver.HRegion(913):
> compaction completed on region TestMergeTool,,1226278422914 in 1sec
> [junit] 2008-11-10 00:53:45,410 DEBUG [main] regionserver.HRegion(260):
> Files for new region
> [junit] 2008-11-10 00:53:45,411 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents
> [junit] 2008-11-10 00:53:45,413 DEBUG [main] regionserver.HRegion(313):
> d hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info
> [junit] 2008-11-10 00:53:45,414 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/info/5581900472901382276
> size=9
> [junit] 2008-11-10 00:53:45,414 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles
> [junit] 2008-11-10 00:53:45,415 DEBUG [main] regionserver.HRegion(313):
> d
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276
> [junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276/data
> size=580
> [junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(316):
> f
> hdfs://localhost:34988/user/hudson/TestMergeTool/1379193769/contents/mapfiles/5581900472901382276/index
> size=227
> [junit] 2008-11-10 00:53:45,417 DEBUG [main] regionserver.HRegion(2355):
> DELETING region hdfs://localhost:34988/user/hudson/TestMergeTool/1721306299
> [junit] 2008-11-10 00:53:45,495 DEBUG [main] regionserver.HRegion(2355):
> DELETING region hdfs://localhost:34988/user/hudson/TestMergeTool/941143000
> [junit] 2008-11-10 00:53:45,567 INFO [main] regionserver.HRegion(266):
> merge completed. New region is TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,567 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,row_0100,1226278415342', STARTKEY
> => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1721306299, 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-10 00:53:45,569 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,,1226278374488', STARTKEY => '',
> ENDKEY => '', ENCODED => 941143000, 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-10 00:53:45,577 INFO [main] util.Merge(244): Adding
> REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY => '', ENDKEY =>
> '', ENCODED => 1379193769, 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 => '1', COMPRESSION =>
> 'NONE', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 'false',
> BLOCKCACHE => 'false'}, {NAME => 'historian', BLOOMFILTER => 'false',
> VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL
> => '-1', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
> [junit] 2008-11-10 00:53:45,577 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region
> TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,577 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HStore(595):
> closed 1379193769/contents
> [junit] 2008-11-10 00:53:45,578 INFO [main] regionserver.HRegion(630):
> closed TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region -ROOT-,,0
> [junit] 2008-11-10 00:53:45,578 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region -ROOT-,,0
> [junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region -ROOT-,,0
> [junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region -ROOT-,,0
> [junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region -ROOT-,,0
> [junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HStore(595):
> closed 70236052/info
> [junit] 2008-11-10 00:53:45,579 INFO [main] regionserver.HRegion(630):
> closed -ROOT-,,0
> [junit] 2008-11-10 00:53:45,579 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region .META.,,1
> [junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region .META.,,1
> [junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region .META.,,1
> [junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region .META.,,1
> [junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region .META.,,1
> [junit] 2008-11-10 00:53:45,580 DEBUG [main] regionserver.HRegion(1024):
> Started memcache flush for region .META.,,1. Current region memcache size
> 466.0
> [junit] 2008-11-10 00:53:46,165 DEBUG [main] regionserver.HStore(690):
> Added /user/hudson/.META./1028785192/info/mapfiles/5550820802377771249 with
> 3 entries, sequence id 21, data size 466.0, file size 618.0
> [junit] 2008-11-10 00:53:46,165 DEBUG [main] regionserver.HRegion(1098):
> Finished memcache flush for region .META.,,1 in 585ms, sequence id=21,
> compaction requested=true
> [junit] 2008-11-10 00:53:46,166 DEBUG [main] regionserver.HStore(595):
> closed 1028785192/historian
> [junit] 2008-11-10 00:53:46,166 DEBUG [main] regionserver.HStore(595):
> closed 1028785192/info
> [junit] 2008-11-10 00:53:46,167 INFO [main] regionserver.HRegion(630):
> closed .META.,,1
> [junit] 2008-11-10 00:53:46,277 DEBUG [main] regionserver.HLog(259):
> Closing current log writer /user/hudson/log_1226278418630/hlog.dat.0
> [junit] 2008-11-10 00:53:46,344 INFO [main] regionserver.HLog(272): New
> log writer created at /user/hudson/log_1226278418630/hlog.dat.1226278426278
> [junit] 2008-11-10 00:53:46,344 DEBUG [main] regionserver.HLog(277):
> Last sequence written is empty. Deleting all old hlogs
> [junit] 2008-11-10 00:53:46,344 INFO [main] regionserver.HLog(329):
> removing old log file /user/hudson/log_1226278418630/hlog.dat.0 whose
> highest sequence/edit id is 21
> [junit] 2008-11-10 00:53:46,345 DEBUG [main] regionserver.HLog(365):
> closing log writer in hdfs://localhost:34988/user/hudson/log_1226278418630
> [junit] 2008-11-10 00:53:46,487 DEBUG [main] regionserver.HRegion(2258):
> Opening region: REGION => {NAME => 'TestMergeTool,,1226278422914', STARTKEY
> => '', ENDKEY => '', ENCODED => 1379193769, 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-10 00:53:46,487 DEBUG [main] regionserver.HRegion(433):
> Opening region TestMergeTool,,1226278422914/1379193769
> [junit] 2008-11-10 00:53:46,494 DEBUG [main] regionserver.HStore(490):
> loaded
> /user/hudson/TestMergeTool/1379193769/contents/info/5581900472901382276,
> isReference=false, sequence id=2, length=580
> [junit] 2008-11-10 00:53:46,495 DEBUG [main] regionserver.HStore(229):
> Loaded 1 file(s) in hstore 1379193769/contents, max sequence id 2
> [junit] 2008-11-10 00:53:46,501 DEBUG [main] regionserver.HRegion(494):
> Next sequence id for region TestMergeTool,,1226278422914 is 3
> [junit] 2008-11-10 00:53:46,502 INFO [main] regionserver.HRegion(516):
> region TestMergeTool,,1226278422914/1379193769 available
> [junit] 2008-11-10 00:53:46,503 DEBUG [main] regionserver.HRegion(579):
> Compactions and cache flushes disabled for region
> TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(594):
> Scanners disabled for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(609):
> No more active scanners for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(611):
> Updates disabled for region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HRegion(617):
> No more row locks outstanding on region TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,504 DEBUG [main] regionserver.HStore(595):
> closed 1379193769/contents
> [junit] 2008-11-10 00:53:46,504 INFO [main] regionserver.HRegion(630):
> closed TestMergeTool,,1226278422914
> [junit] 2008-11-10 00:53:46,505 INFO [main] util.TestMergeTool(171):
> Verified merging regions 0+1+2+3 and 4
> [junit] 2008-11-10 00:53:46,505 DEBUG [main] regionserver.HLog(365):
> closing log writer in /tmp/log_1226278387070
> [junit] 2008-11-10 00:53:46,654 INFO [main] hbase.HBaseTestCase(600):
> Shutting down FileSystem
> [junit] 2008-11-10 00:53:46,654 INFO [main] hbase.HBaseTestCase(607):
> Shutting down Mini DFS
> [junit] Shutting down the Mini HDFS Cluster
> [junit] Shutting down DataNode 1
> [junit] 2008-11-10 00:53:46,662 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:34996
> [junit] 2008-11-10 00:53:46,787 INFO [main] util.Container(156):
> Stopped HttpContext[/static,/static]
> [junit] 2008-11-10 00:53:46,788 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@4a5c78
> [junit] 2008-11-10 00:53:46,862 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-10 00:53:46,862 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@17c2891
> [junit] Shutting down DataNode 0
> [junit] 2008-11-10 00:53:47,873 INFO [Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34993]]
> util.ThreadedServer$Acceptor(656): Stopping Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34993]
> [junit] 2008-11-10 00:53:47,874 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:34993
> [junit] 2008-11-10 00:53:47,975 INFO [main] util.Container(156):
> Stopped HttpContext[/static,/static]
> [junit] 2008-11-10 00:53:47,976 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@4d2af2
> [junit] 2008-11-10 00:53:48,048 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-10 00:53:48,048 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@1579a30
> [junit] 2008-11-10 00:53:49,053 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:34989
> [junit] 2008-11-10 00:53:49,122 INFO [main] util.Container(156):
> Stopped HttpContext[/static,/static]
> [junit] 2008-11-10 00:53:49,123 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@d5eb7
> [junit] 2008-11-10 00:53:49,190 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2008-11-10 00:53:49,190 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@19113f8
> [junit] 2008-11-10 00:53:49,191 WARN
> [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@401369]
> namenode.FSNamesystem$ReplicationMonitor(2280): ReplicationMonitor thread
> received InterruptedException.java.lang.InterruptedException: sleep
> interrupted
> [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 55.181 sec
> [junit] Running org.apache.hadoop.hbase.util.TestRootPath
> [junit] 2008-11-10 00:53:50,123 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.06 sec
> [junit] Running org.onelab.test.TestFilter
> [junit] 2008-11-10 00:53:50,637 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2008-11-10 00:53:50,642 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2008-11-10 00:53:50,643 INFO [main] test.TestFilter(262):
> Success!
> [junit] 2008-11-10 00:53:50,643 INFO [main] test.TestFilter(226):
> Checking serialization/deserialization
> [junit] 2008-11-10 00:53:50,645 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2008-11-10 00:53:50,647 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2008-11-10 00:53:50,648 INFO [main] test.TestFilter(262):
> Success!
> [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.068 sec
>
> BUILD FAILED
> /zonestorage/hudson/home/hudson/hudson/jobs/HBase-Patch/workspace/trunk/build.xml:453:
> Tests failed!
>
> Total time: 36 minutes 43 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 #397
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/397/changes