Mailing-List: contact user-help@zookeeper.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@zookeeper.apache.org
Received-SPF: pass (nike.apache.org: domain of
 Nicholas.Patania@morganstanley.com designates 199.89.103.73 as permitted
 sender)
MIME-Version: 1.0
In-Reply-To: <4D548CC9.6090102@yahoo-inc.com>
References: 
 <6642FC1CAF133548AA8FDF497C547F0A23C0C5265B@NYWEXMBX2126.msad.ms.com>
 <4D548CC9.6090102@yahoo-inc.com>
From: Nick Patania <Nicholas.Patania@morganstanley.com>
Date: Fri, 11 Feb 2011 09:41:05 -0500
Message-ID: <AANLkTimpodJPZ9j_GY5Q8qLxLkQUk_=brsaz2C6jmj4D@mail.gmail.com>
Subject: Re: tickTime and sessionTimeout
To: user@zookeeper.apache.org
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

This is the portion that seems relevant.  For readability, I replaced
the host and session for the host that I kill with HOST_0 and
SESSION_0 (I expect these to timeout).  The client that should be
healthy is HOST_1 and SESSION_1.


2011-02-11 14:18:51,901 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_0 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2011-02-11 14:18:51,901 - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:SESSION_0
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
2011-02-11 14:18:52,005 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_1 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2011-02-11 14:18:52,005 - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:SESSION_1
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
2011-02-11 14:18:52,339 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_1 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2011-02-11 14:18:52,339 - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:SESSION_1
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
2011-02-11 14:18:52,672 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_1 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2011-02-11 14:18:52,672 - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:SESSION_1
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
2011-02-11 14:18:53,002 - INFO  [SessionTracker:ZooKeeperServer@314] -
Expiring session SESSION_0, timeout of 1000ms exceeded
2011-02-11 14:18:53,002 - INFO
[ProcessThread:-1:PrepRequestProcessor@387] - Processed session
termination for sessionid: SESSION_0
2011-02-11 14:18:53,010 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_0 type:closeSession cxid:0x0 zxid:0x103 txntype:-11
reqpath:n/a
2011-02-11 14:18:53,010 - INFO  [SyncThread:0:NIOServerCnxn@1435] -
Closed socket connection for client /HOST_0:34618 which had sessionid
SESSION_0
2011-02-11 14:18:54,502 - INFO  [SessionTracker:ZooKeeperServer@314] -
Expiring session SESSION_1, timeout of 1000ms exceeded
2011-02-11 14:18:54,502 - INFO
[ProcessThread:-1:PrepRequestProcessor@387] - Processed session
termination for sessionid: SESSION_1
2011-02-11 14:18:55,011 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_1 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2011-02-11 14:18:55,011 - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:SESSION_1
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
2011-02-11 14:18:55,011 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn$Factory@251]
- Accepted socket connection from /HOST_1:40556
2011-02-11 14:18:55,019 - DEBUG
[SyncThread:0:FinalRequestProcessor@78] - Processing request::
sessionid:SESSION_1 type:closeSession cxid:0x0 zxid:0x104 txntype:-11
reqpath:n/a
2011-02-11 14:18:55,019 - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:ZooKeeperServer@590] -
Dropping request: No session with sessionid SESSION_1 exists, probably
expired and removed
2011-02-11 14:18:55,019 - INFO  [SyncThread:0:NIOServerCnxn@1435] -
Closed socket connection for client /HOST_1:40555 which had sessionid
SESSION_1
2011-02-11 14:18:55,020 - DEBUG [SyncThread:0: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:651)
	at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368)
	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$Factory.closeSessionWithoutWa=
keup(NIOServerCnxn.java:343)
	at org.apache.zookeeper.server.NIOServerCnxn$Factory.closeSession(NIOServe=
rCnxn.java:330)
	at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalR=
equestProcessor.java:133)
	at org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProce=
ssor.java:161)
	at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcess=
or.java:98)
2011-02-11 14:18:55,021 - DEBUG [SyncThread:0: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:640)
	at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
	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$Factory.closeSessionWithoutWa=
keup(NIOServerCnxn.java:343)
	at org.apache.zookeeper.server.NIOServerCnxn$Factory.closeSession(NIOServe=
rCnxn.java:330)
	at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalR=
equestProcessor.java:133)
	at org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProce=
ssor.java:161)
	at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcess=
or.java:98)
2011-02-11 14:18:55,022 - WARN
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn$Factory@272]
- Ignoring unexpected runtime exception
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)
	at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:69)
	at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.jav=
a:241)
2011-02-11 14:18:55,023 - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn@735] -
Session establishment request from client /HOST_1:40556 client's
lastZxid is 0x0
2011-02-11 14:18:55,023 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn@770] - Client
attempting to renew session SESSION_1 at /HOST_1:40556
2011-02-11 14:18:55,024 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn@1573] -
Invalid session SESSION_1 for client /HOST_1:40556, probably expired
2011-02-11 14:18:55,025 - WARN
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn@634] -
EndOfStreamException: Unable to read additional data from client
sessionid SESSION_1, likely client has closed socket
2011-02-11 14:18:55,025 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4799:NIOServerCnxn@1435] -
Closed socket connection for client /HOST_1:40556 which had sessionid
SESSION_1


On Thu, Feb 10, 2011 at 8:11 PM, Benjamin Reed <breed@yahoo-inc.com> wrote:
> do you see anything in the server log?
>
> ben
>
> On 02/10/2011 03:16 PM, Patania, Nick wrote:
>>
>> Hello,
>>
>> I run the following test:
>>
>>
>> * =A0 =A0 =A0 =A0 Two clients connect to a zookeeper server; the tickTim=
e on the
>> server is 500, and the sessionTimeout on the client is 1000.
>>
>> * =A0 =A0 =A0 =A0 Kill the host running one of the clients.
>>
>> * =A0 =A0 =A0 =A0 The second client receives a session timeout.
>>
>> Is there any reason why this might happen?
>>
>> Thanks
>> Nick Patania
>>
>>
>> ------------------------------------------------------------------------=
--
>> NOTICE: Morgan Stanley is not acting as a municipal advisor and the
>> opinions or views contained herein are not intended to be, and do not
>> constitute, advice within the meaning of Section 975 of the Dodd-Frank W=
all
>> Street Reform and Consumer Protection Act. If you have received this
>> communication in error, please destroy all electronic and paper copies a=
nd
>> notify the sender immediately. Mistransmission is not intended to waive
>> confidentiality or privilege. Morgan Stanley reserves the right, to the
>> extent permitted under applicable law, to monitor electronic communicati=
ons.
>> This message is subject to terms available at the following link:
>> http://www.morganstanley.com/disclaimers. If you cannot access these lin=
ks,
>> please notify us by reply message and we will send the contents to you. =
By
>> messaging with Morgan Stanley you consent to the foregoing.
>
>