YunoHost/moulinette
1
0
Fork 0
mirror of https://github.com/YunoHost/moulinette.git synced 2024-09-03 20:06:31 +02:00
Code Issues Projects Releases Packages Wiki Activity

[enh] Be more verbose in modules using new logging facilities

Browse source
This commit is contained in:
Jérôme Lebleu 2014-10-25 13:46:54 +02:00
parent c93ecbd900
commit 1b0aa97cd7
8 changed files with 178 additions and 82 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
locales/en.json
View file

@ -7,6 +7,7 @@
"permission_denied" : "Permission denied", "permission_denied" : "Permission denied",
"root_required" : "You must be root to perform this action", "root_required" : "You must be root to perform this action",
"instance_already_running" : "An instance is already running", "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_authenticate" : "Unable to authenticate",
"unable_retrieve_session" : "Unable to retrieve the session", "unable_retrieve_session" : "Unable to retrieve the session",
@ -16,6 +17,7 @@
"argument_required" : "Argument {:s} is required", "argument_required" : "Argument {:s} is required",
"invalid_argument": "Invalid argument '{:s}': {:s}", "invalid_argument": "Invalid argument '{:s}': {:s}",
"pattern_not_match": "Does not match pattern",
"password" : "Password", "password" : "Password",
"invalid_password" : "Invalid password", "invalid_password" : "Invalid password",
"confirm" : "Confirm {:s}", "confirm" : "Confirm {:s}",

2
locales/fr.json
View file

@ -6,6 +6,7 @@
"permission_denied": "Permission refusée", "permission_denied": "Permission refusée",
"root_required": "Vous devez avoir les droits super-utilisateur pour exécuter cette action", "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", "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_authenticate": "Impossible de vous authentifier",
"unable_retrieve_session": "Impossible de récupérer la session", "unable_retrieve_session": "Impossible de récupérer la session",
"ldap_server_down": "Impossible d'atteindre le serveur LDAP", "ldap_server_down": "Impossible d'atteindre le serveur LDAP",
@ -13,6 +14,7 @@
"ldap_attribute_already_exists": "L'attribut existe déjà : '{:s}={:s}'", "ldap_attribute_already_exists": "L'attribut existe déjà : '{:s}={:s}'",
"argument_required": "L'argument {:s} est requis", "argument_required": "L'argument {:s} est requis",
"invalid_argument": "Argument '{:s}' incorrect : {:s}", "invalid_argument": "Argument '{:s}' incorrect : {:s}",
"pattern_not_match": "Ne correspond pas au motif",
"password": "Mot de passe", "password": "Mot de passe",
"invalid_password": "Mot de passe incorrect", "invalid_password": "Mot de passe incorrect",
"confirm": "Confirmez le {:s}", "confirm": "Confirmez le {:s}",

66
moulinette/actionsmap.py
View file

@ -94,7 +94,6 @@ class AskParameter(_ExtraParameter):
skipped_iface = [ 'api' ] skipped_iface = [ 'api' ]
def __call__(self, message, arg_name, arg_value): def __call__(self, message, arg_name, arg_value):
# TODO: Fix asked arguments ordering
if arg_value: if arg_value:
return arg_value return arg_value
@ -106,14 +105,14 @@ class AskParameter(_ExtraParameter):
@classmethod @classmethod
def validate(klass, value, arg_name): 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): 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" \ logger.warning("expecting a string for extra parameter '%s' of " \
% (klass.name, arg_name)) "argument '%s'", klass.name, arg_name)
value = arg_name value = arg_name
elif not isinstance(value, str): elif not isinstance(value, str):
raise TypeError("Invalid type of '%s' extra parameter for '%s' argument" \ raise TypeError("parameter value must be a string, got %r" \
% (klass.name, arg_name)) % value)
return value return value
class PasswordParameter(AskParameter): class PasswordParameter(AskParameter):
@ -156,18 +155,28 @@ class PatternParameter(_ExtraParameter):
v = arg_value v = arg_value
if v and not re.match(pattern, v or '', re.UNICODE): 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', raise MoulinetteError(errno.EINVAL, m18n.g('invalid_argument',
arg_name, m18n.n(message))) arg_name, msg))
return arg_value return arg_value
@staticmethod @staticmethod
def validate(value, arg_name): def validate(value, arg_name):
# Tolerate string type # Deprecated string type
if isinstance(value, str): if isinstance(value, str):
logging.warning("value of 'pattern' extra parameter for '%s' argument should be a list" % arg_name) logger.warning("expecting a list for extra parameter 'pattern' of " \
value = [value, _("'%s' argument is not matching the pattern") % arg_name] "argument '%s'", arg_name)
value = [value, 'pattern_not_match']
elif not isinstance(value, list) or len(value) != 2: 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 return value
class RequiredParameter(_ExtraParameter): class RequiredParameter(_ExtraParameter):
@ -181,6 +190,8 @@ class RequiredParameter(_ExtraParameter):
def __call__(self, required, arg_name, arg_value): def __call__(self, required, arg_name, arg_value):
if required and (arg_value is None or 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', raise MoulinetteError(errno.EINVAL, m18n.g('argument_required',
arg_name)) arg_name))
return arg_value return arg_value
@ -188,7 +199,8 @@ class RequiredParameter(_ExtraParameter):
@staticmethod @staticmethod
def validate(value, arg_name): def validate(value, arg_name):
if not isinstance(value, bool): 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 return value
""" """
@ -219,6 +231,7 @@ class ExtraArgumentParser(object):
if iface in klass.skipped_iface: if iface in klass.skipped_iface:
continue continue
self.extra[klass.name] = klass self.extra[klass.name] = klass
logger.debug('extra parameter classes loaded: %s', self.extra.keys())
def validate(self, arg_name, parameters): def validate(self, arg_name, parameters):
""" """
@ -236,8 +249,13 @@ class ExtraArgumentParser(object):
# Remove unknown parameters # Remove unknown parameters
del parameters[p] del parameters[p]
else: else:
try:
# Validate parameter value # Validate parameter value
parameters[p] = klass.validate(v, arg_name) 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 return parameters
@ -332,12 +350,10 @@ class ActionsMap(object):
""" """
def __init__(self, parser, namespaces=[], use_cache=True): def __init__(self, parser, namespaces=[], use_cache=True):
self.use_cache = use_cache
if not issubclass(parser, BaseActionsMapParser): if not issubclass(parser, BaseActionsMapParser):
raise ValueError("Invalid parser class '%s'" % parser.__name__) raise ValueError("Invalid parser class '%s'" % parser.__name__)
self._parser_class = parser self._parser_class = parser
self.use_cache = use_cache
logging.debug("initializing ActionsMap for the interface '%s'" % parser.interface)
if len(namespaces) == 0: if len(namespaces) == 0:
namespaces = self.get_namespaces() namespaces = self.get_namespaces()
@ -345,7 +361,7 @@ class ActionsMap(object):
# Iterate over actions map namespaces # Iterate over actions map namespaces
for n in namespaces: for n in namespaces:
logging.debug("loading '%s' actions map namespace" % n) logger.debug("loading actions map namespace '%s'", n)
if use_cache: if use_cache:
try: try:
@ -424,12 +440,18 @@ class ActionsMap(object):
fromlist=[func_name]) fromlist=[func_name])
func = getattr(mod, func_name) func = getattr(mod, func_name)
except (AttributeError, ImportError): except (AttributeError, ImportError):
raise ImportError("Unable to load function %s.%s/%s" logger.exception("unable to load function %s.%s.%s",
% (namespace, category, func_name)) namespace, category, func_name)
raise MoulinetteError(errno.EIO, m18n.g('error_see_log'))
else: else:
log_id = start_action_logging() log_id = start_action_logging()
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', logger.info('processing action [%s]: %s.%s.%s with args=%s',
log_id, namespace, category, action, arguments) 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 # Load translation and process the action
m18n.load_namespace(namespace) m18n.load_namespace(namespace)
@ -475,7 +497,7 @@ class ActionsMap(object):
# Iterate over actions map namespaces # Iterate over actions map namespaces
for n in 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 # Read actions map from yaml file
am_file = '%s/actionsmap/%s.yml' % (pkg.datadir, n) am_file = '%s/actionsmap/%s.yml' % (pkg.datadir, n)
@ -558,7 +580,8 @@ class ActionsMap(object):
actions = cp.pop('actions') actions = cp.pop('actions')
except KeyError: except KeyError:
# Invalid category without actions # 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 continue
# Get category parser # Get category parser
@ -582,7 +605,8 @@ class ActionsMap(object):
# No parser for the action # No parser for the action
continue continue
except ValueError as e: 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 continue
else: else:
# Store action identifier and add arguments # Store action identifier and add arguments

27
moulinette/authenticators/__init__.py
View file

@ -6,6 +6,9 @@ import logging
from moulinette.core import MoulinetteError from moulinette.core import MoulinetteError
logger = logging.getLogger('moulinette.authenticator')
# Base Class ----------------------------------------------------------- # Base Class -----------------------------------------------------------
class BaseAuthenticator(object): class BaseAuthenticator(object):
@ -92,10 +95,11 @@ class BaseAuthenticator(object):
# Extract id and hash from token # Extract id and hash from token
s_id, s_hash = token s_id, s_hash = token
except TypeError: except TypeError:
if not password: logger.error("unable to extract token parts from '%s'", token)
raise ValueError("Invalid token format") if password is None:
else: raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
# TODO: Log error
logger.info("session will not be stored")
store_session = False store_session = False
else: else:
if password is None: if password is None:
@ -107,14 +111,19 @@ class BaseAuthenticator(object):
self.authenticate(password) self.authenticate(password)
except MoulinetteError: except MoulinetteError:
raise raise
except Exception as e: except:
logging.error("authentication (name: '%s', type: '%s') fails: %s" \ logger.exception("authentication (name: '%s', vendor: '%s') fails",
% (self.name, self.vendor, e)) self.name, self.vendor)
raise MoulinetteError(errno.EACCES, m18n.g('unable_authenticate')) raise MoulinetteError(errno.EACCES, m18n.g('unable_authenticate'))
# Store session # Store session
if store_session: if store_session:
try:
self._store_session(s_id, s_hash, password) self._store_session(s_id, s_hash, password)
except:
logger.exception("unable to store session")
else:
logger.debug("session has been stored")
return self return self
@ -140,6 +149,7 @@ class BaseAuthenticator(object):
with self._open_sessionfile(session_id, 'r') as f: with self._open_sessionfile(session_id, 'r') as f:
enc_pwd = f.read() enc_pwd = f.read()
except IOError: except IOError:
logger.debug("unable to retrieve session", exc_info=1)
raise MoulinetteError(errno.ENOENT, raise MoulinetteError(errno.ENOENT,
m18r.g('unable_retrieve_session')) m18r.g('unable_retrieve_session'))
else: else:
@ -148,7 +158,8 @@ class BaseAuthenticator(object):
decrypted = gpg.decrypt(enc_pwd, passphrase=session_hash) decrypted = gpg.decrypt(enc_pwd, passphrase=session_hash)
if decrypted.ok != True: if decrypted.ok != True:
# TODO: Log decrypted.status logger.error("unable to decrypt password for the session: %s",
decrypted.status)
raise MoulinetteError(errno.EINVAL, raise MoulinetteError(errno.EINVAL,
m18r.g('unable_retrieve_session')) m18r.g('unable_retrieve_session'))
return decrypted.data return decrypted.data

16
moulinette/authenticators/ldap.py
View file

@ -3,12 +3,16 @@
# TODO: Use Python3 to remove this fix! # TODO: Use Python3 to remove this fix!
from __future__ import absolute_import from __future__ import absolute_import
import errno import errno
import logging
import ldap import ldap
import ldap.modlist as modlist import ldap.modlist as modlist
from moulinette.core import MoulinetteError from moulinette.core import MoulinetteError
from moulinette.authenticators import BaseAuthenticator from moulinette.authenticators import BaseAuthenticator
logger = logging.getLogger('moulinette.authenticator.ldap')
# LDAP Class Implementation -------------------------------------------- # LDAP Class Implementation --------------------------------------------
class Authenticator(BaseAuthenticator): class Authenticator(BaseAuthenticator):
@ -25,6 +29,8 @@ class Authenticator(BaseAuthenticator):
""" """
def __init__(self, name, uri, base_dn, user_rdn=None): 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) super(Authenticator, self).__init__(name)
self.uri = uri self.uri = uri
@ -67,6 +73,7 @@ class Authenticator(BaseAuthenticator):
except ldap.INVALID_CREDENTIALS: except ldap.INVALID_CREDENTIALS:
raise MoulinetteError(errno.EACCES, m18n.g('invalid_password')) raise MoulinetteError(errno.EACCES, m18n.g('invalid_password'))
except ldap.SERVER_DOWN: except ldap.SERVER_DOWN:
logger.exception('unable to reach the server to authenticate')
raise MoulinetteError(169, m18n.g('ldap_server_down')) raise MoulinetteError(169, m18n.g('ldap_server_down'))
else: else:
self.con = con self.con = con
@ -96,6 +103,8 @@ class Authenticator(BaseAuthenticator):
try: try:
result = self.con.search_s(base, ldap.SCOPE_SUBTREE, filter, attrs) result = self.con.search_s(base, ldap.SCOPE_SUBTREE, filter, attrs)
except: 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')) raise MoulinetteError(169, m18n.g('ldap_operation_error'))
result_list = [] result_list = []
@ -125,6 +134,8 @@ class Authenticator(BaseAuthenticator):
try: try:
self.con.add_s(dn, ldif) self.con.add_s(dn, ldif)
except: 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')) raise MoulinetteError(169, m18n.g('ldap_operation_error'))
else: else:
return True return True
@ -144,6 +155,7 @@ class Authenticator(BaseAuthenticator):
try: try:
self.con.delete_s(dn) self.con.delete_s(dn)
except: except:
logger.exception("error during LDAP delete operation with: rdn='%s'", rdn)
raise MoulinetteError(169, m18n.g('ldap_operation_error')) raise MoulinetteError(169, m18n.g('ldap_operation_error'))
else: else:
return True return True
@ -172,6 +184,8 @@ class Authenticator(BaseAuthenticator):
self.con.modify_ext_s(dn, ldif) self.con.modify_ext_s(dn, ldif)
except: 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')) raise MoulinetteError(169, m18n.g('ldap_operation_error'))
else: else:
return True return True
@ -191,6 +205,8 @@ class Authenticator(BaseAuthenticator):
if not self.search(filter=attr + '=' + value): if not self.search(filter=attr + '=' + value):
continue continue
else: else:
logger.info("attribute '%s' with value '%s' is not unique",
attr, value)
raise MoulinetteError(errno.EEXIST, raise MoulinetteError(errno.EEXIST,
m18n.g('ldap_attribute_already_exists', m18n.g('ldap_attribute_already_exists',
attr, value)) attr, value))

80
moulinette/core.py
View file

@ -9,6 +9,9 @@ import logging
from importlib import import_module from importlib import import_module
logger = logging.getLogger('moulinette.core')
# Package manipulation ------------------------------------------------- # Package manipulation -------------------------------------------------
class Package(object): class Package(object):
@ -25,6 +28,10 @@ class Package(object):
def __init__(self, _from_source=False): def __init__(self, _from_source=False):
if _from_source: if _from_source:
import sys 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]) +'/../') basedir = os.path.abspath(os.path.dirname(sys.argv[0]) +'/../')
# Set local directories # Set local directories
@ -44,7 +51,8 @@ class Package(object):
def __setattr__(self, name, value): def __setattr__(self, name, value):
if name[0] == '_' and self.__dict__.has_key(name): if name[0] == '_' and self.__dict__.has_key(name):
# Deny reassignation of package directories # Deny reassignation of package directories
raise TypeError("cannot reassign constant '%s'") logger.error("cannot reassign Package variable '%s'", name)
return
self.__dict__[name] = value self.__dict__[name] = value
@ -130,8 +138,8 @@ class Translator(object):
# Attempt to load default translations # Attempt to load default translations
if not self._load_translations(default_locale): if not self._load_translations(default_locale):
raise ValueError("Unable to load locale '%s' from '%s'" logger.error("unable to load locale '%s' from '%s'",
% (default_locale, locale_dir)) default_locale, locale_dir)
self.default_locale = default_locale self.default_locale = default_locale
def get_locales(self): def get_locales(self):
@ -159,8 +167,8 @@ class Translator(object):
""" """
if locale not in self._translations: if locale not in self._translations:
if not self._load_translations(locale): if not self._load_translations(locale):
logging.info("unable to load locale '%s' from '%s'" logger.debug("unable to load locale '%s' from '%s'",
% (self.default_locale, self.locale_dir)) self.default_locale, self.locale_dir)
# Revert to default locale # Revert to default locale
self.locale = self.default_locale self.locale = self.default_locale
@ -180,19 +188,24 @@ class Translator(object):
- key -- The key to translate - key -- The key to translate
""" """
try: def _load_key(locale):
value = self._translations[self.locale][key] value = self._translations[locale][key]
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) return value.encode('utf-8').format(*args, **kwargs)
try:
return _load_key(self.locale)
except KeyError:
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): def _load_translations(self, locale, overwrite=False):
"""Load translations for a locale """Load translations for a locale
@ -288,8 +301,8 @@ class Moulinette18n(object):
""" """
if not self._namespace: if not self._namespace:
logging.error("attempt to retrieve translation for key '%s' " \ logger.error("unable to retrieve translation for key '%s' without " \
"but no namespace is loaded" % key) "loaded namespace", key)
return key return key
return self._namespace[1].translate(key, *args, **kwargs) return self._namespace[1].translate(key, *args, **kwargs)
@ -319,13 +332,15 @@ class MoulinetteSignals(object):
def set_handler(self, signal, handler): def set_handler(self, signal, handler):
"""Set the handler for a signal""" """Set the handler for a signal"""
if signal not in self.signals: if signal not in self.signals:
raise ValueError("unknown signal '%s'" % signal) logger.error("unknown signal '%s'", signal)
return
setattr(self, '_%s' % signal, handler) setattr(self, '_%s' % signal, handler)
def clear_handler(self, signal): def clear_handler(self, signal):
"""Clear the handler of a signal""" """Clear the handler of a signal"""
if signal not in self.signals: 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) setattr(self, '_%s' % signal, self._notimplemented)
@ -424,16 +439,17 @@ def init_interface(name, kwargs={}, actionsmap={}):
try: try:
mod = import_module('moulinette.interfaces.%s' % name) mod = import_module('moulinette.interfaces.%s' % name)
except ImportError as e: except ImportError:
# TODO: List available interfaces logger.exception("unable to load interface '%s'", name)
raise ImportError("Unable to load interface '%s': %s" % (name, str(e))) raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
else: else:
try: try:
# Retrieve interface classes # Retrieve interface classes
parser = mod.ActionsMapParser parser = mod.ActionsMapParser
interface = mod.Interface interface = mod.Interface
except AttributeError as e: except AttributeError:
raise ImportError("Invalid interface '%s': %s" % (name, e)) logger.exception("unable to retrieve classes of interface '%s'", name)
raise MoulinetteError(errno.EIO, m18n.g('error_see_log'))
# Instantiate or retrieve ActionsMap # Instantiate or retrieve ActionsMap
if isinstance(actionsmap, dict): if isinstance(actionsmap, dict):
@ -441,7 +457,8 @@ def init_interface(name, kwargs={}, actionsmap={}):
elif isinstance(actionsmap, ActionsMap): elif isinstance(actionsmap, ActionsMap):
amap = actionsmap amap = actionsmap
else: 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) return interface(amap, **kwargs)
@ -459,10 +476,9 @@ def init_authenticator((vendor, name), kwargs={}):
""" """
try: try:
mod = import_module('moulinette.authenticators.%s' % vendor) mod = import_module('moulinette.authenticators.%s' % vendor)
except ImportError as e: except ImportError:
# TODO: List available authenticators vendors logger.exception("unable to load authenticator vendor '%s'", vendor)
raise ImportError("Unable to load authenticator vendor '%s': %s" raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
% (vendor, str(e)))
else: else:
return mod.Authenticator(name, **kwargs) return mod.Authenticator(name, **kwargs)
@ -547,6 +563,8 @@ class MoulinetteLock(object):
m18n.g('instance_already_running')) m18n.g('instance_already_running'))
# Wait before checking again # Wait before checking again
time.sleep(self.interval) time.sleep(self.interval)
logger.debug('lock has been acquired')
self._locked = True self._locked = True
def release(self): def release(self):
@ -558,6 +576,8 @@ class MoulinetteLock(object):
if self._locked: if self._locked:
if not self._bypass: if not self._bypass:
os.unlink(self._lockfile) os.unlink(self._lockfile)
logger.debug('lock has been released')
self._locked = False self._locked = False
def __enter__(self): def __enter__(self):

31
moulinette/interfaces/__init__.py
View file

@ -5,6 +5,9 @@ import logging
from moulinette.core import (init_authenticator, MoulinetteError) from moulinette.core import (init_authenticator, MoulinetteError)
logger = logging.getLogger('moulinette.interface')
# Base Class ----------------------------------------------------------- # Base Class -----------------------------------------------------------
class BaseActionsMapParser(object): class BaseActionsMapParser(object):
@ -24,6 +27,8 @@ class BaseActionsMapParser(object):
if parent: if parent:
self._o = parent self._o = parent
else: else:
logger.debug('initializing base actions map parser for %s',
self.interface)
msettings['interface'] = self.interface msettings['interface'] = self.interface
self._o = self self._o = self
@ -216,8 +221,9 @@ class BaseActionsMapParser(object):
# Store only if authentication is needed # Store only if authentication is needed
conf['authenticate'] = True if self.interface in ifaces else False conf['authenticate'] = True if self.interface in ifaces else False
else: else:
# TODO: Log error instead and tell valid values logger.error("expecting 'all', 'False' or a list for " \
raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'authenticate'" % ifaces) "configuration 'authenticate', got %r", ifaces)
raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
# -- 'authenticator' # -- 'authenticator'
try: try:
@ -230,10 +236,13 @@ class BaseActionsMapParser(object):
# Store needed authenticator profile # Store needed authenticator profile
conf['authenticator'] = self.global_conf['authenticator'][auth] conf['authenticator'] = self.global_conf['authenticator'][auth]
except KeyError: 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): elif is_global and isinstance(auth, dict):
if len(auth) == 0: if len(auth) == 0:
logging.warning('no authenticator defined in global configuration') logger.warning('no profile defined in global configuration ' \
"for 'authenticator'")
else: else:
auths = {} auths = {}
for auth_name, auth_conf in auth.items(): for auth_name, auth_conf in auth.items():
@ -250,8 +259,9 @@ class BaseActionsMapParser(object):
auth_conf.get('parameters', {})) auth_conf.get('parameters', {}))
conf['authenticator'] = auths conf['authenticator'] = auths
else: else:
# TODO: Log error instead and tell valid values logger.error("expecting a dict of profile(s) or a profile name " \
raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'authenticator'" % auth) "for configuration 'authenticator', got %r", auth)
raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
# -- 'argument_auth' # -- 'argument_auth'
try: try:
@ -262,8 +272,9 @@ class BaseActionsMapParser(object):
if isinstance(arg_auth, bool): if isinstance(arg_auth, bool):
conf['argument_auth'] = arg_auth conf['argument_auth'] = arg_auth
else: else:
# TODO: Log error instead and tell valid values logger.error("expecting a boolean for configuration " \
raise MoulinetteError(errno.EINVAL, "Invalid value '%r' for configuration 'argument_auth'" % arg_auth) "'argument_auth', got %r", arg_auth)
raise MoulinetteError(errno.EINVAL, m18n.g('error_see_log'))
# -- 'lock' # -- 'lock'
try: try:
@ -274,7 +285,9 @@ class BaseActionsMapParser(object):
if isinstance(lock, bool): if isinstance(lock, bool):
conf['lock'] = lock conf['lock'] = lock
else: 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 return conf

24
moulinette/interfaces/api.py
View file

@ -17,6 +17,9 @@ from bottle import run, request, response, Bottle, HTTPResponse
from moulinette.core import MoulinetteError, clean_session from moulinette.core import MoulinetteError, clean_session
from moulinette.interfaces import (BaseActionsMapParser, BaseInterface) from moulinette.interfaces import (BaseActionsMapParser, BaseInterface)
logger = logging.getLogger('moulinette.interface.api')
# API helpers ---------------------------------------------------------- # API helpers ----------------------------------------------------------
def random_ascii(length=20): def random_ascii(length=20):
@ -291,7 +294,7 @@ class _ActionsMapPlugin(object):
# Delete the current queue and break # Delete the current queue and break
del self.queues[s_id] del self.queues[s_id]
break break
logging.warning("invalid item in the messages queue: %r" % item) logger.exception("invalid item in the messages queue: %r", item)
else: else:
try: try:
# Send the message # Send the message
@ -408,8 +411,8 @@ def error_to_response(error):
errno.ENETUNREACH ]: errno.ENETUNREACH ]:
return HTTPErrorResponse(error.strerror) return HTTPErrorResponse(error.strerror)
else: else:
logging.debug('unknown relevant response for error number %d - %s' logger.debug('unknown relevant response for error [%s] %s',
% (error.errno, error.strerror)) error.errno, error.strerror)
return HTTPErrorResponse(error.strerror) return HTTPErrorResponse(error.strerror)
def format_for_response(content): def format_for_response(content):
@ -495,8 +498,8 @@ class ActionsMapParser(BaseActionsMapParser):
try: try:
keys.append(self._extract_route(r)) keys.append(self._extract_route(r))
except ValueError as e: except ValueError as e:
logging.warning("cannot add api route '%s' for " \ logger.warning("cannot add api route '%s' for " \
"action '%s': %s" % (r, tid, str(e))) "action %s: %s", r, tid, e)
continue continue
if len(keys) == 0: if len(keys) == 0:
raise ValueError("no valid api route found") raise ValueError("no valid api route found")
@ -522,7 +525,8 @@ class ActionsMapParser(BaseActionsMapParser):
# Retrieve the tid and the parser for the route # Retrieve the tid and the parser for the route
tid, parser = self._parsers[route] tid, parser = self._parsers[route]
except KeyError: 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() ret = argparse.Namespace()
if not self.get_conf(tid, 'lock'): if not self.get_conf(tid, 'lock'):
@ -538,7 +542,6 @@ class ActionsMapParser(BaseActionsMapParser):
# TODO: Catch errors # TODO: Catch errors
auth = msignals.authenticate(klass(), **auth_conf) auth = msignals.authenticate(klass(), **auth_conf)
if not auth.is_authenticated: if not auth.is_authenticated:
# TODO: Set proper error code
raise MoulinetteError(errno.EACCES, m18n.g('authentication_required_long')) raise MoulinetteError(errno.EACCES, m18n.g('authentication_required_long'))
if self.get_conf(tid, 'argument_auth') and \ if self.get_conf(tid, 'argument_auth') and \
self.get_conf(tid, 'authenticate') == 'all': self.get_conf(tid, 'authenticate') == 'all':
@ -632,6 +635,9 @@ class Interface(BaseInterface):
- port -- Server port to bind to - port -- Server port to bind to
""" """
logger.debug("starting the server instance in %s:%d with websocket=%s",
host, port, self.use_websocket)
try: try:
if self.use_websocket: if self.use_websocket:
from gevent.pywsgi import WSGIServer from gevent.pywsgi import WSGIServer
@ -643,10 +649,12 @@ class Interface(BaseInterface):
else: else:
run(self._app, host=host, port=port) run(self._app, host=host, port=port)
except IOError as e: except IOError as e:
logger.exception("unable to start the server instance on %s:%d",
host, port)
if e.args[0] == errno.EADDRINUSE: if e.args[0] == errno.EADDRINUSE:
raise MoulinetteError(errno.EADDRINUSE, raise MoulinetteError(errno.EADDRINUSE,
m18n.g('server_already_running')) m18n.g('server_already_running'))
raise raise MoulinetteError(errno.EIO, m18n.g('error_see_log'))
## Routes handlers ## Routes handlers