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

@@ -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,16 +133,22 @@ 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
         self.why.pop()
         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

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)"
+    )