Seems my new test is failing. That's good, it means it's working. The problem is that the region which we want to disable is pending open but we clear its state in ChangeTableState. The master is then confused when it gets back as opened by the region server.
J-D On Tue, Dec 22, 2009 at 7:44 PM, Apache Hudson Server <[email protected]> wrote: > See <http://hudson.zones.apache.org/hudson/job/HBase-Patch/1044/changes> > > Changes: > > [jdcryans] HBASE-2064 Cannot disable a table if at the same the Master is > moving > its regions around > HBASE-2065 Cannot disable a table if any of its region is opening > at the same time > > ------------------------------------------ > [...truncated 118988 lines...] > [junit] 2009-12-23 03:48:21,604 DEBUG [main] regionserver.HRegion(2268): d > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/contents > [junit] 2009-12-23 03:48:21,605 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/contents/3530192824530754175 > size=791 > [junit] 2009-12-23 03:48:21,605 DEBUG [main] regionserver.HRegion(2003): > DELETING region hdfs://localhost:48623/user/hudson/TestMergeTool/1695461468 > [junit] 2009-12-23 03:48:21,619 DEBUG [main] regionserver.HRegion(2003): > DELETING region hdfs://localhost:48623/user/hudson/TestMergeTool/1054953998 > [junit] 2009-12-23 03:48:21,631 INFO [main] regionserver.HRegion(2213): > merge completed. New region is TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,631 DEBUG [main] util.Merge(319): Removing > region: REGION => {NAME => 'TestMergeTool,row_0100,1261540097920', STARTKEY > => 'row_0100', ENDKEY => 'row_0400', ENCODED => 1695461468, TABLE => {{NAME > => 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3', > COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} from .META.,,1 > [junit] 2009-12-23 03:48:21,632 DEBUG [main] util.Merge(319): Removing > region: REGION => {NAME => 'TestMergeTool,row_0500,1261540083850', STARTKEY > => 'row_0500', ENDKEY => 'row_0600', ENCODED => 1054953998, TABLE => {{NAME > => 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3', > COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} from .META.,,1 > [junit] 2009-12-23 03:48:21,633 INFO [main] util.Merge(255): Adding > REGION => {NAME => 'TestMergeTool,row_0100,1261540101208', STARTKEY => > 'row_0100', ENDKEY => 'row_0600', ENCODED => 1147554832, TABLE => {{NAME => > 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3', > COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} to REGION => {NAME => '.META.,,1', > STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => > '.META.', IS_META => 'true', FAMILIES => [{NAME => 'historian', VERSIONS => > '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', > IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => > '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', > IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:21,633 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,row_0100,1261540101208: compactions & flushes disabled > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:21,634 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.HRegion(454): > Closing -ROOT-,,0: compactions & flushes disabled > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on -ROOT-,,0 > [junit] 2009-12-23 03:48:21,634 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region -ROOT-,,0 > [junit] 2009-12-23 03:48:21,635 DEBUG [main] regionserver.Store(482): > closed info > [junit] 2009-12-23 03:48:21,635 INFO [main] regionserver.HRegion(490): > Closed -ROOT-,,0 > [junit] 2009-12-23 03:48:21,635 INFO [main] util.MetaUtils(148): CLOSING > META .META.,,1 > [junit] 2009-12-23 03:48:21,635 DEBUG [main] regionserver.HRegion(454): > Closing .META.,,1: compactions & flushes disabled > [junit] 2009-12-23 03:48:21,635 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on .META.,,1 > [junit] 2009-12-23 03:48:21,635 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region .META.,,1 > [junit] 2009-12-23 03:48:21,636 DEBUG [main] regionserver.HRegion(895): > Started memstore flush for region .META.,,1. Current region memstore size 1016 > [junit] 2009-12-23 03:48:21,674 DEBUG [main] regionserver.Store(564): > Added > hdfs://localhost:48623/user/hudson/.META./1028785192/historian/1033018758061668555, > entries=2, sequenceid=27, memsize=288, filesize=521 to .META.,,1 > [junit] 2009-12-23 03:48:21,714 DEBUG [main] regionserver.Store(564): > Added > hdfs://localhost:48623/user/hudson/.META./1028785192/info/2637185596448341006, > entries=3, sequenceid=27, memsize=728, filesize=874 to .META.,,1 > [junit] 2009-12-23 03:48:21,715 DEBUG [main] regionserver.HRegion(971): > Finished memstore flush of ~1016 for region .META.,,1 in 79ms, sequence > id=27, compaction requested=true > [junit] 2009-12-23 03:48:21,715 DEBUG [main] regionserver.Store(482): > closed historian > [junit] 2009-12-23 03:48:21,716 DEBUG [main] regionserver.Store(482): > closed info > [junit] 2009-12-23 03:48:21,717 INFO [main] regionserver.HRegion(490): > Closed .META.,,1 > [junit] 2009-12-23 03:48:21,779 WARN [main] conf.Configuration(616): > fs.checkpoint.size is deprecated. Instead, use dfs.namenode.checkpoint.size > [junit] 2009-12-23 03:48:21,780 WARN [main] conf.Configuration(616): > fs.checkpoint.dir is deprecated. Instead, use dfs.namenode.checkpoint.dir > [junit] 2009-12-23 03:48:21,781 WARN [main] conf.Configuration(616): > fs.checkpoint.edits.dir is deprecated. Instead, use > dfs.namenode.checkpoint.edits.dir > [junit] 2009-12-23 03:48:21,781 WARN [main] conf.Configuration(616): > fs.checkpoint.period is deprecated. Instead, use > dfs.namenode.checkpoint.period > [junit] 2009-12-23 03:48:21,793 INFO [main] wal.HLog(321): Roll > /user/hudson/.logs_1261540099585/hlog.dat.1261540099595, entries=6, > calcsize=1131, filesize=1075. New hlog > /user/hudson/.logs_1261540099585/hlog.dat.1261540101732 > [junit] 2009-12-23 03:48:21,793 DEBUG [main] wal.HLog(330): Last sequence > written is empty. Deleting all old hlogs > [junit] 2009-12-23 03:48:21,794 INFO [main] wal.HLog(490): removing old > hlog file /user/hudson/.logs_1261540099585/hlog.dat.1261540099595 whose > highest sequence/edit id is 26 > [junit] 2009-12-23 03:48:21,806 DEBUG [main.logSyncer] > wal.HLog$LogSyncer(704): main.logSyncerinterrupted while waiting for sync > requests > [junit] 2009-12-23 03:48:21,807 INFO [main.logSyncer] > wal.HLog$LogSyncer(708): main.logSyncer exiting > [junit] 2009-12-23 03:48:21,807 DEBUG [main] wal.HLog(535): closing hlog > writer in hdfs://localhost:48623/user/hudson/.logs_1261540099585 > [junit] 2009-12-23 03:48:21,838 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1261540101208', > STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1147554832, TABLE => > {{NAME => 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3', > COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:21,839 DEBUG [main] regionserver.HRegion(265): > Opening region TestMergeTool,row_0100,1261540101208, encoded=1147554832 > [junit] 2009-12-23 03:48:21,846 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1147554832/contents/3530192824530754175, > isReference=false, sequence id=6, length=791, majorCompaction=false > [junit] 2009-12-23 03:48:21,848 INFO [main] regionserver.HRegion(343): > region TestMergeTool,row_0100,1261540101208/1147554832 available; sequence id > is 7 > [junit] 2009-12-23 03:48:21,852 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,row_0100,1261540101208: compactions & flushes disabled > [junit] 2009-12-23 03:48:21,852 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,852 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,853 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:21,853 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:21,853 INFO [main] util.TestMergeTool(186): > Verified merging regions 0+1+2 and 3 > [junit] 2009-12-23 03:48:21,853 INFO [main] util.TestMergeTool(173): > merging regions 0+1+2+3 and 4 > [junit] 2009-12-23 03:48:21,853 WARN [main] conf.Configuration(616): > mapred.used.genericoptionsparser is deprecated. Instead, use > mapreduce.client.genericoptionsparser.used > [junit] 2009-12-23 03:48:21,853 WARN [main] conf.Configuration(616): > mapred.used.genericoptionsparser is deprecated. Instead, use > mapreduce.client.genericoptionsparser.used > [junit] 2009-12-23 03:48:21,854 INFO [main] util.Merge(82): Verifying > that file system is available... > [junit] 2009-12-23 03:48:21,854 INFO [main] util.Merge(91): Verifying > that HBase is not running... > [junit] 2009-12-23 03:48:21,871 WARN [main] conf.Configuration(616): > fs.checkpoint.size is deprecated. Instead, use dfs.namenode.checkpoint.size > [junit] 2009-12-23 03:48:21,871 WARN [main] conf.Configuration(616): > fs.checkpoint.dir is deprecated. Instead, use dfs.namenode.checkpoint.dir > [junit] 2009-12-23 03:48:21,872 WARN [main] conf.Configuration(616): > fs.checkpoint.edits.dir is deprecated. Instead, use > dfs.namenode.checkpoint.edits.dir > [junit] 2009-12-23 03:48:21,872 WARN [main] conf.Configuration(616): > fs.checkpoint.period is deprecated. Instead, use > dfs.namenode.checkpoint.period > [junit] 2009-12-23 03:48:21,873 INFO [main] util.Merge(197): Merging > regions TestMergeTool,row_0100,1261540101208 and TestMergeTool,,1261540083850 > in table TestMergeTool > [junit] 2009-12-23 03:48:21,883 INFO [main] wal.HLog(243): HLog > configuration: blocksize=67108864, rollsize=63753420, enabled=true, > flushlogentries=1, optionallogflushinternal=1000ms > [junit] 2009-12-23 03:48:21,900 WARN [main] conf.Configuration(616): > fs.checkpoint.size is deprecated. Instead, use dfs.namenode.checkpoint.size > [junit] 2009-12-23 03:48:21,900 WARN [main] conf.Configuration(616): > fs.checkpoint.dir is deprecated. Instead, use dfs.namenode.checkpoint.dir > [junit] 2009-12-23 03:48:21,900 WARN [main] conf.Configuration(616): > fs.checkpoint.edits.dir is deprecated. Instead, use > dfs.namenode.checkpoint.edits.dir > [junit] 2009-12-23 03:48:21,901 WARN [main] conf.Configuration(616): > fs.checkpoint.period is deprecated. Instead, use > dfs.namenode.checkpoint.period > [junit] 2009-12-23 03:48:21,911 INFO [main] wal.HLog(321): New hlog > /user/hudson/.logs_1261540101873/hlog.dat.1261540101883 > [junit] 2009-12-23 03:48:21,912 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', > ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META > => 'true', FAMILIES => [{NAME => 'info', COMPRESSION => 'NONE', VERSIONS => > '10', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', > BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:21,912 DEBUG [main] regionserver.HRegion(265): > Opening region -ROOT-,,0, encoded=70236052 > [junit] 2009-12-23 03:48:21,920 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/-ROOT-/70236052/info/2740212953581004924, > isReference=false, sequence id=2, length=809, majorCompaction=false > [junit] 2009-12-23 03:48:21,922 INFO [main] regionserver.HRegion(343): > region -ROOT-,,0/70236052 available; sequence id is 3 > [junit] 2009-12-23 03:48:21,922 INFO [main] regionserver.HRegion(771): > Starting compaction on region -ROOT-,,0 > [junit] 2009-12-23 03:48:21,924 INFO [main] regionserver.HRegion(786): > compaction completed on region -ROOT-,,0 in 0sec > [junit] 2009-12-23 03:48:21,924 INFO [main] util.Merge(211): Found meta > for region1 .META.,,1, meta for region2 .META.,,1 > [junit] 2009-12-23 03:48:21,925 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', > ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', > FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => > 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', > BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => > 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', > BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:21,925 DEBUG [main] regionserver.HRegion(265): > Opening region .META.,,1, encoded=1028785192 > [junit] 2009-12-23 03:48:21,932 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/.META./1028785192/historian/1033018758061668555, > isReference=false, sequence id=27, length=521, majorCompaction=false > [junit] 2009-12-23 03:48:21,938 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/.META./1028785192/historian/3476054143409226755, > isReference=false, sequence id=20, length=651, majorCompaction=false > [junit] 2009-12-23 03:48:21,947 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/.META./1028785192/info/2637185596448341006, > isReference=false, sequence id=27, length=874, majorCompaction=false > [junit] 2009-12-23 03:48:21,951 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/.META./1028785192/info/2926731446109122526, > isReference=false, sequence id=20, length=994, majorCompaction=false > [junit] 2009-12-23 03:48:21,955 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/.META./1028785192/info/4589151583594890471, > isReference=false, sequence id=6, length=2226, majorCompaction=false > [junit] 2009-12-23 03:48:21,958 INFO [main] regionserver.HRegion(343): > region .META.,,1/1028785192 available; sequence id is 28 > [junit] 2009-12-23 03:48:21,958 INFO [main] regionserver.HRegion(771): > Starting compaction on region .META.,,1 > [junit] 2009-12-23 03:48:21,967 DEBUG [main] regionserver.Store(750): > Compaction size of historian: 1.1k; Skipped 0 file(s), size: 0 > [junit] 2009-12-23 03:48:21,967 DEBUG [main] regionserver.Store(757): > Started compaction of 2 file(s) into > /user/hudson/.META./compaction.dir/1028785192, seqid=27 > [junit] 2009-12-23 03:48:22,168 DEBUG [main] regionserver.Store(764): > Completed compaction of historian; new storefile is > hdfs://localhost:48623/user/hudson/.META./1028785192/historian/6900876774987438370; > store size is 781 > [junit] 2009-12-23 03:48:22,169 DEBUG [main] regionserver.Store(750): > Compaction size of info: 4.0k; Skipped 1 file(s), size: 2226 > [junit] 2009-12-23 03:48:22,170 DEBUG [main] regionserver.Store(757): > Started compaction of 2 file(s) into > /user/hudson/.META./compaction.dir/1028785192, seqid=27 > [junit] 2009-12-23 03:48:22,227 DEBUG [main] regionserver.Store(764): > Completed compaction of info; new storefile is > hdfs://localhost:48623/user/hudson/.META./1028785192/info/8123136151735169395; > store size is 3.3k > [junit] 2009-12-23 03:48:22,238 INFO [main] regionserver.HRegion(786): > compaction completed on region .META.,,1 in 0sec > [junit] 2009-12-23 03:48:22,239 INFO [main] util.MetaUtils(125): OPENING > META .META.,,1 > [junit] 2009-12-23 03:48:22,241 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1261540101208', > STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1147554832, TABLE => > {{NAME => 'TestMergeTool', FAMILIES => [{NAME => 'contents', COMPRESSION => > 'NONE', VERSIONS => '3', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:22,241 DEBUG [main] regionserver.HRegion(265): > Opening region TestMergeTool,row_0100,1261540101208, encoded=1147554832 > [junit] 2009-12-23 03:48:22,248 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1147554832/contents/3530192824530754175, > isReference=false, sequence id=6, length=791, majorCompaction=false > [junit] 2009-12-23 03:48:22,250 INFO [main] regionserver.HRegion(343): > region TestMergeTool,row_0100,1261540101208/1147554832 available; sequence id > is 7 > [junit] 2009-12-23 03:48:22,250 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => 'TestMergeTool,,1261540083850', STARTKEY > => '', ENDKEY => '', ENCODED => 1897256012, TABLE => {{NAME => > 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3', > COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY > => 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:22,251 DEBUG [main] regionserver.HRegion(265): > Opening region TestMergeTool,,1261540083850, encoded=1897256012 > [junit] 2009-12-23 03:48:22,257 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1897256012/contents/3625255122862528899, > isReference=false, sequence id=7, length=471, majorCompaction=false > [junit] 2009-12-23 03:48:22,260 INFO [main] regionserver.HRegion(343): > region TestMergeTool,,1261540083850/1897256012 available; sequence id is 8 > [junit] 2009-12-23 03:48:22,260 INFO [main] regionserver.HRegion(771): > Starting major compaction on region TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:22,271 DEBUG [main] regionserver.Store(757): > Started compaction of 1 file(s) into > /user/hudson/TestMergeTool/compaction.dir/1147554832, seqid=6 > [junit] 2009-12-23 03:48:22,326 DEBUG [main] regionserver.Store(764): > Completed major compaction of contents; new storefile is > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/contents/1222024413056464161; > store size is 791 > [junit] 2009-12-23 03:48:22,335 INFO [main] regionserver.HRegion(786): > compaction completed on region TestMergeTool,row_0100,1261540101208 in 0sec > [junit] 2009-12-23 03:48:22,335 DEBUG [main] regionserver.HRegion(2124): > Files for region: TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:22,336 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/.regioninfo > size=632 > [junit] 2009-12-23 03:48:22,336 DEBUG [main] regionserver.HRegion(2268): d > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/contents > [junit] 2009-12-23 03:48:22,337 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832/contents/1222024413056464161 > size=791 > [junit] 2009-12-23 03:48:22,338 INFO [main] regionserver.HRegion(771): > Starting major compaction on region TestMergeTool,,1261540083850 > [junit] 2009-12-23 03:48:22,347 DEBUG [main] regionserver.Store(757): > Started compaction of 1 file(s) into > /user/hudson/TestMergeTool/compaction.dir/1897256012, seqid=7 > [junit] 2009-12-23 03:48:22,395 DEBUG [main] regionserver.Store(764): > Completed major compaction of contents; new storefile is > hdfs://localhost:48623/user/hudson/TestMergeTool/1897256012/contents/2696629698052375339; > store size is 471 > [junit] 2009-12-23 03:48:22,406 INFO [main] regionserver.HRegion(786): > compaction completed on region TestMergeTool,,1261540083850 in 0sec > [junit] 2009-12-23 03:48:22,406 DEBUG [main] regionserver.HRegion(2129): > Files for region: TestMergeTool,,1261540083850 > [junit] 2009-12-23 03:48:22,407 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1897256012/.regioninfo > size=584 > [junit] 2009-12-23 03:48:22,407 DEBUG [main] regionserver.HRegion(2268): d > hdfs://localhost:48623/user/hudson/TestMergeTool/1897256012/contents > [junit] 2009-12-23 03:48:22,408 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1897256012/contents/2696629698052375339 > size=471 > [junit] 2009-12-23 03:48:22,409 INFO [main] regionserver.HRegion(2158): > Creating new region REGION => {NAME => 'TestMergeTool,,1261540102408', > STARTKEY => '', ENDKEY => '', ENCODED => 1888871559, TABLE => {{NAME => > 'TestMergeTool', FAMILIES => [{NAME => 'contents', COMPRESSION => 'NONE', > VERSIONS => '3', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => > 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:22,419 INFO [main] regionserver.HRegion(2167): > starting merge of regions: TestMergeTool,row_0100,1261540101208 and > TestMergeTool,,1261540083850 into new region REGION => {NAME => > 'TestMergeTool,,1261540102408', STARTKEY => '', ENDKEY => '', ENCODED => > 1888871559, TABLE => {{NAME => 'TestMergeTool', FAMILIES => [{NAME => > 'contents', COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2147483647', > BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}} with > start key <> and end key <> > [junit] 2009-12-23 03:48:22,419 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,row_0100,1261540101208: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,419 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:22,420 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:22,420 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:22,420 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,row_0100,1261540101208 > [junit] 2009-12-23 03:48:22,421 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,,1261540083850: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,421 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,,1261540083850 > [junit] 2009-12-23 03:48:22,421 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,,1261540083850 > [junit] 2009-12-23 03:48:22,421 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:22,422 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,,1261540083850 > [junit] 2009-12-23 03:48:22,455 DEBUG [main] regionserver.HRegion(2200): > Files for new region > [junit] 2009-12-23 03:48:22,455 DEBUG [main] regionserver.HRegion(2268): d > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents > [junit] 2009-12-23 03:48:22,456 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents/1183869435374919717 > size=471 > [junit] 2009-12-23 03:48:22,457 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents/5201998480557514100 > size=791 > [junit] 2009-12-23 03:48:22,457 DEBUG [main] regionserver.HRegion(265): > Opening region TestMergeTool,,1261540102408, encoded=1888871559 > [junit] 2009-12-23 03:48:22,494 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1888871559/contents/1183869435374919717, > isReference=false, sequence id=7, length=471, majorCompaction=true > [junit] 2009-12-23 03:48:22,498 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1888871559/contents/5201998480557514100, > isReference=false, sequence id=6, length=791, majorCompaction=true > [junit] 2009-12-23 03:48:22,500 INFO [main] regionserver.HRegion(343): > region TestMergeTool,,1261540102408/1888871559 available; sequence id is 8 > [junit] 2009-12-23 03:48:22,501 INFO [main] regionserver.HRegion(771): > Starting compaction on region TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,510 DEBUG [main] regionserver.Store(750): > Compaction size of contents: 1.2k; Skipped 0 file(s), size: 0 > [junit] 2009-12-23 03:48:22,511 DEBUG [main] regionserver.Store(757): > Started compaction of 2 file(s) into > /user/hudson/TestMergeTool/compaction.dir/1888871559, seqid=7 > [junit] 2009-12-23 03:48:22,570 DEBUG [main] regionserver.Store(764): > Completed compaction of contents; new storefile is > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents/4485189901783544259; > store size is 929 > [junit] 2009-12-23 03:48:22,581 INFO [main] regionserver.HRegion(786): > compaction completed on region TestMergeTool,,1261540102408 in 0sec > [junit] 2009-12-23 03:48:22,583 DEBUG [main] regionserver.HRegion(2207): > Files for new region > [junit] 2009-12-23 03:48:22,584 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/.regioninfo > size=584 > [junit] 2009-12-23 03:48:22,585 DEBUG [main] regionserver.HRegion(2268): d > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents > [junit] 2009-12-23 03:48:22,586 DEBUG [main] regionserver.HRegion(2271): f > hdfs://localhost:48623/user/hudson/TestMergeTool/1888871559/contents/4485189901783544259 > size=929 > [junit] 2009-12-23 03:48:22,586 DEBUG [main] regionserver.HRegion(2003): > DELETING region hdfs://localhost:48623/user/hudson/TestMergeTool/1147554832 > [junit] 2009-12-23 03:48:22,697 DEBUG [main] regionserver.HRegion(2003): > DELETING region hdfs://localhost:48623/user/hudson/TestMergeTool/1897256012 > [junit] 2009-12-23 03:48:22,713 INFO [main] regionserver.HRegion(2213): > merge completed. New region is TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,713 DEBUG [main] util.Merge(319): Removing > region: REGION => {NAME => 'TestMergeTool,row_0100,1261540101208', STARTKEY > => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1147554832, TABLE => {{NAME > => 'TestMergeTool', FAMILIES => [{NAME => 'contents', COMPRESSION => 'NONE', > VERSIONS => '3', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => > 'false', BLOCKCACHE => 'true'}]}} from .META.,,1 > [junit] 2009-12-23 03:48:22,714 DEBUG [main] util.Merge(319): Removing > region: REGION => {NAME => 'TestMergeTool,,1261540083850', STARTKEY => '', > ENDKEY => '', ENCODED => 1897256012, TABLE => {{NAME => 'TestMergeTool', > FAMILIES => [{NAME => 'contents', VERSIONS => '3', COMPRESSION => 'NONE', TTL > => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => > 'true'}]}} from .META.,,1 > [junit] 2009-12-23 03:48:22,715 INFO [main] util.Merge(255): Adding > REGION => {NAME => 'TestMergeTool,,1261540102408', STARTKEY => '', ENDKEY => > '', ENCODED => 1888871559, TABLE => {{NAME => 'TestMergeTool', FAMILIES => > [{NAME => 'contents', COMPRESSION => 'NONE', VERSIONS => '3', TTL => > '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => > 'true'}]}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', > ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', > FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => > 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', > BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => > 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', > BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:22,715 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,,1261540102408: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,715 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,716 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,716 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:22,716 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,716 DEBUG [main] regionserver.HRegion(454): > Closing -ROOT-,,0: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,717 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on -ROOT-,,0 > [junit] 2009-12-23 03:48:22,717 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region -ROOT-,,0 > [junit] 2009-12-23 03:48:22,717 DEBUG [main] regionserver.Store(482): > closed info > [junit] 2009-12-23 03:48:22,717 INFO [main] regionserver.HRegion(490): > Closed -ROOT-,,0 > [junit] 2009-12-23 03:48:22,718 INFO [main] util.MetaUtils(148): CLOSING > META .META.,,1 > [junit] 2009-12-23 03:48:22,718 DEBUG [main] regionserver.HRegion(454): > Closing .META.,,1: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,718 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on .META.,,1 > [junit] 2009-12-23 03:48:22,718 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region .META.,,1 > [junit] 2009-12-23 03:48:22,719 DEBUG [main] regionserver.HRegion(895): > Started memstore flush for region .META.,,1. Current region memstore size 968 > [junit] 2009-12-23 03:48:22,748 DEBUG [main] regionserver.Store(564): > Added > hdfs://localhost:48623/user/hudson/.META./1028785192/historian/7124521150580429384, > entries=2, sequenceid=34, memsize=280, filesize=505 to .META.,,1 > [junit] 2009-12-23 03:48:22,777 DEBUG [main] regionserver.Store(564): > Added > hdfs://localhost:48623/user/hudson/.META./1028785192/info/372924957441297594, > entries=3, sequenceid=34, memsize=688, filesize=826 to .META.,,1 > [junit] 2009-12-23 03:48:22,777 DEBUG [main] regionserver.HRegion(971): > Finished memstore flush of ~968 for region .META.,,1 in 58ms, sequence id=34, > compaction requested=true > [junit] 2009-12-23 03:48:22,777 DEBUG [main] regionserver.Store(482): > closed historian > [junit] 2009-12-23 03:48:22,778 DEBUG [main] regionserver.Store(482): > closed info > [junit] 2009-12-23 03:48:22,778 INFO [main] regionserver.HRegion(490): > Closed .META.,,1 > [junit] 2009-12-23 03:48:22,809 WARN [main] conf.Configuration(616): > fs.checkpoint.size is deprecated. Instead, use dfs.namenode.checkpoint.size > [junit] 2009-12-23 03:48:22,810 WARN [main] conf.Configuration(616): > fs.checkpoint.dir is deprecated. Instead, use dfs.namenode.checkpoint.dir > [junit] 2009-12-23 03:48:22,810 WARN [main] conf.Configuration(616): > fs.checkpoint.edits.dir is deprecated. Instead, use > dfs.namenode.checkpoint.edits.dir > [junit] 2009-12-23 03:48:22,810 WARN [main] conf.Configuration(616): > fs.checkpoint.period is deprecated. Instead, use > dfs.namenode.checkpoint.period > [junit] 2009-12-23 03:48:22,823 INFO [main] wal.HLog(321): Roll > /user/hudson/.logs_1261540101873/hlog.dat.1261540101883, entries=6, > calcsize=1083, filesize=1007. New hlog > /user/hudson/.logs_1261540101873/hlog.dat.1261540102793 > [junit] 2009-12-23 03:48:22,823 DEBUG [main] wal.HLog(330): Last sequence > written is empty. Deleting all old hlogs > [junit] 2009-12-23 03:48:22,824 INFO [main] wal.HLog(490): removing old > hlog file /user/hudson/.logs_1261540101873/hlog.dat.1261540101883 whose > highest sequence/edit id is 33 > [junit] 2009-12-23 03:48:22,833 DEBUG [main.logSyncer] > wal.HLog$LogSyncer(704): main.logSyncerinterrupted while waiting for sync > requests > [junit] 2009-12-23 03:48:22,834 INFO [main.logSyncer] > wal.HLog$LogSyncer(708): main.logSyncer exiting > [junit] 2009-12-23 03:48:22,834 DEBUG [main] wal.HLog(535): closing hlog > writer in hdfs://localhost:48623/user/hudson/.logs_1261540101873 > [junit] 2009-12-23 03:48:22,857 DEBUG [main] regionserver.HRegion(1885): > Opening region: REGION => {NAME => 'TestMergeTool,,1261540102408', STARTKEY > => '', ENDKEY => '', ENCODED => 1888871559, TABLE => {{NAME => > 'TestMergeTool', FAMILIES => [{NAME => 'contents', COMPRESSION => 'NONE', > VERSIONS => '3', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => > 'false', BLOCKCACHE => 'true'}]}} > [junit] 2009-12-23 03:48:22,858 DEBUG [main] regionserver.HRegion(265): > Opening region TestMergeTool,,1261540102408, encoded=1888871559 > [junit] 2009-12-23 03:48:22,864 DEBUG [main] regionserver.Store(417): > loaded /user/hudson/TestMergeTool/1888871559/contents/4485189901783544259, > isReference=false, sequence id=7, length=929, majorCompaction=false > [junit] 2009-12-23 03:48:22,866 INFO [main] regionserver.HRegion(343): > region TestMergeTool,,1261540102408/1888871559 available; sequence id is 8 > [junit] 2009-12-23 03:48:22,871 DEBUG [main] regionserver.HRegion(454): > Closing TestMergeTool,,1261540102408: compactions & flushes disabled > [junit] 2009-12-23 03:48:22,871 DEBUG [main] regionserver.HRegion(471): > Updates disabled for region, no outstanding scanners on > TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,872 DEBUG [main] regionserver.HRegion(478): No > more row locks outstanding on region TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,872 DEBUG [main] regionserver.Store(482): > closed contents > [junit] 2009-12-23 03:48:22,872 INFO [main] regionserver.HRegion(490): > Closed TestMergeTool,,1261540102408 > [junit] 2009-12-23 03:48:22,872 INFO [main] util.TestMergeTool(186): > Verified merging regions 0+1+2+3 and 4 > [junit] 2009-12-23 03:48:22,872 DEBUG [main.logSyncer] > wal.HLog$LogSyncer(704): main.logSyncerinterrupted while waiting for sync > requests > [junit] 2009-12-23 03:48:22,873 INFO [main.logSyncer] > wal.HLog$LogSyncer(708): main.logSyncer exiting > [junit] 2009-12-23 03:48:22,873 DEBUG [main] wal.HLog(535): closing hlog > writer in /tmp/.logs_1261540094128 > [junit] 2009-12-23 03:48:23,902 INFO [main] hbase.HBaseTestCase(627): > Shutting down Mini DFS > [junit] Shutting down the Mini HDFS Cluster > [junit] Shutting down DataNode 1 > [junit] 2009-12-23 03:48:24,011 WARN > [org.apache.hadoop.hdfs.server.datanode.dataxceiverser...@1df2964] > datanode.DataXceiverServer(140): DatanodeRegistration(127.0.0.1:49057, > storageID=DS-573717694-67.195.138.9-49057-1261540086752, infoPort=34369, > ipcPort=36108):DataXceiveServer: java.nio.channels.AsynchronousCloseException > [junit] at > java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) > [junit] at > sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152) > [junit] at > sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) > [junit] at > org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:133) > [junit] at java.lang.Thread.run(Thread.java:619) > [junit] > [junit] Shutting down DataNode 0 > [junit] 2009-12-23 03:48:24,116 WARN > [org.apache.hadoop.hdfs.server.datanode.dataxceiverser...@9300cc] > datanode.DataXceiverServer(140): DatanodeRegistration(127.0.0.1:34972, > storageID=DS-469890356-67.195.138.9-34972-1261540086036, infoPort=60432, > ipcPort=44611):DataXceiveServer: java.nio.channels.AsynchronousCloseException > [junit] at > java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) > [junit] at > sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152) > [junit] at > sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) > [junit] at > org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:133) > [junit] at java.lang.Thread.run(Thread.java:619) > [junit] > [junit] 2009-12-23 03:48:24,218 WARN > [org.apache.hadoop.hdfs.server.namenode.fsnamesystem$replicationmoni...@5eb489] > namenode.FSNamesystem$ReplicationMonitor(2326): ReplicationMonitor thread > received InterruptedException.java.lang.InterruptedException: sleep > interrupted > [junit] 2009-12-23 03:48:24,218 WARN > [org.apache.hadoop.hdfs.server.namenode.decommissionmanager$moni...@3a1ec6] > namenode.DecommissionManager$Monitor(67): Monitor interrupted: > java.lang.InterruptedException: sleep interrupted > [junit] 2009-12-23 03:48:24,229 INFO [main] hbase.HBaseTestCase(638): > Shutting down FileSystem > [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 20.554 sec > [junit] 2009-12-23 03:48:25,276 DEBUG [HCM.shutdownHook] > zookeeper.ZooKeeperWrapper(632): Closed connection with ZooKeeper > [junit] Running org.apache.hadoop.hbase.util.TestRootPath > [junit] 2009-12-23 03:48:25,640 INFO [main] util.TestRootPath(60): Got > expected exception when checking invalid path: > [junit] java.io.IOException: Root directory does not have a scheme > [junit] at > org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:228) > [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:168) > [junit] at junit.framework.TestCase.runBare(TestCase.java:134) > [junit] at junit.framework.TestResult$1.protect(TestResult.java:110) > [junit] at junit.framework.TestResult.runProtected(TestResult.java:128) > [junit] at junit.framework.TestResult.run(TestResult.java:113) > [junit] at junit.framework.TestCase.run(TestCase.java:124) > [junit] at junit.framework.TestSuite.runTest(TestSuite.java:232) > [junit] at junit.framework.TestSuite.run(TestSuite.java:227) > [junit] at > org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83) > [junit] at > junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) > [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.077 sec > > BUILD FAILED > <http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml>:504: > Tests failed! > > Total time: 28 minutes 11 seconds > [locks-and-latches] Releasing all the locks > [locks-and-latches] All the locks released > Archiving artifacts > Recording test results > Publishing Clover coverage report... > No Clover report will be published due to a Build Failure > >
