From 38ce4a868ac5eeb017833b4f3f9fcd10cde90fad Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Milo=C5=A1=20Prchl=C3=ADk?= <mprchlik@redhat.com>
Date: Fri, 28 Jul 2023 13:53:47 +0200
Subject: [PATCH] Add logging of applied adjust rules

---
 pyproject.toml |  2 +-
 tmt/base.py    | 50 ++++++++++++++++++++++++++++++++++++++++++++++++--
 tmt/log.py     |  1 +
 3 files changed, 50 insertions(+), 3 deletions(-)

diff --git a/pyproject.toml b/pyproject.toml
index c8bd6b4f39..0d46827b3d 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -31,7 +31,7 @@ classifiers = [
     ]
 dependencies = [              # F39 / PyPI
     "click>=8.0.3,!=8.1.4",   # 8.1.3 / 8.1.6 TODO type annotations tmt.cli.Context -> click.core.Context click/issues/2558
-    "fmf>=1.2.1",
+    "fmf>=1.3.0",
     "jinja2>=2.11.3",         # 3.1.2 / 3.1.2
     "pint>=0.16.1",           # 0.16.1 / 0.22
     "requests>=2.25.1",       # 2.28.2 / 2.31.0
diff --git a/tmt/base.py b/tmt/base.py
index 040deae28f..aa402ff159 100644
--- a/tmt/base.py
+++ b/tmt/base.py
@@ -335,6 +335,46 @@ def _export(
     )
 
 
+def create_adjust_callback(logger: tmt.log.Logger) -> fmf.base.AdjustCallback:
+    """
+    Create a custom callback for fmf's adjust.
+
+    Given the ``adjust`` rules are applied on many places, for
+    proper logging they need their own specific logger. Create
+    a callback closure with the given logger.
+    """
+
+    def callback(
+            node: fmf.Tree,
+            rule: _RawAdjustRule,
+            applied: Optional[bool]) -> None:
+        if applied is None:
+            logger.verbose(
+                f"Adjust rule skipped on '{node.name}'",
+                tmt.utils.format_value(rule, key_color='cyan'),
+                color='blue',
+                level=3,
+                topic=tmt.log.Topic.ADJUST_DECISIONS)
+
+        elif applied is False:
+            logger.verbose(
+                f"Adjust rule not applied to '{node.name}'",
+                tmt.utils.format_value(rule, key_color='cyan'),
+                color='red',
+                level=3,
+                topic=tmt.log.Topic.ADJUST_DECISIONS)
+
+        else:
+            logger.verbose(
+                f"Adjust rule applied to '{node.name}'",
+                tmt.utils.format_value(rule, key_color='cyan'),
+                color='green',
+                level=3,
+                topic=tmt.log.Topic.ADJUST_DECISIONS)
+
+    return callback
+
+
 # Types describing content accepted by various require-like keys: strings, fmf ids,
 # paths, or lists mixing various types.
 #
@@ -2628,7 +2668,10 @@ def tree(self) -> fmf.Tree:
             except fmf.utils.FileError as error:
                 raise tmt.utils.GeneralError(f"Invalid yaml syntax: {error}")
             # Adjust metadata for current fmf context
-            self._tree.adjust(fmf.context.Context(**self._fmf_context), case_sensitive=False)
+            self._tree.adjust(
+                fmf.context.Context(**self._fmf_context),
+                case_sensitive=False,
+                decision_callback=create_adjust_callback(self._logger))
         return self._tree
 
     @tree.setter
@@ -3931,7 +3974,10 @@ def resolve_dynamic_ref(
     reference_tree = fmf.Tree(data=data)
     if not plan:
         raise tmt.utils.FileError("Cannot get plan fmf context to evaluate dynamic ref.")
-    reference_tree.adjust(fmf.context.Context(**plan._fmf_context), case_sensitive=False)
+    reference_tree.adjust(
+        fmf.context.Context(**plan._fmf_context),
+        case_sensitive=False,
+        decision_callback=create_adjust_callback(logger))
     # Also temporarily build a plan so that env and context variables are expanded
     Plan(logger=logger, node=reference_tree, run=plan.my_run, skip_validation=True)
     ref = reference_tree.get("ref")
diff --git a/tmt/log.py b/tmt/log.py
index b62ea3a329..ae294159cc 100644
--- a/tmt/log.py
+++ b/tmt/log.py
@@ -64,6 +64,7 @@ class Topic(enum.Enum):
     KEY_NORMALIZATION = 'key-normalization'
     CLI_INVOCATIONS = 'cli-invocations'
     COMMAND_EVENTS = 'command-events'
+    ADJUST_DECISIONS = 'adjust-decisions'
 
 
 DEFAULT_TOPICS: Set[Topic] = set()