From 2ae5f896cb4832a768a58deb064da77d0da515e3 Mon Sep 17 00:00:00 2001
From: Doug Hellmann <doug@doughellmann.com>
Date: Thu, 7 Nov 2024 14:31:11 -0500
Subject: [PATCH] improve formatting of dependency chains during bootstrapping

Format the dependency chain so it is easier to read. Update the way
exceptions and log messages are written. Log the chain at the start
of the build process.

Addresses #498
---
 src/fromager/bootstrapper.py | 19 ++++++++++++-------
 tests/test_bootstrapper.py   | 18 ++++++++++++++++++
 2 files changed, 30 insertions(+), 7 deletions(-)

diff --git a/src/fromager/bootstrapper.py b/src/fromager/bootstrapper.py
index b18ae8d8..5489c69c 100644
--- a/src/fromager/bootstrapper.py
+++ b/src/fromager/bootstrapper.py
@@ -83,7 +83,7 @@ def bootstrap(self, req: Requirement, req_type: RequirementType) -> Version:
         # Avoid cyclic dependencies and redundant processing.
         if self._has_been_seen(req, resolved_version):
             logger.debug(
-                f"{req.name}: redundant {req_type} requirement {self.why} -> {req} resolves to {resolved_version}"
+                f"{req.name}: redundant {req_type} dependency {req} ({resolved_version}) for {self._explain}"
             )
             return resolved_version
         self._mark_as_seen(req, resolved_version)
@@ -133,9 +133,7 @@ def bootstrap(self, req: Requirement, req_type: RequirementType) -> Version:
             try:
                 self.bootstrap(dep, RequirementType.INSTALL)
             except Exception as err:
-                raise ValueError(
-                    f"could not handle {RequirementType.INSTALL} dependency {dep} for {self.why}"
-                ) from err
+                raise ValueError(f"could not handle {self._explain}") from err
             self.progressbar.update()
 
         # we are done processing this req, so lets remove it from the why chain
@@ -143,6 +141,14 @@ def bootstrap(self, req: Requirement, req_type: RequirementType) -> Version:
         self._cleanup(req, sdist_root_dir, build_env)
         return resolved_version
 
+    @property
+    def _explain(self) -> str:
+        """Return message formatting current version of why stack."""
+        return " for ".join(
+            f"{req_type} dependency {req} ({resolved_version})"
+            for req_type, req, resolved_version in reversed(self.why)
+        )
+
     def _is_wheel_built(
         self, req: Requirement, resolved_version: Version
     ) -> pathlib.Path | None:
@@ -194,6 +200,7 @@ def _build(
         except Exception as err:
             logger.warning(f"{req.name}: failed to build source distribution: {err}")
 
+        logger.info(f"{req.name}: starting build of {self._explain}")
         built_filename = wheels.build_wheel(
             ctx=self.ctx,
             req=req,
@@ -262,9 +269,7 @@ def _handle_build_requirements(
             try:
                 resolved = self.bootstrap(req=dep, req_type=build_type)
             except Exception as err:
-                raise ValueError(
-                    f"could not handle {build_type} dependency {dep} for {self.why}"
-                ) from err
+                raise ValueError(f"could not handle {self._explain}") from err
             # We may need these dependencies installed in order to run build hooks
             # Example: frozenlist build-system.requires includes expandvars because
             # it is used by the packaging/pep517_backend/ build backend
diff --git a/tests/test_bootstrapper.py b/tests/test_bootstrapper.py
index 3f4ae56c..777b711f 100644
--- a/tests/test_bootstrapper.py
+++ b/tests/test_bootstrapper.py
@@ -361,3 +361,21 @@ def test_build_order_name_canonicalization(tmp_context):
         },
     ]
     assert expected == contents
+
+
+def test_explain(tmp_context: WorkContext):
+    bt = bootstrapper.Bootstrapper(tmp_context, None, old_graph)
+    bt.why = [(RequirementType.TOP_LEVEL, Requirement("foo"), Version("1.0.0"))]
+    assert bt._explain == f"{RequirementType.TOP_LEVEL} dependency foo (1.0.0)"
+
+    bt.why = []
+    assert bt._explain == ""
+
+    bt.why = [
+        (RequirementType.TOP_LEVEL, Requirement("foo"), Version("1.0.0")),
+        (RequirementType.BUILD, Requirement("bar==4.0.0"), Version("4.0.0")),
+    ]
+    assert (
+        bt._explain
+        == f"{RequirementType.BUILD} dependency bar==4.0.0 (4.0.0) for {RequirementType.TOP_LEVEL} dependency foo (1.0.0)"
+    )