helix-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "dafu (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (HELIX-125) ZkStateChange callbacks may be missing. Logics relies on correct sequence of ZkStateChange callbacks may break
Date Thu, 06 Jun 2013 18:51:20 GMT

     [ https://issues.apache.org/jira/browse/HELIX-125?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

dafu updated HELIX-125:
-----------------------

    Description: 
It seems that ZkStateChange callbacks might be missing in an arbitrary manner.

Note that in the following log, 

1) we missed CONNECT state callback for session 538bfded5e65ca7, but we got DISCONNECT/EXPIRED
state callbacks for this session

2) we got CONNECTED state callback for session 338bfded5e65cd2, but we missed DISCONNECTED/EXPIRED
state callbacks for this session

3) we missed all CONNECTED/DISCONNECTED/EXPIRED state callbacks for session 238bfded5e55cd0

So logics that relies on the correct sequence of zk state change callbacks may break.


=================================================================
2013/06/04 21:38:34.521 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e45, negotiated
timeout = 30000

2013/06/04 21:43:05.603 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e45 has expired, closing socket
connection

-- 2013/06/04 21:43:04.749 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e45, instance:
host_1, type: CONTROLLER

-- 2013/06/04 21:43:05.603 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e45, instance: host_1, type:
CONTROLLER

2013/06/04 21:43:05.724 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e4b, negotiated
timeout = 30000

-- 2013/06/04 21:44:20.060 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x138bfded5e45e4b
local:49952 remoteserver:host:12916 lastZxid:8649556581 xid:5256 sent:5256 recv:5264 queuedpkts:0
pendingresp:0 queuedevents:0

2013/06/04 21:45:03.150 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e4b has expired, closing socket
connection

-- 2013/06/04 21:45:02.226 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e4b, instance:
host_1, type: CONTROLLER

-- 2013/06/04 21:45:03.150 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e4b, instance: host_1, type:
CONTROLLER

2013/06/04 21:45:03.166 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x538bfded5e65ca7, negotiated
timeout = 30000

2013/06/04 21:45:51.201 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x538bfded5e65ca7 has expired, closing socket
connection

2013/06/04 21:45:51.213 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x338bfded5e65cd2, negotiated
timeout = 30000

-- 2013/06/04 21:45:52.780 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x338bfded5e65cd2
local:33493 remoteserver:host:12916 lastZxid:8649558026 xid:2965 sent:2965 recv:2983 queuedpkts:0
pendingresp:0 queuedevents:0

-- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 538bfded5e65ca7, instance:
host_1, type: CONTROLLER

-- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 538bfded5e65ca7, instance: host_1, type:
CONTROLLER

2013/06/04 21:46:45.010 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x338bfded5e65cd2 has expired, closing socket
connection

2013/06/04 21:46:45.022 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on host:12916, sessionid = 0x238bfded5e55cd0, negotiated timeout
= 30000

2013/06/04 21:47:38.430 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x238bfded5e55cd0 has expired, closing socket
connection

2013/06/04 21:47:38.462 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x438bfded5f65b62, negotiated
timeout = 30000

-- 2013/06/04 21:47:39.550 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x438bfded5f65b62
local:47001 remoteserver:host:12916 lastZxid:8649559958 xid:792 sent:792 recv:792 queuedpkts:0
pendingresp:0 queuedevents:0








  was:
It seems that ZkStateChange callbacks might be missing in an arbitrary manner.

Note that in the following log, 

1) we missed CONNECT state callback for session 538bfded5e65ca7, but we got DISCONNECT/EXPIRED
state callbacks for this session

2) we got CONNECTED state callback for session 338bfded5e65cd2, but we missed DISCONNECTED/EXPIRED
state callbacks for this session

3) we missed all CONNECTED/DISCONNECTED/EXPIRED state callbacks for session 238bfded5e55cd0

So logics that relies on the correct sequence of zk state change callbacks may break.


=================================================================
2013/06/04 21:38:34.521 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e45, negotiated
timeout = 30000

2013/06/04 21:43:05.603 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e45 has expired, closing socket
connection

-- 2013/06/04 21:43:04.749 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e45, instance:
host_1, type: CONTROLLER

-- 2013/06/04 21:43:05.603 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e45, instance: host_1, type:
CONTROLLER

2013/06/04 21:43:05.724 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e4b, negotiated
timeout = 30000

-- 2013/06/04 21:44:20.060 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x138bfded5e45e4b
local:49952 remoteserver:host:12916 lastZxid:8649556581 xid:5256 sent:5256 recv:5264 queuedpkts:0
pendingresp:0 queuedevents:0

2013/06/04 21:45:03.150 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e4b has expired, closing socket
connection

-- 2013/06/04 21:45:02.226 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e4b, instance:
ech3-app2879_1, type: CONTROLLER

-- 2013/06/04 21:45:03.150 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e4b, instance: host_1, type:
CONTROLLER

2013/06/04 21:45:03.166 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x538bfded5e65ca7, negotiated
timeout = 30000

2013/06/04 21:45:51.201 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x538bfded5e65ca7 has expired, closing socket
connection

2013/06/04 21:45:51.213 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x338bfded5e65cd2, negotiated
timeout = 30000

-- 2013/06/04 21:45:52.780 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x338bfded5e65cd2
local:33493 remoteserver:host:12916 lastZxid:8649558026 xid:2965 sent:2965 recv:2983 queuedpkts:0
pendingresp:0 queuedevents:0

-- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 538bfded5e65ca7, instance:
host_1, type: CONTROLLER

-- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 538bfded5e65ca7, instance: host_1, type:
CONTROLLER

2013/06/04 21:46:45.010 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x338bfded5e65cd2 has expired, closing socket
connection

2013/06/04 21:46:45.022 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on host:12916, sessionid = 0x238bfded5e55cd0, negotiated timeout
= 30000

2013/06/04 21:47:38.430 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x238bfded5e55cd0 has expired, closing socket
connection

2013/06/04 21:47:38.462 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x438bfded5f65b62, negotiated
timeout = 30000

-- 2013/06/04 21:47:39.550 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x438bfded5f65b62
local:47001 remoteserver:host:12916 lastZxid:8649559958 xid:792 sent:792 recv:792 queuedpkts:0
pendingresp:0 queuedevents:0








    
> ZkStateChange callbacks may be missing. Logics relies on correct sequence of ZkStateChange
callbacks may break
> --------------------------------------------------------------------------------------------------------------
>
>                 Key: HELIX-125
>                 URL: https://issues.apache.org/jira/browse/HELIX-125
>             Project: Apache Helix
>          Issue Type: Bug
>            Reporter: dafu
>
> It seems that ZkStateChange callbacks might be missing in an arbitrary manner.
> Note that in the following log, 
> 1) we missed CONNECT state callback for session 538bfded5e65ca7, but we got DISCONNECT/EXPIRED
state callbacks for this session
> 2) we got CONNECTED state callback for session 338bfded5e65cd2, but we missed DISCONNECTED/EXPIRED
state callbacks for this session
> 3) we missed all CONNECTED/DISCONNECTED/EXPIRED state callbacks for session 238bfded5e55cd0
> So logics that relies on the correct sequence of zk state change callbacks may break.
> =================================================================
> 2013/06/04 21:38:34.521 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e45, negotiated
timeout = 30000
> 2013/06/04 21:43:05.603 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e45 has expired, closing socket
connection
> -- 2013/06/04 21:43:04.749 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e45, instance:
host_1, type: CONTROLLER
> -- 2013/06/04 21:43:05.603 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e45, instance: host_1, type:
CONTROLLER
> 2013/06/04 21:43:05.724 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x138bfded5e45e4b, negotiated
timeout = 30000
> -- 2013/06/04 21:44:20.060 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x138bfded5e45e4b
local:49952 remoteserver:host:12916 lastZxid:8649556581 xid:5256 sent:5256 recv:5264 queuedpkts:0
pendingresp:0 queuedevents:0
> 2013/06/04 21:45:03.150 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x138bfded5e45e4b has expired, closing socket
connection
> -- 2013/06/04 21:45:02.226 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 138bfded5e45e4b, instance:
host_1, type: CONTROLLER
> -- 2013/06/04 21:45:03.150 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 138bfded5e45e4b, instance: host_1, type:
CONTROLLER
> 2013/06/04 21:45:03.166 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x538bfded5e65ca7, negotiated
timeout = 30000
> 2013/06/04 21:45:51.201 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x538bfded5e65ca7 has expired, closing socket
connection
> 2013/06/04 21:45:51.213 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x338bfded5e65cd2, negotiated
timeout = 30000
> -- 2013/06/04 21:45:52.780 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x338bfded5e65cd2
local:33493 remoteserver:host:12916 lastZxid:8649558026 xid:2965 sent:2965 recv:2983 queuedpkts:0
pendingresp:0 queuedevents:0
> -- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Disconnected, disconnectedSessionId: 538bfded5e65ca7, instance:
host_1, type: CONTROLLER
> -- 2013/06/04 21:45:52.782 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState:Expired, expiredSessionId: 538bfded5e65ca7, instance: host_1, type:
CONTROLLER
> 2013/06/04 21:46:45.010 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x338bfded5e65cd2 has expired, closing socket
connection
> 2013/06/04 21:46:45.022 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on host:12916, sessionid = 0x238bfded5e55cd0, negotiated timeout
= 30000
> 2013/06/04 21:47:38.430 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Unable to reconnect to ZooKeeper service, session 0x238bfded5e55cd0 has expired, closing socket
connection
> 2013/06/04 21:47:38.462 INFO [ClientCnxn] [pool-57-thread-3-SendThread(host:12916)] [seas-manager]
Session establishment complete on server host:12916, sessionid = 0x438bfded5f65b62, negotiated
timeout = 30000
> -- 2013/06/04 21:47:39.550 INFO [ZkStateChangeListener] [ZkClient-EventThread-381-host:12916/seas/helix]
[seas-manager] KeeperState: SyncConnected, zookeeper:State:CONNECTED Timeout:30000 sessionid:0x438bfded5f65b62
local:47001 remoteserver:host:12916 lastZxid:8649559958 xid:792 sent:792 recv:792 queuedpkts:0
pendingresp:0 queuedevents:0

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message