From 25b4af70863975fdf2ff282c3517f3fd19916baa Mon Sep 17 00:00:00 2001 From: Foklan Date: Sun, 5 Jul 2026 15:33:14 +0200 Subject: [PATCH 1/7] loader: Handle KeyError from __virtual__() as debug --- salt/loader/lazy.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/salt/loader/lazy.py b/salt/loader/lazy.py index 677371f6734a..d0991dd65e4b 100644 --- a/salt/loader/lazy.py +++ b/salt/loader/lazy.py @@ -1281,6 +1281,17 @@ def _process_virtual(self, mod, module_name, virtual_func="__virtual__"): end, module_name ) log.warning(msg) + + except KeyError as exc: + error_reason = ( + "Missing loader context while processing __virtual__ " + "for {}: {}".format( + mod.__name__, exc + ) + ) + log.debug(error_reason, exc_info=exc) + virtual = None + except Exception as exc: # pylint: disable=broad-except error_reason = ( "Exception raised when processing __virtual__ function" From 55e5fea421f85446d374625be023827fe6fefdb5 Mon Sep 17 00:00:00 2001 From: Foklan Date: Sun, 5 Jul 2026 15:40:00 +0200 Subject: [PATCH 2/7] Add changelog --- changelog/66927.fixed.md | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog/66927.fixed.md diff --git a/changelog/66927.fixed.md b/changelog/66927.fixed.md new file mode 100644 index 000000000000..f3295b6357ef --- /dev/null +++ b/changelog/66927.fixed.md @@ -0,0 +1 @@ +Prevent `KeyError` raised by module `__virtual__()` during loader initialization from being logged as an error; log it at debug level instead. From 044d95f98decc8ce2d6069bc47117f75acbd0778 Mon Sep 17 00:00:00 2001 From: Foklan Date: Sun, 5 Jul 2026 16:39:05 +0200 Subject: [PATCH 3/7] Apply pre-commit formatting --- salt/loader/lazy.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/salt/loader/lazy.py b/salt/loader/lazy.py index d0991dd65e4b..7820c16e191f 100644 --- a/salt/loader/lazy.py +++ b/salt/loader/lazy.py @@ -1285,9 +1285,7 @@ def _process_virtual(self, mod, module_name, virtual_func="__virtual__"): except KeyError as exc: error_reason = ( "Missing loader context while processing __virtual__ " - "for {}: {}".format( - mod.__name__, exc - ) + "for {}: {}".format(mod.__name__, exc) ) log.debug(error_reason, exc_info=exc) virtual = None From 3b51e42c74777492dc6ddcc0469a56aaf1ce68dd Mon Sep 17 00:00:00 2001 From: Foklan Date: Sun, 5 Jul 2026 18:15:46 +0200 Subject: [PATCH 4/7] Add tests --- tests/unit/test_loader.py | 74 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 74 insertions(+) diff --git a/tests/unit/test_loader.py b/tests/unit/test_loader.py index b7266c59effe..876c8bf1d735 100644 --- a/tests/unit/test_loader.py +++ b/tests/unit/test_loader.py @@ -1794,3 +1794,77 @@ def test_lazyloader_pyx_modules(self): loader = self.__init_loader() assert ".pyx" not in loader.suffix_map assert ".pyx" not in loader.suffix_order + + +class LazyLoaderVirtualExceptionLoggingTest(TestCase): + """ + Ensure _process_virtual logs KeyError as debug and other exceptions as error. + """ + + def setUp(self): + self.opts = salt.config.minion_config(None) + self.opts["grains"] = salt.loader.grains(self.opts) + + self.utils = salt.loader.utils(copy.deepcopy(self.opts)) + self.proxy = salt.loader.proxy(self.opts) + self.funcs = salt.loader.minion_mods( + self.opts, utils=self.utils, proxy=self.proxy + ) + + self.module_dir = tempfile.mkdtemp(dir=RUNTIME_VARS.TMP) + self.addCleanup(shutil.rmtree, self.module_dir, ignore_errors=True) + + def _make_loader(self, module_code): + path = os.path.join(self.module_dir, "badmod.py") + + with salt.utils.files.fopen(path, "w") as fh: + fh.write(salt.utils.stringutils.to_str(module_code)) + + return salt.loader.LazyLoader( + [self.module_dir], + copy.deepcopy(self.opts), + pack={ + "__utils__": self.utils, + "__salt__": self.funcs, + "__proxy__": self.proxy, + }, + tag="module", + ) + + def test_keyerror_is_debug_not_error(self): + module = """ +def __virtual__(): + raise KeyError("boom") + +def run(): + return True +""" + + loader = self._make_loader(module) + + with patch.object(salt.loader.lazy.log, "error") as mock_error, \ + patch.object(salt.loader.lazy.log, "debug") as mock_debug: + + _ = "badmod.run" in loader + + mock_error.assert_not_called() + self.assertTrue(mock_debug.called) + + def test_other_exception_is_error(self): + module = """ +def __virtual__(): + raise ValueError("boom") + +def run(): + return True +""" + + loader = self._make_loader(module) + + with patch.object(salt.loader.lazy.log, "error") as mock_error, \ + patch.object(salt.loader.lazy.log, "debug") as mock_debug: + + _ = "badmod.run" in loader + + mock_error.assert_called() + mock_debug.assert_not_called() From f16c01ccec2f8cfc0c1af48e458b79fc36ecd5eb Mon Sep 17 00:00:00 2001 From: Foklan Date: Sun, 5 Jul 2026 18:27:32 +0200 Subject: [PATCH 5/7] Apply pre-commit formatting --- tests/unit/test_loader.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/tests/unit/test_loader.py b/tests/unit/test_loader.py index 876c8bf1d735..f494cd9aa262 100644 --- a/tests/unit/test_loader.py +++ b/tests/unit/test_loader.py @@ -1842,8 +1842,9 @@ def run(): loader = self._make_loader(module) - with patch.object(salt.loader.lazy.log, "error") as mock_error, \ - patch.object(salt.loader.lazy.log, "debug") as mock_debug: + with patch.object(salt.loader.lazy.log, "error") as mock_error, patch.object( + salt.loader.lazy.log, "debug" + ) as mock_debug: _ = "badmod.run" in loader @@ -1861,8 +1862,9 @@ def run(): loader = self._make_loader(module) - with patch.object(salt.loader.lazy.log, "error") as mock_error, \ - patch.object(salt.loader.lazy.log, "debug") as mock_debug: + with patch.object(salt.loader.lazy.log, "error") as mock_error, patch.object( + salt.loader.lazy.log, "debug" + ) as mock_debug: _ = "badmod.run" in loader From e07aa83f0f969d6b588299a4d97813ffdd9bd090 Mon Sep 17 00:00:00 2001 From: Foklan Date: Mon, 6 Jul 2026 23:30:25 +0200 Subject: [PATCH 6/7] Dedent test modules --- tests/unit/test_loader.py | 32 ++++++++++++++++++-------------- 1 file changed, 18 insertions(+), 14 deletions(-) diff --git a/tests/unit/test_loader.py b/tests/unit/test_loader.py index f494cd9aa262..cf5ac31d5d0b 100644 --- a/tests/unit/test_loader.py +++ b/tests/unit/test_loader.py @@ -1832,13 +1832,15 @@ def _make_loader(self, module_code): ) def test_keyerror_is_debug_not_error(self): - module = """ -def __virtual__(): - raise KeyError("boom") - -def run(): - return True -""" + module = textwrap.dedent( + """\ + def __virtual__(): + raise KeyError("boom") + + def run(): + return True + """ + ) loader = self._make_loader(module) @@ -1852,13 +1854,15 @@ def run(): self.assertTrue(mock_debug.called) def test_other_exception_is_error(self): - module = """ -def __virtual__(): - raise ValueError("boom") - -def run(): - return True -""" + module = textwrap.dedent( + """\ + def __virtual__(): + raise ValueError("boom") + + def run(): + return True + """ + ) loader = self._make_loader(module) From 1fd377cb93bddbd34ea9097f41a29ab17e5a6427 Mon Sep 17 00:00:00 2001 From: Foklan Date: Mon, 6 Jul 2026 23:40:17 +0200 Subject: [PATCH 7/7] Use dedent from helpers.support.helpers --- tests/unit/test_loader.py | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/tests/unit/test_loader.py b/tests/unit/test_loader.py index cf5ac31d5d0b..6a65a04019e6 100644 --- a/tests/unit/test_loader.py +++ b/tests/unit/test_loader.py @@ -28,6 +28,7 @@ from tests.support.mock import MagicMock, patch from tests.support.runtests import RUNTIME_VARS from tests.support.unit import TestCase +from tests.support.helpers import dedent log = logging.getLogger(__name__) @@ -1832,8 +1833,8 @@ def _make_loader(self, module_code): ) def test_keyerror_is_debug_not_error(self): - module = textwrap.dedent( - """\ + module = dedent( + """ def __virtual__(): raise KeyError("boom") @@ -1854,8 +1855,8 @@ def run(): self.assertTrue(mock_debug.called) def test_other_exception_is_error(self): - module = textwrap.dedent( - """\ + module = dedent( + """ def __virtual__(): raise ValueError("boom")