summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorKali Kaneko <kali@leap.se>2013-09-27 16:07:29 -0400
committerKali Kaneko <kali@leap.se>2013-09-30 13:58:15 -0400
commitf2c68ba96498f8b88e415aaf27ced735c790510e (patch)
tree6eccf873ae1ef31c8ec4b268e6eb9485f2516c80
parent4728ea9e5cbb0f7ed47e7ca609c0531a31c847e0 (diff)
Improve error handling during soledad boostrapping in the client.
The aim is to have better logs for debugging the different problems behind issues like #3619 and #3867. As I'm finding a good quantity of SSL handshake timeouts, I'm also adding a litte retry subroutine to the load_and_sync. Also, initialization and sync calls are separeted to be able to correlate logs with server-side soledad.
-rw-r--r--src/leap/bitmask/services/soledad/soledadbootstrapper.py205
-rw-r--r--src/leap/bitmask/util/__init__.py14
2 files changed, 170 insertions, 49 deletions
diff --git a/src/leap/bitmask/services/soledad/soledadbootstrapper.py b/src/leap/bitmask/services/soledad/soledadbootstrapper.py
index cac91440..afd7d623 100644
--- a/src/leap/bitmask/services/soledad/soledadbootstrapper.py
+++ b/src/leap/bitmask/services/soledad/soledadbootstrapper.py
@@ -14,15 +14,15 @@
#
# You should have received a copy of the GNU General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
-
"""
Soledad bootstrapping
"""
-
import logging
import os
import socket
+from ssl import SSLError
+
from PySide import QtCore
from u1db import errors as u1db_errors
@@ -32,9 +32,10 @@ from leap.bitmask.crypto.srpauth import SRPAuth
from leap.bitmask.services.abstractbootstrapper import AbstractBootstrapper
from leap.bitmask.services.soledad.soledadconfig import SoledadConfig
from leap.bitmask.util.request_helpers import get_content
+from leap.bitmask.util import is_file, is_empty_file
from leap.bitmask.util import get_path_prefix
-from leap.common.check import leap_assert, leap_assert_type
from leap.common.files import get_mtime
+from leap.common.check import leap_assert, leap_assert_type, leap_check
from leap.keymanager import KeyManager, openpgp
from leap.keymanager.errors import KeyNotFound
from leap.soledad.client import Soledad
@@ -42,6 +43,17 @@ from leap.soledad.client import Soledad
logger = logging.getLogger(__name__)
+# TODO these exceptions could be moved to soledad itself
+# after settling this down.
+
+class SoledadSyncError(Exception):
+ message = "Error while syncing Soledad"
+
+
+class SoledadInitError(Exception):
+ message = "Error while initializing Soledad"
+
+
class SoledadBootstrapper(AbstractBootstrapper):
"""
Soledad init procedure
@@ -109,68 +121,159 @@ class SoledadBootstrapper(AbstractBootstrapper):
"""
self._soledad_retries += 1
+ def _get_db_paths(self, uuid):
+ """
+ Returns the secrets and local db paths needed for soledad
+ initialization
+
+ :param uuid: uuid for user
+ :type uuid: str
+
+ :return: a tuple with secrets, local_db paths
+ :rtype: tuple
+ """
+ prefix = os.path.join(get_path_prefix(), "leap", "soledad")
+ secrets = "%s/%s.secret" % (prefix, uuid)
+ local_db = "%s/%s.db" % (prefix, uuid)
+
+ # We remove an empty file if found to avoid complains
+ # about the db not being properly initialized
+ if is_file(local_db) and is_empty_file(local_db):
+ try:
+ os.remove(local_db)
+ except OSError:
+ logger.warning("Could not remove empty file %s"
+ % local_db)
+ return secrets, local_db
+
# initialization
def load_and_sync_soledad(self):
"""
Once everthing is in the right place, we instantiate and sync
Soledad
-
- :param srp_auth: SRPAuth object used
- :type srp_auth: SRPAuth
"""
- srp_auth = self.srpauth
- uuid = srp_auth.get_uid()
+ uuid = self.srpauth.get_uid()
+ token = self.srpauth.get_token()
- prefix = os.path.join(get_path_prefix(), "leap", "soledad")
- secrets_path = "%s/%s.secret" % (prefix, uuid)
- local_db_path = "%s/%s.db" % (prefix, uuid)
+ secrets_path, local_db_path = self._get_db_paths(uuid)
# TODO: Select server based on timezone (issue #3308)
server_dict = self._soledad_config.get_hosts()
- if server_dict.keys():
- selected_server = server_dict[server_dict.keys()[0]]
- server_url = "https://%s:%s/user-%s" % (
- selected_server["hostname"],
- selected_server["port"],
- uuid)
+ if not server_dict.keys():
+ # XXX raise more specific exception
+ raise Exception("No soledad server found")
+
+ selected_server = server_dict[server_dict.keys()[0]]
+ server_url = "https://%s:%s/user-%s" % (
+ selected_server["hostname"],
+ selected_server["port"],
+ uuid)
+
+ logger.debug("Using soledad server url: %s" % (server_url,))
- logger.debug("Using soledad server url: %s" % (server_url,))
+ cert_file = self._provider_config.get_ca_cert_path()
- cert_file = self._provider_config.get_ca_cert_path()
+ logger.debug('local_db:%s' % (local_db_path,))
+ logger.debug('secrets_path:%s' % (secrets_path,))
- # TODO: If selected server fails, retry with another host
- # (issue #3309)
+ try:
+ self._try_soledad_init(
+ uuid, secrets_path, local_db_path,
+ server_url, cert_file, token)
+ except:
+ # re-raise the exceptions from try_init,
+ # we're currently handling the retries from the
+ # soledad-launcher in the gui.
+ raise
+
+ leap_check(self._soledad is not None,
+ "Null soledad, error while initializing")
+
+ # and now, let's sync
+ sync_tries = 10
+ while sync_tries > 0:
try:
- self._soledad = Soledad(
- uuid,
- self._password.encode("utf-8"),
- secrets_path=secrets_path,
- local_db_path=local_db_path,
- server_url=server_url,
- cert_file=cert_file,
- auth_token=srp_auth.get_token())
- self._soledad.sync()
-
- # XXX All these errors should be handled by soledad itself,
- # and return a subclass of SoledadInitializationFailed
- except socket.timeout:
- logger.debug("SOLEDAD TIMED OUT...")
- self.soledad_timeout.emit()
- except socket.error as exc:
- logger.error("Socket error while initializing soledad")
- self.soledad_failed.emit()
- except u1db_errors.Unauthorized:
- logger.error("Error while initializing soledad "
- "(unauthorized).")
- self.soledad_failed.emit()
- except Exception as exc:
- logger.error("Unhandled error while initializating "
+ self._try_soledad_sync()
+ logger.debug("Soledad has been synced.")
+ # so long, and thanks for all the fish
+ return
+ except SoledadSyncError:
+ # maybe it's my connection, but I'm getting
+ # ssl handshake timeouts and read errors quite often.
+ # A particularly big sync is a disaster.
+ # This deserves further investigation, maybe the
+ # retry strategy can be pushed to u1db, or at least
+ # it's something worthy to talk about with the
+ # ubuntu folks.
+ sync_tries -= 1
+ continue
+
+ # reached bottom, failed to sync
+ # and there's nothing we can do...
+ self.soledad_failed.emit()
+ raise SoledadSyncError()
+
+ def _try_soledad_init(self, uuid, secrets_path, local_db_path,
+ server_url, cert_file, auth_token):
+ """
+ Tries to initialize soledad.
+
+ :param uuid: user identifier
+ :param secrets_path: path to secrets file
+ :param local_db_path: path to local db file
+ :param server_url: soledad server uri
+ :cert_file:
+ :param auth token: auth token
+ :type auth_token: str
+ """
+
+ # TODO: If selected server fails, retry with another host
+ # (issue #3309)
+ try:
+ self._soledad = Soledad(
+ uuid,
+ self._password.encode("utf-8"),
+ secrets_path=secrets_path,
+ local_db_path=local_db_path,
+ server_url=server_url,
+ cert_file=cert_file,
+ auth_token=auth_token)
+
+ # XXX All these errors should be handled by soledad itself,
+ # and return a subclass of SoledadInitializationFailed
+ except socket.timeout:
+ logger.debug("SOLEDAD initialization TIMED OUT...")
+ self.soledad_timeout.emit()
+ except socket.error as exc:
+ logger.error("Socket error while initializing soledad")
+ self.soledad_failed.emit()
+ except u1db_errors.Unauthorized:
+ logger.error("Error while initializing soledad "
+ "(unauthorized).")
+ self.soledad_failed.emit()
+ except Exception as exc:
+ logger.exception("Unhandled error while initializating "
"soledad: %r" % (exc,))
- raise
- else:
- raise Exception("No soledad server found")
+ self.soledad_failed.emit()
+
+ def _try_soledad_sync(self):
+ """
+ Tries to sync soledad.
+ Raises SoledadSyncError if not successful.
+ """
+ try:
+ logger.error("trying to sync soledad....")
+ self._soledad.sync()
+ except SSLError as exc:
+ logger.error("%r" % (exc,))
+ raise SoledadSyncError("Failed to sync soledad")
+ except Exception as exc:
+ logger.exception("Unhandled error while syncing"
+ "soledad: %r" % (exc,))
+ self.soledad_failed.emit()
+ raise SoledadSyncError("Failed to sync soledad")
def _download_config(self):
"""
@@ -185,6 +288,8 @@ class SoledadBootstrapper(AbstractBootstrapper):
self._soledad_config = SoledadConfig()
+ # TODO factor out with eip/provider configs.
+
headers = {}
mtime = get_mtime(
os.path.join(get_path_prefix(), "leap", "providers",
@@ -242,8 +347,10 @@ class SoledadBootstrapper(AbstractBootstrapper):
Generates the key pair if needed, uploads it to the webapp and
nickserver
"""
- leap_assert(self._provider_config,
+ leap_assert(self._provider_config is not None,
"We need a provider configuration!")
+ leap_assert(self._soledad is not None,
+ "We need a non-null soledad to generate keys")
address = "%s@%s" % (self._user, self._provider_config.get_domain())
diff --git a/src/leap/bitmask/util/__init__.py b/src/leap/bitmask/util/__init__.py
index f762a350..b58e6e3b 100644
--- a/src/leap/bitmask/util/__init__.py
+++ b/src/leap/bitmask/util/__init__.py
@@ -62,3 +62,17 @@ def update_modification_ts(path):
"""
os.utime(path, None)
return get_modification_ts(path)
+
+
+def is_file(path):
+ """
+ Returns True if the path exists and is a file.
+ """
+ return os.path.isfile(path)
+
+
+def is_empty_file(path):
+ """
+ Returns True if the file at path is empty.
+ """
+ return os.stat(path).st_size is 0