See <http://hudson.zones.apache.org/hudson/job/HBase-Patch/1032/changes>
Changes:
[jdcryans] HBASE-2041 Change WAL default configuration values
------------------------------------------
[...truncated 960196 lines...]
[junit] 2009-12-15 01:21:10,113 INFO [main] wal.HLog(854): edit=3,
write=.META./.META.,,1/25
[junit] 2009-12-15 01:21:10,113 INFO [main] util.Merge(255): Adding REGION
=> {NAME => 'TestMergeTool,row_0100,1260840069783', STARTKEY => 'row_0100',
ENDKEY => 'row_0600', ENCODED => 193780815, 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-15 01:21:10,114 INFO [main] wal.HLog(854): edit=4,
write=.META./.META.,,1/26
[junit] 2009-12-15 01:21:10,114 DEBUG [main] regionserver.HRegion(454):
Closing TestMergeTool,row_0100,1260840069783: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,114 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on
TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,114 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,115 DEBUG [main] regionserver.Store(483):
closed contents
[junit] 2009-12-15 01:21:10,115 INFO [main] regionserver.HRegion(490):
Closed TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,115 DEBUG [main] regionserver.HRegion(454):
Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,115 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-12-15 01:21:10,115 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region -ROOT-,,0
[junit] 2009-12-15 01:21:10,116 DEBUG [main] regionserver.Store(483):
closed info
[junit] 2009-12-15 01:21:10,116 INFO [main] regionserver.HRegion(490):
Closed -ROOT-,,0
[junit] 2009-12-15 01:21:10,116 INFO [main] util.MetaUtils(148): CLOSING
META .META.,,1
[junit] 2009-12-15 01:21:10,116 DEBUG [main] regionserver.HRegion(454):
Closing .META.,,1: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,116 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-12-15 01:21:10,117 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region .META.,,1
[junit] 2009-12-15 01:21:10,117 DEBUG [main] regionserver.HRegion(895):
Started memstore flush for region .META.,,1. Current region memstore size 1016
[junit] 2009-12-15 01:21:10,154 DEBUG [main] regionserver.Store(565): Added
hdfs://localhost:47723/user/hudson/.META./1028785192/historian/2780637978965774559,
entries=2, sequenceid=27, memsize=288, filesize=521 to .META.,,1
[junit] 2009-12-15 01:21:10,193 DEBUG [main] regionserver.Store(565): Added
hdfs://localhost:47723/user/hudson/.META./1028785192/info/2840594722686356594,
entries=3, sequenceid=27, memsize=728, filesize=874 to .META.,,1
[junit] 2009-12-15 01:21:10,194 DEBUG [main] regionserver.HRegion(971):
Finished memstore flush of ~1016 for region .META.,,1 in 77ms, sequence id=27,
compaction requested=true
[junit] 2009-12-15 01:21:10,194 DEBUG [main] regionserver.Store(483):
closed historian
[junit] 2009-12-15 01:21:10,194 DEBUG [main] regionserver.Store(483):
closed info
[junit] 2009-12-15 01:21:10,195 INFO [main] regionserver.HRegion(490):
Closed .META.,,1
[junit] 2009-12-15 01:21:10,227 INFO [main] wal.HLog(322): Roll
/user/hudson/.logs_1260840069354/hlog.dat.1260840069460, entries=6,
calcsize=1131, filesize=1055. New hlog
/user/hudson/.logs_1260840069354/hlog.dat.1260840070211
[junit] 2009-12-15 01:21:10,227 DEBUG [main] wal.HLog(331): Last sequence
written is empty. Deleting all old hlogs
[junit] 2009-12-15 01:21:10,227 INFO [main] wal.HLog(550): removing old
hlog file /user/hudson/.logs_1260840069354/hlog.dat.1260840069460 whose highest
sequence/edit id is 26
[junit] 2009-12-15 01:21:10,242 DEBUG [main.logSyncer]
wal.HLog$LogSyncer(763): main.logSyncerinterrupted while waiting for sync
requests
[junit] 2009-12-15 01:21:10,243 INFO [main.logSyncer]
wal.HLog$LogSyncer(767): main.logSyncer exiting
[junit] 2009-12-15 01:21:10,243 DEBUG [main] wal.HLog(595): closing hlog
writer in hdfs://localhost:47723/user/hudson/.logs_1260840069354
[junit] 2009-12-15 01:21:10,278 DEBUG [main] regionserver.HRegion(1885):
Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1260840069783',
STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 193780815, TABLE =>
{{NAME => 'TestMergeTool', FAMILIES => [{NAME => 'contents', VERSIONS => '3',
COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY =>
'false', BLOCKCACHE => 'true'}]}}
[junit] 2009-12-15 01:21:10,278 DEBUG [main] regionserver.HRegion(265):
Opening region TestMergeTool,row_0100,1260840069783, encoded=193780815
[junit] 2009-12-15 01:21:10,285 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/TestMergeTool/193780815/contents/6814109759872896693,
isReference=false, sequence id=6, length=837, majorCompaction=false
[junit] 2009-12-15 01:21:10,287 INFO [main] regionserver.HRegion(343):
region TestMergeTool,row_0100,1260840069783/193780815 available; sequence id is
7
[junit] 2009-12-15 01:21:10,291 DEBUG [main] regionserver.HRegion(454):
Closing TestMergeTool,row_0100,1260840069783: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,291 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on
TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,291 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,292 DEBUG [main] regionserver.Store(483):
closed contents
[junit] 2009-12-15 01:21:10,292 INFO [main] regionserver.HRegion(490):
Closed TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,292 INFO [main] util.TestMergeTool(186):
Verified merging regions 0+1+2 and 3
[junit] 2009-12-15 01:21:10,292 INFO [main] util.TestMergeTool(173):
merging regions 0+1+2+3 and 4
[junit] 2009-12-15 01:21:10,292 WARN [main] conf.Configuration(616):
mapred.used.genericoptionsparser is deprecated. Instead, use
mapreduce.client.genericoptionsparser.used
[junit] 2009-12-15 01:21:10,293 WARN [main] conf.Configuration(616):
mapred.used.genericoptionsparser is deprecated. Instead, use
mapreduce.client.genericoptionsparser.used
[junit] 2009-12-15 01:21:10,293 INFO [main] util.Merge(82): Verifying that
file system is available...
[junit] 2009-12-15 01:21:10,294 INFO [main] util.Merge(91): Verifying that
HBase is not running...
[junit] 2009-12-15 01:21:10,315 WARN [main] conf.Configuration(616):
fs.checkpoint.size is deprecated. Instead, use dfs.namenode.checkpoint.size
[junit] 2009-12-15 01:21:10,316 WARN [main] conf.Configuration(616):
fs.checkpoint.dir is deprecated. Instead, use dfs.namenode.checkpoint.dir
[junit] 2009-12-15 01:21:10,316 WARN [main] conf.Configuration(616):
fs.checkpoint.edits.dir is deprecated. Instead, use
dfs.namenode.checkpoint.edits.dir
[junit] 2009-12-15 01:21:10,316 WARN [main] conf.Configuration(616):
fs.checkpoint.period is deprecated. Instead, use dfs.namenode.checkpoint.period
[junit] 2009-12-15 01:21:10,317 INFO [main] util.Merge(197): Merging
regions TestMergeTool,row_0100,1260840069783 and TestMergeTool,,1260840060783
in table TestMergeTool
[junit] 2009-12-15 01:21:10,331 INFO [main] wal.HLog(234): HLog
configuration: blocksize=67108864, rollsize=63753420, enabled=true,
flushlogentries=1, optionallogflushinternal=1000ms
[junit] 2009-12-15 01:21:10,346 INFO [main] wal.HLog(322): New hlog
/user/hudson/.logs_1260840070318/hlog.dat.1260840070331
[junit] 2009-12-15 01:21:10,346 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-15 01:21:10,347 DEBUG [main] regionserver.HRegion(265):
Opening region -ROOT-,,0, encoded=70236052
[junit] 2009-12-15 01:21:10,353 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/-ROOT-/70236052/info/2089104646664809789,
isReference=false, sequence id=2, length=809, majorCompaction=false
[junit] 2009-12-15 01:21:10,355 INFO [main] regionserver.HRegion(343):
region -ROOT-,,0/70236052 available; sequence id is 3
[junit] 2009-12-15 01:21:10,356 INFO [main] regionserver.HRegion(771):
Starting compaction on region -ROOT-,,0
[junit] 2009-12-15 01:21:10,357 INFO [main] regionserver.HRegion(786):
compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-12-15 01:21:10,358 INFO [main] util.Merge(211): Found meta
for region1 .META.,,1, meta for region2 .META.,,1
[junit] 2009-12-15 01:21:10,358 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-15 01:21:10,359 DEBUG [main] regionserver.HRegion(265):
Opening region .META.,,1, encoded=1028785192
[junit] 2009-12-15 01:21:10,365 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/.META./1028785192/historian/2780637978965774559,
isReference=false, sequence id=27, length=521, majorCompaction=false
[junit] 2009-12-15 01:21:10,369 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/.META./1028785192/historian/6415616598034655632,
isReference=false, sequence id=20, length=651, majorCompaction=false
[junit] 2009-12-15 01:21:10,376 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/.META./1028785192/info/2432470090917703621,
isReference=false, sequence id=20, length=994, majorCompaction=false
[junit] 2009-12-15 01:21:10,380 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/.META./1028785192/info/2840594722686356594,
isReference=false, sequence id=27, length=874, majorCompaction=false
[junit] 2009-12-15 01:21:10,384 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/.META./1028785192/info/992144208877318391,
isReference=false, sequence id=6, length=2226, majorCompaction=false
[junit] 2009-12-15 01:21:10,386 INFO [main] regionserver.HRegion(343):
region .META.,,1/1028785192 available; sequence id is 28
[junit] 2009-12-15 01:21:10,387 INFO [main] regionserver.HRegion(771):
Starting compaction on region .META.,,1
[junit] 2009-12-15 01:21:10,402 DEBUG [main] regionserver.Store(751):
Compaction size of historian: 1.1k; Skipped 0 file(s), size: 0
[junit] 2009-12-15 01:21:10,403 DEBUG [main] regionserver.Store(758):
Started compaction of 2 file(s) into
/user/hudson/.META./compaction.dir/1028785192, seqid=27
[junit] 2009-12-15 01:21:10,493 DEBUG [main] regionserver.Store(765):
Completed compaction of historian; new storefile is
hdfs://localhost:47723/user/hudson/.META./1028785192/historian/7220944802610178180;
store size is 781
[junit] 2009-12-15 01:21:10,494 DEBUG [main] regionserver.Store(751):
Compaction size of info: 4.0k; Skipped 1 file(s), size: 2226
[junit] 2009-12-15 01:21:10,495 DEBUG [main] regionserver.Store(758):
Started compaction of 2 file(s) into
/user/hudson/.META./compaction.dir/1028785192, seqid=27
[junit] 2009-12-15 01:21:10,584 DEBUG [main] regionserver.Store(765):
Completed compaction of info; new storefile is
hdfs://localhost:47723/user/hudson/.META./1028785192/info/8655112949574335316;
store size is 3.3k
[junit] 2009-12-15 01:21:10,600 INFO [main] regionserver.HRegion(786):
compaction completed on region .META.,,1 in 0sec
[junit] 2009-12-15 01:21:10,600 INFO [main] util.MetaUtils(125): OPENING
META .META.,,1
[junit] 2009-12-15 01:21:10,602 DEBUG [main] regionserver.HRegion(1885):
Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1260840069783',
STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 193780815, TABLE =>
{{NAME => 'TestMergeTool', FAMILIES => [{NAME => 'contents', COMPRESSION =>
'NONE', VERSIONS => '3', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY
=> 'false', BLOCKCACHE => 'true'}]}}
[junit] 2009-12-15 01:21:10,603 DEBUG [main] regionserver.HRegion(265):
Opening region TestMergeTool,row_0100,1260840069783, encoded=193780815
[junit] 2009-12-15 01:21:10,622 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/TestMergeTool/193780815/contents/6814109759872896693,
isReference=false, sequence id=6, length=837, majorCompaction=false
[junit] 2009-12-15 01:21:10,624 INFO [main] regionserver.HRegion(343):
region TestMergeTool,row_0100,1260840069783/193780815 available; sequence id is
7
[junit] 2009-12-15 01:21:10,625 DEBUG [main] regionserver.HRegion(1885):
Opening region: REGION => {NAME => 'TestMergeTool,,1260840060783', STARTKEY =>
'', ENDKEY => '', ENCODED => 2049848451, TABLE => {{NAME => 'TestMergeTool',
FAMILIES => [{NAME => 'contents', VERSIONS => '3', COMPRESSION => 'NONE', TTL
=> '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE =>
'true'}]}}
[junit] 2009-12-15 01:21:10,625 DEBUG [main] regionserver.HRegion(265):
Opening region TestMergeTool,,1260840060783, encoded=2049848451
[junit] 2009-12-15 01:21:10,632 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/TestMergeTool/2049848451/contents/6158170300459619079,
isReference=false, sequence id=7, length=517, majorCompaction=false
[junit] 2009-12-15 01:21:10,634 INFO [main] regionserver.HRegion(343):
region TestMergeTool,,1260840060783/2049848451 available; sequence id is 8
[junit] 2009-12-15 01:21:10,634 INFO [main] regionserver.HRegion(771):
Starting major compaction on region TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,649 DEBUG [main] regionserver.Store(758):
Started compaction of 1 file(s) into
/user/hudson/TestMergeTool/compaction.dir/193780815, seqid=6
[junit] 2009-12-15 01:21:10,827 DEBUG [main] regionserver.Store(765):
Completed major compaction of contents; new storefile is
hdfs://localhost:47723/user/hudson/TestMergeTool/193780815/contents/3210832989930718045;
store size is 837
[junit] 2009-12-15 01:21:10,843 INFO [main] regionserver.HRegion(786):
compaction completed on region TestMergeTool,row_0100,1260840069783 in 0sec
[junit] 2009-12-15 01:21:10,843 DEBUG [main] regionserver.HRegion(2124):
Files for region: TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,844 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/193780815/.regioninfo size=631
[junit] 2009-12-15 01:21:10,844 DEBUG [main] regionserver.HRegion(2268): d
hdfs://localhost:47723/user/hudson/TestMergeTool/193780815/contents
[junit] 2009-12-15 01:21:10,845 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/193780815/contents/3210832989930718045
size=837
[junit] 2009-12-15 01:21:10,845 INFO [main] regionserver.HRegion(771):
Starting major compaction on region TestMergeTool,,1260840060783
[junit] 2009-12-15 01:21:10,863 DEBUG [main] regionserver.Store(758):
Started compaction of 1 file(s) into
/user/hudson/TestMergeTool/compaction.dir/2049848451, seqid=7
[junit] 2009-12-15 01:21:10,938 DEBUG [main] regionserver.Store(765):
Completed major compaction of contents; new storefile is
hdfs://localhost:47723/user/hudson/TestMergeTool/2049848451/contents/7359636313313266678;
store size is 517
[junit] 2009-12-15 01:21:10,954 INFO [main] regionserver.HRegion(786):
compaction completed on region TestMergeTool,,1260840060783 in 0sec
[junit] 2009-12-15 01:21:10,954 DEBUG [main] regionserver.HRegion(2129):
Files for region: TestMergeTool,,1260840060783
[junit] 2009-12-15 01:21:10,955 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/2049848451/.regioninfo size=584
[junit] 2009-12-15 01:21:10,955 DEBUG [main] regionserver.HRegion(2268): d
hdfs://localhost:47723/user/hudson/TestMergeTool/2049848451/contents
[junit] 2009-12-15 01:21:10,956 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/2049848451/contents/7359636313313266678
size=517
[junit] 2009-12-15 01:21:10,956 INFO [main] regionserver.HRegion(2158):
Creating new region REGION => {NAME => 'TestMergeTool,,1260840070956', STARTKEY
=> '', ENDKEY => '', ENCODED => 1498580675, TABLE => {{NAME => 'TestMergeTool',
FAMILIES => [{NAME => 'contents', COMPRESSION => 'NONE', VERSIONS => '3', TTL
=> '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE =>
'true'}]}}
[junit] 2009-12-15 01:21:10,974 INFO [main] regionserver.HRegion(2167):
starting merge of regions: TestMergeTool,row_0100,1260840069783 and
TestMergeTool,,1260840060783 into new region REGION => {NAME =>
'TestMergeTool,,1260840070956', STARTKEY => '', ENDKEY => '', ENCODED =>
1498580675, 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-15 01:21:10,974 DEBUG [main] regionserver.HRegion(454):
Closing TestMergeTool,row_0100,1260840069783: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,975 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on
TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,975 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,975 DEBUG [main] regionserver.Store(483):
closed contents
[junit] 2009-12-15 01:21:10,975 INFO [main] regionserver.HRegion(490):
Closed TestMergeTool,row_0100,1260840069783
[junit] 2009-12-15 01:21:10,975 DEBUG [main] regionserver.HRegion(454):
Closing TestMergeTool,,1260840060783: compactions & flushes disabled
[junit] 2009-12-15 01:21:10,976 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on
TestMergeTool,,1260840060783
[junit] 2009-12-15 01:21:10,976 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region TestMergeTool,,1260840060783
[junit] 2009-12-15 01:21:10,976 DEBUG [main] regionserver.Store(483):
closed contents
[junit] 2009-12-15 01:21:10,976 INFO [main] regionserver.HRegion(490):
Closed TestMergeTool,,1260840060783
[junit] 2009-12-15 01:21:11,022 DEBUG [main] regionserver.HRegion(2200):
Files for new region
[junit] 2009-12-15 01:21:11,023 DEBUG [main] regionserver.HRegion(2268): d
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents
[junit] 2009-12-15 01:21:11,024 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents/2151866176996142902
size=517
[junit] 2009-12-15 01:21:11,024 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents/7068373864078189248
size=837
[junit] 2009-12-15 01:21:11,024 DEBUG [main] regionserver.HRegion(265):
Opening region TestMergeTool,,1260840070956, encoded=1498580675
[junit] 2009-12-15 01:21:11,067 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/TestMergeTool/1498580675/contents/2151866176996142902,
isReference=false, sequence id=7, length=517, majorCompaction=true
[junit] 2009-12-15 01:21:11,070 DEBUG [main] regionserver.Store(418):
loaded /user/hudson/TestMergeTool/1498580675/contents/7068373864078189248,
isReference=false, sequence id=6, length=837, majorCompaction=true
[junit] 2009-12-15 01:21:11,072 INFO [main] regionserver.HRegion(343):
region TestMergeTool,,1260840070956/1498580675 available; sequence id is 8
[junit] 2009-12-15 01:21:11,072 INFO [main] regionserver.HRegion(771):
Starting compaction on region TestMergeTool,,1260840070956
[junit] 2009-12-15 01:21:11,084 DEBUG [main] regionserver.Store(751):
Compaction size of contents: 1.3k; Skipped 0 file(s), size: 0
[junit] 2009-12-15 01:21:11,084 DEBUG [main] regionserver.Store(758):
Started compaction of 2 file(s) into
/user/hudson/TestMergeTool/compaction.dir/1498580675, seqid=7
[junit] 2009-12-15 01:21:11,173 DEBUG [main] regionserver.Store(765):
Completed compaction of contents; new storefile is
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents/894702647827739546;
store size is 1021
[junit] 2009-12-15 01:21:11,189 INFO [main] regionserver.HRegion(786):
compaction completed on region TestMergeTool,,1260840070956 in 0sec
[junit] 2009-12-15 01:21:11,190 DEBUG [main] regionserver.HRegion(2207):
Files for new region
[junit] 2009-12-15 01:21:11,191 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/.regioninfo size=584
[junit] 2009-12-15 01:21:11,191 DEBUG [main] regionserver.HRegion(2268): d
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents
[junit] 2009-12-15 01:21:11,192 DEBUG [main] regionserver.HRegion(2271): f
hdfs://localhost:47723/user/hudson/TestMergeTool/1498580675/contents/894702647827739546
size=1021
[junit] 2009-12-15 01:21:11,192 DEBUG [main] regionserver.HRegion(2003):
DELETING region hdfs://localhost:47723/user/hudson/TestMergeTool/193780815
[junit] 2009-12-15 01:21:11,209 DEBUG [main] regionserver.HRegion(2003):
DELETING region hdfs://localhost:47723/user/hudson/TestMergeTool/2049848451
[junit] 2009-12-15 01:21:11,231 INFO [main] regionserver.HRegion(2213):
merge completed. New region is TestMergeTool,,1260840070956
[junit] 2009-12-15 01:21:11,231 DEBUG [main] util.Merge(319): Removing
region: REGION => {NAME => 'TestMergeTool,row_0100,1260840069783', STARTKEY =>
'row_0100', ENDKEY => 'row_0600', ENCODED => 193780815, 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-15 01:21:11,232 INFO [main] wal.HLog(854): edit=0,
write=.META./.META.,,1/29
[junit] 2009-12-15 01:21:11,232 INFO [main] wal.HLog(854): edit=1,
write=.META./.META.,,1/30
[junit] 2009-12-15 01:21:11,232 DEBUG [main] util.Merge(319): Removing
region: REGION => {NAME => 'TestMergeTool,,1260840060783', STARTKEY => '',
ENDKEY => '', ENCODED => 2049848451, 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-15 01:21:11,233 INFO [main] wal.HLog(854): edit=2,
write=.META./.META.,,1/31
[junit] 2009-12-15 01:21:11,233 INFO [main] wal.HLog(854): edit=3,
write=.META./.META.,,1/32
[junit] 2009-12-15 01:21:11,234 INFO [main] util.Merge(255): Adding REGION
=> {NAME => 'TestMergeTool,,1260840070956', STARTKEY => '', ENDKEY => '',
ENCODED => 1498580675, 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-15 01:21:11,234 INFO [main] wal.HLog(854): edit=4,
write=.META./.META.,,1/33
[junit] 2009-12-15 01:21:11,235 DEBUG [main] regionserver.HRegion(454):
Closing TestMergeTool,,1260840070956: compactions & flushes disabled
[junit] 2009-12-15 01:21:11,235 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on
TestMergeTool,,1260840070956
[junit] 2009-12-15 01:21:11,235 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region TestMergeTool,,1260840070956
[junit] 2009-12-15 01:21:11,235 DEBUG [main] regionserver.Store(483):
closed contents
[junit] 2009-12-15 01:21:11,235 INFO [main] regionserver.HRegion(490):
Closed TestMergeTool,,1260840070956
[junit] 2009-12-15 01:21:11,236 DEBUG [main] regionserver.HRegion(454):
Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-12-15 01:21:11,236 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-12-15 01:21:11,236 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region -ROOT-,,0
[junit] 2009-12-15 01:21:11,236 DEBUG [main] regionserver.Store(483):
closed info
[junit] 2009-12-15 01:21:11,236 INFO [main] regionserver.HRegion(490):
Closed -ROOT-,,0
[junit] 2009-12-15 01:21:11,237 INFO [main] util.MetaUtils(148): CLOSING
META .META.,,1
[junit] 2009-12-15 01:21:11,237 DEBUG [main] regionserver.HRegion(454):
Closing .META.,,1: compactions & flushes disabled
[junit] 2009-12-15 01:21:11,237 DEBUG [main] regionserver.HRegion(471):
Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-12-15 01:21:11,237 DEBUG [main] regionserver.HRegion(478): No
more row locks outstanding on region .META.,,1
[junit] 2009-12-15 01:21:11,237 DEBUG [main] regionserver.HRegion(895):
Started memstore flush for region .META.,,1. Current region memstore size 968
[junit] 2009-12-15 01:21:11,276 DEBUG [main] regionserver.Store(565): Added
hdfs://localhost:47723/user/hudson/.META./1028785192/historian/7836137733373065942,
entries=2, sequenceid=34, memsize=280, filesize=505 to .META.,,1
[junit] 2009-12-15 01:21:11,315 DEBUG [main] regionserver.Store(565): Added
hdfs://localhost:47723/user/hudson/.META./1028785192/info/4790919223936761099,
entries=3, sequenceid=34, memsize=688, filesize=826 to .META.,,1
[junit] 2009-12-15 01:21:11,316 DEBUG [main] regionserver.HRegion(971):
Finished memstore flush of ~968 for region .META.,,1 in 79ms, sequence id=34,
compaction requested=true
[junit] 2009-12-15 01:21:11,316 DEBUG [main] regionserver.Store(483):
closed historian
[junit] 2009-12-15 01:21:11,316 DEBUG [main] regionserver.Store(483):
closed info
[junit] 2009-12-15 01:21:11,316 INFO [main] regionserver.HRegion(490):
Closed .META.,,1
[junit] 2009-12-15 01:21:11,354 INFO [main] wal.HLog(322): Roll
/user/hudson/.logs_1260840070318/hlog.dat.1260840070331, entries=6,
calcsize=1083, filesize=1007. New hlog
/user/hudson/.logs_1260840070318/hlog.dat.1260840071336
[junit] 2009-12-15 01:21:11,354 DEBUG [main] wal.HLog(331): Last sequence
written is empty. Deleting all old hlogs
[junit] 2009-12-15 01:21:11,354 INFO [main] wal.HLog(550): removing old
hlog file /user/hudson/.logs_1260840070318/hlog.dat.1260840070331 whose highest
sequence/edit id is 33
[junit] 2009-12-15 01:22:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:23:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:24:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:25:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:26:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:27:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:28:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:29:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:30:06,021 DEBUG [pool-1-thread-1]
hfile.LruBlockCache(548): Cache Stats: Sizes: Total=0.4698105MB (492632),
Free=98.14269MB (102910072), Max=98.6125MB (103402704), Counts: Blocks=8,
Access=68, Hit=45, Miss=23, Evictions=0, Evicted=0, Ratios: Hit
Ratio=66.17646813392639%, Miss Ratio=33.82352888584137%, Evicted/Run=NaN
[junit] 2009-12-15 01:31:00,688 FATAL [main.logSyncer] wal.HLog(828): Could
not append. Requesting close of hlog
[junit] java.io.IOException: DF
[junit] Running org.apache.hadoop.hbase.util.TestMergeTool
[junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
[junit] Test org.apache.hadoop.hbase.util.TestMergeTool FAILED (timeout)
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-12-15 01:31:02,241 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:229)
[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.078 sec
BUILD FAILED
<http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml>:504:
Tests failed!
Total time: 39 minutes 35 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Archiving artifacts
Recording test results
ERROR: Failed to archive test reports
hudson.util.IOException2: remote file operation failed
at hudson.FilePath.act(FilePath.java:672)
at hudson.FilePath.act(FilePath.java:660)
at
hudson.tasks.junit.JUnitResultArchiver.perform(JUnitResultArchiver.java:117)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
at
hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:480)
at
hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:466)
at
hudson.model.AbstractBuild$AbstractRunner.performAllBuildStep(AbstractBuild.java:454)
at hudson.model.Build$RunnerImpl.post2(Build.java:181)
at
hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:438)
at hudson.model.Run.run(Run.java:1143)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:123)
Caused by: java.io.IOException: Remote call failed
at hudson.remoting.Channel.call(Channel.java:558)
at hudson.FilePath.act(FilePath.java:667)
... 12 more
Caused by: java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf(Arrays.java:2786)
at java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:94)
at
java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1838)
at
java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1747)
at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1161)
at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:326)
at hudson.remoting.UserRequest._serialize(UserRequest.java:141)
at hudson.remoting.UserRequest.serialize(UserRequest.java:150)
at hudson.remoting.UserRequest.perform(UserRequest.java:112)
at hudson.remoting.UserRequest.perform(UserRequest.java:48)
at hudson.remoting.Request$2.run(Request.java:236)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure
