You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "Jun Rao (JIRA)" <ji...@apache.org> on 2017/08/05 00:05:00 UTC
[jira] [Updated] (ZOOKEEPER-2867) an expired ZK session can be
re-established
[ https://issues.apache.org/jira/browse/ZOOKEEPER-2867?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jun Rao updated ZOOKEEPER-2867:
-------------------------------
Description:
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}
was:
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 1 INFO org.apache.zookeeper.server.ZooKeeperServer Expiring session 0x25cd1e82c110001, timeout of 12000ms exceeded
June 27th 2017, 22:04:39.001 1 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 1 INFO org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x25cd1e82c110001
June 27th 2017, 22:04:39.001 1 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.323 2 DEBUG org.apache.zookeeper.server.quorum.Leader Proposing:: sessionid:0x25cd1e82c110001 type:setData cxid:0xdc zxid:0x30000047b txntype:5 reqpath:n/a
June 27th 2017, 22:05:20.323 2 DEBUG org.apache.zookeeper.server.quorum.CommitProcessor Processing request:: sessionid:0x25cd1e82c110001 type:setData cxid:0xdc zxid:0x30000047b txntype:5 reqpath:n/a
June 27th 2017, 22:05:20.324 1 INFO org.apache.zookeeper.server.quorum.Learner Revalidating client: 0x25cd1e82c110001
June 27th 2017, 22:05:20.324 1 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 1 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}
> 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
>
> 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)