hbase-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Reinis Vicups <hb...@orbit-x.de>
Subject Re: HBaseTestingUtility: Issue with unclosed sessions after minicluster is shutdown
Date Thu, 17 Jul 2014 08:31:38 GMT
I am humbly bumping this, since after a week of searching and trying I 
am still unsuccessful in fixing this.

Thank you guys for your patience
reinis

On 13.07.2014 14:52, Reinis Vicups wrote:
> Thank you, Esteban, for your response!
>
> This issue occurs on all my systems (my local windows machine that is 
> not virtualized, build server - non-virtualized linux, test cluster - 
> virtualized linux).
>
> After further investigation and increasing of log level I see log 
> bellow. It appears as if zookeeper ClientCnxn (or whoever controls it, 
> HBase-Client?) does not get (or believe) that server shut down and 
> keeps on attempting to reconnect. Unfortunately I am a typical 
> consumer and do not understand the HBase/Zookeeper/Hadoop 
> architecture/choreography :( What I found interesting is this log 
> message:
>
> 14/07/13 11:27:57 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x1a97512e-0x1472f0ca7df0002, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received Disconnected 
> from ZooKeeper, ignoring
>
> Why is Watcher ignoring Disconnected from ZooKeeper?
>
> Well, generally I would be very interested to find out how to force 
> client just to shutdown.
>
> I have tried already all this:
>     localConfig.set(HConstants.ZOOKEEPER_ZNODE_PARENT, "/".concat(new 
> RandomStringGeneratorImpl().getRandString)) // give each znode 
> different name to avoid overlapping
>     localConfig.set("zookeeper.recovery.retry", "0") // no recovery
>     localConfig.set("zookeeper.session.timeout", "10000") // short 
> timeouts
>     localConfig.set("hbase.rpc.timeout", "10000") // no idea if this 
> is relevant
>     localConfig.set("hbase.client.retries.number", "1") // could not 
> set it to 0 since then client wouldn't manage to connect at all
>     localConfig.set("hbase.client.pause", "1000") // no idea if this 
> is relevant
>
> Besides that I tried to:
> - run tests in forked and then in non-forked mode
> - set -Djava.net.preferIPv4Stack=true because in some forum it was 
> mentioned as possible reason for connection issues
>
> All in all my integration test consists of 11 somewhat larger 
> integration test suites (multiple test methods) and I observe that at 
> the end I have some 11-14 such stale client sessions attempting to 
> re-connect endlessly.
>
> I thank you guys in advance and hope someone has energy to help me out 
> with this tough sh*t
> reinis
>
>
> LOG
> ----------------------------------------------------
> 14/07/13 11:27:47 INFO zookeeper.ClientCnxn: Opening socket connection 
> to server 0:0:0:0:0:0:0:1/0:0:0:0:0:0:0:1:49713. Will not attempt to 
> authenticate using SASL (unknown error)
> 14/07/13 11:27:47 INFO server.NIOServerCnxnFactory: Accepted socket 
> connection from /0:0:0:0:0:0:0:1:50061
> 14/07/13 11:27:47 INFO zookeeper.ClientCnxn: Socket connection 
> established to 0:0:0:0:0:0:0:1/0:0:0:0:0:0:0:1:49713, initiating session
> 14/07/13 11:27:47 DEBUG zookeeper.ClientCnxn: Session establishment 
> request sent on 0:0:0:0:0:0:0:1/0:0:0:0:0:0:0:1:49713
> 14/07/13 11:27:47 DEBUG server.ZooKeeperServer: Session establishment 
> request from client /0:0:0:0:0:0:0:1:50061 client's lastZxid is 0x0
> 14/07/13 11:27:47 INFO server.ZooKeeperServer: Client attempting to 
> establish new session at /0:0:0:0:0:0:0:1:50061
> 14/07/13 11:27:47 TRACE server.SessionTrackerImpl: SessionTrackerImpl 
> --- Adding session 0x1472f0ca7df0002 10000
> 14/07/13 11:27:47 TRACE server.PrepRequestProcessor: 
> :Psessionid:0x1472f0ca7df0002 type:createSession cxid:0x0 
> zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
> 14/07/13 11:27:47 TRACE server.SessionTrackerImpl: SessionTrackerImpl 
> --- Existing session 0x1472f0ca7df0002 10000
> ...
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:createSession cxid:0x0 
> zxid:0xe txntype:-10 reqpath:n/a
> 14/07/13 11:27:47 TRACE server.FinalRequestProcessor: 
> :Esessionid:0x1472f0ca7df0002 type:createSession cxid:0x0 zxid:0xe 
> txntype:-10 reqpath:n/a
> 14/07/13 11:27:47 TRACE server.SessionTrackerImpl: SessionTrackerImpl 
> --- Existing session 0x1472f0ca7df0002 10000
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:createSession cxid:0x0 zxid:0xe 
> txntype:-10 reqpath:n/a
> ...
> 14/07/13 11:27:47 INFO server.ZooKeeperServer: Established session 
> 0x1472f0ca7df0002 with negotiated timeout 10000 for client 
> /0:0:0:0:0:0:0:1:50061
> 14/07/13 11:27:47 TRACE zookeeper.ClientCnxnSocket: readConnectResult 
> 37 0x[0,0,...
> 14/07/13 11:27:47 INFO zookeeper.ClientCnxn: Session establishment 
> complete on server 0:0:0:0:0:0:0:1/0:0:0:0:0:0:0:1:49713, sessionid = 
> 0x1472f0ca7df0002, negotiated timeout = 10000
> 14/07/13 11:27:47 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x1a97512e, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received ZooKeeper 
> Event, type=None, state=SyncConnected, path=null
> 14/07/13 11:27:47 TRACE server.PrepRequestProcessor: 
> :Psessionid:0x1472f0ca7df0002 type:exists cxid:0x1 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> ...
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:exists cxid:0x1 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 TRACE server.FinalRequestProcessor: 
> :Esessionid:0x1472f0ca7df0002 type:exists cxid:0x1 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x1a97512e-0x1472f0ca7df0002 connected
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:exists cxid:0x1 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 DEBUG zookeeper.ClientCnxn: Reading reply 
> sessionid:0x1472f0ca7df0002, packet:: clientPath:null serverPath:null 
> finished:false header:: 1,3  replyHeader:: 1,14,0 request:: 
> '/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid,F response:: 
> s{13,13,1405243667232,1405243667232,0,0,0,0,67,0,13}
> 14/07/13 11:27:47 TRACE server.PrepRequestProcessor: 
> :Psessionid:0x1472f0ca7df0002 type:getData cxid:0x2 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:getData cxid:0x2 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 TRACE server.FinalRequestProcessor: 
> :Esessionid:0x1472f0ca7df0002 type:getData cxid:0x2 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:getData cxid:0x2 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid
> 14/07/13 11:27:47 DEBUG zookeeper.ClientCnxn: Reading reply 
> sessionid:0x1472f0ca7df0002, packet:: clientPath:null serverPath:null 
> finished:false header:: 2,4  replyHeader:: 2,14,0 request:: 
> '/afc60aef-1620-435e-847a-71cc4192bb22/hbaseid,F response:: 
> #ffffffff000146d61737465723a34393939323d6c467c3affffff86ffffffc9ffffff8250425546a2435396136323662622d393330312d343763332d616462622d626466366436323365646639,s{13,13,1405243667232,1405243667232,0,0,0,0,67,0,13} 
>
> 14/07/13 11:27:47 TRACE zookeeper.ZKUtil: 
> hconnection-0x1a97512e-0x1472f0ca7df0002, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Retrieved 42 byte(s) 
> of data from znode /afc60aef-1620-435e-847a-71cc4192bb22/hbaseid; 
> data=PBUF\x0A$59a626bb-9301-47c3-a...
> ...
> # Number of transactions are being processed normaly, the final 
> transaction is cxid:0x18
> 14/07/13 11:27:51 TRACE server.PrepRequestProcessor: 
> :Psessionid:0x1472f0ca7df0002 type:getData cxid:0x18 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server
> 14/07/13 11:27:51 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:getData cxid:0x18 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server
> 14/07/13 11:27:51 TRACE server.FinalRequestProcessor: 
> :Esessionid:0x1472f0ca7df0002 type:getData cxid:0x18 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server
> 14/07/13 11:27:51 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:getData cxid:0x18 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server
> 14/07/13 11:27:51 DEBUG zookeeper.ClientCnxn: Reading reply 
> sessionid:0x1472f0ca7df0002, packet:: clientPath:null serverPath:null 
> finished:false header:: 24,4  replyHeader:: 24,70,0  request:: 
> '/afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server,F response:: 
> #ffffffff0001a726567696f6e7365727665723a353030323072ffffff9cffffffebffffffc62dffffffb8ffffffc14050425546a20a13616972666f726365312e667269747a2e626f7810ffffffe4ffffff86318ffffffc8ffffffd6ffffffb2fffffff8fffffff228100,s{38,38,1405243668798,1405243668798,0,0,0,0,71,0,38} 
>
> 14/07/13 11:27:51 TRACE zookeeper.ZKUtil: 
> hconnection-0x1a97512e-0x1472f0ca7df0002, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Retrieved 40 byte(s) 
> of data from znode 
> /afc60aef-1620-435e-847a-71cc4192bb22/meta-region-server; 
> data=airforce1.fritz.box,50020,1405243665224
> ...
> # Pings ok too!
> 14/07/13 11:27:54 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:ping 
> cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:n/a
> 14/07/13 11:27:54 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:ping cxid:0xfffffffffffffffe 
> zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
> 14/07/13 11:27:54 DEBUG zookeeper.ClientCnxn: Got ping response for 
> sessionid: 0x1472f0ca7df0002 after 6ms
> ...
> 14/07/13 11:27:57 DEBUG server.FinalRequestProcessor: Processing 
> request:: sessionid:0x1472f0ca7df0002 type:ping 
> cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:n/a
> 14/07/13 11:27:57 DEBUG server.FinalRequestProcessor: 
> sessionid:0x1472f0ca7df0002 type:ping cxid:0xfffffffffffffffe 
> zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
> 14/07/13 11:27:57 TRACE server.PrepRequestProcessor: 
> :Psessionid:0x1472f0ca7df0001 type:getChildren cxid:0x38 
> zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:/afc60aef-1620-435e-847a-71cc4192bb22/replication/rs/airforce1.fritz.box,50020,1405243665224
> 14/07/13 11:27:57 DEBUG zookeeper.ClientCnxn: Got ping response for 
> sessionid: 0x1472f0ca7df0002 after 2ms
> ...
> # Shutdown is starting!
> 14/07/13 11:27:57 INFO server.NIOServerCnxn: Closed socket connection 
> for client /0:0:0:0:0:0:0:1:50061 which had sessionid 0x1472f0ca7df0002
> 14/07/13 11:27:57 INFO zookeeper.ClientCnxn: Unable to read additional 
> data from server sessionid 0x1472f0ca7df0002, likely server has closed 
> socket, closing socket connection and attempting reconnect
> 14/07/13 11:27:57 INFO server.NIOServerCnxnFactory: NIOServerCnxn 
> factory exited run method
> 14/07/13 11:27:57 INFO server.ZooKeeperServer: shutting down
> 14/07/13 11:27:57 INFO server.SessionTrackerImpl: Shutting down
> 14/07/13 11:27:57 TRACE server.SessionTrackerImpl: Shutdown 
> SessionTrackerImpl!
> 14/07/13 11:27:57 INFO server.PrepRequestProcessor: Shutting down
> 14/07/13 11:27:57 INFO server.SyncRequestProcessor: Shutting down
> 14/07/13 11:27:57 TRACE server.PrepRequestProcessor: :Psessionid:0x0 
> type:notification cxid:0x0 zxid:0xfffffffffffffffe txntype:unknown 
> reqpath:n/a
> 14/07/13 11:27:57 INFO server.PrepRequestProcessor: 
> PrepRequestProcessor exited loop!
> 14/07/13 11:27:57 INFO server.SyncRequestProcessor: 
> SyncRequestProcessor exited!
> 14/07/13 11:27:57 INFO server.FinalRequestProcessor: shutdown of 
> request processor complete
> 14/07/13 11:27:57 TRACE zookeeper.ClientCnxnSocketNIO: Doing client 
> selector close
> 14/07/13 11:27:57 TRACE zookeeper.ClientCnxnSocketNIO: Closed client 
> selector
> 14/07/13 11:27:57 TRACE zookeeper.ClientCnxn: SendThread exitedloop.
> ...
> 14/07/13 11:27:57 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x1a97512e-0x1472f0ca7df0002, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received ZooKeeper 
> Event, type=None, state=Disconnected, path=null
> 14/07/13 11:27:57 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x56db0aff-0x1472f0ca7df0007, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received ZooKeeper 
> Event, type=None, state=Disconnected, path=null
>
> # Is it interesting, how ZooKeeperWatcher says 'ignoring' in the log 
> message bellow?
> 14/07/13 11:27:57 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x1a97512e-0x1472f0ca7df0002, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received Disconnected 
> from ZooKeeper, ignoring
> 14/07/13 11:27:57 DEBUG zookeeper.ZooKeeperWatcher: 
> hconnection-0x56db0aff-0x1472f0ca7df0007, quorum=localhost:49713, 
> baseZNode=/afc60aef-1620-435e-847a-71cc4192bb22 Received Disconnected 
> from ZooKeeper, ignoring
> ...
> # from now on this session appears to be stale and attempts to 
> re-connect until JVM is shutdown!
> 14/07/13 11:27:59 WARN zookeeper.ClientCnxn: Session 0x1472f0ca7df0002 
> for server null, unexpected error, closing socket connection and 
> attempting reconnect
> java.net.ConnectException: Connection refused: no further information
>     at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>     at 
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:692)
>     at 
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1075)
> 14/07/13 11:27:59 DEBUG zookeeper.ClientCnxnSocketNIO: Ignoring 
> exception during shutdown input
> java.nio.channels.ClosedChannelException
>     at 
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:755)
>     at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:421)
>     at 
> org.apache.zookeeper.ClientCnxnSocketNIO.cleanup(ClientCnxnSocketNIO.java:189)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1164)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1104)
> ...
> 14/07/13 11:28:02 WARN zookeeper.ClientCnxn: Session 0x1472f0ca7df0002 
> for server null, unexpected error, closing socket connection and 
> attempting reconnect
> java.net.ConnectException: Connection refused: no further information
>     at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>     at 
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:692)
>     at 
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1075)
> 14/07/13 11:28:02 DEBUG zookeeper.ClientCnxnSocketNIO: Ignoring 
> exception during shutdown input
> java.nio.channels.ClosedChannelException
>     at 
> sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:755)
>     at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:421)
>     at 
> org.apache.zookeeper.ClientCnxnSocketNIO.cleanup(ClientCnxnSocketNIO.java:189)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1164)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1104)
> 14/07/13 11:28:02 DEBUG zookeeper.ClientCnxnSocketNIO: Ignoring 
> exception during shutdown output
> java.nio.channels.ClosedChannelException
>     at 
> sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:772)
>     at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:429)
>     at 
> org.apache.zookeeper.ClientCnxnSocketNIO.cleanup(ClientCnxnSocketNIO.java:196)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1164)
>     at 
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1104)
>
>
> On 13.07.2014 06:34, Esteban Gutierrez wrote:
>> Hello Renis,
>>
>> Is this happening every time the test runs? I've seen this happening few
>> times when the test is running with a very small heap or the test is
>> running on VMs and the Java VM or the local file system are unstable due
>> load on the virtualized environment. Have you looked into increasing the
>> heap or the the load of the environment where you are running this test?
>>
>> cheers,
>> esteban.
>>
>> -- 
>> Cloudera, Inc.
>>
>> On Fri, Jul 11, 2014 at 3:40 AM, Reinis Vicups <hbase@orbit-x.de> wrote:
>>
>>> Hi,
>>>
>>> I have built a test-harness that I am using to test integration with 
>>> the
>>> help of HBaseTestingUtility. The code bellow although allows me to run
>>> tests, it has one very annoying side effect - some of the sessions 
>>> woun't
>>> get closed after I shutdown the minicluster, thus causing lag and 
>>> delayed
>>> test execution.
>>>
>>> I would be very grateful to anyone who could give me tip on how to fix
>>> this.
>>>
>>> merci
>>>
>>> reinis
>>>
>>> Test Suite Code:
>>> ------------------------------------------------------------
>>> ----------------------------------
>>>
>>> abstract trait LocalHBaseSuite extends BeforeAndAfterAll {
>>>
>>>    this: Suite =>
>>>    @transient lazy val traitLog: Logger = LoggerFactory.getLogger(this.
>>> getClass.getName)
>>>
>>>    var localHBase: HBaseTestingUtility = null
>>>    var localFileSystem: FileSystem = null
>>>
>>>    override def beforeAll = {
>>>      traitLog.warn("{} before beforeAll", this.getClass.getName) 
>>> //<- see
>>> in log
>>>
>>>      // load snappy.dll found in hadoop bin directory
>>>      val hadoopHomePath = file.Paths.get(ClassLoader.
>>> getSystemResource("hadoop").toURI)
>>> addJavaLibraryPath(file.Paths.get(hadoopHomePath.toAbsolutePath.toString, 
>>>
>>> "bin").toString)
>>>      System.loadLibrary("snappy")
>>>      System.setProperty("hadoop.home.dir", 
>>> hadoopHomePath.toAbsolutePath.
>>> toString)
>>>
>>>      localHBase = new HBaseTestingUtility()
>>>
>>>      val localConfig = localHBase.getConfiguration
>>>      localConfig.set("mapreduce.framework.name", "local")
>>>      localConfig.set("dfs.permissions.enabled", "false")
>>>      localConfig.set("fs.file.impl.disable.cache", "true")
>>>
>>>      localHBase.startMiniCluster()
>>>      localFileSystem = localHBase.getTestFileSystem
>>>
>>>      traitLog.warn("{} after beforeAll", this.getClass.getName) //<- 
>>> see in
>>> log
>>>    }
>>>
>>>    override def afterAll = {
>>>      traitLog.warn("{} before afterAll", this.getClass.getName) //<- 
>>> see in
>>> log
>>>      localHBase.shutdownMiniCluster()
>>>      traitLog.warn("{} after afterAll", this.getClass.getName) //<- 
>>> see in
>>> log
>>>      localHBase = null
>>>    }
>>>
>>>    /**
>>>     * Adds the given path to the java.library.path system property
>>>     */
>>>    private def addJavaLibraryPath(libraryPath: String): Unit = {
>>>      val usrPathsField: Field = classOf[ClassLoader].
>>> getDeclaredField("usr_paths")
>>>      usrPathsField.setAccessible(true)
>>>      val newPaths = 
>>> usrPathsField.get(null).asInstanceOf[Array[String]] :+
>>> libraryPath
>>>      usrPathsField.set(null, newPaths.asInstanceOf[Array[String]])
>>>    }
>>> }
>>>
>>>
>>> Resulting Log-File:
>>> -------------------------------------------
>>>
>>> [info] Loading project definition from D:\git\myproj\project
>>> [info] Set current project to myproj (in build file:/D:/git/myproj/)
>>> [success] Total time: 1 s, completed 11.07.2014 11:00:53
>>> [info] Compiling 1 Scala source to D:\git\myproj\etl\target\
>>> scala-2.10\test-classes...
>>> [info] ScalaTest
>>> [info] Run completed in 42 milliseconds.
>>> [info] Total number of tests run: 0
>>> [info] Suites: completed 0, aborted 0
>>> [info] Tests: succeeded 0, failed 0, canceled 0, ignored 0, pending 0
>>> [info] No tests were executed.
>>> [info] Passed: Total 0, Failed 0, Errors 0, Passed 0
>>> [info] No tests to run for myproj-Root/it:test
>>> [info] ScalaTest
>>> [info] Run completed in 25 milliseconds.
>>> [info] Total number of tests run: 0
>>> [info] Suites: completed 0, aborted 0
>>> [info] Tests: succeeded 0, failed 0, canceled 0, ignored 0, pending 0
>>> [info] No tests were executed.
>>> [info] Passed: Total 0, Failed 0, Errors 0, Passed 0
>>> [info] No tests to run for myproj-API/it:test
>>> [info] VectorizeTicketSolutionLogMRJobTest:
>>> 14/07/11 11:01:01 WARN solutionlog.VectorizeTicketSolutionLogMRJobTest:
>>> com.myproj.quantify.ticket.solutionlog.VectorizeTicketSolutionLogMRJobTest 
>>>
>>> before beforeAll
>>> Formatting using clusterid: testClusterID
>>> 14/07/11 11:01:03 WARN impl.MetricsConfig: Cannot locate configuration:
>>> tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
>>> 14/07/11 11:01:04 WARN server.AuthenticationFilter: 'signature.secret'
>>> configuration not set, using a random value as secret
>>> 14/07/11 11:01:06 WARN hbase.ZNodeClearer: Environment variable
>>> HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start
>>> scripts (Longer MTTR!)
>>> 14/07/11 11:01:08 WARN hbase.ZNodeClearer: Environment variable
>>> HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start
>>> scripts (Longer MTTR!)
>>> 14/07/11 11:01:09 WARN zookeeper.RecoverableZooKeeper: Node
>>> /hbase/meta-region-server already deleted, retry=false
>>> 14/07/11 11:01:10 WARN solutionlog.VectorizeTicketSolutionLogMRJobTest:
>>> com.myproj.quantify.ticket.solutionlog.VectorizeTicketSolutionLogMRJobTest 
>>>
>>> after beforeAll
>>> 14/07/11 11:01:10 WARN hbase.HBaseCommonTestingUtility: close() 
>>> called on
>>> HBaseAdmin instance returned from HBaseTestingUtility.getHBaseAdmin()
>>> 14/07/11 11:01:12 WARN mapreduce.JobSubmitter: No job jar file set. 
>>> User
>>> classes may not be found. See Job or Job#setJar(String).
>>> 14/07/11 11:01:12 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/1e71ff51-76c5-45e9-8d44-1249dbff3055/
>>> hadoop/mapreduce-jobtracker-staging-root-dir/user467204862/.staging/job_local467204862_0001/job.xml:an 
>>>
>>> attempt to override final parameter: mapreduce.job.end-
>>> notification.max.retry.interval;  Ignoring.
>>> 14/07/11 11:01:12 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/1e71ff51-76c5-45e9-8d44-1249dbff3055/
>>> hadoop/mapreduce-jobtracker-staging-root-dir/user467204862/.staging/job_local467204862_0001/job.xml:an 
>>>
>>> attempt to override final parameter: 
>>> mapreduce.job.end-notification.max.attempts;
>>>   Ignoring.
>>> 14/07/11 11:01:12 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/1e71ff51-76c5-45e9-8d44-1249dbff3055/
>>> hadoop_tmp/mapred/local/localRunner/user/job_local467204862_0001/job_local467204862_0001.xml:an 
>>>
>>> attempt to override final parameter: mapreduce.job.end-
>>> notification.max.retry.interval;  Ignoring.
>>> 14/07/11 11:01:12 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/1e71ff51-76c5-45e9-8d44-1249dbff3055/
>>> hadoop_tmp/mapred/local/localRunner/user/job_local467204862_0001/job_local467204862_0001.xml:an 
>>>
>>> attempt to override final parameter: 
>>> mapreduce.job.end-notification.max.attempts;
>>>   Ignoring.
>>> [info] - should validate that VectorizeTicketSolutionLogMRJob generates
>>> correct HBase table
>>> 14/07/11 11:01:13 WARN solutionlog.VectorizeTicketSolutionLogMRJobTest:
>>> com.myproj.quantify.ticket.solutionlog.VectorizeTicketSolutionLogMRJobTest 
>>>
>>> after table close
>>> 14/07/11 11:01:13 WARN solutionlog.VectorizeTicketSolutionLogMRJobTest:
>>> com.myproj.quantify.ticket.solutionlog.VectorizeTicketSolutionLogMRJobTest 
>>>
>>> before afterAll
>>> 14/07/11 11:01:13 WARN server.NIOServerCnxn: caught end of stream 
>>> exception
>>> EndOfStreamException: Unable to read additional data from client 
>>> sessionid
>>> 0x14724a78b320003, likely client has closed socket
>>>      at org.apache.zookeeper.server.NIOServerCnxn.doIO(
>>> NIOServerCnxn.java:220)
>>>      at org.apache.zookeeper.server.NIOServerCnxnFactory.run(
>>> NIOServerCnxnFactory.java:208)
>>>      at java.lang.Thread.run(Thread.java:722)
>>> 14/07/11 11:01:18 WARN server.NIOServerCnxn: caught end of stream 
>>> exception
>>> EndOfStreamException: Unable to read additional data from client 
>>> sessionid
>>> 0x14724a78b320004, likely client has closed socket
>>>      at org.apache.zookeeper.server.NIOServerCnxn.doIO(
>>> NIOServerCnxn.java:220)
>>>      at org.apache.zookeeper.server.NIOServerCnxnFactory.run(
>>> NIOServerCnxnFactory.java:208)
>>>      at java.lang.Thread.run(Thread.java:722)
>>> 14/07/11 11:01:18 ERROR client.HConnectionManager: Connection not 
>>> found in
>>> the list, can't delete it (connection 
>>> key=HConnectionKey{properties={hbase.rpc.timeout=60000,
>>> hbase.zookeeper.property.clientPort=63640, hbase.client.pause=100,
>>> zookeeper.znode.parent=/hbase, hbase.client.retries.number=350,
>>> hbase.zookeeper.quorum=localhost}, username='user'}). May be the key 
>>> was
>>> modified?
>>> java.lang.Exception
>>>      at 
>>> org.apache.hadoop.hbase.client.HConnectionManager.deleteConnection(
>>> HConnectionManager.java:466)
>>>      at 
>>> org.apache.hadoop.hbase.client.HConnectionManager.deleteConnection(
>>> HConnectionManager.java:402)
>>>      at org.apache.hadoop.hbase.replication.master.
>>> ReplicationLogCleaner.stop(ReplicationLogCleaner.java:142)
>>>      at org.apache.hadoop.hbase.master.cleaner.CleanerChore.
>>> cleanup(CleanerChore.java:276)
>>>      at org.apache.hadoop.hbase.Chore.run(Chore.java:94)
>>>      at java.lang.Thread.run(Thread.java:722)
>>> 14/07/11 11:01:19 WARN datanode.DirectoryScanner: DirectoryScanner:
>>> shutdown has been called
>>> 14/07/11 11:01:19 WARN datanode.DataNode: BPOfferService for Block pool
>>> BP-466654724-192.168.178.20-1405069263037 (Datanode Uuid
>>> cc3e8ece-62e2-4877-92fe-8fdec4d1179f) service to /127.0.0.1:61391
>>> interrupted
>>> 14/07/11 11:01:19 WARN datanode.DataNode: Ending block pool service 
>>> for:
>>> Block pool BP-466654724-192.168.178.20-1405069263037 (Datanode Uuid
>>> cc3e8ece-62e2-4877-92fe-8fdec4d1179f) service to /127.0.0.1:61391
>>> 14/07/11 11:01:19 WARN blockmanagement.DecommissionManager: Monitor
>>> interrupted: java.lang.InterruptedException: sleep interrupted
>>> 14/07/11 11:01:19 WARN solutionlog.VectorizeTicketSolutionLogMRJobTest:
>>> com.myproj.quantify.ticket.solutionlog.VectorizeTicketSolutionLogMRJobTest 
>>>
>>> after afterAll
>>> 14/07/11 11:01:19 WARN 
>>> similarity.TicketTextSimilarityPreferenceMRJobTest:
>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest before
>>> beforeAll
>>> [info] TicketTextSimilarityPreferenceMRJobTest:
>>> 14/07/11 11:01:19 WARN hbase.HBaseCommonTestingUtility: hadoop.tmp.dir
>>> property value differs in configuration and system:
>>> Configuration=/tmp/hadoop-user while System=D:/git/myproj/etl/
>>> target/test-data/1e71ff51-76c5-45e9-8d44-1249dbff3055/hadoop_tmp 
>>> Erasing
>>> configuration value by system value.
>>> Formatting using clusterid: testClusterID
>>> 14/07/11 11:01:19 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:20 WARN server.AuthenticationFilter: 'signature.secret'
>>> configuration not set, using a random value as secret
>>> 14/07/11 11:01:20 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:21 WARN hbase.ZNodeClearer: Environment variable
>>> HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start
>>> scripts (Longer MTTR!)
>>> 14/07/11 11:01:22 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:22 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:23 WARN regionserver.HRegionServer: reportForDuty 
>>> failed;
>>> sleeping and then retrying.
>>> 14/07/11 11:01:23 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:24 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:26 WARN hbase.ZNodeClearer: Environment variable
>>> HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start
>>> scripts (Longer MTTR!)
>>> 14/07/11 11:01:26 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:27 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:27 WARN zookeeper.RecoverableZooKeeper: Node
>>> /hbase/meta-region-server already deleted, retry=false
>>> 14/07/11 11:01:28 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:28 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:28 WARN 
>>> similarity.TicketTextSimilarityPreferenceMRJobTest:
>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest after
>>> beforeAll
>>> 14/07/11 11:01:28 WARN hbase.HBaseCommonTestingUtility: close() 
>>> called on
>>> HBaseAdmin instance returned from HBaseTestingUtility.getHBaseAdmin()
>>> 14/07/11 11:01:30 WARN mapreduce.JobSubmitter: No job jar file set. 
>>> User
>>> classes may not be found. See Job or Job#setJar(String).
>>> 14/07/11 11:01:30 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/c85b7f3b-4e4b-40b4-a434-a45cecc9cba8/
>>> hadoop/mapreduce-jobtracker-staging-root-dir/user1872843153/.staging/job_ 
>>>
>>> local1872843153_0002/job.xml:an attempt to override final parameter:
>>> mapreduce.job.end-notification.max.retry.interval;  Ignoring.
>>> 14/07/11 11:01:30 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/c85b7f3b-4e4b-40b4-a434-a45cecc9cba8/
>>> hadoop/mapreduce-jobtracker-staging-root-dir/user1872843153/.staging/job_ 
>>>
>>> local1872843153_0002/job.xml:an attempt to override final parameter:
>>> mapreduce.job.end-notification.max.attempts;  Ignoring.
>>> 14/07/11 11:01:30 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/c85b7f3b-4e4b-40b4-a434-a45cecc9cba8/
>>> mapred_local/localRunner/user/job_local1872843153_0002/job_local1872843153_0002.xml:an 
>>>
>>> attempt to override final parameter: mapreduce.job.end-
>>> notification.max.retry.interval;  Ignoring.
>>> 14/07/11 11:01:30 WARN conf.Configuration: file:/D:/git/myproj/etl/
>>> target/test-data/c85b7f3b-4e4b-40b4-a434-a45cecc9cba8/
>>> mapred_local/localRunner/user/job_local1872843153_0002/job_local1872843153_0002.xml:an 
>>>
>>> attempt to override final parameter: 
>>> mapreduce.job.end-notification.max.attempts;
>>>   Ignoring.
>>> 14/07/11 11:01:31 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:31 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:32 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:33 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> [info] - should run ticket text similarity preference mr job
>>> [info] - should generate preference table that is compatible with
>>> HBasedDataModel
>>> 14/07/11 11:01:33 WARN 
>>> similarity.TicketTextSimilarityPreferenceMRJobTest:
>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest after 
>>> table
>>> close
>>> 14/07/11 11:01:33 WARN 
>>> similarity.TicketTextSimilarityPreferenceMRJobTest:
>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest before
>>> afterAll
>>> 14/07/11 11:01:35 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:36 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:36 ERROR client.HConnectionManager: Connection not 
>>> found in
>>> the list, can't delete it (connection 
>>> key=HConnectionKey{properties={hbase.rpc.timeout=60000,
>>> hbase.zookeeper.property.clientPort=65078, hbase.client.pause=100,
>>> zookeeper.znode.parent=/hbase, hbase.client.retries.number=350,
>>> hbase.zookeeper.quorum=localhost}, username='user'}). May be the key 
>>> was
>>> modified?
>>> java.lang.Exception
>>>      at 
>>> org.apache.hadoop.hbase.client.HConnectionManager.deleteConnection(
>>> HConnectionManager.java:466)
>>>      at 
>>> org.apache.hadoop.hbase.client.HConnectionManager.deleteConnection(
>>> HConnectionManager.java:402)
>>>      at org.apache.hadoop.hbase.replication.master.
>>> ReplicationLogCleaner.stop(ReplicationLogCleaner.java:142)
>>>      at org.apache.hadoop.hbase.master.cleaner.CleanerChore.
>>> cleanup(CleanerChore.java:276)
>>>      at org.apache.hadoop.hbase.Chore.run(Chore.java:94)
>>>      at java.lang.Thread.run(Thread.java:722)
>>> 14/07/11 11:01:37 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:37 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:37 WARN datanode.DirectoryScanner: DirectoryScanner:
>>> shutdown has been called
>>> 14/07/11 11:01:37 WARN datanode.DataNode: BPOfferService for Block pool
>>> BP-912909389-192.168.178.20-1405069279778 (Datanode Uuid
>>> c6c45632-3e50-4575-8b65-92d7479a48ba) service to /127.0.0.1:61553
>>> interrupted
>>> 14/07/11 11:01:37 WARN datanode.DataNode: Ending block pool service 
>>> for:
>>> Block pool BP-912909389-192.168.178.20-1405069279778 (Datanode Uuid
>>> c6c45632-3e50-4575-8b65-92d7479a48ba) service to /127.0.0.1:61553
>>> 14/07/11 11:01:37 WARN blockmanagement.DecommissionManager: Monitor
>>> interrupted: java.lang.InterruptedException: sleep interrupted
>>> 14/07/11 11:01:37 WARN 
>>> similarity.TicketTextSimilarityPreferenceMRJobTest:
>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest after
>>> afterAll
>>> [info] TicketMasterDataCategoryGroupingMRJobTest:
>>> 14/07/11 11:01:37 WARN 
>>> masterdata.TicketMasterDataCategoryGroupingMRJobTest:
>>> com.myproj.quantify.ticket.masterdata.TicketMasterDataCategoryGroupingMRJobTest 
>>>
>>> before beforeAll
>>> 14/07/11 11:01:37 WARN hbase.HBaseCommonTestingUtility: hadoop.tmp.dir
>>> property value differs in configuration and system:
>>> Configuration=/tmp/hadoop-user while System=D:/git/myproj/etl/
>>> target/test-data/c85b7f3b-4e4b-40b4-a434-a45cecc9cba8/hadoop_tmp 
>>> Erasing
>>> configuration value by system value.
>>> Formatting using clusterid: testClusterID
>>> 14/07/11 11:01:38 WARN server.AuthenticationFilter: 'signature.secret'
>>> configuration not set, using a random value as secret
>>> 14/07/11 11:01:38 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a7c5790007 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:38 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a7c5790002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>> 14/07/11 11:01:39 WARN hbase.ZNodeClearer: Environment variable
>>> HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start
>>> scripts (Longer MTTR!)
>>> 14/07/11 11:01:39 WARN zookeeper.ClientCnxn: Session 
>>> 0x14724a78b320002 for
>>> server null, unexpected error, closing socket connection and attempting
>>> reconnect
>>> java.net.ConnectException: Connection refused: no further information
>>>      at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>>      at sun.nio.ch.SocketChannelImpl.finishConnect(
>>> SocketChannelImpl.java:692)
>>>      at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(
>>> ClientCnxnSocketNIO.java:350)
>>>      at org.apache.zookeeper.ClientCnxn$SendThread.run(
>>> ClientCnxn.java:1075)
>>>
>>> # ... This goes on and on and on ...
>>>
>>> [info] ScalaTest
>>> [info] Run completed in 5 minutes, 23 seconds.
>>> [info] Total number of tests run: 22
>>> [info] Suites: completed 10, aborted 0
>>> [info] Tests: succeeded 22, failed 0, canceled 0, ignored 0, pending 0
>>> [info] All tests passed.
>>> [info] Passed: Total 26, Failed 0, Errors 0, Passed 24, Skipped 2
>>> [success] Total time: 331 s, completed 11.07.2014 11:06:24


Mime
View raw message