hbase-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jean-Daniel Cryans <jdcry...@apache.org>
Subject Re: Build failed in Hudson: HBase-Patch #1044
Date Wed, 23 Dec 2009 04:17:39 GMT
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
<hudson@hudson.zones.apache.org> 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.DataXceiverServer@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.DataXceiverServer@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$ReplicationMonitor@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$Monitor@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
>
>

Mime
View raw message