From 649644cb16712d2d57a14822c6d04ed3666b8d74 Mon Sep 17 00:00:00 2001 From: Jakub Jelen Date: Thu, 23 May 2024 15:58:21 +0200 Subject: [PATCH 1/4] 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 --- src/pylibsshext/includes/callbacks.pxd | 7 ++ src/pylibsshext/logging.pyx | 131 +++++++++++++++++++++++++ src/pylibsshext/session.pyx | 20 +--- tests/conftest.py | 5 +- 4 files changed, 144 insertions(+), 19 deletions(-) create mode 100644 src/pylibsshext/logging.pyx diff --git a/src/pylibsshext/includes/callbacks.pxd b/src/pylibsshext/includes/callbacks.pxd index 698f5c60b..c875eafdd 100644 --- a/src/pylibsshext/includes/callbacks.pxd +++ b/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) diff --git a/src/pylibsshext/logging.pyx b/src/pylibsshext/logging.pyx new file mode 100644 index 000000000..75c2e85fd --- /dev/null +++ b/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) diff --git a/src/pylibsshext/session.pyx b/src/pylibsshext/session.pyx index e44746617..a5592ae8c 100644 --- a/src/pylibsshext/session.pyx +++ b/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: diff --git a/tests/conftest.py b/tests/conftest.py index 0770b3482..b329814dc 100644 --- a/tests/conftest.py +++ b/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 From 50ab26e5ceaf1aecc61cb16e0128a082781cb9c8 Mon Sep 17 00:00:00 2001 From: Jakub Jelen Date: Fri, 21 Jun 2024 11:58:26 +0200 Subject: [PATCH 2/4] test for setting log level Signed-off-by: Jakub Jelen --- tests/unit/session_test.py | 63 +++++++++++++++++++++++++++++++++++++- 1 file changed, 62 insertions(+), 1 deletion(-) diff --git a/tests/unit/session_test.py b/tests/unit/session_test.py index d634289a3..6227df52c 100644 --- a/tests/unit/session_test.py +++ b/tests/unit/session_test.py @@ -2,12 +2,18 @@ """Tests suite for session.""" +import logging + import pytest from pylibsshext.errors import LibsshSessionException +from pylibsshext.logging import ANSIBLE_PYLIBSSH_NOLOG, ANSIBLE_PYLIBSSH_TRACE from pylibsshext.session import Session +LOCALHOST = '127.0.0.1' + + def test_make_session(): """Smoke-test Session instance creation.""" assert Session() @@ -27,4 +33,59 @@ def test_session_connection_refused(free_port_num): error_msg = '^ssh connect failed: Connection refused$' ssh_session = Session() with pytest.raises(LibsshSessionException, match=error_msg): - ssh_session.connect(host='127.0.0.1', port=free_port_num) + ssh_session.connect(host=LOCALHOST, port=free_port_num) + + +def test_session_log_level_debug(caplog, free_port_num): + """Test setting the log level to DEBUG should reveal copyright information. But no trace messages.""" + ssh_session = Session() + ssh_session.set_log_level(logging.DEBUG) + + # the connection will fail but first log lands before that + with pytest.raises(LibsshSessionException, match='ssh connect failed: Connection refused'): + ssh_session.connect(host=LOCALHOST, port=free_port_num) + + expected_copyright_substring = 'and libssh contributors.' + # This log message is shown at different log levels + # in different libssh versions: + expected_copyright_log_levels = {'DEBUG', 'INFO'} + informational_log_messages = ( + record.msg + for record in caplog.records + if record.levelname in expected_copyright_log_levels + ) + assert any(expected_copyright_substring in message for message in informational_log_messages) + + for record in caplog.records: + if record.levelname == 'TRACE': + assert not 'Found unexpected TRACE message {msg}'.format(msg=record.msg) + + +def test_session_log_level_no_log(caplog, free_port_num): + """Test setting the log level to NOLOG should be quiet.""" + ssh_session = Session() + ssh_session.set_log_level(ANSIBLE_PYLIBSSH_NOLOG) + + # the connection will fail but first log lands before that + with pytest.raises(LibsshSessionException, match='ssh connect failed: Connection refused'): + ssh_session.connect(host=LOCALHOST, port=free_port_num) + + assert not caplog.records + + +def test_session_log_level_trace(caplog, free_port_num): + """Test setting the log level to TRACE should provide all of the logs.""" + ssh_session = Session() + ssh_session.set_log_level(ANSIBLE_PYLIBSSH_TRACE) + + # the connection will fail but first log lands before that + with pytest.raises(LibsshSessionException, match='ssh connect failed: Connection refused'): + ssh_session.connect(host=LOCALHOST, port=free_port_num) + + expected_poll_message = 'ssh_socket_pollcallback: Poll callback on socket' + informational_log_messages = ( + record.msg + for record in caplog.records + if record.levelname == 'TRACE' + ) + assert any(expected_poll_message in message for message in informational_log_messages) From b47396c1ef02818ce6412d0cb8273e5e5e187622 Mon Sep 17 00:00:00 2001 From: Jakub Jelen Date: Fri, 21 Jun 2024 12:04:05 +0200 Subject: [PATCH 3/4] Add changelog fragments Signed-off-by: Jakub Jelen --- docs/changelog-fragments/597.bugfix.rst | 1 + docs/changelog-fragments/597.feature.rst | 1 + 2 files changed, 2 insertions(+) create mode 100644 docs/changelog-fragments/597.bugfix.rst create mode 100644 docs/changelog-fragments/597.feature.rst diff --git a/docs/changelog-fragments/597.bugfix.rst b/docs/changelog-fragments/597.bugfix.rst new file mode 100644 index 000000000..3e16c561a --- /dev/null +++ b/docs/changelog-fragments/597.bugfix.rst @@ -0,0 +1 @@ +Fixed log level mapping to cover whole libssh range -- by :user:`Jakuje`. diff --git a/docs/changelog-fragments/597.feature.rst b/docs/changelog-fragments/597.feature.rst new file mode 100644 index 000000000..13020ff3f --- /dev/null +++ b/docs/changelog-fragments/597.feature.rst @@ -0,0 +1 @@ +Made libssh use python logging system -- by :user:`Jakuje`. From aa1043213c0f4643b35047585b8630d9cf86627b Mon Sep 17 00:00:00 2001 From: Jakub Jelen Date: Thu, 1 May 2025 15:09:38 +0200 Subject: [PATCH 4/4] XXX: Try to add pxd file --- src/pylibsshext/logging.pxd | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) create mode 100644 src/pylibsshext/logging.pxd diff --git a/src/pylibsshext/logging.pxd b/src/pylibsshext/logging.pxd new file mode 100644 index 000000000..ccbf26b44 --- /dev/null +++ b/src/pylibsshext/logging.pxd @@ -0,0 +1,20 @@ +# 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. +# + +# This file is needed to allow imports from the adjacent pyx file