zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Patrick Hunt <ph...@apache.org>
Subject Re: java.nio.channels.CancelledKeyException in ZK 3.4
Date Wed, 30 Nov 2011 17:30:13 GMT
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 <Karol.Gwaj@skillpages.com> 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,
>

Mime
View raw message