On Mon, Apr 29, 2013 at 2:49 AM, Ted Yu <[email protected]> wrote: > After each zookeeper reconnect, I saw same session Id (0x703e...) > > What version of zookeeper are you using ? Can you search zookeeper log for > this session Id to see what happened ? > > Thanks >
Zookeeper version is 3.4.5, following are the logs from 2 zookeeper servers. The first one was the first time ever the regionserver connected to ZK and after that all of them are retries. I doubt the issue is on the ZK side since I have 3 other services running which run fine with the same quorum and have no issues. I feel I am hitting some other bug with HBase when the number of handlers is increased by a lot. Anyone seen a high number of handlers in any production deployment out there ? Thanks, Viral ===server with first session=== 2013-04-29 07:40:55,574 [myid:1072011376] - INFO [CommitProcessor:1072011376:ZooKeeperServer@595] - Established session 0x703e48a8cfd81be6 with negotiated timeout 40000 for client / 10.155.234.3:53814 EndOfStreamException: Unable to read additional data from client sessionid 0x703e48a8cfd81be6, likely client has closed socket 2013-04-29 07:43:47,737 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:53814 which had sessionid 0x703e48a8cfd81be6 2013-04-29 07:46:29,679 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client attempting to renew session 0x703e48a8cfd81be6 at /10.155.234.3:53831 2013-04-29 07:46:29,679 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:Learner@107] - Revalidating client: 0x703e48a8cfd81be6 2013-04-29 07:46:29,680 [myid:1072011376] - INFO [QuorumPeer[myid=1072011376]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@595] - Established session 0x703e48a8cfd81be6 with negotiated timeout 40000 for client /10.155.234.3:53831 EndOfStreamException: Unable to read additional data from client sessionid 0x703e48a8cfd81be6, likely client has closed socket 2013-04-29 07:49:10,401 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:53831 which had sessionid 0x703e48a8cfd81be6 2013-04-29 07:55:53,441 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client attempting to renew session 0x703e48a8cfd81be6 at /10.155.234.3:53854 2013-04-29 07:55:53,441 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:Learner@107] - Revalidating client: 0x703e48a8cfd81be6 2013-04-29 07:55:53,442 [myid:1072011376] - INFO [QuorumPeer[myid=1072011376]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@595] - Established session 0x703e48a8cfd81be6 with negotiated timeout 40000 for client /10.155.234.3:53854 EndOfStreamException: Unable to read additional data from client sessionid 0x703e48a8cfd81be6, likely client has closed socket 2013-04-29 07:58:33,947 [myid:1072011376] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:53854 which had sessionid 0x703e48a8cfd81be6 ===server with subsequent sessions=== 2013-04-29 07:44:28,733 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client attempting to renew session 0x703e48a8cfd81be6 at /10.155.234.3:51353 2013-04-29 07:44:28,734 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@595] - Established session 0x703e48a8cfd81be6 with negotiated timeout 40000 for client / 10.155.234.3:51353 EndOfStreamException: Unable to read additional data from client sessionid 0x703e48a8cfd81be6, likely client has closed socket 2013-04-29 07:46:29,206 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:51353 which had sessionid 0x703e48a8cfd81be6 2013-04-29 07:53:52,553 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client attempting to renew session 0x703e48a8cfd81be6 at /10.155.234.3:51376 2013-04-29 07:53:52,553 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@595] - Established session 0x703e48a8cfd81be6 with negotiated timeout 40000 for client / 10.155.234.3:51376 EndOfStreamException: Unable to read additional data from client sessionid 0x703e48a8cfd81be6, likely client has closed socket 2013-04-29 07:55:53,049 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:51376 which had sessionid 0x703e48a8cfd81be6 2013-04-29 08:02:36,000 [myid:54242244232] - INFO [SessionTracker:ZooKeeperServer@325] - Expiring session 0x703e48a8cfd81be6, timeout of 40000ms exceeded 2013-04-29 08:02:36,001 [myid:54242244232] - INFO [ProcessThread(sid:54242244232 cport:-1)::PrepRequestProcessor@476] - Processed session termination for sessionid: 0x703e48a8cfd81be6 2013-04-29 08:02:36,283 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client attempting to renew session 0x703e48a8cfd81be6 at /10.155.234.3:51398 2013-04-29 08:02:36,284 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@588] - Invalid session 0x703e48a8cfd81be6 for client /10.155.234.3:51398, probably expired 2013-04-29 08:02:36,284 [myid:54242244232] - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /10.155.234.3:51398 which had sessionid 0x703e48a8cfd81be6
