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 <[email protected]> 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:[email protected]] >> Sent: Wednesday, October 19, 2011 12:57 PM >> To: [email protected] >> 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 <[email protected]> >> 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 >> > >
