Change log level for rules and filesystem intrinsics to trace (#10639)

Currently, `-ldebug` is not very helpful because it is so noisy. It includes messages like `[DEBUG] Completed: Fingerprinting: src/python/pants/util/logging.py` for every single file that's fingerprinted, and `[DEBUG] Completed: pants.engine.internals.build_files.strip_address_origins` hundreds of times becaue we strip source roots for every file.

While this information could indeed be useful, this is why we have `-ltrace`. `-ltrace` is when we need an extremely granular view of everything that Pants is doing. `-ldebug` meanwhile is meant for slightly higher-level messages like `[DEBUG] File handle limit is: 20000` or `[DEBUG] pants.bin.remote_pants_runner:pid=63445: connecting to pantsd on port 64613 (attempt 1/3)`.

[ci skip-build-wheels]

src/python/pants/backend/awslambda/python/awslambda_python_rules.py

@@ -31,6 +31,7 @@
 from pants.engine.process import ProcessResult
 from pants.engine.rules import Get, collect_rules, rule
 from pants.engine.unions import UnionRule
+from pants.util.logging import LogLevel
 
 
 @dataclass(frozen=True)
@@ -46,7 +47,7 @@ class LambdexSetup:
     requirements_pex: Pex
 
 
-@rule(desc="Create Python AWS Lambda")
+@rule(desc="Create Python AWS Lambda", level=LogLevel.DEBUG)
 async def create_python_awslambda(
     field_set: PythonAwsLambdaFieldSet, lambdex_setup: LambdexSetup
 ) -> CreatedAWSLambda:

src/python/pants/backend/codegen/protobuf/python/rules.py

@@ -25,7 +25,7 @@ class GeneratePythonFromProtobufRequest(GenerateSourcesRequest):
     output = PythonSources
 
 
-@rule(desc="Generate Python from Protobuf")
+@rule(desc="Generate Python from Protobuf", level=LogLevel.DEBUG)
 async def generate_python_from_protobuf(
     request: GeneratePythonFromProtobufRequest, protoc: Protoc
 ) -> GeneratedSources:
@@ -40,7 +40,7 @@ async def generate_python_from_protobuf(
         Process(
             ("/bin/mkdir", output_dir),
             description=f"Create the directory {output_dir}",
-            level=LogLevel.DEBUG,
+            level=LogLevel.TRACE,
             output_directories=(output_dir,),
         ),
     )

src/python/pants/backend/project_info/dependees.py

@@ -15,6 +15,7 @@
 from pants.engine.rules import Get, MultiGet, collect_rules, goal_rule, rule
 from pants.engine.target import Dependencies, DependenciesRequest, Targets, UnexpandedTargets
 from pants.util.frozendict import FrozenDict
+from pants.util.logging import LogLevel
 from pants.util.meta import frozen_after_init
 from pants.util.ordered_set import FrozenOrderedSet
 
@@ -24,7 +25,7 @@ class AddressToDependees:
     mapping: FrozenDict[Address, FrozenOrderedSet[Address]]
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def map_addresses_to_dependees() -> AddressToDependees:
     # Get every target in the project so that we can iterate over them to find their dependencies.
     all_expanded_targets, all_explicit_targets = await MultiGet(
@@ -66,7 +67,7 @@ class Dependees(DeduplicatedCollection[Address]):
     sort_input = True
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 def find_dependees(
     request: DependeesRequest, address_to_dependees: AddressToDependees
 ) -> Dependees:

src/python/pants/backend/python/dependency_inference/module_mapper.py

@@ -13,6 +13,7 @@
 from pants.engine.rules import Get, MultiGet, collect_rules, rule
 from pants.engine.target import Targets
 from pants.util.frozendict import FrozenDict
+from pants.util.logging import LogLevel
 
 
 @dataclass(frozen=True)
@@ -57,7 +58,7 @@ def address_for_module(self, module: str) -> Optional[Address]:
         return self.mapping.get(parent_module)
 
 
-@rule
+@rule(desc="Creating map of first party targets to Python modules", level=LogLevel.DEBUG)
 async def map_first_party_modules_to_addresses() -> FirstPartyModuleToAddressMapping:
     all_expanded_targets = await Get(Targets, AddressSpecs([DescendantAddresses("")]))
     candidate_targets = tuple(tgt for tgt in all_expanded_targets if tgt.has_field(PythonSources))
@@ -98,7 +99,7 @@ def address_for_module(self, module: str) -> Optional[Address]:
         return self.address_for_module(parent_module)
 
 
-@rule
+@rule(desc="Creating map of third party targets to Python modules", level=LogLevel.DEBUG)
 async def map_third_party_modules_to_addresses() -> ThirdPartyModuleToAddressMapping:
     all_targets = await Get(Targets, AddressSpecs([DescendantAddresses("")]))
     modules_to_addresses: Dict[str, Address] = {}

src/python/pants/backend/python/lint/bandit/rules.py

@@ -58,7 +58,7 @@ def generate_args(
     return tuple(args)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def bandit_lint_partition(
     partition: BanditPartition, bandit: Bandit, lint_subsystem: LintSubsystem
 ) -> LintResult:
@@ -133,7 +133,7 @@ async def bandit_lint_partition(
     )
 
 
-@rule(desc="Lint with Bandit")
+@rule(desc="Lint with Bandit", level=LogLevel.DEBUG)
 async def bandit_lint(
     request: BanditRequest, bandit: Bandit, python_setup: PythonSetup
 ) -> LintResults:

src/python/pants/backend/python/lint/black/rules.py

@@ -70,8 +70,8 @@ def generate_args(*, source_files: SourceFiles, black: Black, check_only: bool,)
     return tuple(args)
 
 
-@rule
-async def setup(setup_request: SetupRequest, black: Black) -> Setup:
+@rule(level=LogLevel.DEBUG)
+async def setup_black(setup_request: SetupRequest, black: Black) -> Setup:
     requirements_pex_request = Get(
         Pex,
         PexRequest(
@@ -127,7 +127,7 @@ async def setup(setup_request: SetupRequest, black: Black) -> Setup:
     return Setup(process, original_digest=source_files_snapshot.digest)
 
 
-@rule(desc="Format with Black")
+@rule(desc="Format with Black", level=LogLevel.DEBUG)
 async def black_fmt(field_sets: BlackRequest, black: Black) -> FmtResult:
     if black.skip:
         return FmtResult.skip(formatter_name="Black")
@@ -141,7 +141,7 @@ async def black_fmt(field_sets: BlackRequest, black: Black) -> FmtResult:
     )
 
 
-@rule(desc="Lint with Black")
+@rule(desc="Lint with Black", level=LogLevel.DEBUG)
 async def black_lint(field_sets: BlackRequest, black: Black) -> LintResults:
     if black.skip:
         return LintResults([], linter_name="Black")

src/python/pants/backend/python/lint/docformatter/rules.py

@@ -57,8 +57,8 @@ def generate_args(
     return ("--check" if check_only else "--in-place", *docformatter.args, *source_files.files)
 
 
-@rule
-async def setup(setup_request: SetupRequest, docformatter: Docformatter) -> Setup:
+@rule(level=LogLevel.DEBUG)
+async def setup_docformatter(setup_request: SetupRequest, docformatter: Docformatter) -> Setup:
     requirements_pex_request = Get(
         Pex,
         PexRequest(
@@ -107,7 +107,7 @@ async def setup(setup_request: SetupRequest, docformatter: Docformatter) -> Setu
     return Setup(process, original_digest=source_files_snapshot.digest)
 
 
-@rule(desc="Format with docformatter")
+@rule(desc="Format with docformatter", level=LogLevel.DEBUG)
 async def docformatter_fmt(request: DocformatterRequest, docformatter: Docformatter) -> FmtResult:
     if docformatter.skip:
         return FmtResult.skip(formatter_name="Docformatter")
@@ -118,7 +118,7 @@ async def docformatter_fmt(request: DocformatterRequest, docformatter: Docformat
     )
 
 
-@rule(desc="Lint with docformatter")
+@rule(desc="Lint with docformatter", level=LogLevel.DEBUG)
 async def docformatter_lint(
     request: DocformatterRequest, docformatter: Docformatter
 ) -> LintResults:

src/python/pants/backend/python/lint/flake8/rules.py

@@ -58,7 +58,7 @@ def generate_args(
     return tuple(args)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def flake8_lint_partition(
     partition: Flake8Partition, flake8: Flake8, lint_subsystem: LintSubsystem
 ) -> LintResult:
@@ -134,7 +134,7 @@ async def flake8_lint_partition(
     )
 
 
-@rule(desc="Lint with Flake8")
+@rule(desc="Lint with Flake8", level=LogLevel.DEBUG)
 async def flake8_lint(
     request: Flake8Request, flake8: Flake8, python_setup: PythonSetup
 ) -> LintResults:

src/python/pants/backend/python/lint/isort/rules.py

@@ -68,8 +68,8 @@ def generate_args(*, source_files: SourceFiles, isort: Isort, check_only: bool)
     return tuple(args)
 
 
-@rule
-async def setup(setup_request: SetupRequest, isort: Isort) -> Setup:
+@rule(level=LogLevel.DEBUG)
+async def setup_isort(setup_request: SetupRequest, isort: Isort) -> Setup:
     requirements_pex_request = Get(
         Pex,
         PexRequest(
@@ -126,7 +126,7 @@ async def setup(setup_request: SetupRequest, isort: Isort) -> Setup:
     return Setup(process, original_digest=source_files_snapshot.digest)
 
 
-@rule(desc="Format with isort")
+@rule(desc="Format with isort", level=LogLevel.DEBUG)
 async def isort_fmt(request: IsortRequest, isort: Isort) -> FmtResult:
     if isort.skip:
         return FmtResult.skip(formatter_name="isort")
@@ -140,7 +140,7 @@ async def isort_fmt(request: IsortRequest, isort: Isort) -> FmtResult:
     )
 
 
-@rule(desc="Lint with isort")
+@rule(desc="Lint with isort", level=LogLevel.DEBUG)
 async def isort_lint(request: IsortRequest, isort: Isort) -> LintResults:
     if isort.skip:
         return LintResults([], linter_name="isort")

src/python/pants/backend/python/lint/pylint/rules.py

@@ -105,7 +105,7 @@ def generate_args(*, source_files: SourceFiles, pylint: Pylint) -> Tuple[str, ..
     return tuple(args)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def pylint_lint_partition(partition: PylintPartition, pylint: Pylint) -> LintResult:
     # We build one PEX with Pylint requirements and another with all direct 3rd-party dependencies.
     # Splitting this into two PEXes gives us finer-grained caching. We then merge via `--pex-path`.
@@ -238,7 +238,7 @@ async def pylint_lint_partition(partition: PylintPartition, pylint: Pylint) -> L
     )
 
 
-@rule(desc="Lint using Pylint")
+@rule(desc="Lint using Pylint", level=LogLevel.DEBUG)
 async def pylint_lint(
     request: PylintRequest, pylint: Pylint, python_setup: PythonSetup
 ) -> LintResults:

src/python/pants/backend/python/rules/coverage.py

@@ -41,6 +41,7 @@
 from pants.engine.target import TransitiveTargets
 from pants.engine.unions import UnionRule
 from pants.option.custom_types import file_option
+from pants.util.logging import LogLevel
 
 
 """
@@ -208,7 +209,7 @@ class MergedCoverageData:
     coverage_data: Digest
 
 
-@rule(desc="Merge Pytest coverage data")
+@rule(desc="Merge Pytest coverage data", level=LogLevel.DEBUG)
 async def merge_coverage_data(
     data_collection: PytestCoverageDataCollection, coverage_setup: CoverageSetup
 ) -> MergedCoverageData:
@@ -229,12 +230,13 @@ async def merge_coverage_data(
             input_digest=input_digest,
             output_files=(".coverage",),
             description=f"Merge {len(prefixes)} Pytest coverage reports.",
+            level=LogLevel.DEBUG,
         ),
     )
     return MergedCoverageData(result.output_digest)
 
 
-@rule(desc="Generate Pytest coverage reports")
+@rule(desc="Generate Pytest coverage reports", level=LogLevel.DEBUG)
 async def generate_coverage_reports(
     merged_coverage_data: MergedCoverageData,
     coverage_setup: CoverageSetup,
@@ -284,6 +286,7 @@ async def generate_coverage_reports(
                 output_directories=("htmlcov",) if report_type == CoverageReportType.HTML else None,
                 output_files=("coverage.xml",) if report_type == CoverageReportType.XML else None,
                 description=f"Generate Pytest {report_type.report_name} coverage report.",
+                level=LogLevel.DEBUG,
             )
         )
     results = await MultiGet(Get(ProcessResult, PexProcess, process) for process in pex_processes)

src/python/pants/backend/python/rules/create_python_binary.py

@@ -27,6 +27,7 @@
 from pants.engine.rules import Get, collect_rules, rule
 from pants.engine.target import HydratedSources, HydrateSourcesRequest
 from pants.engine.unions import UnionRule
+from pants.util.logging import LogLevel
 
 
 @dataclass(frozen=True)
@@ -63,7 +64,7 @@ def generate_additional_args(
         return tuple(args)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def create_python_binary(
     field_set: PythonBinaryFieldSet, python_binary_defaults: PythonBinaryDefaults
 ) -> CreatedBinary:

src/python/pants/backend/python/rules/pex.py

@@ -293,7 +293,7 @@ class TwoStepPex:
 logger = logging.getLogger(__name__)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def create_pex(
     request: PexRequest,
     python_setup: PythonSetup,
@@ -419,7 +419,7 @@ async def create_pex(
     )
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def two_step_create_pex(two_step_pex_request: TwoStepPexRequest) -> TwoStepPex:
     """Create a PEX in two steps: a requirements-only PEX and then a full PEX from it."""
     request = two_step_pex_request.pex_request

src/python/pants/backend/python/rules/pex_environment.py

@@ -126,7 +126,7 @@ def message(self) -> str:
         return f"Selected {self.bootstrap_python} to bootstrap PEXes with."
 
 
-@rule(desc="Find PEX Python")
+@rule(desc="Find PEX Python", level=LogLevel.DEBUG)
 async def find_pex_python(
     python_setup: PythonSetup,
     pex_runtime_environment: PexRuntimeEnvironment,

src/python/pants/backend/python/rules/pex_from_targets.py

@@ -36,6 +36,7 @@
 from pants.engine.rules import Get, RootRule, collect_rules, rule
 from pants.engine.target import TransitiveTargets
 from pants.python.python_setup import PythonSetup, ResolveAllConstraintsOption
+from pants.util.logging import LogLevel
 from pants.util.meta import frozen_after_init
 
 logger = logging.getLogger(__name__)
@@ -152,7 +153,7 @@ class TwoStepPexFromTargetsRequest:
     pex_from_targets_request: PexFromTargetsRequest
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def pex_from_targets(request: PexFromTargetsRequest, python_setup: PythonSetup) -> PexRequest:
     transitive_targets = await Get(TransitiveTargets, Addresses, request.addresses)
     all_targets = transitive_targets.closure

src/python/pants/backend/python/rules/pytest_runner.py

@@ -75,7 +75,7 @@ class TestTargetSetup:
     __test__ = False
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def setup_pytest_for_target(
     field_set: PythonTestFieldSet,
     pytest: PyTest,
@@ -204,7 +204,7 @@ async def setup_pytest_for_target(
 
 # TODO(#10618): Once this is fixed, move `TestTargetSetup` into an `await Get` so that we only set
 #  up the test if it isn't skipped.
-@rule(desc="Run Pytest")
+@rule(desc="Run Pytest", level=LogLevel.DEBUG)
 async def run_python_test(
     field_set: PythonTestFieldSet,
     setup: TestTargetSetup,
@@ -289,7 +289,7 @@ async def run_python_test(
     )
 
 
-@rule(desc="Set up Pytest to run interactively")
+@rule(desc="Set up Pytest to run interactively", level=LogLevel.DEBUG)
 def debug_python_test(field_set: PythonTestFieldSet, setup: TestTargetSetup) -> TestDebugRequest:
     if field_set.is_conftest():
         return TestDebugRequest(None)

src/python/pants/backend/python/rules/python_sources.py

@@ -16,6 +16,7 @@
 from pants.engine.target import Sources, Target
 from pants.engine.unions import UnionMembership
 from pants.source.source_root import SourceRoot, SourceRootRequest
+from pants.util.logging import LogLevel
 from pants.util.meta import frozen_after_init
 
 
@@ -74,7 +75,7 @@ def valid_sources_types(self) -> Tuple[Type[Sources], ...]:
         return tuple(types)
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def prepare_python_sources(
     request: PythonSourceFilesRequest, union_membership: UnionMembership
 ) -> PythonSourceFiles:
@@ -111,7 +112,7 @@ async def prepare_python_sources(
     )
 
 
-@rule
+@rule(level=LogLevel.DEBUG)
 async def strip_python_sources(python_sources: PythonSourceFiles) -> StrippedPythonSourceFiles:
     stripped = await Get(StrippedSourceFiles, SourceFiles, python_sources.source_files)
     return StrippedPythonSourceFiles(stripped)