From 5da01a12a04c8a6d5fb68b3bda96109373c62292 Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Mon, 17 Aug 2020 10:27:09 -0700 Subject: [PATCH] Stream output of `test`, rather than dumping at the end [ci skip-rust] [ci skip-build-wheels] --- .../backend/python/rules/pytest_runner.py | 4 +- .../rules/pytest_runner_integration_test.py | 2 +- src/python/pants/core/goals/test.py | 84 +++++--- src/python/pants/core/goals/test_test.py | 179 ++++++++---------- 4 files changed, 136 insertions(+), 133 deletions(-) diff --git a/src/python/pants/backend/python/rules/pytest_runner.py b/src/python/pants/backend/python/rules/pytest_runner.py index 7cdc5382577..c8056acb68d 100644 --- a/src/python/pants/backend/python/rules/pytest_runner.py +++ b/src/python/pants/backend/python/rules/pytest_runner.py @@ -39,6 +39,7 @@ from pants.engine.unions import UnionRule from pants.option.global_options import GlobalOptions from pants.python.python_setup import PythonSetup +from pants.util.logging import LogLevel logger = logging.getLogger() @@ -253,6 +254,7 @@ async def run_python_test( timeout_seconds=setup.timeout_seconds, extra_env=env, execution_slot_variable=setup.execution_slot_variable, + level=LogLevel.DEBUG, ), ) @@ -287,7 +289,7 @@ async def run_python_test( ) -@rule(desc="Setup Pytest to run interactively") +@rule(desc="Set up Pytest to run interactively") def debug_python_test(field_set: PythonTestFieldSet, setup: TestTargetSetup) -> TestDebugRequest: if field_set.is_conftest(): return TestDebugRequest(None) diff --git a/src/python/pants/backend/python/rules/pytest_runner_integration_test.py b/src/python/pants/backend/python/rules/pytest_runner_integration_test.py index c666f0ef055..b10d32676bd 100644 --- a/src/python/pants/backend/python/rules/pytest_runner_integration_test.py +++ b/src/python/pants/backend/python/rules/pytest_runner_integration_test.py @@ -377,7 +377,7 @@ def test_conftest_handling(self) -> None: result = self.run_pytest( address=Address(self.source_root, relative_file_path="conftest.py") ) - assert result.skipped is True + assert result.exit_code is None def test_execution_slot_variable(self) -> None: source = FileContent( diff --git a/src/python/pants/core/goals/test.py b/src/python/pants/core/goals/test.py index 39c9d955b28..96e3b490f38 100644 --- a/src/python/pants/core/goals/test.py +++ b/src/python/pants/core/goals/test.py @@ -21,7 +21,7 @@ from pants.engine.fs import Digest, MergeDigests, Workspace from pants.engine.goal import Goal, GoalSubsystem from pants.engine.process import FallibleProcessResult, InteractiveProcess, InteractiveRunner -from pants.engine.rules import Get, MultiGet, collect_rules, goal_rule +from pants.engine.rules import Get, MultiGet, collect_rules, goal_rule, rule from pants.engine.target import ( FieldSet, Sources, @@ -54,7 +54,7 @@ def report_name(self) -> str: @dataclass(frozen=True) -class TestResult(EngineAware): +class TestResult: exit_code: Optional[int] stdout: str stderr: str @@ -87,6 +87,17 @@ def from_fallible_process_result( xml_results=xml_results, ) + +@dataclass(frozen=True) +class EnrichedTestResult(EngineAware): + exit_code: Optional[int] + stdout: str + stderr: str + address: Address + output_setting: "ShowOutput" + coverage_data: Optional["CoverageData"] = None + xml_results: Optional[Digest] = None + @property def skipped(self) -> bool: return ( @@ -102,14 +113,28 @@ def artifacts(self) -> Optional[Dict[str, Digest]]: return None return {"xml_results_digest": self.xml_results} - def level(self): - if self.exit_code != 0: - return LogLevel.ERROR - return None - - def message(self): - result = "succeeded" if self.exit_code == 0 else f"failed (exit code {self.exit_code})" - return f"tests {result}: {self.address}" + def level(self) -> LogLevel: + if self.skipped: + return LogLevel.DEBUG + return LogLevel.INFO if self.exit_code == 0 else LogLevel.WARN + + def message(self) -> str: + if self.skipped: + return f"{self.address} skipped." + status = "succeeded" if self.exit_code == 0 else f"failed (exit code {self.exit_code})" + message = f"{self.address} {status}." + if self.output_setting == ShowOutput.NONE or ( + self.output_setting == ShowOutput.FAILED and self.exit_code == 0 + ): + return message + output = "" + if self.stdout: + output += f"\n{self.stdout}" + if self.stderr: + output += f"\n{self.stderr}" + if output: + output = f"{output.rstrip()}\n\n" + return f"{message}{output}" @dataclass(frozen=True) @@ -343,31 +368,13 @@ async def run_tests( ) results = await MultiGet( - Get(TestResult, TestFieldSet, field_set) for field_set in field_sets_with_sources + Get(EnrichedTestResult, TestFieldSet, field_set) for field_set in field_sets_with_sources ) - # Print details. - for result in results: - if result.skipped: - continue - if test_subsystem.options.output == ShowOutput.NONE or ( - test_subsystem.options.output == ShowOutput.FAILED and result.exit_code == 0 - ): - continue - has_output = result.stdout or result.stderr - if has_output: - status = console.green("✓") if result.exit_code == 0 else console.red("𐄂") - console.print_stderr(f"{status} {result.address}") - if result.stdout: - console.print_stderr(result.stdout) - if result.stderr: - console.print_stderr(result.stderr) - if has_output and result != results[-1]: - console.print_stderr("") - # Print summary exit_code = 0 - console.print_stderr("") + if results: + console.print_stderr("") for result in results: if result.skipped: continue @@ -418,5 +425,20 @@ async def run_tests( return Test(exit_code) +@rule(desc="Run tests") +def enrich_test_result( + test_result: TestResult, test_subsystem: TestSubsystem +) -> EnrichedTestResult: + return EnrichedTestResult( + exit_code=test_result.exit_code, + stdout=test_result.stdout, + stderr=test_result.stderr, + address=test_result.address, + coverage_data=test_result.coverage_data, + xml_results=test_result.xml_results, + output_setting=test_subsystem.output, + ) + + def rules(): return collect_rules() diff --git a/src/python/pants/core/goals/test_test.py b/src/python/pants/core/goals/test_test.py index b9ee9e66e21..a1da4fe25b5 100644 --- a/src/python/pants/core/goals/test_test.py +++ b/src/python/pants/core/goals/test_test.py @@ -3,6 +3,7 @@ from abc import ABCMeta, abstractmethod from dataclasses import dataclass +from functools import partial from textwrap import dedent from typing import List, Optional, Tuple, Type @@ -12,11 +13,11 @@ CoverageData, CoverageDataCollection, CoverageReports, + EnrichedTestResult, ShowOutput, Test, TestDebugRequest, TestFieldSet, - TestResult, TestSubsystem, run_tests, ) @@ -37,6 +38,7 @@ from pants.engine.unions import UnionMembership from pants.testutil.engine.util import MockConsole, MockGet, create_goal_subsystem, run_rule from pants.testutil.test_base import TestBase +from pants.util.logging import LogLevel class MockTarget(Target): @@ -61,23 +63,15 @@ class MockTestFieldSet(TestFieldSet, metaclass=ABCMeta): def exit_code(_: Address) -> int: pass - @staticmethod - def stdout(_: Address) -> str: - return "" - - @staticmethod - def stderr(_: Address) -> str: - return "" - @property - def test_result(self) -> TestResult: - return TestResult( + def test_result(self) -> EnrichedTestResult: + return EnrichedTestResult( exit_code=self.exit_code(self.address), - stdout=self.stdout(self.address), - stderr=self.stderr(self.address), + stdout="", + stderr="", address=self.address, coverage_data=MockCoverageData(self.address), - xml_results=None, + output_setting=ShowOutput.ALL, ) @@ -86,32 +80,12 @@ class SuccessfulFieldSet(MockTestFieldSet): def exit_code(_: Address) -> int: return 0 - @staticmethod - def stdout(address: Address) -> str: - return f"Successful test target: Passed for {address}!" - class ConditionallySucceedsFieldSet(MockTestFieldSet): @staticmethod def exit_code(address: Address) -> int: return 27 if address.target_name == "bad" else 0 - @staticmethod - def stdout(address: Address) -> str: - return ( - f"Conditionally succeeds test target: Passed for {address}!" - if address.target_name != "bad" - else "" - ) - - @staticmethod - def stderr(address: Address) -> str: - return ( - f"Conditionally succeeds test target: Had an issue for {address}! Oh no!" - if address.target_name == "bad" - else "" - ) - class TestTest(TestBase): def make_interactive_process(self) -> InteractiveProcess: @@ -181,7 +155,7 @@ def mock_coverage_report_generation( mock=mock_find_valid_field_sets, ), MockGet( - product_type=TestResult, + product_type=EnrichedTestResult, subject_type=TestFieldSet, mock=lambda fs: fs.test_result, ), @@ -230,70 +204,7 @@ def test_invalid_target_noops(self) -> None: assert exit_code == 0 assert stderr.strip() == "" - def test_single_target(self) -> None: - address = Address.parse(":tests") - exit_code, stderr = self.run_test_rule( - field_set=SuccessfulFieldSet, targets=[self.make_target_with_origin(address)] - ) - assert exit_code == 0 - assert stderr == dedent( - f"""\ - ✓ {address} - {SuccessfulFieldSet.stdout(address)} - - {address} ..... SUCCESS - """ - ) - - def test_multiple_targets(self) -> None: - good_address = Address.parse(":good") - bad_address = Address.parse(":bad") - - exit_code, stderr = self.run_test_rule( - field_set=ConditionallySucceedsFieldSet, - targets=[ - self.make_target_with_origin(good_address), - self.make_target_with_origin(bad_address), - ], - ) - assert exit_code == ConditionallySucceedsFieldSet.exit_code(bad_address) - assert stderr == dedent( - f"""\ - ✓ {good_address} - {ConditionallySucceedsFieldSet.stdout(good_address)} - - 𐄂 {bad_address} - {ConditionallySucceedsFieldSet.stderr(bad_address)} - - {good_address} ..... SUCCESS - {bad_address} ..... FAILURE - """ - ) - - def test_output_failed(self) -> None: - good_address = Address.parse(":good") - bad_address = Address.parse(":bad") - - exit_code, stderr = self.run_test_rule( - field_set=ConditionallySucceedsFieldSet, - targets=[ - self.make_target_with_origin(good_address), - self.make_target_with_origin(bad_address), - ], - output=ShowOutput.FAILED, - ) - assert exit_code == ConditionallySucceedsFieldSet.exit_code(bad_address) - assert stderr == dedent( - f"""\ - 𐄂 {bad_address} - {ConditionallySucceedsFieldSet.stderr(bad_address)} - - {good_address} ..... SUCCESS - {bad_address} ..... FAILURE - """ - ) - - def test_output_none(self) -> None: + def test_summary(self) -> None: good_address = Address.parse(":good") bad_address = Address.parse(":bad") @@ -303,7 +214,6 @@ def test_output_none(self) -> None: self.make_target_with_origin(good_address), self.make_target_with_origin(bad_address), ], - output=ShowOutput.NONE, ) assert exit_code == ConditionallySucceedsFieldSet.exit_code(bad_address) assert stderr == dedent( @@ -330,3 +240,72 @@ def test_coverage(self) -> None: ) assert exit_code == 0 assert stderr.strip().endswith(f"Ran coverage on {addr1.spec}, {addr2.spec}") + + +def assert_streaming_output( + *, + exit_code: Optional[int], + stdout: str = "stdout", + stderr: str = "stderr", + output_setting: ShowOutput = ShowOutput.ALL, + expected_level: LogLevel, + expected_message: str, +) -> None: + result = EnrichedTestResult( + exit_code=exit_code, + stdout=stdout, + stderr=stderr, + output_setting=output_setting, + address=Address("demo_test"), + ) + assert result.level() == expected_level + assert result.message() == expected_message + + +def test_streaming_output_skip() -> None: + assert_streaming_output( + exit_code=None, + stdout="", + stderr="", + expected_level=LogLevel.DEBUG, + expected_message="demo_test skipped.", + ) + + +def test_streaming_output_success() -> None: + assert_success_streamed = partial( + assert_streaming_output, exit_code=0, expected_level=LogLevel.INFO + ) + assert_success_streamed( + expected_message=dedent( + """\ + demo_test succeeded. + stdout + stderr + + """ + ), + ) + assert_success_streamed( + output_setting=ShowOutput.FAILED, expected_message="demo_test succeeded." + ) + assert_success_streamed(output_setting=ShowOutput.NONE, expected_message="demo_test succeeded.") + + +def test_streaming_output_failure() -> None: + assert_failure_streamed = partial( + assert_streaming_output, exit_code=1, expected_level=LogLevel.WARN + ) + message = dedent( + """\ + demo_test failed (exit code 1). + stdout + stderr + + """ + ) + assert_failure_streamed(expected_message=message) + assert_failure_streamed(output_setting=ShowOutput.FAILED, expected_message=message) + assert_failure_streamed( + output_setting=ShowOutput.NONE, expected_message="demo_test failed (exit code 1)." + )