You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/03/20 04:01:59 UTC
Build failed in Hudson: HBase-Patch #539
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/539/changes
Changes:
[stack] HBASE-1270 Fix TestInfoServers
------------------------------------------
[...truncated 37287 lines...]
[junit] 2009-03-20 03:13:32,836 DEBUG [main] regionserver.HRegion(2440): Files for region: TestMergeTool,row_0100,1237518812434
[junit] 2009-03-20 03:13:32,837 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:48090/user/hudson/TestMergeTool/1458130801/contents
[junit] 2009-03-20 03:13:32,838 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:48090/user/hudson/TestMergeTool/1458130801/contents/6587352923206587083 size=718
[junit] 2009-03-20 03:13:32,838 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,,1237518780910
[junit] 2009-03-20 03:13:32,843 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/444003835/contents/3720517125982726215
[junit] 2009-03-20 03:13:32,867 DEBUG [main] regionserver.Store(707): Completed major compaction of 444003835/contents store size is 419.0
[junit] 2009-03-20 03:13:32,868 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237518780910 in 0sec
[junit] 2009-03-20 03:13:32,868 DEBUG [main] regionserver.HRegion(2445): Files for region: TestMergeTool,,1237518780910
[junit] 2009-03-20 03:13:32,869 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:48090/user/hudson/TestMergeTool/444003835/contents
[junit] 2009-03-20 03:13:32,869 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:48090/user/hudson/TestMergeTool/444003835/contents/67637472060244810 size=419
[junit] 2009-03-20 03:13:32,870 INFO [main] regionserver.HRegion(2466): Creating new region REGION => {NAME => 'TestMergeTool,,1237518812870', STARTKEY => '', ENDKEY => '', ENCODED => 2049739120, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-20 03:13:32,875 INFO [main] regionserver.HRegion(2475): starting merge of regions: TestMergeTool,row_0100,1237518812434 and TestMergeTool,,1237518780910 into new region REGION => {NAME => 'TestMergeTool,,1237518812870', STARTKEY => '', ENDKEY => '', ENCODED => 2049739120, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <> and end key <>
[junit] 2009-03-20 03:13:32,875 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237518812434: compactions & flushes disabled
[junit] 2009-03-20 03:13:32,875 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237518812434
[junit] 2009-03-20 03:13:32,875 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237518812434
[junit] 2009-03-20 03:13:32,876 DEBUG [main] regionserver.Store(434): closed 1458130801/contents
[junit] 2009-03-20 03:13:32,876 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237518812434
[junit] 2009-03-20 03:13:32,876 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237518780910: compactions & flushes disabled
[junit] 2009-03-20 03:13:32,876 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237518780910
[junit] 2009-03-20 03:13:32,876 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237518780910
[junit] 2009-03-20 03:13:32,877 DEBUG [main] regionserver.Store(434): closed 444003835/contents
[junit] 2009-03-20 03:13:32,877 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237518780910
[junit] 2009-03-20 03:13:32,899 DEBUG [main] regionserver.HRegion(2510): Files for new region
[junit] 2009-03-20 03:13:32,900 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:48090/user/hudson/TestMergeTool/2049739120/contents
[junit] 2009-03-20 03:13:32,901 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:48090/user/hudson/TestMergeTool/2049739120/contents/1223579493935252277 size=718
[junit] 2009-03-20 03:13:32,901 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:48090/user/hudson/TestMergeTool/2049739120/contents/7107440665587513115 size=419
[junit] 2009-03-20 03:13:32,901 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237518812870/2049739120
[junit] 2009-03-20 03:13:32,905 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@130c132
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 03:13:32,905 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:32,905 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:32,907 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/2049739120/contents/1223579493935252277, isReference=false, sequence id=5, length=718, majorCompaction=true
[junit] 2009-03-20 03:13:32,911 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/2049739120/contents/7107440665587513115, isReference=false, sequence id=6, length=419, majorCompaction=true
[junit] 2009-03-20 03:13:32,911 DEBUG [main] regionserver.Store(213): Loaded 2 file(s) in Store 2049739120/contents, max sequence id 6
[junit] 2009-03-20 03:13:32,912 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237518812870 is 7
[junit] 2009-03-20 03:13:32,913 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237518812870/2049739120 available
[junit] 2009-03-20 03:13:32,914 INFO [main] regionserver.HRegion(701): starting compaction on region TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:32,916 DEBUG [main] regionserver.Store(683): Compaction size of 2049739120/contents: 1.1k; Skipped 0 file(s), size: 0
[junit] 2009-03-20 03:13:32,954 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/2049739120/contents/6386074743477233092
[junit] 2009-03-20 03:13:32,969 DEBUG [main] regionserver.Store(707): Completed compaction of 2049739120/contents store size is 804.0
[junit] 2009-03-20 03:13:32,969 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237518812870 in 0sec
[junit] 2009-03-20 03:13:32,970 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-20 03:13:32,971 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:48090/user/hudson/TestMergeTool/2049739120/contents
[junit] 2009-03-20 03:13:32,971 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:48090/user/hudson/TestMergeTool/2049739120/contents/2323191788684413350 size=804
[junit] 2009-03-20 03:13:32,972 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:48090/user/hudson/TestMergeTool/1458130801
[junit] 2009-03-20 03:13:32,973 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:48090/user/hudson/TestMergeTool/444003835
[junit] 2009-03-20 03:13:32,973 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:32,974 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237518812434', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1458130801, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-20 03:13:32,975 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237518780910', STARTKEY => '', ENDKEY => '', ENCODED => 444003835, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-20 03:13:32,978 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237518812870', STARTKEY => '', ENDKEY => '', ENCODED => 2049739120, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-20 03:13:32,979 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237518812870: compactions & flushes disabled
[junit] 2009-03-20 03:13:32,979 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:32,979 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:32,979 DEBUG [main] regionserver.Store(434): closed 2049739120/contents
[junit] 2009-03-20 03:13:32,979 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:32,980 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-20 03:13:32,980 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-20 03:13:32,980 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-20 03:13:32,980 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-20 03:13:32,980 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-20 03:13:32,980 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-20 03:13:32,981 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-20 03:13:32,981 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-20 03:13:32,981 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-20 03:13:32,993 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:48090/user/hudson/.META./1028785192/info/1491889135714065334, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-20 03:13:32,993 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 12ms, sequence id=21, compaction requested=true
[junit] 2009-03-20 03:13:32,993 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-20 03:13:32,994 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-20 03:13:32,994 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-20 03:13:33,010 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:48090/user/hudson/log_1237518812700/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237518812700/hlog.dat.1237518813008
[junit] 2009-03-20 03:13:33,010 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-20 03:13:33,010 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237518812700/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-20 03:13:33,011 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:48090/user/hudson/log_1237518812700
[junit] 2009-03-20 03:13:33,017 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237518812870', STARTKEY => '', ENDKEY => '', ENCODED => 2049739120, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-20 03:13:33,018 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237518812870/2049739120
[junit] 2009-03-20 03:13:33,022 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/2049739120/contents/2323191788684413350, isReference=false, sequence id=6, length=804, majorCompaction=false
[junit] 2009-03-20 03:13:33,023 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 2049739120/contents, max sequence id 6
[junit] 2009-03-20 03:13:33,024 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237518812870 is 7
[junit] 2009-03-20 03:13:33,025 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237518812870/2049739120 available
[junit] 2009-03-20 03:13:33,025 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-20 03:13:33,049 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237518812870: compactions & flushes disabled
[junit] 2009-03-20 03:13:33,049 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:33,049 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:33,049 DEBUG [main] regionserver.Store(434): closed 2049739120/contents
[junit] 2009-03-20 03:13:33,049 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237518812870
[junit] 2009-03-20 03:13:33,050 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-20 03:13:33,050 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237518811298
[junit] 2009-03-20 03:13:33,056 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-20 03:13:33,056 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-20 03:13:33,056 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35028]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35028]
[junit] 2009-03-20 03:13:33,061 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:35028
[junit] 2009-03-20 03:13:33,061 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@14627a
[junit] 2009-03-20 03:13:33,136 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 03:13:33,136 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@cb42cf
[junit] 2009-03-20 03:13:33,195 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 03:13:33,196 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@134eb84
[junit] 2009-03-20 03:13:33,198 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@873723] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:41646, storageID=DS-1539882887-67.195.138.9-41646-1237518810621, infoPort=35028, ipcPort=55678):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-20 03:13:33,582 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@113c817
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 03:13:33,582 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:33,582 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:33,905 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@1fe0d66
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 03:13:33,906 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:33,906 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:34,004 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@404eb2
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 03:13:34,005 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:34,005 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] Shutting down DataNode 0
[junit] 2009-03-20 03:13:34,199 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=47181]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=47181]
[junit] 2009-03-20 03:13:34,199 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:47181
[junit] 2009-03-20 03:13:34,200 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1000bcf
[junit] 2009-03-20 03:13:34,268 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 03:13:34,269 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e33e18
[junit] 2009-03-20 03:13:34,320 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 03:13:34,321 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@15e92d7
[junit] 2009-03-20 03:13:34,321 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@457d21] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:59208, storageID=DS-67083093-67.195.138.9-59208-1237518810348, infoPort=47181, ipcPort=50104):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-20 03:13:34,325 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@76fb1b
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 03:13:34,325 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:34,326 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 03:13:35,422 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=46483]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=46483]
[junit] 2009-03-20 03:13:35,423 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:46483
[junit] 2009-03-20 03:13:35,424 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@acdd02
[junit] 2009-03-20 03:13:35,474 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 03:13:35,475 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@130633a
[junit] 2009-03-20 03:13:35,522 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 03:13:35,523 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@9cfec1
[junit] 2009-03-20 03:13:35,523 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@b2c6a6] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 34.719 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-20 03:13:35,870 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.071 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-20 03:13:36,205 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-20 03:13:36,210 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-20 03:13:36,210 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-20 03:13:36,211 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-20 03:13:36,212 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-20 03:13:36,215 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-20 03:13:36,216 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.086 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 28 minutes 13 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
Hudson build is back to normal: HBase-Patch #545
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/545/changes
Build failed in Hudson: HBase-Patch #544
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/544/changes
Changes:
[stack] HBASE-803 Atomic increment operations -- part 2 -- fix crash
------------------------------------------
[...truncated 24422 lines...]
[junit] 2009-03-25 10:57:47,520 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237978667050', STARTKEY => 'row_0100', ENDKEY => 'row_0400', ENCODED => 1986790457, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-25 10:57:47,523 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0500,1237978664313', STARTKEY => 'row_0500', ENDKEY => 'row_0600', ENCODED => 31613743, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-25 10:57:47,527 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,row_0100,1237978667465', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 483323205, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,527 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237978667465: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,528 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,528 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,528 DEBUG [main] regionserver.Store(434): closed 483323205/contents
[junit] 2009-03-25 10:57:47,528 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,528 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,529 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-25 10:57:47,529 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-25 10:57:47,529 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-25 10:57:47,529 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-25 10:57:47,529 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,529 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-25 10:57:47,530 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-25 10:57:47,530 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 968.0
[junit] 2009-03-25 10:57:47,542 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:36190/user/hudson/.META./1028785192/info/3637409403534532287, entries=3, sequenceid=17, memsize=968.0, filesize=968.0 to .META.,,1
[junit] 2009-03-25 10:57:47,542 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~968.0 for region .META.,,1 in 12ms, sequence id=17, compaction requested=true
[junit] 2009-03-25 10:57:47,543 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-25 10:57:47,543 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-25 10:57:47,543 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-25 10:57:47,560 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:36190/user/hudson/log_1237978667288/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237978667288/hlog.dat.1237978667559
[junit] 2009-03-25 10:57:47,560 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-25 10:57:47,560 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237978667288/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2009-03-25 10:57:47,561 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:36190/user/hudson/log_1237978667288
[junit] 2009-03-25 10:57:47,572 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237978667465', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 483323205, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,572 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237978667465/483323205
[junit] 2009-03-25 10:57:47,577 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/483323205/contents/8514607181268722785, isReference=false, sequence id=5, length=761, majorCompaction=false
[junit] 2009-03-25 10:57:47,578 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 483323205/contents, max sequence id 5
[junit] 2009-03-25 10:57:47,582 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237978667465 is 6
[junit] 2009-03-25 10:57:47,583 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237978667465/483323205 available
[junit] 2009-03-25 10:57:47,583 DEBUG [main] regionserver.HLog(217): changing sequence number from 5 to 6
[junit] 2009-03-25 10:57:47,609 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237978667465: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,609 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,609 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,609 DEBUG [main] regionserver.Store(434): closed 483323205/contents
[junit] 2009-03-25 10:57:47,610 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,610 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2 and 3
[junit] 2009-03-25 10:57:47,610 INFO [main] util.TestMergeTool(156): merging regions 0+1+2+3 and 4
[junit] 2009-03-25 10:57:47,610 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-03-25 10:57:47,611 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-03-25 10:57:47,728 INFO [main] util.Merge(190): Merging regions TestMergeTool,row_0100,1237978667465 and TestMergeTool,,1237978664313 in table TestMergeTool
[junit] 2009-03-25 10:57:47,731 INFO [main] regionserver.HLog(273): New log writer: /user/hudson/log_1237978667728/hlog.dat.1237978667730
[junit] 2009-03-25 10:57:47,731 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,732 DEBUG [main] regionserver.HRegion(237): Opening region -ROOT-,,0/70236052
[junit] 2009-03-25 10:57:47,750 DEBUG [main] regionserver.Store(383): loaded /user/hudson/-ROOT-/70236052/info/1687446191283567179, isReference=false, sequence id=1, length=856, majorCompaction=false
[junit] 2009-03-25 10:57:47,750 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 70236052/info, max sequence id 1
[junit] 2009-03-25 10:57:47,753 DEBUG [main] regionserver.HRegion(297): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-03-25 10:57:47,755 INFO [main] regionserver.HRegion(314): region -ROOT-,,0/70236052 available
[junit] 2009-03-25 10:57:47,755 DEBUG [main] regionserver.HLog(217): changing sequence number from 0 to 2
[junit] 2009-03-25 10:57:47,755 INFO [main] regionserver.HRegion(701): starting compaction on region -ROOT-,,0
[junit] 2009-03-25 10:57:47,757 INFO [main] regionserver.HRegion(716): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-03-25 10:57:47,759 INFO [main] util.Merge(204): Found meta for region1 .META.,,1, meta for region2 .META.,,1
[junit] 2009-03-25 10:57:47,759 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,759 DEBUG [main] regionserver.HRegion(237): Opening region .META.,,1/1028785192
[junit] 2009-03-25 10:57:47,766 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/1481969681305354611, isReference=false, sequence id=13, length=1531, majorCompaction=false
[junit] 2009-03-25 10:57:47,770 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/3637409403534532287, isReference=false, sequence id=17, length=968, majorCompaction=false
[junit] 2009-03-25 10:57:47,774 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/5497342255300839986, isReference=false, sequence id=5, length=2330, majorCompaction=false
[junit] 2009-03-25 10:57:47,774 DEBUG [main] regionserver.Store(213): Loaded 3 file(s) in Store 1028785192/info, max sequence id 17
[junit] 2009-03-25 10:57:47,776 DEBUG [main] regionserver.HRegion(297): Next sequence id for region .META.,,1 is 18
[junit] 2009-03-25 10:57:47,777 INFO [main] regionserver.HRegion(314): region .META.,,1/1028785192 available
[junit] 2009-03-25 10:57:47,778 DEBUG [main] regionserver.HLog(217): changing sequence number from 2 to 18
[junit] 2009-03-25 10:57:47,778 INFO [main] regionserver.HRegion(701): starting compaction on region .META.,,1
[junit] 2009-03-25 10:57:47,779 DEBUG [main] regionserver.Store(619): 1028785192/historian: no store files to compact
[junit] 2009-03-25 10:57:47,781 DEBUG [main] regionserver.Store(683): Compaction size of 1028785192/info: 4.7k; Skipped 0 file(s), size: 0
[junit] 2009-03-25 10:57:47,785 DEBUG [main] regionserver.Store(692): Started compaction of 3 file(s) into /user/hudson/.META./1028785192/info/3064122389868345668
[junit] 2009-03-25 10:57:47,807 DEBUG [main] regionserver.Store(707): Completed compaction of 1028785192/info store size is 3.9k
[junit] 2009-03-25 10:57:47,808 INFO [main] regionserver.HRegion(716): compaction completed on region .META.,,1 in 0sec
[junit] 2009-03-25 10:57:47,810 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237978667465', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 483323205, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,811 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237978667465/483323205
[junit] 2009-03-25 10:57:47,818 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/483323205/contents/8514607181268722785, isReference=false, sequence id=5, length=761, majorCompaction=false
[junit] 2009-03-25 10:57:47,818 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 483323205/contents, max sequence id 5
[junit] 2009-03-25 10:57:47,819 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237978667465 is 6
[junit] 2009-03-25 10:57:47,821 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237978667465/483323205 available
[junit] 2009-03-25 10:57:47,821 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237978664313', STARTKEY => '', ENDKEY => '', ENCODED => 539220582, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,821 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237978664313/539220582
[junit] 2009-03-25 10:57:47,826 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/539220582/contents/5444456770098715385, isReference=false, sequence id=6, length=462, majorCompaction=false
[junit] 2009-03-25 10:57:47,827 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 539220582/contents, max sequence id 6
[junit] 2009-03-25 10:57:47,828 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237978664313 is 7
[junit] 2009-03-25 10:57:47,829 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237978664313/539220582 available
[junit] 2009-03-25 10:57:47,829 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,834 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/483323205/contents/3260141529647213813
[junit] 2009-03-25 10:57:47,857 DEBUG [main] regionserver.Store(707): Completed major compaction of 483323205/contents store size is 761.0
[junit] 2009-03-25 10:57:47,858 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,row_0100,1237978667465 in 0sec
[junit] 2009-03-25 10:57:47,858 DEBUG [main] regionserver.HRegion(2440): Files for region: TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,859 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:36190/user/hudson/TestMergeTool/483323205/contents
[junit] 2009-03-25 10:57:47,860 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:36190/user/hudson/TestMergeTool/483323205/contents/5764239083654065699 size=761
[junit] 2009-03-25 10:57:47,860 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,,1237978664313
[junit] 2009-03-25 10:57:47,865 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/539220582/contents/7941812437844119967
[junit] 2009-03-25 10:57:47,879 DEBUG [main] regionserver.Store(707): Completed major compaction of 539220582/contents store size is 462.0
[junit] 2009-03-25 10:57:47,879 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237978664313 in 0sec
[junit] 2009-03-25 10:57:47,879 DEBUG [main] regionserver.HRegion(2445): Files for region: TestMergeTool,,1237978664313
[junit] 2009-03-25 10:57:47,880 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:36190/user/hudson/TestMergeTool/539220582/contents
[junit] 2009-03-25 10:57:47,881 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:36190/user/hudson/TestMergeTool/539220582/contents/3480325254428219047 size=462
[junit] 2009-03-25 10:57:47,881 INFO [main] regionserver.HRegion(2466): Creating new region REGION => {NAME => 'TestMergeTool,,1237978667881', STARTKEY => '', ENDKEY => '', ENCODED => 1092687669, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,883 INFO [main] regionserver.HRegion(2475): starting merge of regions: TestMergeTool,row_0100,1237978667465 and TestMergeTool,,1237978664313 into new region REGION => {NAME => 'TestMergeTool,,1237978667881', STARTKEY => '', ENDKEY => '', ENCODED => 1092687669, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <> and end key <>
[junit] 2009-03-25 10:57:47,883 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237978667465: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,883 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,884 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,884 DEBUG [main] regionserver.Store(434): closed 483323205/contents
[junit] 2009-03-25 10:57:47,884 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237978667465
[junit] 2009-03-25 10:57:47,884 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237978664313: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,884 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237978664313
[junit] 2009-03-25 10:57:47,885 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237978664313
[junit] 2009-03-25 10:57:47,885 DEBUG [main] regionserver.Store(434): closed 539220582/contents
[junit] 2009-03-25 10:57:47,885 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237978664313
[junit] 2009-03-25 10:57:47,896 DEBUG [main] regionserver.HRegion(2510): Files for new region
[junit] 2009-03-25 10:57:47,897 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:36190/user/hudson/TestMergeTool/1092687669/contents
[junit] 2009-03-25 10:57:47,898 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:36190/user/hudson/TestMergeTool/1092687669/contents/1720702563331747380 size=462
[junit] 2009-03-25 10:57:47,898 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:36190/user/hudson/TestMergeTool/1092687669/contents/8056382654884204524 size=761
[junit] 2009-03-25 10:57:47,899 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237978667881/1092687669
[junit] 2009-03-25 10:57:47,904 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1092687669/contents/1720702563331747380, isReference=false, sequence id=6, length=462, majorCompaction=true
[junit] 2009-03-25 10:57:47,908 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1092687669/contents/8056382654884204524, isReference=false, sequence id=5, length=761, majorCompaction=true
[junit] 2009-03-25 10:57:47,908 DEBUG [main] regionserver.Store(213): Loaded 2 file(s) in Store 1092687669/contents, max sequence id 6
[junit] 2009-03-25 10:57:47,909 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237978667881 is 7
[junit] 2009-03-25 10:57:47,910 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237978667881/1092687669 available
[junit] 2009-03-25 10:57:47,911 INFO [main] regionserver.HRegion(701): starting compaction on region TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:47,913 DEBUG [main] regionserver.Store(683): Compaction size of 1092687669/contents: 1.2k; Skipped 0 file(s), size: 0
[junit] 2009-03-25 10:57:47,917 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/1092687669/contents/7201478332828572406
[junit] 2009-03-25 10:57:47,931 DEBUG [main] regionserver.Store(707): Completed compaction of 1092687669/contents store size is 890.0
[junit] 2009-03-25 10:57:47,931 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237978667881 in 0sec
[junit] 2009-03-25 10:57:47,932 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-25 10:57:47,933 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:36190/user/hudson/TestMergeTool/1092687669/contents
[junit] 2009-03-25 10:57:47,933 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:36190/user/hudson/TestMergeTool/1092687669/contents/3656414949403565464 size=890
[junit] 2009-03-25 10:57:47,934 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:36190/user/hudson/TestMergeTool/483323205
[junit] 2009-03-25 10:57:47,935 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:36190/user/hudson/TestMergeTool/539220582
[junit] 2009-03-25 10:57:47,935 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:47,936 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237978667465', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 483323205, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-25 10:57:47,937 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237978664313', STARTKEY => '', ENDKEY => '', ENCODED => 539220582, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-25 10:57:47,940 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237978667881', STARTKEY => '', ENDKEY => '', ENCODED => 1092687669, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,941 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237978667881: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,941 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:47,941 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:47,941 DEBUG [main] regionserver.Store(434): closed 1092687669/contents
[junit] 2009-03-25 10:57:47,942 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:47,942 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,942 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-25 10:57:47,942 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-25 10:57:47,942 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-25 10:57:47,943 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-25 10:57:47,943 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-25 10:57:47,943 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-25 10:57:47,943 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-25 10:57:47,943 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-25 10:57:47,962 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:36190/user/hudson/.META./1028785192/info/3167853667440384683, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-25 10:57:47,962 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 19ms, sequence id=21, compaction requested=true
[junit] 2009-03-25 10:57:47,962 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-25 10:57:47,963 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-25 10:57:47,963 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-25 10:57:47,984 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:36190/user/hudson/log_1237978667728/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237978667728/hlog.dat.1237978667982
[junit] 2009-03-25 10:57:47,984 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-25 10:57:47,984 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237978667728/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-25 10:57:47,985 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:36190/user/hudson/log_1237978667728
[junit] 2009-03-25 10:57:47,992 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237978667881', STARTKEY => '', ENDKEY => '', ENCODED => 1092687669, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-25 10:57:47,992 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237978667881/1092687669
[junit] 2009-03-25 10:57:47,997 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1092687669/contents/3656414949403565464, isReference=false, sequence id=6, length=890, majorCompaction=false
[junit] 2009-03-25 10:57:47,997 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1092687669/contents, max sequence id 6
[junit] 2009-03-25 10:57:47,998 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237978667881 is 7
[junit] 2009-03-25 10:57:47,999 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237978667881/1092687669 available
[junit] 2009-03-25 10:57:48,000 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-25 10:57:48,020 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237978667881: compactions & flushes disabled
[junit] 2009-03-25 10:57:48,021 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:48,021 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:48,021 DEBUG [main] regionserver.Store(434): closed 1092687669/contents
[junit] 2009-03-25 10:57:48,021 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237978667881
[junit] 2009-03-25 10:57:48,021 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-25 10:57:48,021 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237978666308
[junit] 2009-03-25 10:57:48,439 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-25 10:57:48,439 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-25 10:57:48,439 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=58053]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=58053]
[junit] 2009-03-25 10:57:48,443 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:58053
[junit] 2009-03-25 10:57:48,443 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@9bad5a
[junit] 2009-03-25 10:57:48,521 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-25 10:57:48,522 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@d58ce2
[junit] 2009-03-25 10:57:48,581 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-25 10:57:48,581 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1302fc5
[junit] 2009-03-25 10:57:48,585 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@ad2c30] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:59023, storageID=DS-407575145-67.195.138.9-59023-1237978665826, infoPort=58053, ipcPort=59167):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-03-25 10:57:49,583 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=41070]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=41070]
[junit] 2009-03-25 10:57:49,583 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:41070
[junit] 2009-03-25 10:57:49,583 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1b54362
[junit] 2009-03-25 10:57:49,652 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-25 10:57:49,653 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1a80aea
[junit] 2009-03-25 10:57:49,706 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-25 10:57:49,706 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@fa39d7
[junit] 2009-03-25 10:57:49,707 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@6963d0] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:48796, storageID=DS-750659235-67.195.138.9-48796-1237978665579, infoPort=41070, ipcPort=46507):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-25 10:57:50,808 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57785]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57785]
[junit] 2009-03-25 10:57:50,808 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:57785
[junit] 2009-03-25 10:57:50,809 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@3e96cf
[junit] 2009-03-25 10:57:50,860 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-25 10:57:50,860 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@5c3987
[junit] 2009-03-25 10:57:50,908 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-25 10:57:50,909 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@113beb5
[junit] 2009-03-25 10:57:50,909 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@e1eea8] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 6.701 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-25 10:57:51,263 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.072 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-25 10:57:51,650 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-25 10:57:51,655 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-25 10:57:51,656 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-25 10:57:51,656 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-25 10:57:51,658 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-25 10:57:51,661 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-25 10:57:51,661 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.086 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 28 minutes 5 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
Build failed in Hudson: HBase-Patch #543
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/543/changes
Changes:
[stack] HBASE-1283 thrift's package descrpition needs to update for start/stop procedure
------------------------------------------
[...truncated 24315 lines...]
[junit] 2009-03-24 03:16:47,021 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237864606556', STARTKEY => 'row_0100', ENDKEY => 'row_0400', ENCODED => 1316539015, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-24 03:16:47,023 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0500,1237864603755', STARTKEY => 'row_0500', ENDKEY => 'row_0600', ENCODED => 547738600, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-24 03:16:47,027 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,row_0100,1237864606964', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1435425508, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,028 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237864606964: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,028 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,028 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,029 DEBUG [main] regionserver.Store(434): closed 1435425508/contents
[junit] 2009-03-24 03:16:47,029 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,029 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,029 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-24 03:16:47,029 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-24 03:16:47,030 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-24 03:16:47,030 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-24 03:16:47,030 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,030 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-24 03:16:47,030 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-24 03:16:47,030 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 968.0
[junit] 2009-03-24 03:16:47,044 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:33187/user/hudson/.META./1028785192/info/4707938262205082035, entries=3, sequenceid=17, memsize=968.0, filesize=968.0 to .META.,,1
[junit] 2009-03-24 03:16:47,044 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~968.0 for region .META.,,1 in 14ms, sequence id=17, compaction requested=true
[junit] 2009-03-24 03:16:47,044 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-24 03:16:47,045 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-24 03:16:47,045 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-24 03:16:47,052 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:33187/user/hudson/log_1237864606821/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237864606821/hlog.dat.1237864607050
[junit] 2009-03-24 03:16:47,052 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-24 03:16:47,052 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237864606821/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2009-03-24 03:16:47,053 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:33187/user/hudson/log_1237864606821
[junit] 2009-03-24 03:16:47,058 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237864606964', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1435425508, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,059 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237864606964/1435425508
[junit] 2009-03-24 03:16:47,064 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1435425508/contents/1416867873645456759, isReference=false, sequence id=5, length=804, majorCompaction=false
[junit] 2009-03-24 03:16:47,064 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1435425508/contents, max sequence id 5
[junit] 2009-03-24 03:16:47,065 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237864606964 is 6
[junit] 2009-03-24 03:16:47,066 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237864606964/1435425508 available
[junit] 2009-03-24 03:16:47,066 DEBUG [main] regionserver.HLog(217): changing sequence number from 5 to 6
[junit] 2009-03-24 03:16:47,080 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237864606964: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,080 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,080 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,080 DEBUG [main] regionserver.Store(434): closed 1435425508/contents
[junit] 2009-03-24 03:16:47,081 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,081 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2 and 3
[junit] 2009-03-24 03:16:47,081 INFO [main] util.TestMergeTool(156): merging regions 0+1+2+3 and 4
[junit] 2009-03-24 03:16:47,081 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-03-24 03:16:47,082 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-03-24 03:16:47,206 INFO [main] util.Merge(190): Merging regions TestMergeTool,row_0100,1237864606964 and TestMergeTool,,1237864603755 in table TestMergeTool
[junit] 2009-03-24 03:16:47,210 INFO [main] regionserver.HLog(273): New log writer: /user/hudson/log_1237864607207/hlog.dat.1237864607208
[junit] 2009-03-24 03:16:47,210 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,210 DEBUG [main] regionserver.HRegion(237): Opening region -ROOT-,,0/70236052
[junit] 2009-03-24 03:16:47,216 DEBUG [main] regionserver.Store(383): loaded /user/hudson/-ROOT-/70236052/info/5499745103574564460, isReference=false, sequence id=1, length=856, majorCompaction=false
[junit] 2009-03-24 03:16:47,216 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 70236052/info, max sequence id 1
[junit] 2009-03-24 03:16:47,217 DEBUG [main] regionserver.HRegion(297): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-03-24 03:16:47,218 INFO [main] regionserver.HRegion(314): region -ROOT-,,0/70236052 available
[junit] 2009-03-24 03:16:47,218 DEBUG [main] regionserver.HLog(217): changing sequence number from 0 to 2
[junit] 2009-03-24 03:16:47,218 INFO [main] regionserver.HRegion(701): starting compaction on region -ROOT-,,0
[junit] 2009-03-24 03:16:47,220 INFO [main] regionserver.HRegion(716): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-03-24 03:16:47,222 INFO [main] util.Merge(204): Found meta for region1 .META.,,1, meta for region2 .META.,,1
[junit] 2009-03-24 03:16:47,222 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,223 DEBUG [main] regionserver.HRegion(237): Opening region .META.,,1/1028785192
[junit] 2009-03-24 03:16:47,228 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/4707938262205082035, isReference=false, sequence id=17, length=968, majorCompaction=false
[junit] 2009-03-24 03:16:47,232 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/6031205252373249676, isReference=false, sequence id=5, length=2330, majorCompaction=false
[junit] 2009-03-24 03:16:47,235 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/6838516380475536243, isReference=false, sequence id=13, length=1531, majorCompaction=false
[junit] 2009-03-24 03:16:47,236 DEBUG [main] regionserver.Store(213): Loaded 3 file(s) in Store 1028785192/info, max sequence id 17
[junit] 2009-03-24 03:16:47,238 DEBUG [main] regionserver.HRegion(297): Next sequence id for region .META.,,1 is 18
[junit] 2009-03-24 03:16:47,239 INFO [main] regionserver.HRegion(314): region .META.,,1/1028785192 available
[junit] 2009-03-24 03:16:47,240 DEBUG [main] regionserver.HLog(217): changing sequence number from 2 to 18
[junit] 2009-03-24 03:16:47,240 INFO [main] regionserver.HRegion(701): starting compaction on region .META.,,1
[junit] 2009-03-24 03:16:47,241 DEBUG [main] regionserver.Store(619): 1028785192/historian: no store files to compact
[junit] 2009-03-24 03:16:47,244 DEBUG [main] regionserver.Store(683): Compaction size of 1028785192/info: 4.7k; Skipped 0 file(s), size: 0
[junit] 2009-03-24 03:16:47,248 DEBUG [main] regionserver.Store(692): Started compaction of 3 file(s) into /user/hudson/.META./1028785192/info/6920583197911259649
[junit] 2009-03-24 03:16:47,276 DEBUG [main] regionserver.Store(707): Completed compaction of 1028785192/info store size is 3.9k
[junit] 2009-03-24 03:16:47,277 INFO [main] regionserver.HRegion(716): compaction completed on region .META.,,1 in 0sec
[junit] 2009-03-24 03:16:47,280 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237864606964', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1435425508, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,280 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237864606964/1435425508
[junit] 2009-03-24 03:16:47,285 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1435425508/contents/1416867873645456759, isReference=false, sequence id=5, length=804, majorCompaction=false
[junit] 2009-03-24 03:16:47,285 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1435425508/contents, max sequence id 5
[junit] 2009-03-24 03:16:47,286 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237864606964 is 6
[junit] 2009-03-24 03:16:47,287 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237864606964/1435425508 available
[junit] 2009-03-24 03:16:47,288 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237864603755', STARTKEY => '', ENDKEY => '', ENCODED => 155812872, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,288 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237864603755/155812872
[junit] 2009-03-24 03:16:47,293 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/155812872/contents/367152735698946245, isReference=false, sequence id=6, length=462, majorCompaction=false
[junit] 2009-03-24 03:16:47,293 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 155812872/contents, max sequence id 6
[junit] 2009-03-24 03:16:47,294 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237864603755 is 7
[junit] 2009-03-24 03:16:47,295 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237864603755/155812872 available
[junit] 2009-03-24 03:16:47,295 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,300 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/1435425508/contents/1836683848639654805
[junit] 2009-03-24 03:16:47,326 DEBUG [main] regionserver.Store(707): Completed major compaction of 1435425508/contents store size is 804.0
[junit] 2009-03-24 03:16:47,327 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,row_0100,1237864606964 in 0sec
[junit] 2009-03-24 03:16:47,327 DEBUG [main] regionserver.HRegion(2440): Files for region: TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,328 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:33187/user/hudson/TestMergeTool/1435425508/contents
[junit] 2009-03-24 03:16:47,329 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:33187/user/hudson/TestMergeTool/1435425508/contents/7141017865677193178 size=804
[junit] 2009-03-24 03:16:47,329 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,,1237864603755
[junit] 2009-03-24 03:16:47,333 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/155812872/contents/4901707005894566563
[junit] 2009-03-24 03:16:47,346 DEBUG [main] regionserver.Store(707): Completed major compaction of 155812872/contents store size is 462.0
[junit] 2009-03-24 03:16:47,346 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237864603755 in 0sec
[junit] 2009-03-24 03:16:47,347 DEBUG [main] regionserver.HRegion(2445): Files for region: TestMergeTool,,1237864603755
[junit] 2009-03-24 03:16:47,347 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:33187/user/hudson/TestMergeTool/155812872/contents
[junit] 2009-03-24 03:16:47,348 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:33187/user/hudson/TestMergeTool/155812872/contents/8237751868448056817 size=462
[junit] 2009-03-24 03:16:47,348 INFO [main] regionserver.HRegion(2466): Creating new region REGION => {NAME => 'TestMergeTool,,1237864607348', STARTKEY => '', ENDKEY => '', ENCODED => 26680852, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,350 INFO [main] regionserver.HRegion(2475): starting merge of regions: TestMergeTool,row_0100,1237864606964 and TestMergeTool,,1237864603755 into new region REGION => {NAME => 'TestMergeTool,,1237864607348', STARTKEY => '', ENDKEY => '', ENCODED => 26680852, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <> and end key <>
[junit] 2009-03-24 03:16:47,350 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237864606964: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,350 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,351 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,351 DEBUG [main] regionserver.Store(434): closed 1435425508/contents
[junit] 2009-03-24 03:16:47,351 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237864606964
[junit] 2009-03-24 03:16:47,351 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237864603755: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,351 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237864603755
[junit] 2009-03-24 03:16:47,352 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237864603755
[junit] 2009-03-24 03:16:47,352 DEBUG [main] regionserver.Store(434): closed 155812872/contents
[junit] 2009-03-24 03:16:47,352 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237864603755
[junit] 2009-03-24 03:16:47,361 DEBUG [main] regionserver.HRegion(2510): Files for new region
[junit] 2009-03-24 03:16:47,362 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:33187/user/hudson/TestMergeTool/26680852/contents
[junit] 2009-03-24 03:16:47,363 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:33187/user/hudson/TestMergeTool/26680852/contents/4648446966968187351 size=462
[junit] 2009-03-24 03:16:47,363 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:33187/user/hudson/TestMergeTool/26680852/contents/5554799567041358642 size=804
[junit] 2009-03-24 03:16:47,364 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237864607348/26680852
[junit] 2009-03-24 03:16:47,368 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/26680852/contents/4648446966968187351, isReference=false, sequence id=6, length=462, majorCompaction=true
[junit] 2009-03-24 03:16:47,372 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/26680852/contents/5554799567041358642, isReference=false, sequence id=5, length=804, majorCompaction=true
[junit] 2009-03-24 03:16:47,372 DEBUG [main] regionserver.Store(213): Loaded 2 file(s) in Store 26680852/contents, max sequence id 6
[junit] 2009-03-24 03:16:47,373 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237864607348 is 7
[junit] 2009-03-24 03:16:47,375 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237864607348/26680852 available
[junit] 2009-03-24 03:16:47,375 INFO [main] regionserver.HRegion(701): starting compaction on region TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,377 DEBUG [main] regionserver.Store(683): Compaction size of 26680852/contents: 1.2k; Skipped 0 file(s), size: 0
[junit] 2009-03-24 03:16:47,399 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/26680852/contents/8826737439084969013
[junit] 2009-03-24 03:16:47,413 DEBUG [main] regionserver.Store(707): Completed compaction of 26680852/contents store size is 933.0
[junit] 2009-03-24 03:16:47,414 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237864607348 in 0sec
[junit] 2009-03-24 03:16:47,414 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-24 03:16:47,415 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:33187/user/hudson/TestMergeTool/26680852/contents
[junit] 2009-03-24 03:16:47,416 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:33187/user/hudson/TestMergeTool/26680852/contents/7398226564963201306 size=933
[junit] 2009-03-24 03:16:47,416 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:33187/user/hudson/TestMergeTool/1435425508
[junit] 2009-03-24 03:16:47,417 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:33187/user/hudson/TestMergeTool/155812872
[junit] 2009-03-24 03:16:47,418 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,418 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237864606964', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1435425508, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-24 03:16:47,419 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237864603755', STARTKEY => '', ENDKEY => '', ENCODED => 155812872, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-24 03:16:47,422 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237864607348', STARTKEY => '', ENDKEY => '', ENCODED => 26680852, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,423 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237864607348: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,423 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,423 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,423 DEBUG [main] regionserver.Store(434): closed 26680852/contents
[junit] 2009-03-24 03:16:47,424 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,424 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,424 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-24 03:16:47,424 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-24 03:16:47,424 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-24 03:16:47,424 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-24 03:16:47,425 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,425 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-24 03:16:47,425 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-24 03:16:47,425 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-24 03:16:47,437 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:33187/user/hudson/.META./1028785192/info/2865737506349265425, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-24 03:16:47,438 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 13ms, sequence id=21, compaction requested=true
[junit] 2009-03-24 03:16:47,438 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-24 03:16:47,438 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-24 03:16:47,438 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-24 03:16:47,453 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:33187/user/hudson/log_1237864607207/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237864607207/hlog.dat.1237864607451
[junit] 2009-03-24 03:16:47,453 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-24 03:16:47,453 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237864607207/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-24 03:16:47,454 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:33187/user/hudson/log_1237864607207
[junit] 2009-03-24 03:16:47,460 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237864607348', STARTKEY => '', ENDKEY => '', ENCODED => 26680852, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-24 03:16:47,461 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237864607348/26680852
[junit] 2009-03-24 03:16:47,465 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/26680852/contents/7398226564963201306, isReference=false, sequence id=6, length=933, majorCompaction=false
[junit] 2009-03-24 03:16:47,465 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 26680852/contents, max sequence id 6
[junit] 2009-03-24 03:16:47,466 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237864607348 is 7
[junit] 2009-03-24 03:16:47,467 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237864607348/26680852 available
[junit] 2009-03-24 03:16:47,468 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-24 03:16:47,487 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237864607348: compactions & flushes disabled
[junit] 2009-03-24 03:16:47,487 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,488 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,488 DEBUG [main] regionserver.Store(434): closed 26680852/contents
[junit] 2009-03-24 03:16:47,488 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237864607348
[junit] 2009-03-24 03:16:47,488 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-24 03:16:47,488 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237864605792
[junit] 2009-03-24 03:16:47,494 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-24 03:16:47,494 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-24 03:16:47,495 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34784]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34784]
[junit] 2009-03-24 03:16:47,496 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34784
[junit] 2009-03-24 03:16:47,497 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@179d854
[junit] 2009-03-24 03:16:47,565 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-24 03:16:47,566 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@98350a
[junit] 2009-03-24 03:16:47,624 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-24 03:16:47,624 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@205756
[junit] 2009-03-24 03:16:47,625 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@6c5482] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:45841, storageID=DS-2115082498-67.195.138.9-45841-1237864605316, infoPort=34784, ipcPort=37596):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-03-24 03:16:48,626 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=43547]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=43547]
[junit] 2009-03-24 03:16:48,626 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:43547
[junit] 2009-03-24 03:16:48,627 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@5b675e
[junit] 2009-03-24 03:16:48,697 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-24 03:16:48,698 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e90943
[junit] 2009-03-24 03:16:48,750 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-24 03:16:48,750 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@104fc23
[junit] 2009-03-24 03:16:48,752 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@4eeaaf] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:50187, storageID=DS-1983811236-67.195.138.9-50187-1237864605082, infoPort=43547, ipcPort=38616):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-24 03:16:49,852 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57925]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=57925]
[junit] 2009-03-24 03:16:49,852 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:57925
[junit] 2009-03-24 03:16:49,854 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@2ab653
[junit] 2009-03-24 03:16:49,904 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-24 03:16:49,907 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@3f96ee
[junit] 2009-03-24 03:16:49,955 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-24 03:16:49,955 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1402d5a
[junit] 2009-03-24 03:16:49,955 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@b02928] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 6.306 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-24 03:16:50,333 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.087 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-24 03:16:50,717 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-24 03:16:50,721 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-24 03:16:50,722 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-24 03:16:50,723 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-24 03:16:50,724 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-24 03:16:50,727 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-24 03:16:50,728 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.087 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 26 minutes 13 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
Build failed in Hudson: HBase-Patch #542
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/542/changes
Changes:
[stack] HBASE-1274 TestMergeTable is broken in Hudson
------------------------------------------
[...truncated 24751 lines...]
[junit] 2009-03-23 23:09:16,588 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237849755716', STARTKEY => 'row_0100', ENDKEY => 'row_0400', ENCODED => 650969229, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-23 23:09:16,590 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0500,1237849752957', STARTKEY => 'row_0500', ENDKEY => 'row_0600', ENCODED => 745044614, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-23 23:09:16,594 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,row_0100,1237849756534', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 594635471, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,595 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237849756534: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,595 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,595 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,595 DEBUG [main] regionserver.Store(434): closed 594635471/contents
[junit] 2009-03-23 23:09:16,596 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,596 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,596 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-23 23:09:16,596 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-23 23:09:16,596 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-23 23:09:16,597 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-23 23:09:16,597 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,597 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-23 23:09:16,597 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-23 23:09:16,597 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 968.0
[junit] 2009-03-23 23:09:16,611 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:43708/user/hudson/.META./1028785192/info/1538768886596860005, entries=3, sequenceid=17, memsize=968.0, filesize=968.0 to .META.,,1
[junit] 2009-03-23 23:09:16,611 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~968.0 for region .META.,,1 in 14ms, sequence id=17, compaction requested=true
[junit] 2009-03-23 23:09:16,611 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-23 23:09:16,611 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-23 23:09:16,612 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-23 23:09:16,619 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:43708/user/hudson/log_1237849756370/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237849756370/hlog.dat.1237849756617
[junit] 2009-03-23 23:09:16,619 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-23 23:09:16,619 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237849756370/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2009-03-23 23:09:16,620 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:43708/user/hudson/log_1237849756370
[junit] 2009-03-23 23:09:16,630 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237849756534', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 594635471, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,631 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237849756534/594635471
[junit] 2009-03-23 23:09:16,636 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/594635471/contents/3531018025308098914, isReference=false, sequence id=5, length=761, majorCompaction=false
[junit] 2009-03-23 23:09:16,636 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 594635471/contents, max sequence id 5
[junit] 2009-03-23 23:09:16,637 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237849756534 is 6
[junit] 2009-03-23 23:09:16,638 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237849756534/594635471 available
[junit] 2009-03-23 23:09:16,638 DEBUG [main] regionserver.HLog(217): changing sequence number from 5 to 6
[junit] 2009-03-23 23:09:16,652 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237849756534: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,652 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,652 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,652 DEBUG [main] regionserver.Store(434): closed 594635471/contents
[junit] 2009-03-23 23:09:16,652 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,653 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2 and 3
[junit] 2009-03-23 23:09:16,653 INFO [main] util.TestMergeTool(156): merging regions 0+1+2+3 and 4
[junit] 2009-03-23 23:09:16,653 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-03-23 23:09:16,654 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-03-23 23:09:16,771 INFO [main] util.Merge(190): Merging regions TestMergeTool,row_0100,1237849756534 and TestMergeTool,,1237849752957 in table TestMergeTool
[junit] 2009-03-23 23:09:16,774 INFO [main] regionserver.HLog(273): New log writer: /user/hudson/log_1237849756771/hlog.dat.1237849756772
[junit] 2009-03-23 23:09:16,774 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,775 DEBUG [main] regionserver.HRegion(237): Opening region -ROOT-,,0/70236052
[junit] 2009-03-23 23:09:16,782 DEBUG [main] regionserver.Store(383): loaded /user/hudson/-ROOT-/70236052/info/3933279371582899978, isReference=false, sequence id=1, length=856, majorCompaction=false
[junit] 2009-03-23 23:09:16,783 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 70236052/info, max sequence id 1
[junit] 2009-03-23 23:09:16,784 DEBUG [main] regionserver.HRegion(297): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-03-23 23:09:16,786 INFO [main] regionserver.HRegion(314): region -ROOT-,,0/70236052 available
[junit] 2009-03-23 23:09:16,787 DEBUG [main] regionserver.HLog(217): changing sequence number from 0 to 2
[junit] 2009-03-23 23:09:16,787 INFO [main] regionserver.HRegion(701): starting compaction on region -ROOT-,,0
[junit] 2009-03-23 23:09:16,789 INFO [main] regionserver.HRegion(716): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-03-23 23:09:16,808 INFO [main] util.Merge(204): Found meta for region1 .META.,,1, meta for region2 .META.,,1
[junit] 2009-03-23 23:09:16,808 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,809 DEBUG [main] regionserver.HRegion(237): Opening region .META.,,1/1028785192
[junit] 2009-03-23 23:09:16,816 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/1538768886596860005, isReference=false, sequence id=17, length=968, majorCompaction=false
[junit] 2009-03-23 23:09:16,820 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/329649070878583085, isReference=false, sequence id=13, length=1531, majorCompaction=false
[junit] 2009-03-23 23:09:16,824 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/5726846262073967472, isReference=false, sequence id=5, length=2330, majorCompaction=false
[junit] 2009-03-23 23:09:16,825 DEBUG [main] regionserver.Store(213): Loaded 3 file(s) in Store 1028785192/info, max sequence id 17
[junit] 2009-03-23 23:09:16,827 DEBUG [main] regionserver.HRegion(297): Next sequence id for region .META.,,1 is 18
[junit] 2009-03-23 23:09:16,828 INFO [main] regionserver.HRegion(314): region .META.,,1/1028785192 available
[junit] 2009-03-23 23:09:16,828 DEBUG [main] regionserver.HLog(217): changing sequence number from 2 to 18
[junit] 2009-03-23 23:09:16,828 INFO [main] regionserver.HRegion(701): starting compaction on region .META.,,1
[junit] 2009-03-23 23:09:16,829 DEBUG [main] regionserver.Store(619): 1028785192/historian: no store files to compact
[junit] 2009-03-23 23:09:16,831 DEBUG [main] regionserver.Store(683): Compaction size of 1028785192/info: 4.7k; Skipped 0 file(s), size: 0
[junit] 2009-03-23 23:09:16,844 DEBUG [main] regionserver.Store(692): Started compaction of 3 file(s) into /user/hudson/.META./1028785192/info/9056485218559675493
[junit] 2009-03-23 23:09:16,867 DEBUG [main] regionserver.Store(707): Completed compaction of 1028785192/info store size is 3.9k
[junit] 2009-03-23 23:09:16,868 INFO [main] regionserver.HRegion(716): compaction completed on region .META.,,1 in 0sec
[junit] 2009-03-23 23:09:16,871 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237849756534', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 594635471, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,872 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237849756534/594635471
[junit] 2009-03-23 23:09:16,877 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/594635471/contents/3531018025308098914, isReference=false, sequence id=5, length=761, majorCompaction=false
[junit] 2009-03-23 23:09:16,877 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 594635471/contents, max sequence id 5
[junit] 2009-03-23 23:09:16,878 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237849756534 is 6
[junit] 2009-03-23 23:09:16,879 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237849756534/594635471 available
[junit] 2009-03-23 23:09:16,880 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237849752957', STARTKEY => '', ENDKEY => '', ENCODED => 1252302601, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,880 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237849752957/1252302601
[junit] 2009-03-23 23:09:16,885 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1252302601/contents/4083879025510053082, isReference=false, sequence id=6, length=462, majorCompaction=false
[junit] 2009-03-23 23:09:16,885 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1252302601/contents, max sequence id 6
[junit] 2009-03-23 23:09:16,887 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237849752957 is 7
[junit] 2009-03-23 23:09:16,888 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237849752957/1252302601 available
[junit] 2009-03-23 23:09:16,888 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,892 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/594635471/contents/2843931150038109122
[junit] 2009-03-23 23:09:16,921 DEBUG [main] regionserver.Store(707): Completed major compaction of 594635471/contents store size is 761.0
[junit] 2009-03-23 23:09:16,922 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,row_0100,1237849756534 in 0sec
[junit] 2009-03-23 23:09:16,922 DEBUG [main] regionserver.HRegion(2440): Files for region: TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,923 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:43708/user/hudson/TestMergeTool/594635471/contents
[junit] 2009-03-23 23:09:16,924 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:43708/user/hudson/TestMergeTool/594635471/contents/8272742465132492781 size=761
[junit] 2009-03-23 23:09:16,924 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,,1237849752957
[junit] 2009-03-23 23:09:16,930 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/1252302601/contents/2553877952610573140
[junit] 2009-03-23 23:09:16,944 DEBUG [main] regionserver.Store(707): Completed major compaction of 1252302601/contents store size is 462.0
[junit] 2009-03-23 23:09:16,945 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237849752957 in 0sec
[junit] 2009-03-23 23:09:16,945 DEBUG [main] regionserver.HRegion(2445): Files for region: TestMergeTool,,1237849752957
[junit] 2009-03-23 23:09:16,946 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:43708/user/hudson/TestMergeTool/1252302601/contents
[junit] 2009-03-23 23:09:16,946 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:43708/user/hudson/TestMergeTool/1252302601/contents/4149405721831706106 size=462
[junit] 2009-03-23 23:09:16,947 INFO [main] regionserver.HRegion(2466): Creating new region REGION => {NAME => 'TestMergeTool,,1237849756947', STARTKEY => '', ENDKEY => '', ENCODED => 1027444135, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:16,948 INFO [main] regionserver.HRegion(2475): starting merge of regions: TestMergeTool,row_0100,1237849756534 and TestMergeTool,,1237849752957 into new region REGION => {NAME => 'TestMergeTool,,1237849756947', STARTKEY => '', ENDKEY => '', ENCODED => 1027444135, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <> and end key <>
[junit] 2009-03-23 23:09:16,948 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237849756534: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,949 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,949 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,949 DEBUG [main] regionserver.Store(434): closed 594635471/contents
[junit] 2009-03-23 23:09:16,949 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237849756534
[junit] 2009-03-23 23:09:16,949 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237849752957: compactions & flushes disabled
[junit] 2009-03-23 23:09:16,950 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237849752957
[junit] 2009-03-23 23:09:16,950 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237849752957
[junit] 2009-03-23 23:09:16,950 DEBUG [main] regionserver.Store(434): closed 1252302601/contents
[junit] 2009-03-23 23:09:16,950 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237849752957
[junit] 2009-03-23 23:09:16,964 DEBUG [main] regionserver.HRegion(2510): Files for new region
[junit] 2009-03-23 23:09:16,964 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:43708/user/hudson/TestMergeTool/1027444135/contents
[junit] 2009-03-23 23:09:16,965 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:43708/user/hudson/TestMergeTool/1027444135/contents/5156304902849043473 size=761
[junit] 2009-03-23 23:09:16,966 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:43708/user/hudson/TestMergeTool/1027444135/contents/8553235745433992931 size=462
[junit] 2009-03-23 23:09:16,966 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237849756947/1027444135
[junit] 2009-03-23 23:09:16,972 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1027444135/contents/5156304902849043473, isReference=false, sequence id=5, length=761, majorCompaction=true
[junit] 2009-03-23 23:09:16,975 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1027444135/contents/8553235745433992931, isReference=false, sequence id=6, length=462, majorCompaction=true
[junit] 2009-03-23 23:09:16,976 DEBUG [main] regionserver.Store(213): Loaded 2 file(s) in Store 1027444135/contents, max sequence id 6
[junit] 2009-03-23 23:09:16,977 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237849756947 is 7
[junit] 2009-03-23 23:09:16,981 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237849756947/1027444135 available
[junit] 2009-03-23 23:09:16,981 INFO [main] regionserver.HRegion(701): starting compaction on region TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:16,983 DEBUG [main] regionserver.Store(683): Compaction size of 1027444135/contents: 1.2k; Skipped 0 file(s), size: 0
[junit] 2009-03-23 23:09:16,994 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/1027444135/contents/3240118998749663630
[junit] 2009-03-23 23:09:17,037 DEBUG [main] regionserver.Store(707): Completed compaction of 1027444135/contents store size is 890.0
[junit] 2009-03-23 23:09:17,038 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237849756947 in 0sec
[junit] 2009-03-23 23:09:17,038 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-23 23:09:17,039 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:43708/user/hudson/TestMergeTool/1027444135/contents
[junit] 2009-03-23 23:09:17,040 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:43708/user/hudson/TestMergeTool/1027444135/contents/8822702418985436322 size=890
[junit] 2009-03-23 23:09:17,040 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:43708/user/hudson/TestMergeTool/594635471
[junit] 2009-03-23 23:09:17,041 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:43708/user/hudson/TestMergeTool/1252302601
[junit] 2009-03-23 23:09:17,041 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,042 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237849756534', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 594635471, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-23 23:09:17,043 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237849752957', STARTKEY => '', ENDKEY => '', ENCODED => 1252302601, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-23 23:09:17,046 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237849756947', STARTKEY => '', ENDKEY => '', ENCODED => 1027444135, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:17,046 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237849756947: compactions & flushes disabled
[junit] 2009-03-23 23:09:17,046 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,046 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,047 DEBUG [main] regionserver.Store(434): closed 1027444135/contents
[junit] 2009-03-23 23:09:17,047 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,047 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-23 23:09:17,047 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-23 23:09:17,047 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-23 23:09:17,048 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-23 23:09:17,048 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-23 23:09:17,048 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-23 23:09:17,048 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-23 23:09:17,048 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-23 23:09:17,048 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-23 23:09:17,061 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:43708/user/hudson/.META./1028785192/info/8124324586109158344, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-23 23:09:17,062 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 14ms, sequence id=21, compaction requested=true
[junit] 2009-03-23 23:09:17,062 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-23 23:09:17,062 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-23 23:09:17,062 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-23 23:09:17,074 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:43708/user/hudson/log_1237849756771/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237849756771/hlog.dat.1237849757072
[junit] 2009-03-23 23:09:17,074 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-23 23:09:17,074 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237849756771/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-23 23:09:17,075 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:43708/user/hudson/log_1237849756771
[junit] 2009-03-23 23:09:17,083 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237849756947', STARTKEY => '', ENDKEY => '', ENCODED => 1027444135, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-23 23:09:17,083 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237849756947/1027444135
[junit] 2009-03-23 23:09:17,088 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1027444135/contents/8822702418985436322, isReference=false, sequence id=6, length=890, majorCompaction=false
[junit] 2009-03-23 23:09:17,088 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1027444135/contents, max sequence id 6
[junit] 2009-03-23 23:09:17,089 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237849756947 is 7
[junit] 2009-03-23 23:09:17,090 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237849756947/1027444135 available
[junit] 2009-03-23 23:09:17,090 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-23 23:09:17,109 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237849756947: compactions & flushes disabled
[junit] 2009-03-23 23:09:17,110 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,110 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,110 DEBUG [main] regionserver.Store(434): closed 1027444135/contents
[junit] 2009-03-23 23:09:17,110 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237849756947
[junit] 2009-03-23 23:09:17,110 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-23 23:09:17,111 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237849754976
[junit] 2009-03-23 23:09:17,128 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-23 23:09:17,129 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-23 23:09:17,129 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=37764]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=37764]
[junit] 2009-03-23 23:09:17,132 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:37764
[junit] 2009-03-23 23:09:17,133 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@3a0ab1
[junit] 2009-03-23 23:09:17,208 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-23 23:09:17,208 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@739f3f
[junit] 2009-03-23 23:09:17,270 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-23 23:09:17,271 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1a3ca10
[junit] 2009-03-23 23:09:17,272 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@105eb6f] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:47634, storageID=DS-1260967626-67.195.138.9-47634-1237849754507, infoPort=37764, ipcPort=60434):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-03-23 23:09:17,273 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34794]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=34794]
[junit] 2009-03-23 23:09:17,273 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:34794
[junit] 2009-03-23 23:09:17,274 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@ffd135
[junit] 2009-03-23 23:09:17,343 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-23 23:09:17,344 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e33e18
[junit] 2009-03-23 23:09:17,397 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-23 23:09:17,397 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1c18a4c
[junit] 2009-03-23 23:09:17,398 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@104fc23] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:57986, storageID=DS-1437765307-67.195.138.9-57986-1237849754280, infoPort=34794, ipcPort=55834):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-23 23:09:18,499 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=47234]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=47234]
[junit] 2009-03-23 23:09:18,499 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:47234
[junit] 2009-03-23 23:09:18,500 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@acdd02
[junit] 2009-03-23 23:09:18,552 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-23 23:09:18,552 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@32bd65
[junit] 2009-03-23 23:09:18,599 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-23 23:09:18,600 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@61736e
[junit] 2009-03-23 23:09:18,600 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@15e234c] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 5.748 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-23 23:09:18,982 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.071 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-23 23:09:19,331 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-23 23:09:19,335 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-23 23:09:19,336 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-23 23:09:19,337 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-23 23:09:19,338 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-23 23:09:19,341 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-23 23:09:19,342 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.088 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 27 minutes 4 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
Build failed in Hudson: HBase-Patch #541
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/541/changes
Changes:
[stack] HBASE-1273 ZooKeeper WARN spits out lots of useless messages
------------------------------------------
[...truncated 24393 lines...]
[junit] 2009-03-21 03:14:33,654 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237605273239', STARTKEY => 'row_0100', ENDKEY => 'row_0400', ENCODED => 1005975442, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-21 03:14:33,657 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0500,1237605239317', STARTKEY => 'row_0500', ENDKEY => 'row_0600', ENCODED => 1336691590, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-21 03:14:33,661 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,row_0100,1237605273604', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1303967493, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,662 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237605273604: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,662 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,662 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,662 DEBUG [main] regionserver.Store(434): closed 1303967493/contents
[junit] 2009-03-21 03:14:33,662 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,663 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,663 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-21 03:14:33,663 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-21 03:14:33,663 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-21 03:14:33,663 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-21 03:14:33,663 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,664 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-21 03:14:33,664 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-21 03:14:33,664 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 968.0
[junit] 2009-03-21 03:14:33,676 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:52476/user/hudson/.META./1028785192/info/3805207438086958412, entries=3, sequenceid=17, memsize=968.0, filesize=968.0 to .META.,,1
[junit] 2009-03-21 03:14:33,677 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~968.0 for region .META.,,1 in 13ms, sequence id=17, compaction requested=true
[junit] 2009-03-21 03:14:33,677 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-21 03:14:33,677 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-21 03:14:33,677 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-21 03:14:33,685 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:52476/user/hudson/log_1237605273471/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237605273471/hlog.dat.1237605273684
[junit] 2009-03-21 03:14:33,686 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-21 03:14:33,686 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237605273471/hlog.dat.0 whose highest sequence/edit id is 17
[junit] 2009-03-21 03:14:33,687 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:52476/user/hudson/log_1237605273471
[junit] 2009-03-21 03:14:33,695 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237605273604', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1303967493, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,695 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237605273604/1303967493
[junit] 2009-03-21 03:14:33,700 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1303967493/contents/1136725411393157603, isReference=false, sequence id=5, length=804, majorCompaction=false
[junit] 2009-03-21 03:14:33,701 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1303967493/contents, max sequence id 5
[junit] 2009-03-21 03:14:33,702 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237605273604 is 6
[junit] 2009-03-21 03:14:33,703 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237605273604/1303967493 available
[junit] 2009-03-21 03:14:33,703 DEBUG [main] regionserver.HLog(217): changing sequence number from 5 to 6
[junit] 2009-03-21 03:14:33,717 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237605273604: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,717 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,717 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,718 DEBUG [main] regionserver.Store(434): closed 1303967493/contents
[junit] 2009-03-21 03:14:33,718 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,718 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2 and 3
[junit] 2009-03-21 03:14:33,718 INFO [main] util.TestMergeTool(156): merging regions 0+1+2+3 and 4
[junit] 2009-03-21 03:14:33,719 INFO [main] util.Merge(80): Verifying that file system is available...
[junit] 2009-03-21 03:14:33,719 INFO [main] util.Merge(89): Verifying that HBase is not running...
[junit] 2009-03-21 03:14:33,849 INFO [main] util.Merge(190): Merging regions TestMergeTool,row_0100,1237605273604 and TestMergeTool,,1237605239317 in table TestMergeTool
[junit] 2009-03-21 03:14:33,853 INFO [main] regionserver.HLog(273): New log writer: /user/hudson/log_1237605273850/hlog.dat.1237605273851
[junit] 2009-03-21 03:14:33,853 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '10', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,853 DEBUG [main] regionserver.HRegion(237): Opening region -ROOT-,,0/70236052
[junit] 2009-03-21 03:14:33,858 DEBUG [main] regionserver.Store(383): loaded /user/hudson/-ROOT-/70236052/info/3693442419111546714, isReference=false, sequence id=1, length=856, majorCompaction=false
[junit] 2009-03-21 03:14:33,858 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 70236052/info, max sequence id 1
[junit] 2009-03-21 03:14:33,859 DEBUG [main] regionserver.HRegion(297): Next sequence id for region -ROOT-,,0 is 2
[junit] 2009-03-21 03:14:33,860 INFO [main] regionserver.HRegion(314): region -ROOT-,,0/70236052 available
[junit] 2009-03-21 03:14:33,861 DEBUG [main] regionserver.HLog(217): changing sequence number from 0 to 2
[junit] 2009-03-21 03:14:33,861 INFO [main] regionserver.HRegion(701): starting compaction on region -ROOT-,,0
[junit] 2009-03-21 03:14:33,862 INFO [main] regionserver.HRegion(716): compaction completed on region -ROOT-,,0 in 0sec
[junit] 2009-03-21 03:14:33,864 INFO [main] util.Merge(204): Found meta for region1 .META.,,1, meta for region2 .META.,,1
[junit] 2009-03-21 03:14:33,865 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,865 DEBUG [main] regionserver.HRegion(237): Opening region .META.,,1/1028785192
[junit] 2009-03-21 03:14:33,870 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/245885823880984734, isReference=false, sequence id=13, length=1531, majorCompaction=false
[junit] 2009-03-21 03:14:33,873 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/3330784844313168751, isReference=false, sequence id=5, length=2330, majorCompaction=false
[junit] 2009-03-21 03:14:33,877 DEBUG [main] regionserver.Store(383): loaded /user/hudson/.META./1028785192/info/3805207438086958412, isReference=false, sequence id=17, length=968, majorCompaction=false
[junit] 2009-03-21 03:14:33,877 DEBUG [main] regionserver.Store(213): Loaded 3 file(s) in Store 1028785192/info, max sequence id 17
[junit] 2009-03-21 03:14:33,888 DEBUG [main] regionserver.HRegion(297): Next sequence id for region .META.,,1 is 18
[junit] 2009-03-21 03:14:33,889 INFO [main] regionserver.HRegion(314): region .META.,,1/1028785192 available
[junit] 2009-03-21 03:14:33,889 DEBUG [main] regionserver.HLog(217): changing sequence number from 2 to 18
[junit] 2009-03-21 03:14:33,889 INFO [main] regionserver.HRegion(701): starting compaction on region .META.,,1
[junit] 2009-03-21 03:14:33,890 DEBUG [main] regionserver.Store(619): 1028785192/historian: no store files to compact
[junit] 2009-03-21 03:14:33,891 DEBUG [main] regionserver.Store(683): Compaction size of 1028785192/info: 4.7k; Skipped 0 file(s), size: 0
[junit] 2009-03-21 03:14:33,895 DEBUG [main] regionserver.Store(692): Started compaction of 3 file(s) into /user/hudson/.META./1028785192/info/8069999046440989056
[junit] 2009-03-21 03:14:33,916 DEBUG [main] regionserver.Store(707): Completed compaction of 1028785192/info store size is 3.9k
[junit] 2009-03-21 03:14:33,916 INFO [main] regionserver.HRegion(716): compaction completed on region .META.,,1 in 0sec
[junit] 2009-03-21 03:14:33,919 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,row_0100,1237605273604', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1303967493, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,920 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,row_0100,1237605273604/1303967493
[junit] 2009-03-21 03:14:33,924 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1303967493/contents/1136725411393157603, isReference=false, sequence id=5, length=804, majorCompaction=false
[junit] 2009-03-21 03:14:33,925 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1303967493/contents, max sequence id 5
[junit] 2009-03-21 03:14:33,925 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,row_0100,1237605273604 is 6
[junit] 2009-03-21 03:14:33,927 INFO [main] regionserver.HRegion(314): region TestMergeTool,row_0100,1237605273604/1303967493 available
[junit] 2009-03-21 03:14:33,927 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237605239317', STARTKEY => '', ENDKEY => '', ENCODED => 543356916, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,927 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237605239317/543356916
[junit] 2009-03-21 03:14:33,932 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/543356916/contents/124016612862438724, isReference=false, sequence id=6, length=419, majorCompaction=false
[junit] 2009-03-21 03:14:33,932 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 543356916/contents, max sequence id 6
[junit] 2009-03-21 03:14:33,933 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237605239317 is 7
[junit] 2009-03-21 03:14:33,934 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237605239317/543356916 available
[junit] 2009-03-21 03:14:33,934 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,939 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/1303967493/contents/5208188366971552175
[junit] 2009-03-21 03:14:33,975 DEBUG [main] regionserver.Store(707): Completed major compaction of 1303967493/contents store size is 804.0
[junit] 2009-03-21 03:14:33,975 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,row_0100,1237605273604 in 0sec
[junit] 2009-03-21 03:14:33,975 DEBUG [main] regionserver.HRegion(2440): Files for region: TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,976 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:52476/user/hudson/TestMergeTool/1303967493/contents
[junit] 2009-03-21 03:14:33,977 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:52476/user/hudson/TestMergeTool/1303967493/contents/7791574484341008861 size=804
[junit] 2009-03-21 03:14:33,977 INFO [main] regionserver.HRegion(701): starting major compaction on region TestMergeTool,,1237605239317
[junit] 2009-03-21 03:14:33,981 DEBUG [main] regionserver.Store(692): Started compaction of 1 file(s) into /user/hudson/TestMergeTool/543356916/contents/261534484213113778
[junit] 2009-03-21 03:14:33,994 DEBUG [main] regionserver.Store(707): Completed major compaction of 543356916/contents store size is 419.0
[junit] 2009-03-21 03:14:33,995 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237605239317 in 0sec
[junit] 2009-03-21 03:14:33,995 DEBUG [main] regionserver.HRegion(2445): Files for region: TestMergeTool,,1237605239317
[junit] 2009-03-21 03:14:33,995 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:52476/user/hudson/TestMergeTool/543356916/contents
[junit] 2009-03-21 03:14:33,996 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:52476/user/hudson/TestMergeTool/543356916/contents/5638007260606810157 size=419
[junit] 2009-03-21 03:14:33,996 INFO [main] regionserver.HRegion(2466): Creating new region REGION => {NAME => 'TestMergeTool,,1237605273996', STARTKEY => '', ENDKEY => '', ENCODED => 1245836152, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:33,998 INFO [main] regionserver.HRegion(2475): starting merge of regions: TestMergeTool,row_0100,1237605273604 and TestMergeTool,,1237605239317 into new region REGION => {NAME => 'TestMergeTool,,1237605273996', STARTKEY => '', ENDKEY => '', ENCODED => 1245836152, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} with start key <> and end key <>
[junit] 2009-03-21 03:14:33,998 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,row_0100,1237605273604: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,998 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,998 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,999 DEBUG [main] regionserver.Store(434): closed 1303967493/contents
[junit] 2009-03-21 03:14:33,999 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,row_0100,1237605273604
[junit] 2009-03-21 03:14:33,999 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237605239317: compactions & flushes disabled
[junit] 2009-03-21 03:14:33,999 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237605239317
[junit] 2009-03-21 03:14:34,000 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237605239317
[junit] 2009-03-21 03:14:34,000 DEBUG [main] regionserver.Store(434): closed 543356916/contents
[junit] 2009-03-21 03:14:34,000 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237605239317
[junit] 2009-03-21 03:14:34,009 DEBUG [main] regionserver.HRegion(2510): Files for new region
[junit] 2009-03-21 03:14:34,010 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:52476/user/hudson/TestMergeTool/1245836152/contents
[junit] 2009-03-21 03:14:34,011 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:52476/user/hudson/TestMergeTool/1245836152/contents/3235560532777246106 size=804
[junit] 2009-03-21 03:14:34,011 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:52476/user/hudson/TestMergeTool/1245836152/contents/7690365460247261377 size=419
[junit] 2009-03-21 03:14:34,011 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237605273996/1245836152
[junit] 2009-03-21 03:14:34,016 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1245836152/contents/3235560532777246106, isReference=false, sequence id=5, length=804, majorCompaction=true
[junit] 2009-03-21 03:14:34,020 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1245836152/contents/7690365460247261377, isReference=false, sequence id=6, length=419, majorCompaction=true
[junit] 2009-03-21 03:14:34,020 DEBUG [main] regionserver.Store(213): Loaded 2 file(s) in Store 1245836152/contents, max sequence id 6
[junit] 2009-03-21 03:14:34,021 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237605273996 is 7
[junit] 2009-03-21 03:14:34,040 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237605273996/1245836152 available
[junit] 2009-03-21 03:14:34,040 INFO [main] regionserver.HRegion(701): starting compaction on region TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,042 DEBUG [main] regionserver.Store(683): Compaction size of 1245836152/contents: 1.2k; Skipped 0 file(s), size: 0
[junit] 2009-03-21 03:14:34,045 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/1245836152/contents/694636035773228276
[junit] 2009-03-21 03:14:34,060 DEBUG [main] regionserver.Store(707): Completed compaction of 1245836152/contents store size is 890.0
[junit] 2009-03-21 03:14:34,060 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237605273996 in 0sec
[junit] 2009-03-21 03:14:34,061 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-21 03:14:34,061 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:52476/user/hudson/TestMergeTool/1245836152/contents
[junit] 2009-03-21 03:14:34,062 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:52476/user/hudson/TestMergeTool/1245836152/contents/5001104343695015167 size=890
[junit] 2009-03-21 03:14:34,062 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:52476/user/hudson/TestMergeTool/1303967493
[junit] 2009-03-21 03:14:34,063 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:52476/user/hudson/TestMergeTool/543356916
[junit] 2009-03-21 03:14:34,064 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,064 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237605273604', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 1303967493, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-21 03:14:34,066 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237605239317', STARTKEY => '', ENDKEY => '', ENCODED => 543356916, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-21 03:14:34,069 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237605273996', STARTKEY => '', ENDKEY => '', ENCODED => 1245836152, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:34,069 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237605273996: compactions & flushes disabled
[junit] 2009-03-21 03:14:34,069 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,070 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,070 DEBUG [main] regionserver.Store(434): closed 1245836152/contents
[junit] 2009-03-21 03:14:34,070 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,070 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-21 03:14:34,070 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-21 03:14:34,070 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-21 03:14:34,071 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-21 03:14:34,071 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-21 03:14:34,071 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-21 03:14:34,071 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-21 03:14:34,071 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-21 03:14:34,072 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-21 03:14:34,092 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:52476/user/hudson/.META./1028785192/info/2604195010190926965, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-21 03:14:34,092 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 20ms, sequence id=21, compaction requested=true
[junit] 2009-03-21 03:14:34,093 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-21 03:14:34,093 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-21 03:14:34,093 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-21 03:14:34,100 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:52476/user/hudson/log_1237605273850/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237605273850/hlog.dat.1237605274098
[junit] 2009-03-21 03:14:34,100 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-21 03:14:34,100 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237605273850/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-21 03:14:34,100 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:52476/user/hudson/log_1237605273850
[junit] 2009-03-21 03:14:34,106 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237605273996', STARTKEY => '', ENDKEY => '', ENCODED => 1245836152, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-21 03:14:34,106 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237605273996/1245836152
[junit] 2009-03-21 03:14:34,111 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1245836152/contents/5001104343695015167, isReference=false, sequence id=6, length=890, majorCompaction=false
[junit] 2009-03-21 03:14:34,111 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1245836152/contents, max sequence id 6
[junit] 2009-03-21 03:14:34,112 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237605273996 is 7
[junit] 2009-03-21 03:14:34,113 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237605273996/1245836152 available
[junit] 2009-03-21 03:14:34,113 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-21 03:14:34,131 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237605273996: compactions & flushes disabled
[junit] 2009-03-21 03:14:34,132 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,132 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,132 DEBUG [main] regionserver.Store(434): closed 1245836152/contents
[junit] 2009-03-21 03:14:34,132 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237605273996
[junit] 2009-03-21 03:14:34,132 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-21 03:14:34,132 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237605272462
[junit] 2009-03-21 03:14:34,138 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-21 03:14:34,138 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-21 03:14:34,138 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=52363]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=52363]
[junit] 2009-03-21 03:14:34,142 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:52363
[junit] 2009-03-21 03:14:34,142 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1a5ec6c
[junit] 2009-03-21 03:14:34,218 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-21 03:14:34,219 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@c1186f
[junit] 2009-03-21 03:14:34,277 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-21 03:14:34,277 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@11a4bd4
[junit] 2009-03-21 03:14:34,281 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@8e4805] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:40290, storageID=DS-1046087803-67.195.138.9-40290-1237605271956, infoPort=52363, ipcPort=42476):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] Shutting down DataNode 0
[junit] 2009-03-21 03:14:34,282 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=33810]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=33810]
[junit] 2009-03-21 03:14:34,283 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:33810
[junit] 2009-03-21 03:14:34,284 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@970c0e
[junit] 2009-03-21 03:14:34,354 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-21 03:14:34,354 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@103de90
[junit] 2009-03-21 03:14:34,406 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-21 03:14:34,406 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1aa2c23
[junit] 2009-03-21 03:14:34,407 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@15d252d] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:42601, storageID=DS-1601566865-67.195.138.9-42601-1237605271698, infoPort=33810, ipcPort=45409):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-21 03:14:35,407 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=36078]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=36078]
[junit] 2009-03-21 03:14:35,407 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:36078
[junit] 2009-03-21 03:14:35,408 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@3e96cf
[junit] 2009-03-21 03:14:35,460 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-21 03:14:35,460 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@e29820
[junit] 2009-03-21 03:14:35,507 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-21 03:14:35,508 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@113beb5
[junit] 2009-03-21 03:14:35,508 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@e1eea8] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 36.297 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-21 03:14:35,862 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.077 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-21 03:14:36,207 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-21 03:14:36,212 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-21 03:14:36,213 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-21 03:14:36,213 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-21 03:14:36,215 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-21 03:14:36,218 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-21 03:14:36,219 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.087 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 28 minutes 15 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...
Re: Build failed in Hudson: HBase-Patch #540
Posted by stack <st...@duboce.net>.
Just two tests now -- the merge test and the thrift one that was failing
because of the server name redo.
St.Ack
On Fri, Mar 20, 2009 at 8:54 AM, Apache Hudson Server <
hudson@hudson.zones.apache.org> wrote:
> See http://hudson.zones.apache.org/hudson/job/HBase-Patch/540/changes
>
> Changes:
>
> [stack] HBASE-1277, HBASE-1275 HStoreKey: Wrong comparator logic &
> TestTable.testCreateTable broken
>
> ------------------------------------------
> [...truncated 36809 lines...]
> [junit] 2009-03-20 16:06:14,126 DEBUG [main] regionserver.Store(692):
> Started compaction of 2 file(s) into
> /user/hudson/TestMergeTool/1999606133/contents/851602297028147304
> [junit] 2009-03-20 16:06:14,141 DEBUG [main] regionserver.Store(707):
> Completed compaction of 1999606133/contents store size is 890.0
> [junit] 2009-03-20 16:06:14,142 INFO [main] regionserver.HRegion(716):
> compaction completed on region TestMergeTool,,1237565174073 in 0sec
> [junit] 2009-03-20 16:06:14,142 DEBUG [main] regionserver.HRegion(2517):
> Files for new region
> [junit] 2009-03-20 16:06:14,143 DEBUG [main] regionserver.HRegion(2585):
> d hdfs://localhost:38036/user/hudson/TestMergeTool/1999606133/contents
> [junit] 2009-03-20 16:06:14,144 DEBUG [main] regionserver.HRegion(2588):
> f
> hdfs://localhost:38036/user/hudson/TestMergeTool/1999606133/contents/6574646755201211965
> size=890
> [junit] 2009-03-20 16:06:14,144 DEBUG [main] regionserver.HRegion(2318):
> DELETING region hdfs://localhost:38036/user/hudson/TestMergeTool/976447066
> [junit] 2009-03-20 16:06:14,145 DEBUG [main] regionserver.HRegion(2318):
> DELETING region hdfs://localhost:38036/user/hudson/TestMergeTool/1714568240
> [junit] 2009-03-20 16:06:14,146 INFO [main] regionserver.HRegion(2523):
> merge completed. New region is TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,146 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,row_0100,1237565173668', STARTKEY
> => 'row_0100', ENDKEY => 'row_0600', ENCODED => 976447066, TABLE => {{NAME
> => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES =>
> [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE',
> VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536',
> IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from
> .META.,,1
> [junit] 2009-03-20 16:06:14,148 DEBUG [main] util.Merge(308): Removing
> region: REGION => {NAME => 'TestMergeTool,,1237565170533', STARTKEY => '',
> ENDKEY => '', ENCODED => 1714568240, TABLE => {{NAME => 'TestMergeTool',
> IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents',
> BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH =>
> '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false',
> BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
> [junit] 2009-03-20 16:06:14,151 INFO [main] util.Merge(244): Adding
> REGION => {NAME => 'TestMergeTool,,1237565174073', STARTKEY => '', ENDKEY =>
> '', ENCODED => 1999606133, TABLE => {{NAME => 'TestMergeTool', IS_ROOT =>
> 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER
> => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647',
> TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE =>
> 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY =>
> '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.',
> IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info',
> BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH =>
> '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false',
> BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false',
> VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL
> => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE =>
> 'false'}], INDEXES => []}}
> [junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(385):
> Closing TestMergeTool,,1237565174073: compactions & flushes disabled
> [junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(415):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(422):
> No more row locks outstanding on region TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,153 DEBUG [main] regionserver.Store(434):
> closed 1999606133/contents
> [junit] 2009-03-20 16:06:14,153 INFO [main] regionserver.HRegion(434):
> Closed TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,153 DEBUG [main] regionserver.HRegion(385):
> Closing -ROOT-,,0: compactions & flushes disabled
> [junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.HRegion(415):
> Updates disabled for region, no outstanding scanners on -ROOT-,,0
> [junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.HRegion(422):
> No more row locks outstanding on region -ROOT-,,0
> [junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.Store(434):
> closed 70236052/info
> [junit] 2009-03-20 16:06:14,155 INFO [main] regionserver.HRegion(434):
> Closed -ROOT-,,0
> [junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(385):
> Closing .META.,,1: compactions & flushes disabled
> [junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(415):
> Updates disabled for region, no outstanding scanners on .META.,,1
> [junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(422):
> No more row locks outstanding on region .META.,,1
> [junit] 2009-03-20 16:06:14,156 DEBUG [main] regionserver.HRegion(826):
> Started memcache flush for region .META.,,1. Current region memcache size
> 928.0
> [junit] 2009-03-20 16:06:14,167 DEBUG [main] regionserver.Store(516):
> Added
> hdfs://localhost:38036/user/hudson/.META./1028785192/info/4786692866467181595,
> entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
> [junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.HRegion(903):
> Finished memcache flush of ~928.0 for region .META.,,1 in 12ms, sequence
> id=21, compaction requested=true
> [junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.Store(434):
> closed 1028785192/historian
> [junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.Store(434):
> closed 1028785192/info
> [junit] 2009-03-20 16:06:14,169 INFO [main] regionserver.HRegion(434):
> Closed .META.,,1
> [junit] 2009-03-20 16:06:14,182 INFO [main] regionserver.HLog(273):
> Closed hdfs://localhost:38036/user/hudson/log_1237565173919/hlog.dat.0,
> entries=4. New log writer:
> /user/hudson/log_1237565173919/hlog.dat.1237565174180
> [junit] 2009-03-20 16:06:14,182 DEBUG [main] regionserver.HLog(280):
> Last sequence written is empty. Deleting all old hlogs
> [junit] 2009-03-20 16:06:14,182 INFO [main] regionserver.HLog(391):
> removing old log file /user/hudson/log_1237565173919/hlog.dat.0 whose
> highest sequence/edit id is 21
> [junit] 2009-03-20 16:06:14,183 DEBUG [main] regionserver.HLog(427):
> closing log writer in hdfs://localhost:38036/user/hudson/log_1237565173919
> [junit] 2009-03-20 16:06:14,189 DEBUG [main] regionserver.HRegion(2200):
> Opening region: REGION => {NAME => 'TestMergeTool,,1237565174073', STARTKEY
> => '', ENDKEY => '', ENCODED => 1999606133, TABLE => {{NAME =>
> 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME
> => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS =>
> '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY =>
> 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
> [junit] 2009-03-20 16:06:14,190 DEBUG [main] regionserver.HRegion(237):
> Opening region TestMergeTool,,1237565174073/1999606133
> [junit] 2009-03-20 16:06:14,195 DEBUG [main] regionserver.Store(383):
> loaded /user/hudson/TestMergeTool/1999606133/contents/6574646755201211965,
> isReference=false, sequence id=6, length=890, majorCompaction=false
> [junit] 2009-03-20 16:06:14,195 DEBUG [main] regionserver.Store(213):
> Loaded 1 file(s) in Store 1999606133/contents, max sequence id 6
> [junit] 2009-03-20 16:06:14,197 DEBUG [main] regionserver.HRegion(297):
> Next sequence id for region TestMergeTool,,1237565174073 is 7
> [junit] 2009-03-20 16:06:14,198 INFO [main] regionserver.HRegion(314):
> region TestMergeTool,,1237565174073/1999606133 available
> [junit] 2009-03-20 16:06:14,198 DEBUG [main] regionserver.HLog(217):
> changing sequence number from 6 to 7
> [junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(385):
> Closing TestMergeTool,,1237565174073: compactions & flushes disabled
> [junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(415):
> Updates disabled for region, no outstanding scanners on
> TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(422):
> No more row locks outstanding on region TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,218 DEBUG [main] regionserver.Store(434):
> closed 1999606133/contents
> [junit] 2009-03-20 16:06:14,218 INFO [main] regionserver.HRegion(434):
> Closed TestMergeTool,,1237565174073
> [junit] 2009-03-20 16:06:14,218 INFO [main] util.TestMergeTool(169):
> Verified merging regions 0+1+2+3 and 4
> [junit] 2009-03-20 16:06:14,219 DEBUG [main] regionserver.HLog(427):
> closing log writer in /tmp/log_1237565172550
> [junit] 2009-03-20 16:06:14,224 INFO [main] hbase.HBaseTestCase(587):
> Shutting down FileSystem
> [junit] 2009-03-20 16:06:14,225 INFO [main] hbase.HBaseTestCase(594):
> Shutting down Mini DFS
> [junit] Shutting down the Mini HDFS Cluster
> [junit] Shutting down DataNode 1
> [junit] 2009-03-20 16:06:14,226 INFO [Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=40115]]
> util.ThreadedServer$Acceptor(656): Stopping Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=40115]
> [junit] 2009-03-20 16:06:14,228 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:40115
> [junit] 2009-03-20 16:06:14,228 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1117a20
> [junit] 2009-03-20 16:06:14,299 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2009-03-20 16:06:14,300 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@58dd2d
> [junit] 2009-03-20 16:06:14,360 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2009-03-20 16:06:14,360 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@17c96a9
> [junit] 2009-03-20 16:06:14,362 WARN
> [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@1283052]
> datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:54187,
> storageID=DS-1234589010-67.195.138.9-54187-1237565172044, infoPort=40115,
> ipcPort=34619):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:129)
> [junit] at java.lang.Thread.run(Thread.java:619)
> [junit]
> [junit] 2009-03-20 16:06:14,409 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@6b3fc7
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:14,410 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:14,410 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:14,685 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@1284903
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:14,686 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:14,686 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:14,947 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@1557a77
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:14,947 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:14,947 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:15,171 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@17ed710
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:15,171 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:15,171 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] Shutting down DataNode 0
> [junit] 2009-03-20 16:06:15,362 INFO [Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35593]]
> util.ThreadedServer$Acceptor(656): Stopping Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35593]
> [junit] 2009-03-20 16:06:15,362 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:35593
> [junit] 2009-03-20 16:06:15,362 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1000bcf
> [junit] 2009-03-20 16:06:15,431 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2009-03-20 16:06:15,432 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1f1bd98
> [junit] 2009-03-20 16:06:15,485 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2009-03-20 16:06:15,486 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@15e92d7
> [junit] 2009-03-20 16:06:15,487 WARN
> [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@457d21]
> datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:37032,
> storageID=DS-214411499-67.195.138.9-37032-1237565171819, infoPort=35593,
> ipcPort=57902):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:129)
> [junit] at java.lang.Thread.run(Thread.java:619)
> [junit]
> [junit] 2009-03-20 16:06:15,735 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@177e6b4
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:15,735 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:15,736 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:16,431 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@cb5d35
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:16,431 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:16,431 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:16,486 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to
> sun.nio.ch.SelectionKeyImpl@1de530a
> [junit] java.net.ConnectException: Connection refused
> [junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [junit] at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
> [junit] 2009-03-20 16:06:16,487 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown
> input
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:16,487 WARN [main-SendThread]
> zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown
> output
> [junit] java.nio.channels.ClosedChannelException
> [junit] at
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
> [junit] at
> sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
> [junit] at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
> [junit] 2009-03-20 16:06:16,588 INFO [Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=45994]]
> util.ThreadedServer$Acceptor(656): Stopping Acceptor
> ServerSocket[addr=localhost/127.0.0.1,port=0,localport=45994]
> [junit] 2009-03-20 16:06:16,588 INFO [main] http.SocketListener(212):
> Stopped SocketListener on 127.0.0.1:45994
> [junit] 2009-03-20 16:06:16,588 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@2ab653
> [junit] 2009-03-20 16:06:16,639 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/static,/static]
> [junit] 2009-03-20 16:06:16,642 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.servlet.WebApplicationHandler@32bd65
> [junit] 2009-03-20 16:06:16,690 INFO [main] util.Container(156):
> Stopped WebApplicationContext[/,/]
> [junit] 2009-03-20 16:06:16,691 INFO [main] util.Container(156):
> Stopped org.mortbay.jetty.Server@1e13e07
> [junit] 2009-03-20 16:06:16,691 WARN
> [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@15e234c]
> namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread
> received InterruptedException.java.lang.InterruptedException: sleep
> interrupted
> [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 6.263 sec
> [junit] Running org.apache.hadoop.hbase.util.TestRootPath
> [junit] 2009-03-20 16:06:17,060 INFO [main] util.TestRootPath(60): Got
> expected exception when checking invalid path:
> [junit] java.io.IOException: Root directory does not contain a scheme
> [junit] at
> org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
> [junit] at
> org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
> [junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)
> [junit] at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> [junit] at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> [junit] at java.lang.reflect.Method.invoke(Method.java:597)
> [junit] at junit.framework.TestCase.runTest(TestCase.java:154)
> [junit] at junit.framework.TestCase.runBare(TestCase.java:127)
> [junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
> [junit] at
> junit.framework.TestResult.runProtected(TestResult.java:124)
> [junit] at junit.framework.TestResult.run(TestResult.java:109)
> [junit] at junit.framework.TestCase.run(TestCase.java:118)
> [junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
> [junit] at junit.framework.TestSuite.run(TestSuite.java:203)
> [junit] at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
> [junit] at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
> [junit] at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
> [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.076 sec
> [junit] Running org.onelab.test.TestFilter
> [junit] 2009-03-20 16:06:17,447 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2009-03-20 16:06:17,452 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2009-03-20 16:06:17,453 INFO [main] test.TestFilter(262):
> Success!
> [junit] 2009-03-20 16:06:17,453 INFO [main] test.TestFilter(226):
> Checking serialization/deserialization
> [junit] 2009-03-20 16:06:17,455 INFO [main] test.TestFilter(244):
> Checking for false negatives
> [junit] 2009-03-20 16:06:17,458 INFO [main] test.TestFilter(255):
> Checking for false positives
> [junit] 2009-03-20 16:06:17,459 INFO [main] test.TestFilter(262):
> Success!
> [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.087 sec
>
> BUILD FAILED
> http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml:458: Tests failed!
>
> Total time: 26 minutes 51 seconds
> [locks-and-latches] Releasing all the locks
> [locks-and-latches] All the locks released
> Recording test results
> Publishing Clover coverage report...
>
>
Build failed in Hudson: HBase-Patch #540
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/HBase-Patch/540/changes
Changes:
[stack] HBASE-1277, HBASE-1275 HStoreKey: Wrong comparator logic & TestTable.testCreateTable broken
------------------------------------------
[...truncated 36809 lines...]
[junit] 2009-03-20 16:06:14,126 DEBUG [main] regionserver.Store(692): Started compaction of 2 file(s) into /user/hudson/TestMergeTool/1999606133/contents/851602297028147304
[junit] 2009-03-20 16:06:14,141 DEBUG [main] regionserver.Store(707): Completed compaction of 1999606133/contents store size is 890.0
[junit] 2009-03-20 16:06:14,142 INFO [main] regionserver.HRegion(716): compaction completed on region TestMergeTool,,1237565174073 in 0sec
[junit] 2009-03-20 16:06:14,142 DEBUG [main] regionserver.HRegion(2517): Files for new region
[junit] 2009-03-20 16:06:14,143 DEBUG [main] regionserver.HRegion(2585): d hdfs://localhost:38036/user/hudson/TestMergeTool/1999606133/contents
[junit] 2009-03-20 16:06:14,144 DEBUG [main] regionserver.HRegion(2588): f hdfs://localhost:38036/user/hudson/TestMergeTool/1999606133/contents/6574646755201211965 size=890
[junit] 2009-03-20 16:06:14,144 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:38036/user/hudson/TestMergeTool/976447066
[junit] 2009-03-20 16:06:14,145 DEBUG [main] regionserver.HRegion(2318): DELETING region hdfs://localhost:38036/user/hudson/TestMergeTool/1714568240
[junit] 2009-03-20 16:06:14,146 INFO [main] regionserver.HRegion(2523): merge completed. New region is TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,146 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,row_0100,1237565173668', STARTKEY => 'row_0100', ENDKEY => 'row_0600', ENCODED => 976447066, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-20 16:06:14,148 DEBUG [main] util.Merge(308): Removing region: REGION => {NAME => 'TestMergeTool,,1237565170533', STARTKEY => '', ENDKEY => '', ENCODED => 1714568240, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', VERSIONS => '3', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} from .META.,,1
[junit] 2009-03-20 16:06:14,151 INFO [main] util.Merge(244): Adding REGION => {NAME => 'TestMergeTool,,1237565174073', STARTKEY => '', ENDKEY => '', ENCODED => 1999606133, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}} to REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_ROOT => 'false', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false', VERSIONS => '10', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'historian', BLOOMFILTER => 'false', VERSIONS => '2147483647', COMPRESSION => 'NONE', LENGTH => '2147483647', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237565174073: compactions & flushes disabled
[junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,152 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,153 DEBUG [main] regionserver.Store(434): closed 1999606133/contents
[junit] 2009-03-20 16:06:14,153 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,153 DEBUG [main] regionserver.HRegion(385): Closing -ROOT-,,0: compactions & flushes disabled
[junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on -ROOT-,,0
[junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region -ROOT-,,0
[junit] 2009-03-20 16:06:14,154 DEBUG [main] regionserver.Store(434): closed 70236052/info
[junit] 2009-03-20 16:06:14,155 INFO [main] regionserver.HRegion(434): Closed -ROOT-,,0
[junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(385): Closing .META.,,1: compactions & flushes disabled
[junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on .META.,,1
[junit] 2009-03-20 16:06:14,155 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region .META.,,1
[junit] 2009-03-20 16:06:14,156 DEBUG [main] regionserver.HRegion(826): Started memcache flush for region .META.,,1. Current region memcache size 928.0
[junit] 2009-03-20 16:06:14,167 DEBUG [main] regionserver.Store(516): Added hdfs://localhost:38036/user/hudson/.META./1028785192/info/4786692866467181595, entries=3, sequenceid=21, memsize=928.0, filesize=920.0 to .META.,,1
[junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.HRegion(903): Finished memcache flush of ~928.0 for region .META.,,1 in 12ms, sequence id=21, compaction requested=true
[junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.Store(434): closed 1028785192/historian
[junit] 2009-03-20 16:06:14,168 DEBUG [main] regionserver.Store(434): closed 1028785192/info
[junit] 2009-03-20 16:06:14,169 INFO [main] regionserver.HRegion(434): Closed .META.,,1
[junit] 2009-03-20 16:06:14,182 INFO [main] regionserver.HLog(273): Closed hdfs://localhost:38036/user/hudson/log_1237565173919/hlog.dat.0, entries=4. New log writer: /user/hudson/log_1237565173919/hlog.dat.1237565174180
[junit] 2009-03-20 16:06:14,182 DEBUG [main] regionserver.HLog(280): Last sequence written is empty. Deleting all old hlogs
[junit] 2009-03-20 16:06:14,182 INFO [main] regionserver.HLog(391): removing old log file /user/hudson/log_1237565173919/hlog.dat.0 whose highest sequence/edit id is 21
[junit] 2009-03-20 16:06:14,183 DEBUG [main] regionserver.HLog(427): closing log writer in hdfs://localhost:38036/user/hudson/log_1237565173919
[junit] 2009-03-20 16:06:14,189 DEBUG [main] regionserver.HRegion(2200): Opening region: REGION => {NAME => 'TestMergeTool,,1237565174073', STARTKEY => '', ENDKEY => '', ENCODED => 1999606133, TABLE => {{NAME => 'TestMergeTool', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'contents', BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}], INDEXES => []}}
[junit] 2009-03-20 16:06:14,190 DEBUG [main] regionserver.HRegion(237): Opening region TestMergeTool,,1237565174073/1999606133
[junit] 2009-03-20 16:06:14,195 DEBUG [main] regionserver.Store(383): loaded /user/hudson/TestMergeTool/1999606133/contents/6574646755201211965, isReference=false, sequence id=6, length=890, majorCompaction=false
[junit] 2009-03-20 16:06:14,195 DEBUG [main] regionserver.Store(213): Loaded 1 file(s) in Store 1999606133/contents, max sequence id 6
[junit] 2009-03-20 16:06:14,197 DEBUG [main] regionserver.HRegion(297): Next sequence id for region TestMergeTool,,1237565174073 is 7
[junit] 2009-03-20 16:06:14,198 INFO [main] regionserver.HRegion(314): region TestMergeTool,,1237565174073/1999606133 available
[junit] 2009-03-20 16:06:14,198 DEBUG [main] regionserver.HLog(217): changing sequence number from 6 to 7
[junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(385): Closing TestMergeTool,,1237565174073: compactions & flushes disabled
[junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(415): Updates disabled for region, no outstanding scanners on TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,217 DEBUG [main] regionserver.HRegion(422): No more row locks outstanding on region TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,218 DEBUG [main] regionserver.Store(434): closed 1999606133/contents
[junit] 2009-03-20 16:06:14,218 INFO [main] regionserver.HRegion(434): Closed TestMergeTool,,1237565174073
[junit] 2009-03-20 16:06:14,218 INFO [main] util.TestMergeTool(169): Verified merging regions 0+1+2+3 and 4
[junit] 2009-03-20 16:06:14,219 DEBUG [main] regionserver.HLog(427): closing log writer in /tmp/log_1237565172550
[junit] 2009-03-20 16:06:14,224 INFO [main] hbase.HBaseTestCase(587): Shutting down FileSystem
[junit] 2009-03-20 16:06:14,225 INFO [main] hbase.HBaseTestCase(594): Shutting down Mini DFS
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-03-20 16:06:14,226 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=40115]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=40115]
[junit] 2009-03-20 16:06:14,228 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:40115
[junit] 2009-03-20 16:06:14,228 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1117a20
[junit] 2009-03-20 16:06:14,299 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 16:06:14,300 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@58dd2d
[junit] 2009-03-20 16:06:14,360 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 16:06:14,360 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@17c96a9
[junit] 2009-03-20 16:06:14,362 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@1283052] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:54187, storageID=DS-1234589010-67.195.138.9-54187-1237565172044, infoPort=40115, ipcPort=34619):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-20 16:06:14,409 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@6b3fc7
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:14,410 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:14,410 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:14,685 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@1284903
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:14,686 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:14,686 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:14,947 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@1557a77
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:14,947 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:14,947 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:15,171 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@17ed710
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:15,171 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:15,171 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] Shutting down DataNode 0
[junit] 2009-03-20 16:06:15,362 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35593]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=35593]
[junit] 2009-03-20 16:06:15,362 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:35593
[junit] 2009-03-20 16:06:15,362 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1000bcf
[junit] 2009-03-20 16:06:15,431 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 16:06:15,432 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@1f1bd98
[junit] 2009-03-20 16:06:15,485 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 16:06:15,486 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@15e92d7
[junit] 2009-03-20 16:06:15,487 WARN [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@457d21] datanode.DataXceiverServer(134): DatanodeRegistration(127.0.0.1:37032, storageID=DS-214411499-67.195.138.9-37032-1237565171819, infoPort=35593, ipcPort=57902):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:129)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 2009-03-20 16:06:15,735 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@177e6b4
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:15,735 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:15,736 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:16,431 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@cb5d35
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:16,431 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:16,431 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:16,486 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(898): Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@1de530a
[junit] java.net.ConnectException: Connection refused
[junit] at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:864)
[junit] 2009-03-20 16:06:16,487 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(932): Ignoring exception during shutdown input
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638)
[junit] at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:930)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:16,487 WARN [main-SendThread] zookeeper.ClientCnxn$SendThread(937): Ignoring exception during shutdown output
[junit] java.nio.channels.ClosedChannelException
[junit] at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649)
[junit] at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:935)
[junit] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:901)
[junit] 2009-03-20 16:06:16,588 INFO [Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=45994]] util.ThreadedServer$Acceptor(656): Stopping Acceptor ServerSocket[addr=localhost/127.0.0.1,port=0,localport=45994]
[junit] 2009-03-20 16:06:16,588 INFO [main] http.SocketListener(212): Stopped SocketListener on 127.0.0.1:45994
[junit] 2009-03-20 16:06:16,588 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@2ab653
[junit] 2009-03-20 16:06:16,639 INFO [main] util.Container(156): Stopped WebApplicationContext[/static,/static]
[junit] 2009-03-20 16:06:16,642 INFO [main] util.Container(156): Stopped org.mortbay.jetty.servlet.WebApplicationHandler@32bd65
[junit] 2009-03-20 16:06:16,690 INFO [main] util.Container(156): Stopped WebApplicationContext[/,/]
[junit] 2009-03-20 16:06:16,691 INFO [main] util.Container(156): Stopped org.mortbay.jetty.Server@1e13e07
[junit] 2009-03-20 16:06:16,691 WARN [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$ReplicationMonitor@15e234c] namenode.FSNamesystem$ReplicationMonitor(2300): ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 6.263 sec
[junit] Running org.apache.hadoop.hbase.util.TestRootPath
[junit] 2009-03-20 16:06:17,060 INFO [main] util.TestRootPath(60): Got expected exception when checking invalid path:
[junit] java.io.IOException: Root directory does not contain a scheme
[junit] at org.apache.hadoop.hbase.util.FSUtils.validateRootPath(FSUtils.java:199)
[junit] at org.apache.hadoop.hbase.util.TestRootPath.testRootPath(TestRootPath.java:56)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.076 sec
[junit] Running org.onelab.test.TestFilter
[junit] 2009-03-20 16:06:17,447 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-20 16:06:17,452 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-20 16:06:17,453 INFO [main] test.TestFilter(262): Success!
[junit] 2009-03-20 16:06:17,453 INFO [main] test.TestFilter(226): Checking serialization/deserialization
[junit] 2009-03-20 16:06:17,455 INFO [main] test.TestFilter(244): Checking for false negatives
[junit] 2009-03-20 16:06:17,458 INFO [main] test.TestFilter(255): Checking for false positives
[junit] 2009-03-20 16:06:17,459 INFO [main] test.TestFilter(262): Success!
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.087 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/HBase-Patch/ws/trunk/build.xml :458: Tests failed!
Total time: 26 minutes 51 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Publishing Clover coverage report...