From 05645ca1508fbb96bf8d1de6f4c132b623acdd44 Mon Sep 17 00:00:00 2001 From: Tony Asleson Date: Mon, 27 Apr 2026 10:58:40 -0500 Subject: [PATCH] lvm2: add debug logging for all LVM2 command lines Introduce two new debug subsystems for LVM2 command tracing: --debug=lvm2 Log every command line and its stdout on success. --debug=lvm2err Log only commands that fail, with their stderr. All logging is centralised in _Lvm2._run() so every subprocess invocation is covered. Command lines are formatted with shlex.join(). Both subsystems are included in --debug=all but can be enabled independently for fine-grained control. Resolves: #979 Assisted-by: Claude Signed-off-by: Tony Asleson --- snapm/_snapm.py | 12 +++++++++ snapm/command.py | 4 +++ snapm/manager/plugins/lvm2.py | 47 +++++++++++++++++++++++++++++------ tests/test_command.py | 2 +- 4 files changed, 56 insertions(+), 9 deletions(-) diff --git a/snapm/_snapm.py b/snapm/_snapm.py index e93585ea..0c87dcc1 100644 --- a/snapm/_snapm.py +++ b/snapm/_snapm.py @@ -43,6 +43,8 @@ SNAPM_DEBUG_MOUNTS = 16 SNAPM_DEBUG_FSDIFF = 32 SNAPM_DEBUG_PLUGIN = 64 +SNAPM_DEBUG_LVM2 = 128 +SNAPM_DEBUG_LVM2_ERR = 256 SNAPM_DEBUG_ALL = ( SNAPM_DEBUG_MANAGER | SNAPM_DEBUG_COMMAND @@ -51,6 +53,8 @@ | SNAPM_DEBUG_MOUNTS | SNAPM_DEBUG_FSDIFF | SNAPM_DEBUG_PLUGIN + | SNAPM_DEBUG_LVM2 + | SNAPM_DEBUG_LVM2_ERR ) # Snapm debugging subsystem names @@ -61,6 +65,8 @@ SNAPM_SUBSYSTEM_MOUNTS = "snapm.mounts" SNAPM_SUBSYSTEM_FSDIFF = "snapm.fsdiff" SNAPM_SUBSYSTEM_PLUGIN = "snapm.plugin" +SNAPM_SUBSYSTEM_LVM2 = "snapm.lvm2" +SNAPM_SUBSYSTEM_LVM2_ERR = "snapm.lvm2err" _DEBUG_MASK_TO_SUBSYSTEM = { SNAPM_DEBUG_MANAGER: SNAPM_SUBSYSTEM_MANAGER, @@ -70,6 +76,8 @@ SNAPM_DEBUG_MOUNTS: SNAPM_SUBSYSTEM_MOUNTS, SNAPM_DEBUG_FSDIFF: SNAPM_SUBSYSTEM_FSDIFF, SNAPM_DEBUG_PLUGIN: SNAPM_SUBSYSTEM_PLUGIN, + SNAPM_DEBUG_LVM2: SNAPM_SUBSYSTEM_LVM2, + SNAPM_DEBUG_LVM2_ERR: SNAPM_SUBSYSTEM_LVM2_ERR, } _debug_subsystems = set() @@ -2523,6 +2531,8 @@ def _check_snapm_dir(dirpath: str, mode: int, name: str) -> str: "SNAPM_DEBUG_MOUNTS", "SNAPM_DEBUG_FSDIFF", "SNAPM_DEBUG_PLUGIN", + "SNAPM_DEBUG_LVM2", + "SNAPM_DEBUG_LVM2_ERR", "SNAPM_DEBUG_ALL", # Path to runtime directory "SNAPM_RUNTIME_DIR", @@ -2539,6 +2549,8 @@ def _check_snapm_dir(dirpath: str, mode: int, name: str) -> str: "SNAPM_SUBSYSTEM_MOUNTS", "SNAPM_SUBSYSTEM_FSDIFF", "SNAPM_SUBSYSTEM_PLUGIN", + "SNAPM_SUBSYSTEM_LVM2", + "SNAPM_SUBSYSTEM_LVM2_ERR", # Debug logging - legacy interface "set_debug_mask", "get_debug_mask", diff --git a/snapm/command.py b/snapm/command.py index fb9f2129..2c9db5ec 100644 --- a/snapm/command.py +++ b/snapm/command.py @@ -67,6 +67,8 @@ SNAPM_DEBUG_MOUNTS, SNAPM_DEBUG_FSDIFF, SNAPM_DEBUG_PLUGIN, + SNAPM_DEBUG_LVM2, + SNAPM_DEBUG_LVM2_ERR, SNAPM_DEBUG_ALL, SNAPM_SUBSYSTEM_COMMAND, SubsystemFilter, @@ -2448,6 +2450,8 @@ def set_debug(debug_arg): "mounts": SNAPM_DEBUG_MOUNTS, "fsdiff": SNAPM_DEBUG_FSDIFF, "plugin": SNAPM_DEBUG_PLUGIN, + "lvm2": SNAPM_DEBUG_LVM2, + "lvm2err": SNAPM_DEBUG_LVM2_ERR, "all": SNAPM_DEBUG_ALL, } diff --git a/snapm/manager/plugins/lvm2.py b/snapm/manager/plugins/lvm2.py index 69141e16..869e12cb 100644 --- a/snapm/manager/plugins/lvm2.py +++ b/snapm/manager/plugins/lvm2.py @@ -15,9 +15,15 @@ from math import floor from stat import S_ISBLK from time import time +from shlex import join as shlex_join from shutil import which +import logging from snapm import ( + SNAPM_DEBUG_LVM2, + SNAPM_SUBSYSTEM_LVM2, + SNAPM_SUBSYSTEM_LVM2_ERR, + get_debug_mask, SnapmInvalidIdentifierError, SnapmSizePolicyError, SnapmCalloutError, @@ -48,6 +54,19 @@ encode_mount_point, ) +_log = logging.getLogger(__name__) + + +def _log_debug_lvm2(msg, *args, **kwargs): + """A wrapper for lvm2 subsystem debug logs.""" + _log.debug(msg, *args, extra={"subsystem": SNAPM_SUBSYSTEM_LVM2}, **kwargs) + + +def _log_debug_lvm2_err(msg, *args, **kwargs): + """A wrapper for lvm2err subsystem debug logs.""" + _log.debug(msg, *args, extra={"subsystem": SNAPM_SUBSYSTEM_LVM2_ERR}, **kwargs) + + #: Maximum length for LVM2 LV names LVM_MAX_NAME_LEN = 127 #: Length of extension for LVM2 CoW snapshot LV name @@ -518,14 +537,26 @@ def _run( in ``self._env``. """ kwargs["env"] = self._env | kwargs["env"] if "env" in kwargs else self._env - return run( - *popenargs, - input=input, - capture_output=capture_output, - timeout=timeout, - check=check, - **kwargs, - ) + cmd_str = shlex_join(popenargs[0]) + _log_debug_lvm2("lvm2: %s", cmd_str) + try: + result = run( + *popenargs, + input=input, + capture_output=capture_output, + timeout=timeout, + check=check, + **kwargs, + ) + except CalledProcessError as err: + err_msg = err.stderr.decode("utf8").strip() if err.stderr else "" + _log_debug_lvm2("lvm2: %s failed: %s", cmd_str, err_msg) + if not get_debug_mask() & SNAPM_DEBUG_LVM2: + _log_debug_lvm2_err("lvm2: %s failed: %s", cmd_str, err_msg) + raise + if capture_output and result.stdout: + _log_debug_lvm2("lvm2: output: %s", result.stdout.decode("utf8").strip()) + return result def _is_lvm_device(self, device): """ diff --git a/tests/test_command.py b/tests/test_command.py index 4319ecd3..1a9e6fdf 100644 --- a/tests/test_command.py +++ b/tests/test_command.py @@ -206,7 +206,7 @@ def test_set_debug_list(self): from snapm import get_debug_mask, SNAPM_DEBUG_ALL args = MockArgs() - args.debug = "manager,command,report,schedule,mounts,fsdiff,plugin" + args.debug = "manager,command,report,schedule,mounts,fsdiff,plugin,lvm2,lvm2err" command.set_debug(args.debug) self.assertEqual(get_debug_mask(), SNAPM_DEBUG_ALL)