zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jun Rao (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (ZOOKEEPER-2867) an expired ZK session can be re-established
Date Tue, 08 Aug 2017 21:17:00 GMT

    [ https://issues.apache.org/jira/browse/ZOOKEEPER-2867?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16119048#comment-16119048
] 

Jun Rao edited comment on ZOOKEEPER-2867 at 8/8/17 9:16 PM:
------------------------------------------------------------

[~hanm], thanks for the explanation. The client on session 25cd1e82c110001 actually died around
Aug 2, 23:16:11. From ZK server's log, the last ping from that session was around that time.
Then ZK server was restarted around 23:41:28.

{code:java}
August 2nd 2017, 23:16:11.086	DEBUG	org.apache.zookeeper.server.FinalRequestProcessor	sessionid:0x25cd1e82c110001
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
August 2nd 2017, 23:16:11.086	DEBUG	org.apache.zookeeper.server.quorum.CommitProcessor	Processing
request:: sessionid:0x25cd1e82c110001 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
August 2nd 2017, 23:41:28.699	INFO	org.apache.zookeeper.server.NIOServerCnxnFactory	binding
to port 0.0.0.0/0.0.0.0:2181
August 2nd 2017, 23:41:29.149	DEBUG	org.apache.zookeeper.server.DataTree	Deleting ephemeral
node /cp15/brokers/ids/0 for session 0x25cd1e82c110001
{code}

However, I couldn't find any entry about the closing of that session in ZK commit log around
that time. So, it's not clear to me if ZK server ever closed that session. Should every closed
session be in the ZK commit log?



was (Author: junrao):
[~hanm], thanks for the explanation. The client on session 25cd1e82c110001 actually died around
Aug 2, 23:16:11. From ZK server's log, the last ping from that session was around that time.
Then ZK server was restarted around 23:41:28.

{code:java}
August 2nd 2017, 23:16:11.086	DEBUG	org.apache.zookeeper.server.FinalRequestProcessor	sessionid:0x25cd1e82c110001
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
August 2nd 2017, 23:16:11.086	DEBUG	org.apache.zookeeper.server.quorum.CommitProcessor	Processing
request:: sessionid:0x25cd1e82c110001 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe
txntype:unknown reqpath:n/a
August 2nd 2017, 23:41:28.699	INFO	org.apache.zookeeper.server.NIOServerCnxnFactory	binding
to port 0.0.0.0/0.0.0.0:2181
August 2nd 2017, 23:41:29.149	DEBUG	org.apache.zookeeper.server.DataTree	Deleting ephemeral
node /cp15/brokers/ids/0 for session 0x25cd1e82c110001
{code}

However, I could find any entry about the closing of that session in ZK commit log around
that time. So, it's not clear to me if ZK server ever closed that session. Should every closed
session be in the ZK commit log?


> an expired ZK session can be re-established
> -------------------------------------------
>
>                 Key: ZOOKEEPER-2867
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2867
>             Project: ZooKeeper
>          Issue Type: Bug
>    Affects Versions: 3.4.10
>            Reporter: Jun Rao
>         Attachments: zk.0.formatted, zk.1.formatted
>
>
> Not sure if this is a real bug, but I found an instance when a ZK client seems to be
able to renew a session already expired by the ZK server.
> From ZK server log, session 25cd1e82c110001 was expired at 22:04:39.
> {code:java}
> June 27th 2017, 22:04:39.000	INFO	org.apache.zookeeper.server.ZooKeeperServer	Expiring
session 0x25cd1e82c110001, timeout of 12000ms exceeded
> June 27th 2017, 22:04:39.001	DEBUG	org.apache.zookeeper.server.quorum.Leader	Proposing::
sessionid:0x25cd1e82c110001 type:closeSession cxid:0x0 zxid:0x200000fc4 txntype:-11 reqpath:n/a
> June 27th 2017, 22:04:39.001	INFO	org.apache.zookeeper.server.PrepRequestProcessor	Processed
session termination for sessionid: 0x25cd1e82c110001
> June 27th 2017, 22:04:39.001	DEBUG	org.apache.zookeeper.server.quorum.CommitProcessor
Processing request:: sessionid:0x25cd1e82c110001 type:closeSession cxid:0x0 zxid:0x200000fc4
txntype:-11 reqpath:n/a
> June 27th 2017, 22:05:20.324	INFO	org.apache.zookeeper.server.quorum.Learner	Revalidating
client: 0x25cd1e82c110001
> June 27th 2017, 22:05:20.324	INFO	org.apache.zookeeper.server.ZooKeeperServer	Client
attempting to renew session 0x25cd1e82c110001 at /100.96.5.6:47618
> June 27th 2017, 22:05:20.325	INFO	org.apache.zookeeper.server.ZooKeeperServer	Established
session 0x25cd1e82c110001 with negotiated timeout 12000 for client /100.96.5.6:47618
> {code}
> From ZK client's log, it was able to renew the expired session on 22:05:20.
> {code:java}
> June 27th 2017, 22:05:18.590	INFO	org.apache.zookeeper.ClientCnxn	Client session timed
out, have not heard from server in 4485ms for sessionid 0x25cd1e82c110001, closing socket
connection and attempting reconnect	0
> June 27th 2017, 22:05:18.590	WARN	org.apache.zookeeper.ClientCnxn	Client session timed
out, have not heard from server in 4485ms for sessionid 0x25cd1e82c110001	0
> June 27th 2017, 22:05:19.325	WARN	org.apache.zookeeper.ClientCnxn	SASL configuration
failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client'
was found in specified JAAS configuration file: '/opt/confluent/etc/kafka/server_jaas.conf'.
Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server
allows it.	0
> June 27th 2017, 22:05:19.326	INFO	org.apache.zookeeper.ClientCnxn	Opening socket connection
to server 100.65.188.168/100.65.188.168:2181	0
> June 27th 2017, 22:05:20.324	INFO	org.apache.zookeeper.ClientCnxn	Socket connection established
to 100.65.188.168/100.65.188.168:2181, initiating session	0
> June 27th 2017, 22:05:20.327	INFO	org.apache.zookeeper.ClientCnxn	Session establishment
complete on server 100.65.188.168/100.65.188.168:2181, sessionid = 0x25cd1e82c110001, negotiated
timeout = 12000	0
> {code}



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message