Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Threaded View
Zookeeper, mail # user - Testing expired sessions bug?


Copy link to this message
-
Testing expired sessions bug?
Ben Bangert 2012-08-21, 20:00
The Zookeeper FAQ documents the following to create a session expiration for testing:

"In the case of testing we want to cause a problem, so to explicitly expire a session an application connects to ZooKeeper, saves the session id and password, creates another ZooKeeper handle with that id and password, and then closes the new handle. Since both handles reference the same session, the close on second handle will invalidate the session causing a SESSION_EXPIRED on the first handle."
This apparently works.... some of the time. Our tests show that it seems to work as this describes about 95% of the time. The other times, the new client being connected with the existing client id immediately gets an EXPIRED_SESSION_STATE upon connecting. The existing client does *not* get the session expiration as the docs seem to think, its session is fine. This is a bit odd as the client attempting to re-use the session ID/password is told the session is expired, while the existing connected client is fine (seemingly invalidating the claim that the session is expired).

This appears in a 3-server setup when having the new client go to a separate server in the cluster from the first one, and when they're both on the same Zookeeper server.

When they go to the same server, I get rather confusing information by watching the clients global watcher debug info:

ZooKeeper: INFO: log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.3
ZooKeeper: INFO: log_env@716: Client environment:host.name=Lars.local
ZooKeeper: INFO: log_env@723: Client environment:os.name=Darwin
ZooKeeper: INFO: log_env@724: Client environment:os.arch=12.0.0
ZooKeeper: INFO: log_env@725: Client environment:os.version=Darwin Kernel Version 12.0.0: Sun Jun 24 23:00:16 PDT 2012; root:xnu-2050.7.9~1/RELEASE_X86_64
ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20000/kazootests6859289a29b041e9bf7c4f69afde7e6c sessionTimeout=10000 watcher=0x1016c2420 sessionId=0 sessionPasswd=<null> context=0x102d12f00 flags=0
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20000]
ZooKeeper: INFO: check_events@1748: session establishment complete on server [127.0.0.1:20000], sessionId=0x1393db197700bff, negotiated timeout=10000
kazoo.client: DEBUG: Client Instance: 4319500112, Handle: 2, Type: SESSION_EVENT, State: CONNECTED_STATE, Path:
ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20000 sessionTimeout=10000 watcher=0x1016c2420 sessionId=0x1393db197700bff sessionPasswd=<hidden> context=0x102d14050 flags=0
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20000]
ZooKeeper: ERROR: handle_socket_error_msg@1719: Socket [127.0.0.1:20000] zk retcode=-4, errno=64(Host is down): failed while receiving a server response
ZooKeeper: ERROR: handle_socket_error_msg@1737: Socket [127.0.0.1:20000] zk retcode=-112, errno=70(Stale NFS file handle): sessionId=0x1393db197700bff has expired.
kazoo.client: DEBUG: Client Instance: 4319532240, Handle: 3, Type: SESSION_EVENT, State: EXPIRED_SESSION_STATE, Path:
kazoo.client: DEBUG: Client Instance: 4319500112, Handle: 2, Type: SESSION_EVENT, State: CONNECTING_STATE, Path:
ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20000 sessionTimeout=10000 watcher=0x1016c2420 sessionId=0 sessionPasswd=<null> context=0x102d08cc0 flags=0
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20000]
ZooKeeper: INFO: check_events@1748: session establishment complete on server [127.0.0.1:20000], sessionId=0x1393db197700c00, negotiated timeout=10000
kazoo.client: DEBUG: Client Instance: 4319532240, Handle: 4, Type: SESSION_EVENT, State: CONNECTED_STATE, Path:
ZooKeeper: INFO: zookeeper_close@2506: Closing zookeeper sessionId=0x1393db197700c00 to [127.0.0.1:20000]
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20000]
ZooKeeper: INFO: check_events@1748: session establishment complete on server [127.0.0.1:20000], sessionId=0x1393db197700bff, negotiated timeout=10000
kazoo.client: DEBUG: Client Instance: 4319500112, Handle: 2, Type: SESSION_EVENT, State: CONNECTED_STATE, Path:

The second client gets an expired session state upon connecting, the first client gets disconnect (but NOT expired). The debug clearly indicates the server just said that sessionId 0x1393db197700bff has expired. Yet the second line from the bottom, we can see the first client successfully reconnect with its session that supposedly is expired.

When the second client uses a different server, it just gets kicked off and the first client never gets disconnected:

ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20000/kazootests0209e8a645674d4d865d22960fb579bb sessionTimeout=10000 watcher=0x1016c2420 sessionId=0 sessionPasswd=<null> context=0x10189bf10 flags=0
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20000]
ZooKeeper: INFO: check_events@1748: session establishment complete on server [127.0.0.1:20000], sessionId=0x1393db197700cc7, negotiated timeout=10000
kazoo.client: DEBUG: Client Instance: 4319500688, Handle: 2, Type: SESSION_EVENT, State: CONNECTED_STATE, Path:
ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20010 sessionTimeout=10000 watcher=0x1016c2420 sessionId=0x1393db197700cc7 sessionPasswd=<hidden> context=0x101835030 flags=0
ZooKeeper: INFO: check_events@1701: initiated connection to server [127.0.0.1:20010]
ZooKeeper: ERROR: handle_socket_error_msg@1737: Socket [127.0.0.1:20010] zk retcode=-112, errno=70(Stale NFS file handle): sessionId=0x1393db197700cc7 has expired.
kazoo.client: DEBUG: Client Instance: 4319532240, Handle: 3, Type: SESSION_EVENT, State: EXPIRED_SESSION_STATE, Path:
ZooKeeper: INFO: zookeeper_init@786: Initiating client connection, host=127.0.0.1:20010 sessionTimeout=10000 watcher=0x1016c2420 sessionId=0 sessionPass