Using Java client: ================== 2011-12-06 16:03:50,919 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33877 2011-12-06 16:03:50,922 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33877 client's lastZxid is 0x0 2011-12-06 16:03:50,922 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@777] - Client attempting to establish new session at /127.0.0.1:33877 2011-12-06 16:03:50,923 - INFO [SyncThread:0:FileTxnLog@199] - Creating new log file: log.21 2011-12-06 16:03:51,008 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0000 type:createSession cxid:0x0 zxid:0x21 txntype:-10 reqpath:n/a 2011-12-06 16:03:51,010 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0000 type:createSession cxid:0x0 zxid:0x21 txntype:-10 reqpath:n/a 2011-12-06 16:03:51,013 - INFO [SyncThread:0:NIOServerCnxn@1580] - Established session 0x13415d54bee0000 with negotiated timeout 40000 for client /127.0.0.1:33877 2011-12-06 16:03:51,018 - INFO [ProcessThread:-1:PrepRequestProcessor@411] - Got user-level KeeperException when processing sessionid:0x13415d54bee0000 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/test Error:KeeperErrorCode = NodeExists for /test 2011-12-06 16:03:51,036 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0000 type:create cxid:0x1 zxid:0x22 txntype:-1 reqpath:n/a 2011-12-06 16:03:51,059 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0000 type:setData cxid:0x2 zxid:0x23 txntype:5 reqpath:n/a 2011-12-06 16:03:51,060 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0000 type:setData cxid:0x2 zxid:0x23 txntype:5 reqpath:n/a 2011-12-06 16:03:51,065 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33878 2011-12-06 16:03:51,066 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33878 client's lastZxid is 0x0 2011-12-06 16:03:51,066 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@770] - Client attempting to renew session 0x13415d54bee0000 at /127.0.0.1:33878 2011-12-06 16:03:51,067 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33877 which had sessionid 0x13415d54bee0000 2011-12-06 16:03:51,068 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1580] - Established session 0x13415d54bee0000 with negotiated timeout 40000 for client /127.0.0.1:33878 2011-12-06 16:03:51,068 - INFO [ProcessThread:-1:PrepRequestProcessor@391] - Processed session termination for sessionid: 0x13415d54bee0000 2011-12-06 16:03:51,077 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0000 type:closeSession cxid:0x1 zxid:0x24 txntype:-11 reqpath:n/a 2011-12-06 16:03:51,078 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0000 type:closeSession cxid:0x1 zxid:0x24 txntype:-11 reqpath:n/a 2011-12-06 16:03:51,079 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33878 which had sessionid 0x13415d54bee0000 2011-12-06 16:03:52,802 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33879 2011-12-06 16:03:52,803 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33879 client's lastZxid is 0x23 2011-12-06 16:03:52,803 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@770] - Client attempting to renew session 0x13415d54bee0000 at /127.0.0.1:33879 2011-12-06 16:03:52,803 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1573] - Invalid session 0x13415d54bee0000 for client /127.0.0.1:33879, probably expired 2011-12-06 16:03:52,804 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@590] - Dropping request: No session with sessionid 0x13415d54bee0000 exists, probably expired and removed 2011-12-06 16:03:52,804 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33879 which had sessionid 0x13415d54bee0000 2011-12-06 16:03:52,805 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1459] - 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:658) at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:378) at org.apache.zookeeper.server.NIOServerCnxn.closeSock(NIOServerCnxn.java:1455) at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1412) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:632) at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262) Using C client: =============== 2011-12-06 16:08:08,754 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33897 2011-12-06 16:08:08,755 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33897 client's lastZxid is 0x0 2011-12-06 16:08:08,755 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@777] - Client attempting to establish new session at /127.0.0.1:33897 2011-12-06 16:08:08,792 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0001 type:createSession cxid:0x0 zxid:0x25 txntype:-10 reqpath:n/a 2011-12-06 16:08:08,792 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0001 type:createSession cxid:0x0 zxid:0x25 txntype:-10 reqpath:n/a 2011-12-06 16:08:08,793 - INFO [SyncThread:0:NIOServerCnxn@1580] - Established session 0x13415d54bee0001 with negotiated timeout 40000 for client /127.0.0.1:33897 2011-12-06 16:08:08,793 - INFO [ProcessThread:-1:PrepRequestProcessor@411] - Got user-level KeeperException when processing sessionid:0x13415d54bee0001 type:create cxid:0x4edeae69 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/test Error:KeeperErrorCode = NodeExists for /test 2011-12-06 16:08:08,811 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0001 type:create cxid:0x4edeae69 zxid:0x26 txntype:-1 reqpath:n/a 2011-12-06 16:08:08,825 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6a zxid:0x27 txntype:5 reqpath:n/a 2011-12-06 16:08:08,825 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6a zxid:0x27 txntype:5 reqpath:n/a 2011-12-06 16:08:08,826 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33898 2011-12-06 16:08:08,826 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33898 client's lastZxid is 0x0 2011-12-06 16:08:08,827 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@770] - Client attempting to renew session 0x13415d54bee0001 at /127.0.0.1:33898 2011-12-06 16:08:08,827 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33897 which had sessionid 0x13415d54bee0001 2011-12-06 16:08:08,828 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1580] - Established session 0x13415d54bee0001 with negotiated timeout 40000 for client /127.0.0.1:33898 2011-12-06 16:08:08,828 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x13415d54bee0001, likely client has closed socket 2011-12-06 16:08:08,828 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33898 which had sessionid 0x13415d54bee0001 2011-12-06 16:08:08,829 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1451] - ignoring exception during output shutdown java.net.SocketException: Transport endpoint is not connected at sun.nio.ch.SocketChannelImpl.shutdown(Native Method) at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:669) at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:386) at org.apache.zookeeper.server.NIOServerCnxn.closeSock(NIOServerCnxn.java:1447) at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1412) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:637) at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262) 2011-12-06 16:08:08,829 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1459] - 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:658) at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:378) at org.apache.zookeeper.server.NIOServerCnxn.closeSock(NIOServerCnxn.java:1455) at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1412) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:637) at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262) 2011-12-06 16:08:08,829 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33900 2011-12-06 16:08:08,830 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@735] - Session establishment request from client /127.0.0.1:33900 client's lastZxid is 0x27 2011-12-06 16:08:08,830 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@770] - Client attempting to renew session 0x13415d54bee0001 at /127.0.0.1:33900 2011-12-06 16:08:08,830 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1580] - Established session 0x13415d54bee0001 with negotiated timeout 40000 for client /127.0.0.1:33900 2011-12-06 16:08:08,836 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6b zxid:0x28 txntype:5 reqpath:n/a 2011-12-06 16:08:08,836 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6b zxid:0x28 txntype:5 reqpath:n/a 2011-12-06 16:08:08,836 - ERROR [SyncThread:0:NIOServerCnxn@445] - Unexpected Exception: java.nio.channels.CancelledKeyException at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73) at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77) at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:418) at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1509) at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:367) at org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProcessor.java:161) at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:98) 2011-12-06 16:08:08,844 - DEBUG [SyncThread:0:FinalRequestProcessor@78] - Processing request:: sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6c zxid:0x29 txntype:5 reqpath:n/a 2011-12-06 16:08:08,844 - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x13415d54bee0001 type:setData cxid:0x4edeae6c zxid:0x29 txntype:5 reqpath:n/a 2011-12-06 16:08:09,007 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x13415d54bee0001, likely client has closed socket 2011-12-06 16:08:09,007 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:33900 which had sessionid 0x13415d54bee0001 2011-12-06 16:08:09,007 - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1459] - 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:658) at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:378) at org.apache.zookeeper.server.NIOServerCnxn.closeSock(NIOServerCnxn.java:1455) at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1412) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:637) at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262)