From 1b0aa97cd740d1251142ccd8d407bdf5a9b7afa8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?J=C3=A9r=C3=B4me=20Lebleu?= Date: Sat, 25 Oct 2014 13:46:54 +0200 Subject: [PATCH] [enh] Be more verbose in modules using new logging facilities --- locales/en.json | 2 + locales/fr.json | 4 +- moulinette/actionsmap.py | 74 ++++++++++++++++--------- moulinette/authenticators/__init__.py | 31 +++++++---- moulinette/authenticators/ldap.py | 16 ++++++ moulinette/core.py | 78 +++++++++++++++++---------- moulinette/interfaces/__init__.py | 31 +++++++---- moulinette/interfaces/api.py | 24 ++++++--- 8 files changed, 178 insertions(+), 82 deletions(-) diff --git a/locales/en.json b/locales/en.json index 408ec0cf..b2c6ccb0 100644 --- a/locales/en.json +++ b/locales/en.json @@ -7,6 +7,7 @@ "permission_denied" : "Permission denied", "root_required" : "You must be root to perform this action", "instance_already_running" : "An instance is already running", + "error_see_log" : "An error occured. Please see the log for details.", "unable_authenticate" : "Unable to authenticate", "unable_retrieve_session" : "Unable to retrieve the session", @@ -16,6 +17,7 @@ "argument_required" : "Argument {:s} is required", "invalid_argument": "Invalid argument '{:s}': {:s}", + "pattern_not_match": "Does not match pattern", "password" : "Password", "invalid_password" : "Invalid password", "confirm" : "Confirm {:s}", diff --git a/locales/fr.json b/locales/fr.json index 16097f1e..6dc7ca63 100644 --- a/locales/fr.json +++ b/locales/fr.json @@ -6,6 +6,7 @@ "permission_denied": "Permission refusée", "root_required": "Vous devez avoir les droits super-utilisateur pour exécuter cette action", "instance_already_running": "Une instance est déjà en cours d'exécution", + "error_see_log" : "Une erreur est survenue. Veuillez consulter les journaux pour plus de détails.", "unable_authenticate": "Impossible de vous authentifier", "unable_retrieve_session": "Impossible de récupérer la session", "ldap_server_down": "Impossible d'atteindre le serveur LDAP", @@ -13,6 +14,7 @@ "ldap_attribute_already_exists": "L'attribut existe déjà : '{:s}={:s}'", "argument_required": "L'argument {:s} est requis", "invalid_argument": "Argument '{:s}' incorrect : {:s}", + "pattern_not_match": "Ne correspond pas au motif", "password": "Mot de passe", "invalid_password": "Mot de passe incorrect", "confirm": "Confirmez le {:s}", @@ -26,4 +28,4 @@ "not_logged_in": "Vous n'êtes pas connecté", "server_already_running": "Un server est déjà en cours d'exécution sur ce port", "websocket_request_expected": "Excepter une demande de WebSocket" -} \ No newline at end of file +} diff --git a/moulinette/actionsmap.py b/moulinette/actionsmap.py index b8858a4e..eaa558ba 100644 --- a/moulinette/actionsmap.py +++ b/moulinette/actionsmap.py @@ -94,7 +94,6 @@ class AskParameter(_ExtraParameter): skipped_iface = [ 'api' ] def __call__(self, message, arg_name, arg_value): - # TODO: Fix asked arguments ordering if arg_value: return arg_value @@ -106,14 +105,14 @@ class AskParameter(_ExtraParameter): @classmethod def validate(klass, value, arg_name): - # Allow boolean or empty string + # Deprecated boolean or empty string if isinstance(value, bool) or (isinstance(value, str) and not value): - logging.debug("value of '%s' extra parameter for '%s' argument should be a string" \ - % (klass.name, arg_name)) + logger.warning("expecting a string for extra parameter '%s' of " \ + "argument '%s'", klass.name, arg_name) value = arg_name elif not isinstance(value, str): - raise TypeError("Invalid type of '%s' extra parameter for '%s' argument" \ - % (klass.name, arg_name)) + raise TypeError("parameter value must be a string, got %r" \ + % value) return value class PasswordParameter(AskParameter): @@ -156,18 +155,28 @@ class PatternParameter(_ExtraParameter): v = arg_value if v and not re.match(pattern, v or '', re.UNICODE): + logger.debug("argument value '%s' for '%s' doesn't match pattern '%s'", + v, arg_name, pattern) + + # Attempt to retrieve message translation + msg = m18n.n(message) + if msg == message: + msg = m18n.g(message) + raise MoulinetteError(errno.EINVAL, m18n.g('invalid_argument', - arg_name, m18n.n(message))) + arg_name, msg)) return arg_value @staticmethod def validate(value, arg_name): - # Tolerate string type + # Deprecated string type if isinstance(value, str): - logging.warning("value of 'pattern' extra parameter for '%s' argument should be a list" % arg_name) - value = [value, _("'%s' argument is not matching the pattern") % arg_name] + logger.warning("expecting a list for extra parameter 'pattern' of " \ + "argument '%s'", arg_name) + value = [value, 'pattern_not_match'] elif not isinstance(value, list) or len(value) != 2: - raise TypeError("Invalid type of 'pattern' extra parameter for '%s' argument" % arg_name) + raise TypeError("parameter value must be a list, got %r" \ + % value) return value class RequiredParameter(_ExtraParameter): @@ -181,6 +190,8 @@ class RequiredParameter(_ExtraParameter): def __call__(self, required, arg_name, arg_value): if required and (arg_value is None or arg_value == ''): + logger.debug("argument '%s' is required", + v, arg_name, pattern) raise MoulinetteError(errno.EINVAL, m18n.g('argument_required', arg_name)) return arg_value @@ -188,7 +199,8 @@ class RequiredParameter(_ExtraParameter): @staticmethod def validate(value, arg_name): if not isinstance(value, bool): - raise TypeError("Invalid type of 'required' extra parameter for '%s' argument" % arg_name) + raise TypeError("parameter value must be a list, got %r" \ + % value) return value """ @@ -219,6 +231,7 @@ class ExtraArgumentParser(object): if iface in klass.skipped_iface: continue self.extra[klass.name] = klass + logger.debug('extra parameter classes loaded: %s', self.extra.keys()) def validate(self, arg_name, parameters): """ @@ -236,8 +249,13 @@ class ExtraArgumentParser(object): # Remove unknown parameters del parameters[p] else: - # Validate parameter value - parameters[p] = klass.validate(v, arg_name) + try: + # Validate parameter value + parameters[p] = klass.validate(v, arg_name) + except Exception as e: + logger.error("unable to validate extra parameter '%s' " \ + "for argument '%s': %s", p, arg_name, e) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) return parameters @@ -332,12 +350,10 @@ class ActionsMap(object): """ def __init__(self, parser, namespaces=[], use_cache=True): - self.use_cache = use_cache if not issubclass(parser, BaseActionsMapParser): raise ValueError("Invalid parser class '%s'" % parser.__name__) self._parser_class = parser - - logging.debug("initializing ActionsMap for the interface '%s'" % parser.interface) + self.use_cache = use_cache if len(namespaces) == 0: namespaces = self.get_namespaces() @@ -345,7 +361,7 @@ class ActionsMap(object): # Iterate over actions map namespaces for n in namespaces: - logging.debug("loading '%s' actions map namespace" % n) + logger.debug("loading actions map namespace '%s'", n) if use_cache: try: @@ -424,12 +440,18 @@ class ActionsMap(object): fromlist=[func_name]) func = getattr(mod, func_name) except (AttributeError, ImportError): - raise ImportError("Unable to load function %s.%s/%s" - % (namespace, category, func_name)) + logger.exception("unable to load function %s.%s.%s", + namespace, category, func_name) + raise MoulinetteError(errno.EIO, m18n.g('error_see_log')) else: log_id = start_action_logging() - logger.info('processing action [%s]: %s.%s.%s with args=%s', - log_id, namespace, category, action, arguments) + if logger.isEnabledFor(logging.DEBUG): + # Log arguments in debug mode only for safety reasons + logger.info('processing action [%s]: %s.%s.%s with args=%s', + log_id, namespace, category, action, arguments) + else: + logger.info('processing action [%s]: %s.%s.%s', + log_id, namespace, category, action) # Load translation and process the action m18n.load_namespace(namespace) @@ -475,7 +497,7 @@ class ActionsMap(object): # Iterate over actions map namespaces for n in namespaces: - logging.debug("generating cache for '%s' actions map namespace" % n) + logger.debug("generating cache for actions map namespace '%s'", n) # Read actions map from yaml file am_file = '%s/actionsmap/%s.yml' % (pkg.datadir, n) @@ -558,7 +580,8 @@ class ActionsMap(object): actions = cp.pop('actions') except KeyError: # Invalid category without actions - logging.warning("no actions found in category '%s'" % cn) + logger.warning("no actions found in category '%s' in " \ + "namespace '%s'", cn, n) continue # Get category parser @@ -582,7 +605,8 @@ class ActionsMap(object): # No parser for the action continue except ValueError as e: - logging.warning("cannot add action (%s, %s, %s): %s" % (n, cn, an, e)) + logger.warning("cannot add action (%s, %s, %s): %s", + n, cn, an, e) continue else: # Store action identifier and add arguments diff --git a/moulinette/authenticators/__init__.py b/moulinette/authenticators/__init__.py index 42996fa8..9953438c 100644 --- a/moulinette/authenticators/__init__.py +++ b/moulinette/authenticators/__init__.py @@ -6,6 +6,9 @@ import logging from moulinette.core import MoulinetteError +logger = logging.getLogger('moulinette.authenticator') + + # Base Class ----------------------------------------------------------- class BaseAuthenticator(object): @@ -92,11 +95,12 @@ class BaseAuthenticator(object): # Extract id and hash from token s_id, s_hash = token except TypeError: - if not password: - raise ValueError("Invalid token format") - else: - # TODO: Log error - store_session = False + logger.error("unable to extract token parts from '%s'", token) + if password is None: + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) + + logger.info("session will not be stored") + store_session = False else: if password is None: # Retrieve session @@ -107,14 +111,19 @@ class BaseAuthenticator(object): self.authenticate(password) except MoulinetteError: raise - except Exception as e: - logging.error("authentication (name: '%s', type: '%s') fails: %s" \ - % (self.name, self.vendor, e)) + except: + logger.exception("authentication (name: '%s', vendor: '%s') fails", + self.name, self.vendor) raise MoulinetteError(errno.EACCES, m18n.g('unable_authenticate')) # Store session if store_session: - self._store_session(s_id, s_hash, password) + try: + self._store_session(s_id, s_hash, password) + except: + logger.exception("unable to store session") + else: + logger.debug("session has been stored") return self @@ -140,6 +149,7 @@ class BaseAuthenticator(object): with self._open_sessionfile(session_id, 'r') as f: enc_pwd = f.read() except IOError: + logger.debug("unable to retrieve session", exc_info=1) raise MoulinetteError(errno.ENOENT, m18r.g('unable_retrieve_session')) else: @@ -148,7 +158,8 @@ class BaseAuthenticator(object): decrypted = gpg.decrypt(enc_pwd, passphrase=session_hash) if decrypted.ok != True: - # TODO: Log decrypted.status + logger.error("unable to decrypt password for the session: %s", + decrypted.status) raise MoulinetteError(errno.EINVAL, m18r.g('unable_retrieve_session')) return decrypted.data diff --git a/moulinette/authenticators/ldap.py b/moulinette/authenticators/ldap.py index 4f53a528..439824b3 100644 --- a/moulinette/authenticators/ldap.py +++ b/moulinette/authenticators/ldap.py @@ -3,12 +3,16 @@ # TODO: Use Python3 to remove this fix! from __future__ import absolute_import import errno +import logging import ldap import ldap.modlist as modlist from moulinette.core import MoulinetteError from moulinette.authenticators import BaseAuthenticator +logger = logging.getLogger('moulinette.authenticator.ldap') + + # LDAP Class Implementation -------------------------------------------- class Authenticator(BaseAuthenticator): @@ -25,6 +29,8 @@ class Authenticator(BaseAuthenticator): """ def __init__(self, name, uri, base_dn, user_rdn=None): + logger.debug("initialize authenticator '%s' with: uri='%s', " \ + "base_dn='%s', user_rdn='%s'", name, uri, base_dn, user_rdn) super(Authenticator, self).__init__(name) self.uri = uri @@ -67,6 +73,7 @@ class Authenticator(BaseAuthenticator): except ldap.INVALID_CREDENTIALS: raise MoulinetteError(errno.EACCES, m18n.g('invalid_password')) except ldap.SERVER_DOWN: + logger.exception('unable to reach the server to authenticate') raise MoulinetteError(169, m18n.g('ldap_server_down')) else: self.con = con @@ -96,6 +103,8 @@ class Authenticator(BaseAuthenticator): try: result = self.con.search_s(base, ldap.SCOPE_SUBTREE, filter, attrs) except: + logger.exception("error during LDAP search operation with: base='%s', " \ + "filter='%s', attrs=%s", base, filter, attrs) raise MoulinetteError(169, m18n.g('ldap_operation_error')) result_list = [] @@ -125,6 +134,8 @@ class Authenticator(BaseAuthenticator): try: self.con.add_s(dn, ldif) except: + logger.exception("error during LDAP add operation with: rdn='%s', " \ + "attr_dict=%s", rdn, attr_dict) raise MoulinetteError(169, m18n.g('ldap_operation_error')) else: return True @@ -144,6 +155,7 @@ class Authenticator(BaseAuthenticator): try: self.con.delete_s(dn) except: + logger.exception("error during LDAP delete operation with: rdn='%s'", rdn) raise MoulinetteError(169, m18n.g('ldap_operation_error')) else: return True @@ -172,6 +184,8 @@ class Authenticator(BaseAuthenticator): self.con.modify_ext_s(dn, ldif) except: + logger.exception("error during LDAP update operation with: rdn='%s', " \ + "attr_dict=%s, new_rdn=%s", rdn, attr_dict, new_rdn) raise MoulinetteError(169, m18n.g('ldap_operation_error')) else: return True @@ -191,6 +205,8 @@ class Authenticator(BaseAuthenticator): if not self.search(filter=attr + '=' + value): continue else: + logger.info("attribute '%s' with value '%s' is not unique", + attr, value) raise MoulinetteError(errno.EEXIST, m18n.g('ldap_attribute_already_exists', attr, value)) diff --git a/moulinette/core.py b/moulinette/core.py index c3944ce2..f91a04d0 100644 --- a/moulinette/core.py +++ b/moulinette/core.py @@ -9,6 +9,9 @@ import logging from importlib import import_module +logger = logging.getLogger('moulinette.core') + + # Package manipulation ------------------------------------------------- class Package(object): @@ -25,6 +28,10 @@ class Package(object): def __init__(self, _from_source=False): if _from_source: import sys + + logger.debug('initialize Package object running from source') + + # Retrieve source's base directory basedir = os.path.abspath(os.path.dirname(sys.argv[0]) +'/../') # Set local directories @@ -44,7 +51,8 @@ class Package(object): def __setattr__(self, name, value): if name[0] == '_' and self.__dict__.has_key(name): # Deny reassignation of package directories - raise TypeError("cannot reassign constant '%s'") + logger.error("cannot reassign Package variable '%s'", name) + return self.__dict__[name] = value @@ -130,8 +138,8 @@ class Translator(object): # Attempt to load default translations if not self._load_translations(default_locale): - raise ValueError("Unable to load locale '%s' from '%s'" - % (default_locale, locale_dir)) + logger.error("unable to load locale '%s' from '%s'", + default_locale, locale_dir) self.default_locale = default_locale def get_locales(self): @@ -159,8 +167,8 @@ class Translator(object): """ if locale not in self._translations: if not self._load_translations(locale): - logging.info("unable to load locale '%s' from '%s'" - % (self.default_locale, self.locale_dir)) + logger.debug("unable to load locale '%s' from '%s'", + self.default_locale, self.locale_dir) # Revert to default locale self.locale = self.default_locale @@ -180,18 +188,23 @@ class Translator(object): - key -- The key to translate """ + def _load_key(locale): + value = self._translations[locale][key] + return value.encode('utf-8').format(*args, **kwargs) + try: - value = self._translations[self.locale][key] + return _load_key(self.locale) except KeyError: - try: - value = self._translations[self.default_locale][key] - logging.info("untranslated key '%s' for locale '%s'" % - (key, self.locale)) - except KeyError: - logging.warning("unknown key '%s' for locale '%s'" % - (key, self.default_locale)) - return key - return value.encode('utf-8').format(*args, **kwargs) + if self.default_locale != self.locale: + logger.info("untranslated key '%s' for locale '%s'", + key, self.locale) + try: + return _load_key(self.default_locale) + except: + pass + logger.warning("unable to retrieve key '%s' for default locale '%s'", + key, self.default_locale) + return key def _load_translations(self, locale, overwrite=False): """Load translations for a locale @@ -288,8 +301,8 @@ class Moulinette18n(object): """ if not self._namespace: - logging.error("attempt to retrieve translation for key '%s' " \ - "but no namespace is loaded" % key) + logger.error("unable to retrieve translation for key '%s' without " \ + "loaded namespace", key) return key return self._namespace[1].translate(key, *args, **kwargs) @@ -319,13 +332,15 @@ class MoulinetteSignals(object): def set_handler(self, signal, handler): """Set the handler for a signal""" if signal not in self.signals: - raise ValueError("unknown signal '%s'" % signal) + logger.error("unknown signal '%s'", signal) + return setattr(self, '_%s' % signal, handler) def clear_handler(self, signal): """Clear the handler of a signal""" if signal not in self.signals: - raise ValueError("unknown signal '%s'" % signal) + logger.error("unknown signal '%s'", signal) + return setattr(self, '_%s' % signal, self._notimplemented) @@ -424,16 +439,17 @@ def init_interface(name, kwargs={}, actionsmap={}): try: mod = import_module('moulinette.interfaces.%s' % name) - except ImportError as e: - # TODO: List available interfaces - raise ImportError("Unable to load interface '%s': %s" % (name, str(e))) + except ImportError: + logger.exception("unable to load interface '%s'", name) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) else: try: # Retrieve interface classes parser = mod.ActionsMapParser interface = mod.Interface - except AttributeError as e: - raise ImportError("Invalid interface '%s': %s" % (name, e)) + except AttributeError: + logger.exception("unable to retrieve classes of interface '%s'", name) + raise MoulinetteError(errno.EIO, m18n.g('error_see_log')) # Instantiate or retrieve ActionsMap if isinstance(actionsmap, dict): @@ -441,7 +457,8 @@ def init_interface(name, kwargs={}, actionsmap={}): elif isinstance(actionsmap, ActionsMap): amap = actionsmap else: - raise ValueError("Invalid actions map '%r'" % actionsmap) + logger.error("invalid actionsmap value %r", actionsmap) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) return interface(amap, **kwargs) @@ -459,10 +476,9 @@ def init_authenticator((vendor, name), kwargs={}): """ try: mod = import_module('moulinette.authenticators.%s' % vendor) - except ImportError as e: - # TODO: List available authenticators vendors - raise ImportError("Unable to load authenticator vendor '%s': %s" - % (vendor, str(e))) + except ImportError: + logger.exception("unable to load authenticator vendor '%s'", vendor) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) else: return mod.Authenticator(name, **kwargs) @@ -547,6 +563,8 @@ class MoulinetteLock(object): m18n.g('instance_already_running')) # Wait before checking again time.sleep(self.interval) + + logger.debug('lock has been acquired') self._locked = True def release(self): @@ -558,6 +576,8 @@ class MoulinetteLock(object): if self._locked: if not self._bypass: os.unlink(self._lockfile) + + logger.debug('lock has been released') self._locked = False def __enter__(self): diff --git a/moulinette/interfaces/__init__.py b/moulinette/interfaces/__init__.py index 724a98ae..a1f5124f 100644 --- a/moulinette/interfaces/__init__.py +++ b/moulinette/interfaces/__init__.py @@ -5,6 +5,9 @@ import logging from moulinette.core import (init_authenticator, MoulinetteError) +logger = logging.getLogger('moulinette.interface') + + # Base Class ----------------------------------------------------------- class BaseActionsMapParser(object): @@ -24,6 +27,8 @@ class BaseActionsMapParser(object): if parent: self._o = parent else: + logger.debug('initializing base actions map parser for %s', + self.interface) msettings['interface'] = self.interface self._o = self @@ -216,8 +221,9 @@ class BaseActionsMapParser(object): # Store only if authentication is needed conf['authenticate'] = True if self.interface in ifaces else False else: - # TODO: Log error instead and tell valid values - raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'authenticate'" % ifaces) + logger.error("expecting 'all', 'False' or a list for " \ + "configuration 'authenticate', got %r", ifaces) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) # -- 'authenticator' try: @@ -230,10 +236,13 @@ class BaseActionsMapParser(object): # Store needed authenticator profile conf['authenticator'] = self.global_conf['authenticator'][auth] except KeyError: - raise MoulinetteError(errno.EINVAL, "Undefined authenticator '%s' in global configuration" % auth) + logger.error("requesting profile '%s' which is undefined in " \ + "global configuration of 'authenticator'", auth) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) elif is_global and isinstance(auth, dict): if len(auth) == 0: - logging.warning('no authenticator defined in global configuration') + logger.warning('no profile defined in global configuration ' \ + "for 'authenticator'") else: auths = {} for auth_name, auth_conf in auth.items(): @@ -250,8 +259,9 @@ class BaseActionsMapParser(object): auth_conf.get('parameters', {})) conf['authenticator'] = auths else: - # TODO: Log error instead and tell valid values - raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'authenticator'" % auth) + logger.error("expecting a dict of profile(s) or a profile name " \ + "for configuration 'authenticator', got %r", auth) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) # -- 'argument_auth' try: @@ -262,8 +272,9 @@ class BaseActionsMapParser(object): if isinstance(arg_auth, bool): conf['argument_auth'] = arg_auth else: - # TODO: Log error instead and tell valid values - raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'argument_auth'" % arg_auth) + logger.error("expecting a boolean for configuration " \ + "'argument_auth', got %r", arg_auth) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) # -- 'lock' try: @@ -274,7 +285,9 @@ class BaseActionsMapParser(object): if isinstance(lock, bool): conf['lock'] = lock else: - raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'lock'" % lock) + logger.error("expecting a boolean for configuration 'lock', " \ + "got %r", lock) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) return conf diff --git a/moulinette/interfaces/api.py b/moulinette/interfaces/api.py index d1c1038a..2dc3baf0 100644 --- a/moulinette/interfaces/api.py +++ b/moulinette/interfaces/api.py @@ -17,6 +17,9 @@ from bottle import run, request, response, Bottle, HTTPResponse from moulinette.core import MoulinetteError, clean_session from moulinette.interfaces import (BaseActionsMapParser, BaseInterface) +logger = logging.getLogger('moulinette.interface.api') + + # API helpers ---------------------------------------------------------- def random_ascii(length=20): @@ -291,7 +294,7 @@ class _ActionsMapPlugin(object): # Delete the current queue and break del self.queues[s_id] break - logging.warning("invalid item in the messages queue: %r" % item) + logger.exception("invalid item in the messages queue: %r", item) else: try: # Send the message @@ -408,8 +411,8 @@ def error_to_response(error): errno.ENETUNREACH ]: return HTTPErrorResponse(error.strerror) else: - logging.debug('unknown relevant response for error number %d - %s' - % (error.errno, error.strerror)) + logger.debug('unknown relevant response for error [%s] %s', + error.errno, error.strerror) return HTTPErrorResponse(error.strerror) def format_for_response(content): @@ -495,8 +498,8 @@ class ActionsMapParser(BaseActionsMapParser): try: keys.append(self._extract_route(r)) except ValueError as e: - logging.warning("cannot add api route '%s' for " \ - "action '%s': %s" % (r, tid, str(e))) + logger.warning("cannot add api route '%s' for " \ + "action %s: %s", r, tid, e) continue if len(keys) == 0: raise ValueError("no valid api route found") @@ -522,7 +525,8 @@ class ActionsMapParser(BaseActionsMapParser): # Retrieve the tid and the parser for the route tid, parser = self._parsers[route] except KeyError: - raise MoulinetteError(errno.EINVAL, "No parser found for route '%s'" % route) + logger.error("no argument parser found for route '%s'", route) + raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log')) ret = argparse.Namespace() if not self.get_conf(tid, 'lock'): @@ -538,7 +542,6 @@ class ActionsMapParser(BaseActionsMapParser): # TODO: Catch errors auth = msignals.authenticate(klass(), **auth_conf) if not auth.is_authenticated: - # TODO: Set proper error code raise MoulinetteError(errno.EACCES, m18n.g('authentication_required_long')) if self.get_conf(tid, 'argument_auth') and \ self.get_conf(tid, 'authenticate') == 'all': @@ -632,6 +635,9 @@ class Interface(BaseInterface): - port -- Server port to bind to """ + logger.debug("starting the server instance in %s:%d with websocket=%s", + host, port, self.use_websocket) + try: if self.use_websocket: from gevent.pywsgi import WSGIServer @@ -643,10 +649,12 @@ class Interface(BaseInterface): else: run(self._app, host=host, port=port) except IOError as e: + logger.exception("unable to start the server instance on %s:%d", + host, port) if e.args[0] == errno.EADDRINUSE: raise MoulinetteError(errno.EADDRINUSE, m18n.g('server_already_running')) - raise + raise MoulinetteError(errno.EIO, m18n.g('error_see_log')) ## Routes handlers