zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Patrick Hunt <ph...@apache.org>
Subject Re: is there a 40s connection timeout that expires a session?
Date Wed, 19 Oct 2011 17:31:46 GMT
Ack, sorry about that, jumped directly to my canned response. :-)

Does 600 seconds typically work, but just failed in this particular
case? (what version of zk are you using?) Can you reproduce this or
just a one off?

Could the time on the server have been changed? ie say via ntp? (we've
seen this before)

Any idea why the client is unable to access the server during this
period? Is this the only client activity against the server?

Patrick

On Wed, Oct 19, 2011 at 10:18 AM, Martin Serrano <martin@attivio.com> wrote:
> Patrick,
>
> Thanks.  I know about the negotiated timeout and how the maximum is specified.  We
start up our server so that it allows a greater timeout.  In the logs I attached you can
see that the negotiated timeout is 600000ms, but I still get the session expired message at
40s.
>
> -Martin
>
>> -----Original Message-----
>> From: Patrick Hunt [mailto:phunt@apache.org]
>> Sent: Wednesday, October 19, 2011 12:57 PM
>> To: user@zookeeper.apache.org
>> Subject: Re: is there a 40s connection timeout that expires a session?
>>
>> The actual session timeout is negotiated btw the client and server, there is
>> both a min and a max enforced by the server.
>>
>> See this section on session details:
>> http://zookeeper.apache.org/doc/r3.3.3/zookeeperProgrammers.html#ch_
>> zkSessions
>> "One of the parameters to the ZooKeeper client library call to create a
>> ZooKeeper session is the session timeout in milliseconds. The client sends a
>> requested timeout, the server responds with the timeout that it can give the
>> client. The current implementation requires that the timeout be a minimum
>> of 2 times the tickTime (as set in the server
>> configuration) and a maximum of 20 times the tickTime. The ZooKeeper
>> client API allows access to the negotiated timeout."
>>
>> You're seeing the default (20*ticktime, which is typically 2 sec, so 40sec max)
>>
>> See here: (maxSessionTimeout)
>> http://zookeeper.apache.org/doc/r3.3.3/zookeeperAdmin.html#sc_advanc
>> edConfiguration
>>
>>
>> btw, setting a 10min timeout will probably cause you problems down the
>> road - as things that depend on ephemeral nodes (e.g. leader failover) will
>> take too long to be effective. (typically)
>>
>> Patrick
>>
>> On Wed, Oct 19, 2011 at 8:48 AM, Martin Serrano <martin@attivio.com>
>> wrote:
>> > I'm seeing something a bit weird.  In our environment we've upped the
>> session timeout to 10 minutes.  I see that the client connections successfully
>> negotiate the 10 minute timeout.  However I've seen a case where the client
>> session gets timed out in 40s if it is unable to ever initiate the session.  Is
>> there a separate timeout somewhere?
>> >
>> > Thanks,
>> > Martin
>> >
>> > Log excerpts below (unfortunately the server-side logs are not available):
>> >
>> > 2011-10-18 21:38:59,218 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread()-0] - Opening socket connection to
>> > server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:38:59,220 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Session 0x0 for
>> > server null, unexpected error, closing socket connection and
>> > attempting reconnect
>> > 2011-10-18 21:39:00,181 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:00,184 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Socket
>> > connection established to localhost/127.0.0.1:16015, initiating
>> > session
>> > 2011-10-18 21:39:00,241 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Session
>> > establishment complete on server localhost/127.0.0.1:16015, sessionid
>> > = 0x13319d4a8c3000c, negotiated timeout = 600000
>> > 2011-10-18 21:39:00,326 INFO  ZooKeeper [main] - Initiating client
>> > connection, connectString=localhost:16015 sessionTimeout=600000
>> > watcher=com.attivio.global.AieZooKeeper@45490eb5
>> > 2011-10-18 21:39:00,329 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread()-0] - Opening socket connection to
>> > server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:00,329 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Session 0x0 for
>> > server null, unexpected error, closing socket connection and
>> > attempting reconnect
>> > 2011-10-18 21:39:00,665 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:00,666 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread(localhost:16015)-0] - Socket
>> > connection established to localhost/127.0.0.1:16015, initiating
>> > session
>> > 2011-10-18 21:39:00,670 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Session
>> > establishment complete on server localhost/127.0.0.1:16015, sessionid
>> > = 0x13319d4a8c3000d, negotiated timeout = 600000
>> > 2011-10-18 21:39:02,125 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Unable to read
>> > additional data from server sessionid 0x13319d4a8c3000d, likely server
>> > has closed socket, closing socket connection and attempting reconnect
>> > 2011-10-18 21:39:02,125 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Unable to read
>> > additional data from server sessionid 0x13319d4a8c3000c, likely server
>> > has closed socket, closing socket connection and attempting reconnect
>> > 2011-10-18 21:39:02,295 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:02,295 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Session
>> > 0x13319d4a8c3000d for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:02,873 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:02,873 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Session
>> > 0x13319d4a8c3000c for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:03,676 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:03,677 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Socket
>> connection
>> > established to localhost/127.0.0.1:16015, initiating session
>> > 2011-10-18 21:39:03,678 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Session
>> > 0x13319d4a8c3000d for server localhost/127.0.0.1:16015, unexpected
>> > error, closing socket connection and attempting reconnect
>> > 2011-10-18 21:39:04,027 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:04,027 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Session
>> > 0x13319d4a8c3000d for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:04,416 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:04,417 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Socket
>> connection
>> > established to localhost/127.0.0.1:16015, initiating session
>> > 2011-10-18 21:39:04,417 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Unable to read
>> > additional data from server sessionid 0x13319d4a8c3000c, likely server
>> > has closed socket, closing socket connection and attempting reconnect
>> > 2011-10-18 21:39:04,705 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:04,705 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Session
>> > 0x13319d4a8c3000c for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:05,447 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:05,448 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Socket
>> connection
>> > established to localhost/127.0.0.1:16015, initiating session
>> > 2011-10-18 21:39:05,449 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Unable to read
>> > additional data from server sessionid 0x13319d4a8c3000d, likely server
>> > has closed socket, closing socket connection and attempting reconnect
>> >
>> > Lots more of those, then:
>> >
>> > 2011-10-18 21:39:39,387 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:39,388 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Socket
>> connection
>> > established to localhost/127.0.0.1:16015, initiating session
>> > 2011-10-18 21:39:39,388 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Unable to read
>> > additional data from server sessionid 0x13319d4a8c3000c, likely server
>> > has closed socket, closing socket connection and attempting reconnect
>> > 2011-10-18 21:39:39,592 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:39,592 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Session
>> > 0x13319d4a8c3000d for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:39,735 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Opening socket
>> > connection to server localhost/0:0:0:0:0:0:0:1:16015
>> > 2011-10-18 21:39:39,735 WARN  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000c] - Session
>> > 0x13319d4a8c3000c for server null, unexpected error, closing socket
>> > connection and attempting reconnect
>> > 2011-10-18 21:39:41,400 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Opening socket
>> > connection to server localhost/127.0.0.1:16015
>> > 2011-10-18 21:39:41,401 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Socket
>> connection
>> > established to localhost/127.0.0.1:16015, initiating session
>> > 2011-10-18 21:39:41,402 INFO  ClientCnxn
>> > [ZooKeeperClientCnxn--SendThread-13319d4a8c3000d] - Unable to
>> > reconnect to ZooKeeper service, session 0x13319d4a8c3000d has expired,
>> > closing socket connection
>> >
>

Mime
View raw message