Fix the log levels mapping

The libssh provides the most verbose logging with SSH_LOG_TRACE, which
was not mapped to any of the standard values so the users are unable
to get full debug logs. These are critical for libssh developers to be
able to investigate issues.

Signed-off-by: Jakub Jelen <[email protected]>

Author: Jakuje

src/pylibsshext/includes/callbacks.pxd

@@ -127,3 +127,10 @@ cdef extern from "libssh/callbacks.h":
     ctypedef ssh_channel_callbacks_struct * ssh_channel_callbacks
 
     int ssh_set_channel_callbacks(ssh_channel channel, ssh_channel_callbacks cb)
+
+    ctypedef void(*ssh_logging_callback)(
+        int priority,
+        const char *function,
+        const char *buffer,
+        void *userdata)
+    int ssh_set_log_callback(ssh_logging_callback cb)

src/pylibsshext/logging.pxd

@@ -0,0 +1,22 @@
+# distutils: libraries = ssh
+#
+# This file is part of the pylibssh library
+#
+# This library is free software; you can redistribute it and/or
+# modify it under the terms of the GNU Lesser General Public
+# License as published by the Free Software Foundation; either
+# version 2.1 of the License, or (at your option) any later version.
+#
+# This library is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+# Lesser General Public License for more details.
+#
+# You should have received a copy of the GNU Lesser General Public
+# License along with this library; if not, see file LICENSE.rst in this
+# repository.
+
+"""
+The Logging module of pylibssh providers interface between libssh logging and
+python log facility.
+"""

src/pylibsshext/logging.pyx

@@ -0,0 +1,131 @@
+#
+# This file is part of the pylibssh library
+#
+# This library is free software; you can redistribute it and/or
+# modify it under the terms of the GNU Lesser General Public
+# License as published by the Free Software Foundation; either
+# version 2.1 of the License, or (at your option) any later version.
+#
+# This library is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+# Lesser General Public License for more details.
+#
+# You should have received a copy of the GNU Lesser General Public
+# License along with this library; if not, see file LICENSE.rst in this
+# repository.
+
+"""
+The Logging module of pylibssh providers interface between libssh logging and
+python log facility.
+
+It provides two new log levels, that can be used with to set the log verbosity
+using ``set_log_level()`` method on ``Session`` object.
+
+.. data:: ANSIBLE_PYLIBSSH_NOLOG
+
+    Indicates the pylibssh will not log any events.
+
+.. data:: ANSIBLE_PYLIBSSH_TRACE
+
+    Indicates the pylibssh will produce all possible logs, generally useful for debugging low-level libssh operations.
+
+"""
+
+import logging
+
+from pylibsshext.errors cimport LibsshSessionException
+from pylibsshext.includes cimport callbacks, libssh
+
+
+ANSIBLE_PYLIBSSH_NOLOG = logging.FATAL * 2
+ANSIBLE_PYLIBSSH_TRACE = int(logging.DEBUG / 2)
+
+_NOT_SET_SENTINEL = object()
+
+LOG_MAP = {
+    logging.NOTSET: _NOT_SET_SENTINEL,
+    ANSIBLE_PYLIBSSH_TRACE: libssh.SSH_LOG_TRACE,
+    logging.DEBUG: libssh.SSH_LOG_DEBUG,
+    logging.INFO: libssh.SSH_LOG_INFO,
+    logging.WARNING: libssh.SSH_LOG_WARN,
+    ANSIBLE_PYLIBSSH_NOLOG: libssh.SSH_LOG_NONE,
+}
+
+LOG_MAP_REV = {
+    **{
+        libssh_name: py_name
+        for py_name, libssh_name in LOG_MAP.items()
+    },
+}
+
+# mapping aliases
+LOG_MAP[logging.ERROR] = libssh.SSH_LOG_WARN
+LOG_MAP[logging.CRITICAL] = libssh.SSH_LOG_WARN
+
+
+_logger = logging.getLogger("ansible-pylibssh")
+
+
+def _add_trace_log_level():
+    """
+    Adds a trace log level to the python logging system.
+    """
+    level_num = ANSIBLE_PYLIBSSH_TRACE
+    level_name = "TRACE"
+
+    logging.addLevelName(level_num, level_name)
+
+
+cdef void _pylibssh_log_wrapper(int priority,
+                                const char *function,
+                                const char *buffer,
+                                void *userdata) noexcept:
+    log_level = LOG_MAP_REV[priority]
+    _logger.log(log_level, buffer.decode('utf-8'))
+
+
+def _set_log_callback():
+    """
+    Note, that we could also set the set_log_userdata() to access the logger object,
+    but I did not find it much useful when it is global already.
+    """
+    callbacks.ssh_set_log_callback(_pylibssh_log_wrapper)
+
+
+def _initialize_logging():
+    """
+    This is done globally, as the libssh logging is not tied to specific session
+    (its thread-local state in libssh) so either very good care needs to be taken
+    to make sure the logger is in place when callback can be called almost from
+    anywhere in the code or just keep it global.
+    """
+    _add_trace_log_level()
+    _set_log_callback()
+
+
+def _set_level(level):
+    """
+    Set logging level to the given value from LOG_MAP
+
+    :param level: The level to set.
+
+    :raises LibsshSessionException: If the log level is not known by pylibssh.
+
+    :return: Nothing.
+    :rtype: NoneType
+    """
+    _initialize_logging()
+    if level not in LOG_MAP:
+        raise LibsshSessionException(f'Invalid log level [{level:d}]')
+
+    # Special case not-set does not go deeper
+    if level == _NOT_SET_SENTINEL:
+        return
+
+    rc = libssh.ssh_set_log_level(LOG_MAP[level])
+    if rc != libssh.SSH_OK:
+        raise LibsshSessionException(
+            f'Failed to set log level [{level:d}] with error [{rc:d}]',
+        )
+    _logger.setLevel(level)

src/pylibsshext/session.pyx

@@ -15,12 +15,14 @@
 # License along with this library; if not, see file LICENSE.rst in this
 # repository.
 import inspect
-import logging
 
 from cpython.bytes cimport PyBytes_AS_STRING
 
 from pylibsshext.channel import Channel
+
 from pylibsshext.errors cimport LibsshSessionException
+
+from pylibsshext.logging import _set_level
 from pylibsshext.scp import SCP
 from pylibsshext.sftp import SFTP
 
@@ -45,15 +47,6 @@ OPTS_DIR_MAP = {
     "add_identity": libssh.SSH_OPTIONS_ADD_IDENTITY,
 }
 
-LOG_MAP = {
-    logging.NOTSET: libssh.SSH_LOG_NONE,
-    logging.DEBUG: libssh.SSH_LOG_DEBUG,
-    logging.INFO: libssh.SSH_LOG_INFO,
-    logging.WARNING: libssh.SSH_LOG_WARN,
-    logging.ERROR: libssh.SSH_LOG_WARN,
-    logging.CRITICAL: libssh.SSH_LOG_TRACE
-}
-
 KNOW_HOST_MSG_MAP = {
     libssh.SSH_KNOWN_HOSTS_CHANGED: "Host key for server has changed: ",
     libssh.SSH_KNOWN_HOSTS_OTHER: "Host key type for server has changed: ",
@@ -528,12 +521,7 @@ cdef class Session(object):
         return SFTP(self)
 
     def set_log_level(self, level):
-        if level in LOG_MAP.keys():
-            rc = libssh.ssh_set_log_level(LOG_MAP[level])
-            if rc != libssh.SSH_OK:
-                raise LibsshSessionException("Failed to set log level [%d] with error [%d]" % (level, rc))
-        else:
-            raise LibsshSessionException("Invalid log level [%d]" % level)
+        _set_level(level)
 
     def close(self):
         if self._libssh_session is not NULL:

tests/conftest.py

@@ -3,7 +3,6 @@
 
 """Pytest plugins and fixtures configuration."""
 
-import logging
 import shutil
 import socket
 import subprocess
@@ -14,6 +13,7 @@
     ensure_ssh_session_connected, wait_for_svc_ready_state,
 )
 
+from pylibsshext.logging import ANSIBLE_PYLIBSSH_TRACE
 from pylibsshext.session import Session
 
 
@@ -116,8 +116,7 @@ def ssh_client_session(ssh_session_connect):
     # noqa: DAR101
     """
     ssh_session = Session()
-    # TODO Adjust when #597 will be merged
-    ssh_session.set_log_level(logging.CRITICAL)
+    ssh_session.set_log_level(ANSIBLE_PYLIBSSH_TRACE)
     ssh_session_connect(ssh_session)
     try:  # noqa: WPS501
         yield ssh_session