From: Ricardo Dias Date: Thu, 17 Oct 2019 09:16:25 +0000 (+0100) Subject: mgr: module file logger support X-Git-Tag: v15.1.0~694^2~8 X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=3e39413a222a9d649099b86e0338437a1c83257c;p=ceph.git mgr: module file logger support Signed-off-by: Ricardo Dias --- diff --git a/src/mgr/PyModuleRunner.cc b/src/mgr/PyModuleRunner.cc index ca90f87a1db9..dbddfd411eef 100644 --- a/src/mgr/PyModuleRunner.cc +++ b/src/mgr/PyModuleRunner.cc @@ -93,7 +93,7 @@ void PyModuleRunner::shutdown() void PyModuleRunner::log(const std::string &record) { #undef dout_prefix -#define dout_prefix *_dout << "[" << get_name() << "] " +#define dout_prefix *_dout dout(0) << record << dendl; #undef dout_prefix #define dout_prefix *_dout << "mgr " << __func__ << " " diff --git a/src/pybind/mgr/mgr_module.py b/src/pybind/mgr/mgr_module.py index 12811a14ecfe..3da93f3b3972 100644 --- a/src/pybind/mgr/mgr_module.py +++ b/src/pybind/mgr/mgr_module.py @@ -48,65 +48,6 @@ PG_STATES = [ "unknown"] -class CPlusPlusHandler(logging.Handler): - def __init__(self, module_inst): - super(CPlusPlusHandler, self).__init__() - self._module = module_inst - self.setFormatter(logging.Formatter("[%(levelname)-4s] %(message)s")) - - def emit(self, record): - if record.levelno >= self._module._get_log_level(): - self._module._ceph_log(self.format(record)) - - -def configure_logger(module_inst, module_name): - """ - Create and configure the logger with the specified module. - - A handler will be added to the root logger which will redirect - the messages from all loggers (incl. 3rd party libraries) to the - Ceph log. - - :param module_inst: The module instance. - :type module_inst: instance - :param module_name: The module name. - :type module_name: str - :return: Return the logger with the specified name. - """ - logger = logging.getLogger(module_name) - # Don't filter any logs at the python level, leave it to C++. - # FIXME: We should learn the log level from C++ land, and then - # avoid calling the C++ level log when we know a message - # is of an insufficient level to be ultimately output. - logger.setLevel(logging.DEBUG) # Don't use NOTSET - - root_logger = logging.getLogger() - # Add handler to the root logger, thus this module and all - # 3rd party libraries will log their messages to the Ceph log. - root_logger.addHandler(CPlusPlusHandler(module_inst)) - # Set the log level to ``ERROR`` to ensure that we only get - # those message from 3rd party libraries (only effective if - # they use the default log level ``NOTSET``). - # Check https://docs.python.org/3/library/logging.html#logging.Logger.setLevel - # for more information about how the effective log level is - # determined. - root_logger.setLevel(logging.CRITICAL) - - return logger - - -def unconfigure_logger(module_name=None): - """ - :param module_name: The module name. Defaults to ``None``. - :type module_name: str or None - """ - logger = logging.getLogger(module_name) - rm_handlers = [ - h for h in logger.handlers if isinstance(h, CPlusPlusHandler)] - for h in rm_handlers: - logger.removeHandler(h) - - class CommandResult(object): """ Use with MgrModule.send_command @@ -459,7 +400,92 @@ class Command(dict): ) -class MgrStandbyModule(ceph_module.BaseMgrStandbyModule): +class CPlusPlusHandler(logging.Handler): + def __init__(self, module_inst): + super(CPlusPlusHandler, self).__init__() + self._module = module_inst + self.setFormatter(logging.Formatter("[{}] [%(levelname)-4s] [%(name)s] %(message)s" + .format(module_inst.module_name))) + + def emit(self, record): + if record.levelno >= self.level: + self._module._ceph_log(self.format(record)) + + +class FileHandler(logging.FileHandler): + def __init__(self, module_inst): + path = module_inst._ceph_get_option("log_file") + idx = path.rfind(".log") + if idx != -1: + self.path = "{}.{}.log".format(path[:idx], module_inst.module_name) + else: + self.path = "{}.{}".format(path, module_inst.module_name) + super(FileHandler, self).__init__(self.path, delay=True) + self.setFormatter(logging.Formatter("%(asctime)s [%(threadName)s] [%(levelname)-4s] [%(name)s] %(message)s")) + + +class MgrModuleLoggingTrait(object): + def _configure_logging(self, level, log_to_file): + self._root_logger = logging.getLogger() + + self._unconfigure_logging() + # the ceph log handler is initialized only once + self._ceph_log_handler = CPlusPlusHandler(self) + self._ceph_log_handler.setLevel(level) + self._file_log_handler = FileHandler(self) + self._file_log_handler.setLevel(self._ceph_log_handler.level) + + if log_to_file: + self._root_logger.addHandler(self._file_log_handler) + else: + self._root_logger.addHandler(self._ceph_log_handler) + + self._root_logger.setLevel(logging.NOTSET) + + def _unconfigure_logging(self): + # remove existing handlers: + rm_handlers = [ + h for h in self._root_logger.handlers if isinstance(h, CPlusPlusHandler) or isinstance(h, FileHandler)] + for h in rm_handlers: + self._root_logger.removeHandler(h) + + def _set_log_level(self, level): + self._ceph_log_handler.setLevel(level) + self._file_log_handler.setLevel(level) + + def _enable_file_log(self): + # disable ceph log and enable file log + self._root_logger.addHandler(self._file_log_handler) + self._root_logger.removeHandler(self._ceph_log_handler) + + def _disable_file_log(self): + # disable file log and enable ceph log + self._root_logger.addHandler(self._ceph_log_handler) + self._root_logger.removeHandler(self._file_log_handler) + + def _ceph_log_level_to_python(self, ceph_log_level): + if ceph_log_level: + try: + ceph_log_level = int(ceph_log_level.split("/", 1)[0]) + except ValueError: + ceph_log_level = 0 + else: + ceph_log_level = 0 + + log_level = "DEBUG" + if ceph_log_level <= 0: + log_level = "CRITICAL" + elif ceph_log_level <= 1: + log_level = "WARNING" + elif ceph_log_level <= 4: + log_level = "INFO" + return log_level + + def getLogger(self, name=None): + return logging.getLogger(name) + + +class MgrStandbyModule(ceph_module.BaseMgrStandbyModule, MgrModuleLoggingTrait): """ Standby modules only implement a serve and shutdown method, they are not permitted to implement commands and they do not receive @@ -475,7 +501,17 @@ class MgrStandbyModule(ceph_module.BaseMgrStandbyModule): def __init__(self, module_name, capsule): super(MgrStandbyModule, self).__init__(capsule) self.module_name = module_name - self._logger = configure_logger(self, module_name) + + ceph_log_level = self._ceph_get_option("debug_mgr") + log_level = self.get_module_option("log_level") + if not log_level: + log_level = self._ceph_log_level_to_python(ceph_log_level) + + self._configure_logging(log_level, False) + + # for backwards compatibility + self._logger = self.getLogger() + # see also MgrModule.__init__() for o in self.MODULE_OPTIONS: if 'default' in o: @@ -485,7 +521,7 @@ class MgrStandbyModule(ceph_module.BaseMgrStandbyModule): self.MODULE_OPTION_DEFAULTS[o['name']] = str(o['default']) def __del__(self): - unconfigure_logger() + self._unconfigure_logging() @property def log(self): @@ -538,7 +574,7 @@ class MgrStandbyModule(ceph_module.BaseMgrStandbyModule): return r -class MgrModule(ceph_module.BaseMgrModule): +class MgrModule(ceph_module.BaseMgrModule, MgrModuleLoggingTrait): COMMANDS = [] MODULE_OPTIONS = [] MODULE_OPTION_DEFAULTS = {} @@ -573,14 +609,18 @@ class MgrModule(ceph_module.BaseMgrModule): def __init__(self, module_name, py_modules_ptr, this_ptr): self.module_name = module_name - self._log_level = None + super(MgrModule, self).__init__(py_modules_ptr, this_ptr) - # If we're taking over from a standby module, let's make sure - # its logger was unconfigured before we hook ours up - unconfigure_logger() - self._logger = configure_logger(self, module_name) + ceph_log_level = self._ceph_get_option("debug_mgr") + log_level = self.get_module_option("log_level") + if not log_level: + log_level = self._ceph_log_level_to_python(ceph_log_level) - super(MgrModule, self).__init__(py_modules_ptr, this_ptr) + self._configure_logging(log_level, + self.get_module_option("log_to_file", False)) + + # for backwards compatibility + self._logger = self.getLogger() self._version = self._ceph_get_version() @@ -602,23 +642,36 @@ class MgrModule(ceph_module.BaseMgrModule): self.MODULE_OPTION_DEFAULTS[o['name']] = str(o['default']) def __del__(self): - unconfigure_logger() + self._unconfigure_logging() @classmethod def _register_commands(cls, module_name): - cls.MODULE_OPTIONS.append(Option(name='log_level', type='str', default="WARNING", runtime=True)) + cls.MODULE_OPTIONS.append(Option(name='log_level', type='str', default="", runtime=True)) + cls.MODULE_OPTIONS.append(Option(name='log_to_file', type='bool', default=False, runtime=True)) cls.COMMANDS.extend(CLICommand.dump_cmd_list()) cls.COMMANDS.extend([{ - 'cmd': '{} set log_level ' + 'cmd': '{} logging level set ' 'name=level,type=CephChoices,' 'strings=INFO|DEBUG|CRITICAL|ERROR|WARNING|NOTSET'.format(module_name), - 'desc': 'Set the module python log level', + 'desc': 'Set the module python logging level', 'perm': 'w' }, { - 'cmd': '{} get log_level'.format(module_name), - 'desc': 'Show the module python log level', + 'cmd': '{} logging level get'.format(module_name), + 'desc': 'Show the module python logging level', 'perm': 'r' + }, { + 'cmd': '{} logging file enable'.format(module_name), + 'desc': 'Enable module logging to its own file', + 'perm': 'w' + }, { + 'cmd': '{} logging file disable'.format(module_name), + 'desc': 'Disable module logging to its own file', + 'perm': 'w' + }, { + 'cmd': '{} logging file status'.format(module_name), + 'desc': 'Show module logging to its own file status', + 'perm': 'w' }]) @property @@ -978,26 +1031,37 @@ class MgrModule(ceph_module.BaseMgrModule): """ self._ceph_set_health_checks(checks) - def _get_log_level(self): - if self._log_level is None: - self._log_level = getattr(logging, self.get_module_option("log_level", "WARNING")) - return self._log_level - - def _set_log_level(self, level): - self._log_level = getattr(logging, level) - self.set_module_option("log_level", level) - def _handle_command(self, inbuf, cmd): - if cmd['prefix'] == '{} set log_level'.format(self.module_name): + if cmd['prefix'] == '{} logging level set'.format(self.module_name): if cmd['level'] not in ['INFO', 'WARNING', 'ERROR', 'DEBUG', 'CRITICAL', 'NOTSET']: return HandleCommandResult(retval=-errno.EINVAL, stderr='invalid log level: {}'.format(cmd['level'])) + self.set_module_option("log_level", cmd['level']) self._set_log_level(cmd['level']) return HandleCommandResult(stdout='log level updated to {}'.format(cmd['level'])) - if cmd['prefix'] == '{} get log_level'.format(self.module_name): - return HandleCommandResult(stdout=self.get_module_option("log_level", "WARNING")) + + if cmd['prefix'] == '{} logging level get'.format(self.module_name): + return HandleCommandResult(stdout=logging.getLevelName(self._ceph_log_handler.level)) + + if cmd['prefix'] == '{} logging file enable'.format(self.module_name): + self.set_module_option("log_to_file", True) + self._enable_file_log() + return HandleCommandResult(stdout="Enabled logging to file: {}" + .format(self._file_log_handler.path)) + + if cmd['prefix'] == '{} logging file disable'.format(self.module_name): + self.set_module_option("log_to_file", False) + self._disable_file_log() + return HandleCommandResult(stdout="Disabled logging to file") + + if cmd['prefix'] == '{} logging file status'.format(self.module_name): + is_enabled = self.get_module_option("log_to_file", False) + return HandleCommandResult(stdout="Logging to file is {}" + .format("enabled" if is_enabled else "disabled")) + if cmd['prefix'] not in CLICommand.COMMANDS: return self.handle_command(inbuf, cmd) + return CLICommand.COMMANDS[cmd['prefix']].call(self, cmd, inbuf) def handle_command(self, inbuf, cmd):