From 71b947b4f0bc56b7588c399604a558d50b16f4d5 Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Wed, 26 Apr 2023 14:26:55 -0500 Subject: [PATCH 1/8] Call global logger when catching pip.list exceptions in states.pip.installed --- changelog/64169.fixed.md | 1 + salt/states/pip_state.py | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) create mode 100644 changelog/64169.fixed.md diff --git a/changelog/64169.fixed.md b/changelog/64169.fixed.md new file mode 100644 index 000000000000..499b94b693ba --- /dev/null +++ b/changelog/64169.fixed.md @@ -0,0 +1 @@ +Call global logger when catching pip.list exceptions in states.pip.installed diff --git a/salt/states/pip_state.py b/salt/states/pip_state.py index 542a7f6c751b..fd99d6bd626d 100644 --- a/salt/states/pip_state.py +++ b/salt/states/pip_state.py @@ -852,7 +852,7 @@ def installed( ) # If we fail, then just send False, and we'll try again in the next function call except Exception as exc: # pylint: disable=broad-except - log.exception(exc) + globals().get("log").exception(exc) pip_list = False for prefix, state_pkg_name, version_spec in pkgs_details: From e42fe2af4788a86b8a54da7eab1a9a246afbf5f2 Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Wed, 26 Apr 2023 18:27:11 -0500 Subject: [PATCH 2/8] Add unit test for #64169 --- tests/pytests/unit/states/test_pip.py | 69 +++++++++++++++++++++++++++ 1 file changed, 69 insertions(+) create mode 100644 tests/pytests/unit/states/test_pip.py diff --git a/tests/pytests/unit/states/test_pip.py b/tests/pytests/unit/states/test_pip.py new file mode 100644 index 000000000000..7e04602ce440 --- /dev/null +++ b/tests/pytests/unit/states/test_pip.py @@ -0,0 +1,69 @@ +""" + :codeauthor: Eric Graham +""" +import logging + +import pytest + +import salt.states.pip_state as pip_state +from salt.exceptions import CommandExecutionError +from tests.support.mock import MagicMock, patch + + +@pytest.fixture +def configure_loader_modules(): + return { + pip_state: { + '__env__': 'base', + '__opts__': { + 'test': False + } + } + } + + +def test_issue_64169(caplog): + pkg_to_install = 'nonexistent_package' + exception_message = 'Invalid JSON (test_issue_64169)' + + mock_pip_list = MagicMock(side_effect=[ + CommandExecutionError(exception_message), # pre-cache the pip list (preinstall) + {}, # Checking if the pkg is already installed + {pkg_to_install: '100.10.1'} # Confirming successful installation + ]) + mock_pip_version = MagicMock(return_value='100.10.1') + mock_pip_install = MagicMock(return_value={"retcode": 0, "stdout": ""}) + + with patch.dict(pip_state.__salt__, { + "pip.list": mock_pip_list, + "pip.version": mock_pip_version, + "pip.install": mock_pip_install + }): + with caplog.at_level(logging.WARNING): + # Call pip.installed with a specifically 'broken' pip.list. + # pip.installed should continue, but log the exception from pip.list. + # pip.installed should NOT raise an exception itself. + # noinspection PyBroadException + try: + pip_state.installed( + name=pkg_to_install, + use_wheel=False, # Set False to simplify testing + no_use_wheel=False, # ' + no_binary=False, # ' + log=None # Regression will cause this function call to throw + # an AttributeError + ) + except AttributeError: + # Observed behavior in #64169 + assert False + except: + # Something went wrong, but it isn't what's being tested for here. + return + + # Take 64169 further and actually confirm that the targeted exception from pip.list got logged. + assert exception_message in caplog.messages + + # Confirm that the state continued to install the package as expected. + # Only check the 'pkgs' parameter of pip.install + mock_install_call_args, mock_install_call_kwargs = mock_pip_install.call_args + assert mock_install_call_kwargs['pkgs'] == pkg_to_install From 2d15b8c384016cb35e04a449c9aca608de34e88e Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Mon, 1 May 2023 10:55:29 -0500 Subject: [PATCH 3/8] Rename Global Logger log to logger in pip_state.py --- changelog/64169.fixed.md | 1 + salt/states/pip_state.py | 14 ++++++++------ tests/pytests/unit/states/test_pip.py | 11 +++++++++-- 3 files changed, 18 insertions(+), 8 deletions(-) diff --git a/changelog/64169.fixed.md b/changelog/64169.fixed.md index 499b94b693ba..fe80eff1e94e 100644 --- a/changelog/64169.fixed.md +++ b/changelog/64169.fixed.md @@ -1 +1,2 @@ Call global logger when catching pip.list exceptions in states.pip.installed +Rename gloabl logger `log` to `logger` inside pip_state \ No newline at end of file diff --git a/salt/states/pip_state.py b/salt/states/pip_state.py index fd99d6bd626d..cc5d877c06e9 100644 --- a/salt/states/pip_state.py +++ b/salt/states/pip_state.py @@ -114,7 +114,7 @@ def pip_has_exceptions_mod(ver): # pylint: enable=import-error -log = logging.getLogger(__name__) +logger = logging.getLogger(__name__) # Define the module's virtual name __virtualname__ = "pip" @@ -189,10 +189,10 @@ def _check_pkg_version_format(pkg): # vcs+URL urls are not properly parsed. # The next line is meant to trigger an AttributeError and # handle lower pip versions - log.debug("Installed pip version: %s", pip.__version__) + logger.debug("Installed pip version: %s", pip.__version__) install_req = _from_line(pkg) except AttributeError: - log.debug("Installed pip version is lower than 1.2") + logger.debug("Installed pip version is lower than 1.2") supported_vcs = ("git", "svn", "hg", "bzr") if pkg.startswith(supported_vcs): for vcs in supported_vcs: @@ -351,7 +351,7 @@ def _pep440_version_cmp(pkg1, pkg2, ignore_epoch=False): making the comparison. """ if HAS_PKG_RESOURCES is False: - log.warning( + logger.warning( "The pkg_resources packages was not loaded. Please install setuptools." ) return None @@ -367,7 +367,7 @@ def _pep440_version_cmp(pkg1, pkg2, ignore_epoch=False): if pkg_resources.parse_version(pkg1) > pkg_resources.parse_version(pkg2): return 1 except Exception as exc: # pylint: disable=broad-except - log.exception(exc) + logger.exception(f'Comparison of package versions "{pkg1}" and "{pkg2}" failed: {exc}') return None @@ -852,7 +852,9 @@ def installed( ) # If we fail, then just send False, and we'll try again in the next function call except Exception as exc: # pylint: disable=broad-except - globals().get("log").exception(exc) + logger.exception( + f'Pre-caching of PIP packages during states.pip.installed failed by exception from pip.list: {exc}' + ) pip_list = False for prefix, state_pkg_name, version_spec in pkgs_details: diff --git a/tests/pytests/unit/states/test_pip.py b/tests/pytests/unit/states/test_pip.py index 7e04602ce440..1b6d8afb3643 100644 --- a/tests/pytests/unit/states/test_pip.py +++ b/tests/pytests/unit/states/test_pip.py @@ -60,8 +60,15 @@ def test_issue_64169(caplog): # Something went wrong, but it isn't what's being tested for here. return - # Take 64169 further and actually confirm that the targeted exception from pip.list got logged. - assert exception_message in caplog.messages + # Take 64169 further and actually confirm that the exception from pip.list got logged. + exc_msg_present = False + for log_line in caplog.messages: + # The exception must be somewhere in the log, but may optionally not be on a line by itself. + if exception_message in log_line: + exc_msg_present = True + break + + assert exc_msg_present # Confirm that the state continued to install the package as expected. # Only check the 'pkgs' parameter of pip.install From 2b78379e9c424639e5f54d0cf7782e7c57114f73 Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Mon, 1 May 2023 15:51:25 -0500 Subject: [PATCH 4/8] Clarify Failing Test Message; Search for Entire Log Line in caplog --- tests/pytests/unit/states/test_pip.py | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/tests/pytests/unit/states/test_pip.py b/tests/pytests/unit/states/test_pip.py index 1b6d8afb3643..7d93faa3eb84 100644 --- a/tests/pytests/unit/states/test_pip.py +++ b/tests/pytests/unit/states/test_pip.py @@ -53,22 +53,19 @@ def test_issue_64169(caplog): log=None # Regression will cause this function call to throw # an AttributeError ) - except AttributeError: + except AttributeError as exc: # Observed behavior in #64169 - assert False + pytest.fail( + 'Regression on #64169: pip_state.installed seems to be throwing an unexpected AttributeException: ' + f'{exc}' + ) except: # Something went wrong, but it isn't what's being tested for here. return # Take 64169 further and actually confirm that the exception from pip.list got logged. - exc_msg_present = False - for log_line in caplog.messages: - # The exception must be somewhere in the log, but may optionally not be on a line by itself. - if exception_message in log_line: - exc_msg_present = True - break - - assert exc_msg_present + assert 'Pre-caching of PIP packages during states.pip.installed failed by exception ' \ + f'from pip.list: {exception_message}' in caplog.messages # Confirm that the state continued to install the package as expected. # Only check the 'pkgs' parameter of pip.install From 61b73dd3ed701bf1c728294d1c6d7e4bcb347696 Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Mon, 1 May 2023 15:53:52 -0500 Subject: [PATCH 5/8] Fix Changelog Typo --- changelog/64169.fixed.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/changelog/64169.fixed.md b/changelog/64169.fixed.md index fe80eff1e94e..d6ce2bf19370 100644 --- a/changelog/64169.fixed.md +++ b/changelog/64169.fixed.md @@ -1,2 +1,2 @@ Call global logger when catching pip.list exceptions in states.pip.installed -Rename gloabl logger `log` to `logger` inside pip_state \ No newline at end of file +Rename global logger `log` to `logger` inside pip_state \ No newline at end of file From 24a8893a01fff220b8c730ef022076187251e46b Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Mon, 1 May 2023 16:08:55 -0500 Subject: [PATCH 6/8] Remove Silent Catch --- tests/pytests/unit/states/test_pip.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/tests/pytests/unit/states/test_pip.py b/tests/pytests/unit/states/test_pip.py index 7d93faa3eb84..a7cdc106e62f 100644 --- a/tests/pytests/unit/states/test_pip.py +++ b/tests/pytests/unit/states/test_pip.py @@ -59,9 +59,6 @@ def test_issue_64169(caplog): 'Regression on #64169: pip_state.installed seems to be throwing an unexpected AttributeException: ' f'{exc}' ) - except: - # Something went wrong, but it isn't what's being tested for here. - return # Take 64169 further and actually confirm that the exception from pip.list got logged. assert 'Pre-caching of PIP packages during states.pip.installed failed by exception ' \ From c23fe80ffa1881e444114688099f2058eb9fbe88 Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Tue, 2 May 2023 13:22:13 -0500 Subject: [PATCH 7/8] Run Black Pre-Commit Step --- salt/states/pip_state.py | 16 ++++--- tests/pytests/unit/states/test_pip.py | 61 ++++++++++++++------------- 2 files changed, 40 insertions(+), 37 deletions(-) diff --git a/salt/states/pip_state.py b/salt/states/pip_state.py index cc5d877c06e9..de75057adf47 100644 --- a/salt/states/pip_state.py +++ b/salt/states/pip_state.py @@ -251,7 +251,7 @@ def _check_if_installed( index_url, extra_index_url, pip_list=False, - **kwargs + **kwargs, ): """ Takes a package name and version specification (if any) and checks it is @@ -367,7 +367,9 @@ def _pep440_version_cmp(pkg1, pkg2, ignore_epoch=False): if pkg_resources.parse_version(pkg1) > pkg_resources.parse_version(pkg2): return 1 except Exception as exc: # pylint: disable=broad-except - logger.exception(f'Comparison of package versions "{pkg1}" and "{pkg2}" failed: {exc}') + logger.exception( + f'Comparison of package versions "{pkg1}" and "{pkg2}" failed: {exc}' + ) return None @@ -418,7 +420,7 @@ def installed( cache_dir=None, no_binary=None, extra_args=None, - **kwargs + **kwargs, ): """ Make sure the package is installed @@ -853,7 +855,7 @@ def installed( # If we fail, then just send False, and we'll try again in the next function call except Exception as exc: # pylint: disable=broad-except logger.exception( - f'Pre-caching of PIP packages during states.pip.installed failed by exception from pip.list: {exc}' + f"Pre-caching of PIP packages during states.pip.installed failed by exception from pip.list: {exc}" ) pip_list = False @@ -874,7 +876,7 @@ def installed( index_url, extra_index_url, pip_list, - **kwargs + **kwargs, ) # If _check_if_installed result is None, something went wrong with # the command running. This way we keep stateful output. @@ -980,7 +982,7 @@ def installed( no_cache_dir=no_cache_dir, extra_args=extra_args, disable_version_check=True, - **kwargs + **kwargs, ) if pip_install_call and pip_install_call.get("retcode", 1) == 0: @@ -1045,7 +1047,7 @@ def installed( user=user, cwd=cwd, env_vars=env_vars, - **kwargs + **kwargs, ) ) diff --git a/tests/pytests/unit/states/test_pip.py b/tests/pytests/unit/states/test_pip.py index a7cdc106e62f..307ba5e1e650 100644 --- a/tests/pytests/unit/states/test_pip.py +++ b/tests/pytests/unit/states/test_pip.py @@ -12,33 +12,33 @@ @pytest.fixture def configure_loader_modules(): - return { - pip_state: { - '__env__': 'base', - '__opts__': { - 'test': False - } - } - } + return {pip_state: {"__env__": "base", "__opts__": {"test": False}}} def test_issue_64169(caplog): - pkg_to_install = 'nonexistent_package' - exception_message = 'Invalid JSON (test_issue_64169)' + pkg_to_install = "nonexistent_package" + exception_message = "Invalid JSON (test_issue_64169)" - mock_pip_list = MagicMock(side_effect=[ - CommandExecutionError(exception_message), # pre-cache the pip list (preinstall) - {}, # Checking if the pkg is already installed - {pkg_to_install: '100.10.1'} # Confirming successful installation - ]) - mock_pip_version = MagicMock(return_value='100.10.1') + mock_pip_list = MagicMock( + side_effect=[ + CommandExecutionError( + exception_message + ), # pre-cache the pip list (preinstall) + {}, # Checking if the pkg is already installed + {pkg_to_install: "100.10.1"}, # Confirming successful installation + ] + ) + mock_pip_version = MagicMock(return_value="100.10.1") mock_pip_install = MagicMock(return_value={"retcode": 0, "stdout": ""}) - with patch.dict(pip_state.__salt__, { - "pip.list": mock_pip_list, - "pip.version": mock_pip_version, - "pip.install": mock_pip_install - }): + with patch.dict( + pip_state.__salt__, + { + "pip.list": mock_pip_list, + "pip.version": mock_pip_version, + "pip.install": mock_pip_install, + }, + ): with caplog.at_level(logging.WARNING): # Call pip.installed with a specifically 'broken' pip.list. # pip.installed should continue, but log the exception from pip.list. @@ -47,24 +47,25 @@ def test_issue_64169(caplog): try: pip_state.installed( name=pkg_to_install, - use_wheel=False, # Set False to simplify testing + use_wheel=False, # Set False to simplify testing no_use_wheel=False, # ' - no_binary=False, # ' - log=None # Regression will cause this function call to throw - # an AttributeError + no_binary=False, # ' + log=None, # Regression will cause this function call to throw an AttributeError ) except AttributeError as exc: # Observed behavior in #64169 pytest.fail( - 'Regression on #64169: pip_state.installed seems to be throwing an unexpected AttributeException: ' - f'{exc}' + "Regression on #64169: pip_state.installed seems to be throwing an unexpected AttributeException: " + f"{exc}" ) # Take 64169 further and actually confirm that the exception from pip.list got logged. - assert 'Pre-caching of PIP packages during states.pip.installed failed by exception ' \ - f'from pip.list: {exception_message}' in caplog.messages + assert ( + "Pre-caching of PIP packages during states.pip.installed failed by exception " + f"from pip.list: {exception_message}" in caplog.messages + ) # Confirm that the state continued to install the package as expected. # Only check the 'pkgs' parameter of pip.install mock_install_call_args, mock_install_call_kwargs = mock_pip_install.call_args - assert mock_install_call_kwargs['pkgs'] == pkg_to_install + assert mock_install_call_kwargs["pkgs"] == pkg_to_install From ec1e2878521ddbdf46fdf3aea1ed17986cf73fae Mon Sep 17 00:00:00 2001 From: Eric Graham Date: Wed, 3 May 2023 09:39:26 -0500 Subject: [PATCH 8/8] Add New Line to Changelog --- changelog/64169.fixed.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/changelog/64169.fixed.md b/changelog/64169.fixed.md index d6ce2bf19370..e8631285aaac 100644 --- a/changelog/64169.fixed.md +++ b/changelog/64169.fixed.md @@ -1,2 +1,2 @@ Call global logger when catching pip.list exceptions in states.pip.installed -Rename global logger `log` to `logger` inside pip_state \ No newline at end of file +Rename global logger `log` to `logger` inside pip_state