diff --git a/src/fromager/__main__.py b/src/fromager/__main__.py index e4afffd9..2363fdbc 100644 --- a/src/fromager/__main__.py +++ b/src/fromager/__main__.py @@ -238,6 +238,13 @@ def main( main.add_command(cmd) +def _format_exception(exc): + if exc.__cause__: + cause = _format_exception(exc.__cause__) + return f"{exc} because {cause}" + return str(exc) + + def invoke_main() -> None: # Wrapper for the click main command that ensures any exceptions # are logged so that build pipeline outputs include the traceback. @@ -248,7 +255,7 @@ def invoke_main() -> None: err, exc_info=True, ) # log the full traceback details to the debug log file, if any - logger.error(f"ERROR: {err}") + logger.error(f"ERROR: {_format_exception(err)}") if _DEBUG: raise sys.exit(1) 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/src/fromager/overrides.py b/src/fromager/overrides.py index a6b8165f..8a83b17f 100644 --- a/src/fromager/overrides.py +++ b/src/fromager/overrides.py @@ -50,7 +50,12 @@ def find_and_invoke( fn = default_fn result = invoke(fn, **kwargs) - logger.info(f"{distname}: override method {fn.__name__} returned {result}") + if fn is default_fn: + log_method = logger.debug + else: + log_method = logger.info + log_method(f"{distname}: override method {fn.__name__} returned {result}") + return result 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)" + )