]> git-server-git.apps.pok.os.sepia.ceph.com Git - ceph.git/commitdiff
mgr: module file logger support
authorRicardo Dias <rdias@suse.com>
Thu, 17 Oct 2019 09:16:25 +0000 (10:16 +0100)
committerRicardo Dias <rdias@suse.com>
Tue, 12 Nov 2019 11:49:56 +0000 (11:49 +0000)
Signed-off-by: Ricardo Dias <rdias@suse.com>
src/mgr/PyModuleRunner.cc
src/pybind/mgr/mgr_module.py

index ca90f87a1db9ae13b56e4a6e5108c6808d52f393..dbddfd411eef3a089277d64d91b9d942d35aac60 100644 (file)
@@ -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__ << " "
index 12811a14ecfe0ddd00185cec950a0fd9d06fd90c..3da93f3b3972e1a9fe6ea71de7bdb9489c59e8f0 100644 (file)
@@ -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):