{"action":"created","issue":{"url":"https://api.github.com/repos/sakamotomsh/zha/issues/5","labels_url":"https://api.github.com/repos/sakamotomsh/zha/issues/5/labels{/name}","comments_url":"https://api.github.com/repos/sakamotomsh/zha/issues/5/comments","events_url":"https://api.github.com/repos/sakamotomsh/zha/issues/5/events","html_url":"https://github.com/sakamotomsh/zha/issues/5","id":123857363,"number":5,"title":"ZHA in SBY stopped when zookeeper leader process down","user":{"login":"bwtakacy","id":5819897,"avatar_url":"https://avatars.githubusercontent.com/u/5819897?v=3","gravatar_id":"","url":"https://api.github.com/users/bwtakacy","html_url":"https://github.com/bwtakacy","followers_url":"https://api.github.com/users/bwtakacy/followers","following_url":"https://api.github.com/users/bwtakacy/following{/other_user}","gists_url":"https://api.github.com/users/bwtakacy/gists{/gist_id}","starred_url":"https://api.github.com/users/bwtakacy/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bwtakacy/subscriptions","organizations_url":"https://api.github.com/users/bwtakacy/orgs","repos_url":"https://api.github.com/users/bwtakacy/repos","events_url":"https://api.github.com/users/bwtakacy/events{/privacy}","received_events_url":"https://api.github.com/users/bwtakacy/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":1,"created_at":"2015-12-25T06:29:52Z","updated_at":"2015-12-28T06:17:39Z","closed_at":null,"body":"From the stacktrace, there happened SessionExpiredError inside kazoo.\r\n\r\n```\r\nWARNING: 2015-12-25 15:17:45,504 Connection dropped: socket connection error: Connection refused\r\nINFO: 2015-12-25 15:17:45,504 Connecting to oonishitk-pg1:2181\r\nWARNING: 2015-12-25 15:17:45,520 Connection dropped: socket connection broken\r\nINFO: 2015-12-25 15:17:45,683 Connecting to oonishitk-pg3:2181\r\nWARNING: 2015-12-25 15:17:45,684 Connection dropped: socket connection error: Connection refused\r\nINFO: 2015-12-25 15:17:45,685 Connecting to oonishitk-pg1:2181\r\nINFO: 2015-12-25 15:17:45,690 Zookeeper connection established, state: CONNECTED\r\nINFO: 2015-12-25 15:17:45,690 zookeeper connection state changed CONNECTED\r\nException in thread Thread-6:\r\nTraceback (most recent call last):\r\n  File \"/usr/lib64/python2.6/threading.py\", line 532, in __bootstrap_inner\r\n    self.run()\r\n  File \"/home/postgres/zha/zha.py\", line 284, in run\r\n    self.in_elector_loop()\r\n  File \"/home/postgres/zha/zha.py\", line 303, in in_elector_loop\r\n    lock_result = self.lock.acquire(timeout=self.zha.config.get(\"elector_interval\",3))\r\n  File \"/usr/lib/python2.6/site-packages/kazoo-2.2.1-py2.6.egg/kazoo/recipe/lock.py\", line 174,\r\nin acquire\r\n    self._delete_node(self.node)\r\n  File \"/usr/lib/python2.6/site-packages/kazoo-2.2.1-py2.6.egg/kazoo/recipe/lock.py\", line 266,\r\nin _delete_node\r\n    self.client.delete(self.path + \"/\" + node)\r\n  File \"/usr/lib/python2.6/site-packages/kazoo-2.2.1-py2.6.egg/kazoo/client.py\", line 1293, in d\r\nelete\r\n    return self.delete_async(path, version).get()\r\n  File \"/usr/lib/python2.6/site-packages/kazoo-2.2.1-py2.6.egg/kazoo/handlers/utils.py\", line 72\r\n, in get\r\n    raise self._exception\r\nSessionExpiredError\r\n\r\nINFO: 2015-12-25 15:17:46,473 Connecting to oonishitk-pg2:2181\r\nINFO: 2015-12-25 15:17:46,477 Zookeeper connection established, state: CONNECTED\r\nINFO: 2015-12-25 15:17:46,478 zookeeper connection state changed CONNECTED\r\nINFO: 2015-12-25 15:17:47,027 State=(SBY:HEALTHY) TTL=(9,9) Threads=(ON,ON,OFF,)\r\nERROR: 2015-12-25 15:17:47,027 monitor/elector thread ended unexpectedly. Exit\r\nINFO: 2015-12-25 15:17:49,183 cluster monitor thread stopped.\r\nINFO: 2015-12-25 15:17:51,119 health monitor thread stopped.\r\nINFO: 2015-12-25 15:17:51,120 ZHA: main thread stopped.\r\nINFO: 2015-12-25 15:17:54,123 ZHA: main thread stopped.\r\n\r\n```"},"comment":{"url":"https://api.github.com/repos/sakamotomsh/zha/issues/comments/167493360","html_url":"https://github.com/sakamotomsh/zha/issues/5#issuecomment-167493360","issue_url":"https://api.github.com/repos/sakamotomsh/zha/issues/5","id":167493360,"user":{"login":"bwtakacy","id":5819897,"avatar_url":"https://avatars.githubusercontent.com/u/5819897?v=3","gravatar_id":"","url":"https://api.github.com/users/bwtakacy","html_url":"https://github.com/bwtakacy","followers_url":"https://api.github.com/users/bwtakacy/followers","following_url":"https://api.github.com/users/bwtakacy/following{/other_user}","gists_url":"https://api.github.com/users/bwtakacy/gists{/gist_id}","starred_url":"https://api.github.com/users/bwtakacy/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bwtakacy/subscriptions","organizations_url":"https://api.github.com/users/bwtakacy/orgs","repos_url":"https://api.github.com/users/bwtakacy/repos","events_url":"https://api.github.com/users/bwtakacy/events{/privacy}","received_events_url":"https://api.github.com/users/bwtakacy/received_events","type":"User","site_admin":false},"created_at":"2015-12-28T06:17:39Z","updated_at":"2015-12-28T06:17:39Z","body":"After some struggle with kazoo code, I have found that the below point in clinent.py at kazoo is doubtful.\r\n\r\n```\r\n 497     def _call(self, request, async_object):\r\n 498         \"\"\"Ensure there's an active connection and put the request in\r\n 499         the queue if there is.\r\n 500\r\n 501         Returns False if the call short circuits due to AUTH_FAILED,\r\n 502         CLOSED, EXPIRED_SESSION or CONNECTING state.\r\n 503\r\n 504         \"\"\"\r\n 505\r\n 506         if self._state == KeeperState.AUTH_FAILED:\r\n 507             async_object.set_exception(AuthFailedError())\r\n 508             return False\r\n 509         elif self._state == KeeperState.CLOSED:\r\n 510             async_object.set_exception(ConnectionClosedError(\r\n 511                 \"Connection has been closed\"))\r\n 512             return False\r\n 513         elif self._state in (KeeperState.EXPIRED_SESSION,\r\n 514                              KeeperState.CONNECTING):\r\n 515             async_object.set_exception(SessionExpiredError())\r\n 516             return False\r\n```\r\n\r\nThe last elif block raises SessionExpiredError even in KeeperState.CONNECTING.\r\nThis is what ZHA in SBY process encountered.\r\n\r\nAfter modifying the code as below, ZHA process comes to survive against ZooKeeper leader process down.\r\n\r\n```\r\n\r\n 497\r\n 498     def _call(self, request, async_object):\r\n 499         \"\"\"Ensure there's an active connection and put the request in\r\n 500         the queue if there is.\r\n 501\r\n 502         Returns False if the call short circuits due to AUTH_FAILED,\r\n 503         CLOSED, EXPIRED_SESSION or CONNECTING state.\r\n 504\r\n 505         \"\"\"\r\n 506\r\n 507         if self._state == KeeperState.AUTH_FAILED:\r\n 508             async_object.set_exception(AuthFailedError())\r\n 509             return False\r\n 510         elif self._state == KeeperState.CLOSED:\r\n 511             async_object.set_exception(ConnectionClosedError(\r\n 512                 \"Connection has been closed\"))\r\n 513             return False\r\n 514 #        elif self._state in (KeeperState.EXPIRED_SESSION,\r\n 515 #                             KeeperState.CONNECTING):\r\n 516         elif self._state == KeeperState.CONNECTING:\r\n 517             self.logger.warning('_call is called during KeepserState.CONNECTING')\r\n 518             return False\r\n 519         elif self._state == KeeperState.EXPIRED_SESSION:\r\n 520             self.logger.warning('SessionExpiredError from _call in client.py')\r\n 521             async_object.set_exception(SessionExpiredError())\r\n 522             return False\r\n```\r\n\r\nThe catch of KeeperState.CONNECTING may be not necessary.\r\nThe above fix is just for debuggin.\r\n\r\nAnyway, it seems to be not a bug of zha but a bug of  kazoo...\r\n\r\nRegards,\r\n"}}