I believe it's this: https://issues.apache.org/jira/browse/ZOOKEEPER-1237
Timing issue btw multiple threads (client closing and the server writing). The problem is that the socket has been closed prior to the server getting out the "close session response" to the client. Patrick On Wed, Nov 30, 2011 at 6:49 AM, Karol Gwaj <[email protected]> wrote: > Hi, > > Im getting error on the server every time I close session with zk (version > 3.4) > > Server debug logs for my connection: > 2011-11-30 12:43:01,421 [myid:] - INFO > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:NIOServerCnxnFactory@213][] - > Accepted socket connection from /127.0.0.1:42298 > 2011-11-30 12:43:01,427 [myid:] - DEBUG > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:ZooKeeperServer@772][] - Session > establishment request from client /127.0.0.1:42298 client's lastZxid is 0x0 > 2011-11-30 12:43:01,427 [myid:] - WARN > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:ZooKeeperServer@784][] - > Connection request from old client /127.0.0.1:42298; will be dropped if > server is in r-o mode > 2011-11-30 12:43:01,428 [myid:] - INFO > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:ZooKeeperServer@830][] - Client > attempting to establish new session at /127.0.0.1:42298 > 2011-11-30 12:43:01,430 [myid:] - INFO [SyncThread:0:FileTxnLog@200][] - > Creating new log file: log.18761 > 2011-11-30 12:43:01,437 [myid:] - DEBUG > [SyncThread:0:FinalRequestProcessor@87][] - Processing request:: > sessionid:0x133f47fd0d00000 type:createSession cxid:0x0 zxid:0x18761 > txntype:-10 reqpath:n/a > 2011-11-30 12:43:01,439 [myid:] - DEBUG > [SyncThread:0:FinalRequestProcessor@169][] - sessionid:0x133f47fd0d00000 > type:createSession cxid:0x0 zxid:0x18761 txntype:-10 reqpath:n/a > 2011-11-30 12:43:01,443 [myid:] - INFO [SyncThread:0:ZooKeeperServer@596][] > - Established session 0x133f47fd0d00000 with negotiated timeout 30000 for > client /127.0.0.1:42298 > 2011-11-30 12:43:04,564 [myid:] - INFO [ProcessThread(sid:0 > cport:-1)::PrepRequestProcessor@466][] - Processed session termination for > sessionid: 0x133f47fd0d00000 > 2011-11-30 12:43:04,565 [myid:] - WARN > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:NIOServerCnxn@349][] - caught end > of stream exception > EndOfStreamException: Unable to read additional data from client sessionid > 0x133f47fd0d00000, likely client has closed socket > at > org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220) > at > org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:224) > at java.lang.Thread.run(Thread.java:662) > 2011-11-30 12:43:04,566 [myid:] - INFO > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:NIOServerCnxn@1000][] - Closed > socket connection for client /127.0.0.1:42298 which had sessionid > 0x133f47fd0d00000 > 2011-11-30 12:43:04,567 [myid:] - DEBUG > [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2111:NIOServerCnxn@1024][] - ignoring > exception during input shutdown > java.net.SocketException: Transport endpoint is not connected > at sun.nio.ch.SocketChannelImpl.shutdown(Native Method) > at > sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:633) > at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360) > at > org.apache.zookeeper.server.NIOServerCnxn.closeSock(NIOServerCnxn.java:1020) > at > org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:977) > at > org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:352) > at > org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:224) > at java.lang.Thread.run(Thread.java:662) > 2011-11-30 12:43:04,568 [myid:] - DEBUG > [SyncThread:0:FinalRequestProcessor@87][] - Processing request:: > sessionid:0x133f47fd0d00000 type:closeSession cxid:0x4ed624d6 zxid:0x18762 > txntype:-11 reqpath:n/a > 2011-11-30 12:43:04,569 [myid:] - DEBUG > [SyncThread:0:FinalRequestProcessor@169][] - sessionid:0x133f47fd0d00000 > type:closeSession cxid:0x4ed624d6 zxid:0x18762 txntype:-11 reqpath:n/a > 2011-11-30 12:43:04,570 [myid:] - ERROR [SyncThread:0:NIOServerCnxn@180][] - > Unexpected Exception: > java.nio.channels.CancelledKeyException > at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55) > at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:59) > at > org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:153) > at > org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1075) > at > org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:412) > at > org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProcessor.java:165) > at > org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:101) > > > Steps to reproduce: > > 1. Start c client: cli_mt localhost:2111 > > 2. Execute quit from client console > > > > > Any idea if it is expected behaviour ? > > Any help will be greatly appreciated > > Thx, >
