Return-Path: X-Original-To: apmail-hbase-user-archive@www.apache.org Delivered-To: apmail-hbase-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 82F401160F for ; Thu, 17 Jul 2014 09:03:03 +0000 (UTC) Received: (qmail 79949 invoked by uid 500); 17 Jul 2014 09:03:01 -0000 Delivered-To: apmail-hbase-user-archive@hbase.apache.org Received: (qmail 79885 invoked by uid 500); 17 Jul 2014 09:03:01 -0000 Mailing-List: contact user-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@hbase.apache.org Delivered-To: mailing list user@hbase.apache.org Received: (qmail 79873 invoked by uid 99); 17 Jul 2014 09:03:01 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 17 Jul 2014 09:03:01 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of olorinbant@gmail.com designates 74.125.82.170 as permitted sender) Received: from [74.125.82.170] (HELO mail-we0-f170.google.com) (74.125.82.170) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 17 Jul 2014 09:02:50 +0000 Received: by mail-we0-f170.google.com with SMTP id w62so2082788wes.1 for ; Thu, 17 Jul 2014 02:02:23 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:from:date:message-id:subject:to :content-type; bh=V9qug80PVjoijcKTFUq0/lcfDyyNQ3V4bms6bxkYZ/g=; b=PKdiJ+DTEy+KQUgnK6n1aMiRPJyM9oUB+g9EZ4im421HPL2nUusOcDHX8duHYeiwIR 2lchgQnmGC8z500JAminiOXNTk9mTHJoSeiB3eiM+xcmMI5mJgPAy61td+bz9v8h09FB 4dvhsLuJzI/G8ctRaDNrL8PXhI8hkyxli/M1NZ3HGoFZhx/up4gOwL5C/J5JF0R3HnkY CENyIZ9UOvT9uIrss6m4w1xMWfANWqmHRcaicL9+MdsWvXL83XdkjTgk7m0dAiWuYKIc azgBwI0ONX4CCYDsfkaz805HtX36uJjEmJafIzN4PBssGtRrBpYbz/QsfEHdcLEiBXA0 rj1g== X-Received: by 10.180.82.97 with SMTP id h1mr20104258wiy.30.1405587741990; Thu, 17 Jul 2014 02:02:21 -0700 (PDT) MIME-Version: 1.0 Received: by 10.216.156.2 with HTTP; Thu, 17 Jul 2014 02:01:51 -0700 (PDT) In-Reply-To: <53C789EA.7020702@orbit-x.de> References: <53BFBF23.6010605@orbit-x.de> <53C28116.6050801@orbit-x.de> <53C789EA.7020702@orbit-x.de> From: Mikhail Antonov Date: Thu, 17 Jul 2014 02:01:51 -0700 Message-ID: Subject: Re: HBaseTestingUtility: Issue with unclosed sessions after minicluster is shutdown To: "user@hbase.apache.org" Content-Type: multipart/alternative; boundary=f46d044267300fe77404fe5fe6f3 X-Virus-Checked: Checked by ClamAV on apache.org --f46d044267300fe77404fe5fe6f3 Content-Type: text/plain; charset=UTF-8 Hi Reinis, sorry, may be missing some context here, you're saying - "Why is Watcher ignoring Disconnected from ZooKeeper?". Normally there's a quorum of zookeeper nodes in the cluster, and when client (having ZooKeeperWatcher) receives this event from zookeeper, it assumes that this zookeeper node failed and it needs to connect to another node. I.e. the fact the or several zookeeper servers appear to have shut down generally doesn't (shouldn't) suggest clients to stop reconnecting. Do you explicitly close client's connections (like HBaseAdmin) when you don't need them anymore? -Mikhail 2014-07-17 1:31 GMT-07:00 Reinis Vicups : > 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:: # >> ffffffff000146d61737465723a34393939323d6c467c3affffff86fffff >> fc9ffffff8250425546a2435396136323662622d393330312d343763332d >> 616462622d626466366436323365646639,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:: # >> ffffffff0001a726567696f6e7365727665723a353030323072ffffff9cf >> fffffebffffffc62dffffffb8ffffffc14050425546a20a13616972666f7 >> 26365312e667269747a2e626f7810ffffffe4ffffff86318ffffffc8ffff >> ffd6ffffffb2fffffff8fffffff228100,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 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.TicketTextSimilarityPreference >>>> MRJobTest: >>>> 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.TicketTextSimilarityPreference >>>> MRJobTest: >>>> 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.TicketTextSimilarityPreference >>>> MRJobTest: >>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest after >>>> table >>>> close >>>> 14/07/11 11:01:33 WARN similarity.TicketTextSimilarityPreference >>>> MRJobTest: >>>> 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.TicketTextSimilarityPreference >>>> MRJobTest: >>>> com.myproj.similarity.TicketTextSimilarityPreferenceMRJobTest after >>>> afterAll >>>> [info] TicketMasterDataCategoryGroupingMRJobTest: >>>> 14/07/11 11:01:37 WARN masterdata.TicketMasterDataCategoryGroupi >>>> ngMRJobTest: >>>> 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 >>>> >>> > -- Thanks, Michael Antonov --f46d044267300fe77404fe5fe6f3--