mgr: route the root-logger fallback through a module-independent sink

MgrRootHandler captures third-party logs from the Python root logger
and emits them through the _ceph_log method of whichever mgr module
last configured logging.  A handler on the root logger outlives any
single module, so once that module unloads the handler emits through
a stale pointer until another module reconfigures logging.

Add a free mgr_log() function to the ceph_module binding, emitting
via dout() like PyModuleRunner::log but with no PyModule involved,
and rewrite MgrRootHandler to route through it.  The handler no
longer references a module instance, so it cannot go stale.

Signed-off-by: Kefu Chai <k.chai@proxmox.com>

diff --git a/src/mgr/PyModule.cc b/src/mgr/PyModule.cc
index 40531f6db8f768d58bec886e0808139ab36bd227..8e152e248e4c6f43979cd3cf04a10485cbf5cec2 100644 (file)
--- a/src/mgr/PyModule.cc
+++ b/src/mgr/PyModule.cc
@@ -299,9 +299,28 @@ PyObject* PyModule::init_ceph_logger()
   return py_logger;
 }
 
+// module-independent sink for the Python root-logger fallback; the Python
+// side filters and formats, this just emits like PyModuleRunner::log()
+static PyObject*
+ceph_mgr_log(PyObject *self, PyObject *args)
+{
+  char *record = nullptr;
+  if (!PyArg_ParseTuple(args, "s:mgr_log", &record)) {
+    return nullptr;
+  }
+#undef dout_prefix
+#define dout_prefix *_dout
+  dout(0) << record << dendl;
+#undef dout_prefix
+#define dout_prefix *_dout << "mgr[py] "
+  Py_RETURN_NONE;
+}
+
 PyObject* PyModule::init_ceph_module()
 {
   static PyMethodDef module_methods[] = {
+    {"mgr_log", ceph_mgr_log, METH_VARARGS,
+     "log a preformatted record to the mgr daemon log"},
     {nullptr, nullptr, 0, nullptr}
   };
   static PyModuleDef ceph_module_def = {

diff --git a/src/pybind/mgr/ceph_module.pyi b/src/pybind/mgr/ceph_module.pyi
index 920f80f1eb1ef2cc640b3eda314839a14d3202a8..22a353e9f3e9799688a0764c60c2a43e87a3451c 100644 (file)
--- a/src/pybind/mgr/ceph_module.pyi
+++ b/src/pybind/mgr/ceph_module.pyi
@@ -10,6 +10,9 @@ except ImportError:
         pass
 
 
+def mgr_log(record: str) -> None: ...
+
+
 class BasePyOSDMap(object):
     def _get_epoch(self): ...
     def _get_crush_version(self): ...

diff --git a/src/pybind/mgr/mgr_module.py b/src/pybind/mgr/mgr_module.py
index fc24804f18563b253efe350be2fd1bfae562b789..d91ee7140335ae379acad3b0ab1e7c6c5edf3ff8 100644 (file)
--- a/src/pybind/mgr/mgr_module.py
+++ b/src/pybind/mgr/mgr_module.py
@@ -702,15 +702,19 @@ class CPlusPlusHandler(logging.Handler):
             self._module._ceph_log(self.format(record))
 
 
-class MgrRootHandler(CPlusPlusHandler):
-    def __init__(self, module_inst: 'MgrModuleLoggingMixin') -> None:
-        super().__init__(module_inst)
+class MgrRootHandler(logging.Handler):
+    # fallback for third-party libraries logging to the root logger; emits
+    # via the module-independent ceph_module.mgr_log, so it holds no module
+    # reference to go stale.  installed once; its level follows debug_mgr.
+    def __init__(self) -> None:
+        super().__init__()
         self.setFormatter(logging.Formatter(
             "[mgr %(levelname)-4s %(name)s] %(message)s"
         ))
 
-    def set_module(self, module_inst: 'MgrModuleLoggingMixin') -> None:
-        self._module = module_inst
+    def emit(self, record: logging.LogRecord) -> None:
+        if record.levelno >= self.level:
+            ceph_module.mgr_log(self.format(record))
 
 
 class ClusterLogHandler(logging.Handler):
@@ -748,7 +752,6 @@ class FileHandler(logging.FileHandler):
 
 class MgrModuleLoggingMixin(object):
     module_name: str
-    _root_log_handler: Optional[MgrRootHandler] = None
 
     def _configure_logging(self,
                            mgr_level: str,
@@ -771,20 +774,11 @@ class MgrModuleLoggingMixin(object):
         self.log_to_cluster = log_to_cluster
 
         root = logging.getLogger()
-        root_handler = None
-        for handler in root.handlers:
-            if isinstance(handler, MgrRootHandler):
-                root_handler = handler
-                break
-        if root_handler is None:
-            root_handler = MgrRootHandler(self)
-            root.addHandler(root_handler)
-        else:
-            root_handler.set_module(self)
-        self._root_log_handler = root_handler
-        # Module loggers rely on handler thresholds, so keep root permissive
-        # and apply the mgr fallback threshold on MgrRootHandler itself.
-        root.setLevel(logging.NOTSET)
+        if self._mgr_root_handler() is None:
+            # keep root permissive; the fallback handler gates on its own
+            # level, set from debug_mgr in _set_log_level()
+            root.addHandler(MgrRootHandler())
+            root.setLevel(logging.NOTSET)
 
         self._module_logger.addHandler(self._mgr_log_handler)
         if log_to_file:
@@ -807,13 +801,22 @@ class MgrModuleLoggingMixin(object):
         self.log_to_file = False
         self.log_to_cluster = False
 
+    @staticmethod
+    def _mgr_root_handler() -> Optional['MgrRootHandler']:
+        root = logging.getLogger()
+        return next((h for h in root.handlers
+                     if isinstance(h, MgrRootHandler)), None)
+
     def _set_log_level(self,
                        mgr_level: str,
                        module_level: str,
                        cluster_level: str) -> None:
         self._cluster_log_handler.setLevel(cluster_level.upper())
-        if self._root_log_handler is not None:
-            self._root_log_handler.setLevel(self._ceph_log_level_to_python(mgr_level))
+        # set before the early returns below so a debug_mgr change applies
+        # even when the module level is unchanged
+        root_handler = self._mgr_root_handler()
+        if root_handler is not None:
+            root_handler.setLevel(self._ceph_log_level_to_python(mgr_level))
 
         module_level = module_level.upper() if module_level else ''
         if not self._module_level: