plugins/python/sudo_module: add sudo.LogHandler

so python log system can be used with sudo logsystem.
Loggers use it by default (the handler is set on the root logger).
If that is not the intent, it can be overridden explicitly.

MANIFEST

@@ -318,6 +318,7 @@ plugins/python/pyhelpers_cpychecker.h
 plugins/python/python_baseplugin.c
 plugins/python/python_convmessage.c
 plugins/python/python_importblocker.c
+plugins/python/python_loghandler.c
 plugins/python/python_plugin_approval.c
 plugins/python/python_plugin_approval_multi.inc
 plugins/python/python_plugin_audit.c

doc/sudo_plugin_python.man.in

@@ -1668,6 +1668,20 @@ trace	sudo.DEBUG.TRACE
 .PP
 debug	sudo.DEBUG.DEBUG	very extreme verbose debugging
 .TE
+.PP
+\fIUsing the logging module\fR
+.PP
+Alternatively, a plugin can use the built in logging module of Python as well.
+Sudo adds its log handler to the root logger, so by default all output of a
+logger will get forwarded to sudo log system, as it would call sudo.debug.
+.PP
+The log handler of sudo will map each Python log level of a message to
+the appropriate sudo debug level.
+Note however, that sudo debug system will only get the messages not filtered
+out by the Python loggers.
+For example, the log level of the python logger will be an additional filter
+for the log messages, and is usually very different from what level is set in sudo.conf
+for the sudo debug system.
 .SS "Debug example"
 Sudo ships an example debug plugin by default.
 To try it, register it by adding the following lines to

doc/sudo_plugin_python.mdoc.in

@@ -1332,6 +1332,20 @@ one or more messages to log
 .It trace Ta sudo.DEBUG.TRACE Ta
 .It debug Ta sudo.DEBUG.DEBUG Ta very extreme verbose debugging
 .El
+.Pp
+.Em Using the logging module
+.Pp
+Alternatively, a plugin can use the built in logging module of Python as well.
+Sudo adds its log handler to the root logger, so by default all output of a
+logger will get forwarded to sudo log system, as it would call sudo.debug.
+.Pp
+The log handler of sudo will map each Python log level of a message to
+the appropriate sudo debug level.
+Note however, that sudo debug system will only get the messages not filtered
+out by the Python loggers.
+For example, the log level of the python logger will be an additional filter
+for the log messages, and is usually very different from what level is set in sudo.conf
+for the sudo debug system.
 .Ss Debug example
 Sudo ships an example debug plugin by default.
 To try it, register it by adding the following lines to

plugins/python/Makefile.in

@@ -118,6 +118,7 @@ EXAMPLES = example_conversation.py  example_debugging.py  example_group_plugin.p
            example_audit_plugin.py example_approval_plugin.py
 
 OBJS =	python_plugin_common.lo python_plugin_policy.lo python_plugin_io.lo python_plugin_group.lo pyhelpers.lo \
+	python_loghandler.lo \
 	python_importblocker.lo python_convmessage.lo sudo_python_module.lo sudo_python_debug.lo \
 	python_baseplugin.lo python_plugin_audit.lo python_plugin_approval.lo
 
@@ -266,6 +267,12 @@ python_importblocker.i: $(srcdir)/python_importblocker.c \
 	$(CC) -E -o $@ $(CPPFLAGS) $<
 python_importblocker.plog: python_importblocker.i
 	rm -f $@; pvs-studio --cfg $(PVS_CFG) --sourcetree-root $(top_srcdir) --skip-cl-exe yes --source-file $(srcdir)/python_importblocker.c --i-file $< --output-file $@
+python_loghandler.lo: $(srcdir)/python_loghandler.c 
+	$(LIBTOOL) $(LTFLAGS) --mode=compile $(CC) -c $(CPPFLAGS) $(CFLAGS) $(ASAN_CFLAGS) $(PIE_CFLAGS) $(SSP_CFLAGS) $(srcdir)/python_loghandler.c
+python_loghandler.i: $(srcdir)/python_loghandler.c 
+	$(CC) -E -o $@ $(CPPFLAGS) $<
+python_loghandler.plog: python_loghandler.i
+	rm -f $@; pvs-studio --cfg $(PVS_CFG) --sourcetree-root $(top_srcdir) --skip-cl-exe yes --source-file $(srcdir)/python_loghandler.c --i-file $< --output-file $@
 python_plugin_approval.lo: $(srcdir)/python_plugin_approval.c 
 	$(LIBTOOL) $(LTFLAGS) --mode=compile $(CC) -c $(CPPFLAGS) $(CFLAGS) $(ASAN_CFLAGS) $(PIE_CFLAGS) $(SSP_CFLAGS) $(srcdir)/python_plugin_approval.c
 python_plugin_approval.i: $(srcdir)/python_plugin_approval.c 

plugins/python/python_baseplugin.c

@@ -66,7 +66,7 @@ sudo_module_register_baseplugin(PyObject *py_module)
     int rc = SUDO_RC_ERROR;
     PyObject *py_class = NULL;
 
-    py_class = sudo_module_create_class("sudo.Plugin", _sudo_Plugin_class_methods);
+    py_class = sudo_module_create_class("sudo.Plugin", _sudo_Plugin_class_methods, NULL);
     if (py_class == NULL)
         goto cleanup;
 

plugins/python/python_convmessage.c

@@ -83,7 +83,7 @@ sudo_module_register_conv_message(PyObject *py_module)
     int rc = SUDO_RC_ERROR;
     PyObject *py_class = NULL;
 
-    py_class = sudo_module_create_class("sudo.ConvMessage", _sudo_ConvMessage_class_methods);
+    py_class = sudo_module_create_class("sudo.ConvMessage", _sudo_ConvMessage_class_methods, NULL);
     if (py_class == NULL)
         goto cleanup;
 

plugins/python/python_importblocker.c

@@ -178,7 +178,7 @@ sudo_module_register_importblocker(void)
     }
     Py_INCREF(py_meta_path);
 
-    py_import_blocker_cls = sudo_module_create_class("sudo.ImportBlocker", _sudo_ImportBlocker_class_methods);
+    py_import_blocker_cls = sudo_module_create_class("sudo.ImportBlocker", _sudo_ImportBlocker_class_methods, NULL);
     if (py_import_blocker_cls == NULL)
         goto cleanup;
 

plugins/python/python_loghandler.c

@@ -0,0 +1,190 @@
+/*
+ * SPDX-License-Identifier: ISC
+ *
+ * Copyright (c) 2019 Robert Manner <robert.manner@oneidentity.com>
+ *
+ * Permission to use, copy, modify, and distribute this software for any
+ * purpose with or without fee is hereby granted, provided that the above
+ * copyright notice and this permission notice appear in all copies.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
+ * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
+ * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
+ * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
+ * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
+ * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
+ * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+ */
+
+/*
+ * This is an open source non-commercial project. Dear PVS-Studio, please check it.
+ * PVS-Studio Static Code Analyzer for C, C++ and C#: http://www.viva64.com
+ */
+
+#include "sudo_python_module.h"
+
+PyObject *sudo_type_LogHandler;
+
+
+static void
+_debug_plugin(int log_level, const char *log_message)
+{
+    debug_decl_vars(python_sudo_debug, PYTHON_DEBUG_PLUGIN);
+
+    if (sudo_debug_needed(SUDO_DEBUG_INFO)) {
+        // at trace level we output the position for the python log as well
+        char *func_name = NULL, *file_name = NULL;
+        long line_number = -1;
+
+        if (py_get_current_execution_frame(&file_name, &line_number, &func_name) == SUDO_RC_OK) {
+            sudo_debug_printf(SUDO_DEBUG_INFO, "%s @ %s:%ld debugs:\n",
+                              func_name, file_name, line_number);
+        }
+
+        free(func_name);
+        free(file_name);
+    }
+
+    sudo_debug_printf(log_level, "%s\n", log_message);
+}
+
+PyObject *
+python_sudo_debug(PyObject *Py_UNUSED(py_self), PyObject *py_args)
+{
+    debug_decl(python_sudo_debug, PYTHON_DEBUG_C_CALLS);
+    py_debug_python_call("sudo", "debug", py_args, NULL, PYTHON_DEBUG_C_CALLS);
+
+    int log_level = SUDO_DEBUG_DEBUG;
+    const char *log_message = NULL;
+    if (!PyArg_ParseTuple(py_args, "is:sudo.debug", &log_level, &log_message)) {
+        debug_return_ptr(NULL);
+    }
+
+    _debug_plugin(log_level, log_message);
+
+    debug_return_ptr_pynone;
+}
+
+static int
+_sudo_log_level_from_python(long level)
+{
+    if (level >= 50)
+        return SUDO_DEBUG_CRIT;
+    if (level >= 40)
+        return SUDO_DEBUG_ERROR;
+    if (level >= 30)
+        return SUDO_DEBUG_WARN;
+    if (level >= 20)
+        return SUDO_DEBUG_INFO;
+
+    return SUDO_DEBUG_TRACE;
+}
+
+static PyObject *
+_sudo_LogHandler__emit(PyObject *py_self, PyObject *py_args)
+{
+    debug_decl(_sudo_LogHandler__emit, PYTHON_DEBUG_C_CALLS);
+
+    PyObject *py_record = NULL; // borrowed
+    PyObject *py_message = NULL;
+
+    py_debug_python_call("LogHandler", "emit", py_args, NULL, PYTHON_DEBUG_C_CALLS);
+
+    if (!PyArg_UnpackTuple(py_args, "sudo.LogHandler.emit", 2, 2, &py_self, &py_record))
+        goto cleanup;
+
+    long python_loglevel = py_object_get_optional_attr_number(py_record, "levelno");
+    if (PyErr_Occurred()) {
+        PyErr_Format(sudo_exc_SudoException, "sudo.LogHandler: Failed to determine log level");
+        goto cleanup;
+    }
+
+    int sudo_loglevel = _sudo_log_level_from_python(python_loglevel);
+
+    py_message = PyObject_CallMethod(py_self, "format", "O", py_record);
+    if (py_message == NULL)
+        goto cleanup;
+
+    _debug_plugin(sudo_loglevel, PyUnicode_AsUTF8(py_message));
+
+cleanup:
+    Py_CLEAR(py_message);
+    if (PyErr_Occurred()) {
+        debug_return_ptr(NULL);
+    }
+
+    debug_return_ptr_pynone;
+}
+
+/* The sudo.LogHandler class can be used to make the default python logger
+ * use sudo's built in log system. */
+static PyMethodDef _sudo_LogHandler_class_methods[] =
+{
+    {"emit", _sudo_LogHandler__emit, METH_VARARGS, ""},
+    {NULL, NULL, 0, NULL}
+};
+
+// This function registers sudo.LogHandler class
+int
+sudo_module_register_loghandler(PyObject *py_module)
+{
+    debug_decl(sudo_module_register_loghandler, PYTHON_DEBUG_INTERNAL);
+
+    PyObject *py_logging_module = NULL, *py_streamhandler = NULL;
+
+    py_logging_module = PyImport_ImportModule("logging");
+    if (py_logging_module == NULL)
+        goto cleanup;
+
+    py_streamhandler = PyObject_GetAttrString(py_logging_module, "StreamHandler");
+    if (py_streamhandler == NULL)
+        goto cleanup;
+
+    sudo_type_LogHandler = sudo_module_create_class("sudo.LogHandler",
+        _sudo_LogHandler_class_methods, py_streamhandler);
+    if (sudo_type_LogHandler == NULL)
+        goto cleanup;
+
+    if (PyModule_AddObject(py_module, "LogHandler", sudo_type_LogHandler) < 0)
+        goto cleanup;
+
+    Py_INCREF(sudo_type_LogHandler);
+
+cleanup:
+    Py_CLEAR(py_streamhandler);
+    Py_CLEAR(py_logging_module);
+    debug_return_int(PyErr_Occurred() ? SUDO_RC_ERROR : SUDO_RC_OK);
+}
+
+// This sets sudo.LogHandler as the default log handler:
+//   logging.getLogger().addHandler(sudo.LogHandler())
+int
+sudo_module_set_default_loghandler(void)
+{
+    debug_decl(sudo_module_set_default_loghandler, PYTHON_DEBUG_INTERNAL);
+
+    PyObject *py_loghandler = NULL, *py_logging_module = NULL,
+             *py_logger = NULL, *py_result = NULL;
+
+    py_loghandler = PyObject_CallObject(sudo_type_LogHandler, NULL);
+    if (py_loghandler == NULL)
+        goto cleanup;
+
+    py_logging_module = PyImport_ImportModule("logging");
+    if (py_logging_module == NULL)
+        goto cleanup;
+
+    py_logger = PyObject_CallMethod(py_logging_module, "getLogger", NULL);
+    if (py_logger == NULL)
+        goto cleanup;
+
+    py_result = PyObject_CallMethod(py_logger, "addHandler", "O", py_loghandler);
+
+cleanup:
+    Py_CLEAR(py_result);
+    Py_CLEAR(py_logger);
+    Py_CLEAR(py_logging_module);
+    Py_CLEAR(py_loghandler);
+
+    debug_return_int(PyErr_Occurred() ? SUDO_RC_ERROR : SUDO_RC_OK);
+}

plugins/python/python_plugin_common.c

@@ -498,6 +498,9 @@ python_plugin_init(struct PluginContext *plugin_ctx, char * const plugin_options
         goto cleanup;
     }
 
+    if (sudo_module_set_default_loghandler() < 0)
+        goto cleanup;
+
     if (_python_plugin_set_path(plugin_ctx, _lookup_value(plugin_options, "ModulePath")) != SUDO_RC_OK) {
         goto cleanup;
     }

plugins/python/sudo_python_module.c

@@ -38,7 +38,6 @@ static PyObject *sudo_exc_ConversationInterrupted;
 // "kwargs" is a dict of the keyword arguments or NULL if there are none
 static PyObject *python_sudo_log_info(PyObject *py_self, PyObject *py_args, PyObject *py_kwargs);
 static PyObject *python_sudo_log_error(PyObject *py_self, PyObject *py_args, PyObject *py_kwargs);
-static PyObject *python_sudo_debug(PyObject *py_self, PyObject *py_args);
 static PyObject *python_sudo_conversation(PyObject *py_self, PyObject *py_args, PyObject *py_kwargs);
 static PyObject *python_sudo_options_as_dict(PyObject *py_self, PyObject *py_args);
 static PyObject *python_sudo_options_from_dict(PyObject *py_self, PyObject *py_args);
@@ -250,46 +249,6 @@ python_sudo_log_error(PyObject *py_self, PyObject *py_args, PyObject *py_kwargs)
     return python_sudo_log(SUDO_CONV_ERROR_MSG, py_self, py_args, py_kwargs);
 }
 
-static void
-_debug_plugin(int log_level, const char *log_message)
-{
-    debug_decl_vars(python_sudo_debug, PYTHON_DEBUG_PLUGIN);
-
-    if (sudo_debug_needed(SUDO_DEBUG_INFO)) {
-        // at trace level we output the position for the python log as well
-        char *func_name = NULL, *file_name = NULL;
-        long line_number = -1;
-
-        if (py_get_current_execution_frame(&file_name, &line_number, &func_name) == SUDO_RC_OK) {
-            sudo_debug_printf(SUDO_DEBUG_INFO, "%s @ %s:%ld debugs:\n",
-                              func_name, file_name, line_number);
-        }
-
-        free(func_name);
-        free(file_name);
-    }
-
-    sudo_debug_printf(log_level, "%s\n", log_message);
-}
-
-static PyObject *
-python_sudo_debug(PyObject *Py_UNUSED(py_self), PyObject *py_args)
-{
-    debug_decl(python_sudo_debug, PYTHON_DEBUG_C_CALLS);
-    py_debug_python_call("sudo", "debug", py_args, NULL, PYTHON_DEBUG_C_CALLS);
-
-    int log_level = SUDO_DEBUG_DEBUG;
-    const char *log_message = NULL;
-    if (!PyArg_ParseTuple(py_args, "is:sudo.debug", &log_level, &log_message)) {
-        debug_return_ptr(NULL);
-    }
-
-    _debug_plugin(log_level, log_message);
-
-    debug_return_ptr_pynone;
-}
-
-
 CPYCHECKER_NEGATIVE_RESULT_SETS_EXCEPTION
 static int py_expect_arg_callable(PyObject *py_callable,
     const char *func_name, const char *arg_name)
@@ -451,13 +410,19 @@ cleanup:
  * The resulting class object can be added to a module using PyModule_AddObject.
  */
 PyObject *
-sudo_module_create_class(const char *class_name, PyMethodDef *class_methods)
+sudo_module_create_class(const char *class_name, PyMethodDef *class_methods,
+                         PyObject *base_class)
 {
     debug_decl(sudo_module_create_class, PYTHON_DEBUG_INTERNAL);
 
     PyObject *py_base_classes = NULL, *py_class = NULL, *py_member_dict = NULL;
 
-    py_base_classes = PyTuple_New(0);
+    if (base_class == NULL) {
+        py_base_classes = PyTuple_New(0);
+    } else {
+        py_base_classes = Py_BuildValue("(O)", base_class);
+    }
+
     if (py_base_classes == NULL)
         goto cleanup;
 
@@ -629,6 +594,9 @@ sudo_module_init(void)
     if (sudo_module_register_baseplugin(py_module) != SUDO_RC_OK)
         goto cleanup;
 
+    if (sudo_module_register_loghandler(py_module) != SUDO_RC_OK)
+        goto cleanup;
+
 cleanup:
     if (PyErr_Occurred()) {
         Py_CLEAR(py_module);

plugins/python/sudo_python_module.h

@@ -31,7 +31,10 @@ extern PyObject *sudo_exc_PluginError;   // an error with message
 extern PyTypeObject *sudo_type_Plugin;
 extern PyTypeObject *sudo_type_ConvMessage;
 
-PyObject *sudo_module_create_class(const char *class_name, PyMethodDef *class_methods);
+extern PyObject *sudo_type_LogHandler;
+
+PyObject *sudo_module_create_class(const char *class_name, PyMethodDef *class_methods,
+                                   PyObject *base_class);
 
 CPYCHECKER_NEGATIVE_RESULT_SETS_EXCEPTION
 int sudo_module_register_importblocker(void);
@@ -48,6 +51,14 @@ int sudo_module_ConvMessages_to_c(PyObject *py_tuple, Py_ssize_t *num_msgs, stru
 CPYCHECKER_NEGATIVE_RESULT_SETS_EXCEPTION
 int sudo_module_register_baseplugin(PyObject *py_module);
 
+CPYCHECKER_NEGATIVE_RESULT_SETS_EXCEPTION
+int sudo_module_register_loghandler(PyObject *py_module);
+
+CPYCHECKER_NEGATIVE_RESULT_SETS_EXCEPTION
+int sudo_module_set_default_loghandler(void);
+
+PyObject *python_sudo_debug(PyObject *py_self, PyObject *py_args);
+
 PyMODINIT_FUNC sudo_module_init(void);
 
 #endif // SUDO_PYTHON_MODULE_H