zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Marshall McMullen <marshall.mcmul...@gmail.com>
Subject Re: Testing expired sessions bug?
Date Wed, 22 Aug 2012 21:59:53 GMT
There is also a proposed patch to zookeeper (
https://issues.apache.org/jira/browse/ZOOKEEPER-829) that creates a znode
at /zookeeper/sessions that you could use to test session loss and recovery.

On Tue, Aug 21, 2012 at 2:00 PM, Ben Bangert <ben@groovie.org> wrote:

> 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/kazootests6859289a29b041e9bf7c4f69afde7e6csessionTimeout=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/kazootests0209e8a645674d4d865d22960fb579bbsessionTimeout=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
> sessionPasswd=<null> context=0x1015e0070 flags=0
> ZooKeeper: INFO: check_events@1701: initiated connection to server [
> 127.0.0.1:20010]
> ZooKeeper: INFO: check_events@1748: session establishment complete on
> server [127.0.0.1:20010], sessionId=0x2393db19cfe0015, 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=0x2393db19cfe0015 to [127.0.0.1:20010]
>
> I've even setup the test so that it creates new ephemeral nodes and such
> with the old supposedly expired session, and its just fine.
>
> Is this intended behavior?
>
> I have the tickTime set at 2000, setting it to 20000 didn't seem to help,
> nor did waiting longer to see if the first client would someday get its
> session expired.
>
> Cheers,
> Ben

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message