From 2ae5f896cb4832a768a58deb064da77d0da515e3 Mon Sep 17 00:00:00 2001 From: Doug Hellmann Date: Thu, 7 Nov 2024 14:31:11 -0500 Subject: [PATCH 1/3] 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)" + ) From a3fa2a5fc70e72a5cae0ea62f142927051c534c2 Mon Sep 17 00:00:00 2001 From: Doug Hellmann Date: Thu, 7 Nov 2024 15:34:35 -0500 Subject: [PATCH 2/3] log override method return values at different verbosity levels Log return values from default functions at debug and real overrides at info. --- src/fromager/overrides.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) 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 From 6f55040f3019809199b39f3c19b362a89f16418f Mon Sep 17 00:00:00 2001 From: Doug Hellmann Date: Thu, 7 Nov 2024 15:35:12 -0500 Subject: [PATCH 3/3] format chained exceptions to include all of the messages When we get an exception chain with more than one member, include the messages from all of them. --- src/fromager/__main__.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) 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)