From 02ad5ddf0ec2905987dce8edc9fcf4c03905e95a Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Tue, 14 May 2019 13:21:20 -0700 Subject: [PATCH 1/6] Add logging for V2 test scheduler --- src/python/pants/rules/core/test.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/src/python/pants/rules/core/test.py b/src/python/pants/rules/core/test.py index c4ef4e51cf9..50379ca2dad 100644 --- a/src/python/pants/rules/core/test.py +++ b/src/python/pants/rules/core/test.py @@ -4,6 +4,8 @@ from __future__ import absolute_import, division, print_function, unicode_literals +import logging + from pants.backend.python.rules.python_test_runner import PyTestResult from pants.base.exiter import PANTS_FAILED_EXIT_CODE, PANTS_SUCCEEDED_EXIT_CODE from pants.build_graph.address import Address @@ -16,6 +18,10 @@ from pants.rules.core.core_test_model import Status, TestResult +# TODO(#6004): use proper Logging singleton, rather than static logger. +logger = logging.getLogger(__name__) + + class Test(Goal): """Runs tests.""" @@ -66,7 +72,12 @@ def coordinator_of_tests(target): #if isinstance(target.adaptor, PythonTestsAdaptor): # See https://github.com/pantsbuild/pants/issues/4535 if target.adaptor.type_alias == 'python_tests': + logger.info("Starting test for {}...".format(target.address.reference())) result = yield Get(PyTestResult, HydratedTarget, target) + logger.info("Result of test for {}: {}".format( + target.address.reference(), + "success" if result.status == Status.SUCCESS else "failure") + ) yield TestResult(status=result.status, stdout=result.stdout, stderr=result.stderr) else: raise Exception("Didn't know how to run tests for type {}".format(target.adaptor.type_alias)) From 81c78832e4050035ce7a401020e55b9d58b86a80 Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Tue, 14 May 2019 13:47:00 -0700 Subject: [PATCH 2/6] Tweak logging message --- src/python/pants/rules/core/test.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/python/pants/rules/core/test.py b/src/python/pants/rules/core/test.py index 50379ca2dad..f30b4f12c45 100644 --- a/src/python/pants/rules/core/test.py +++ b/src/python/pants/rules/core/test.py @@ -72,12 +72,12 @@ def coordinator_of_tests(target): #if isinstance(target.adaptor, PythonTestsAdaptor): # See https://github.com/pantsbuild/pants/issues/4535 if target.adaptor.type_alias == 'python_tests': - logger.info("Starting test for {}...".format(target.address.reference())) + logger.info("Starting tests for {}...".format(target.address.reference())) result = yield Get(PyTestResult, HydratedTarget, target) - logger.info("Result of test for {}: {}".format( + logger.info("Tests {}: {}".format( + "succeeded" if result.status == Status.SUCCESS else "failed", target.address.reference(), - "success" if result.status == Status.SUCCESS else "failure") - ) + )) yield TestResult(status=result.status, stdout=result.stdout, stderr=result.stderr) else: raise Exception("Didn't know how to run tests for type {}".format(target.adaptor.type_alias)) From 7f1b0fd480081f6321b7c1bc00250ed6de186e5e Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Tue, 14 May 2019 14:19:02 -0700 Subject: [PATCH 3/6] Fix tests by capturing logging --- tests/python/pants_test/rules/test_test.py | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/tests/python/pants_test/rules/test_test.py b/tests/python/pants_test/rules/test_test.py index 66a8f487a86..57b64dc7f2c 100644 --- a/tests/python/pants_test/rules/test_test.py +++ b/tests/python/pants_test/rules/test_test.py @@ -4,6 +4,7 @@ from __future__ import absolute_import, division, print_function, unicode_literals +import logging from builtins import str from textwrap import dedent @@ -104,17 +105,17 @@ def test_stderr(self): def test_coordinator_python_test(self): target_adaptor = PythonTestsAdaptor(type_alias='python_tests') - - result = run_rule(coordinator_of_tests, HydratedTarget(Address.parse("some/target"), target_adaptor, ()), { - (PyTestResult, HydratedTarget): lambda _: PyTestResult(status=Status.FAILURE, stdout='foo', stderr=''), - }) + with self.captured_logging(logging.INFO): + result = run_rule(coordinator_of_tests, HydratedTarget(Address.parse("some/target"), target_adaptor, ()), { + (PyTestResult, HydratedTarget): lambda _: PyTestResult(status=Status.FAILURE, stdout='foo', stderr=''), + }) self.assertEqual(result, TestResult(status=Status.FAILURE, stdout='foo', stderr='')) def test_coordinator_unknown_test(self): target_adaptor = PythonTestsAdaptor(type_alias='unknown_tests') - with self.assertRaises(Exception) as cm: + with self.captured_logging(logging.INFO), self.assertRaises(Exception) as cm: run_rule(coordinator_of_tests, HydratedTarget(Address.parse("some/target"), target_adaptor, ()), { (PyTestResult, HydratedTarget): lambda _: PyTestResult(status=Status.FAILURE, stdout='foo', stderr=''), }) From 863d99ebae357b6ad8832c00eb90fdc06671a7c0 Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Wed, 15 May 2019 01:18:42 -0700 Subject: [PATCH 4/6] Change starting tests log to be more symmetrical with result log --- src/python/pants/rules/core/test.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/python/pants/rules/core/test.py b/src/python/pants/rules/core/test.py index f30b4f12c45..7e095146e20 100644 --- a/src/python/pants/rules/core/test.py +++ b/src/python/pants/rules/core/test.py @@ -72,7 +72,7 @@ def coordinator_of_tests(target): #if isinstance(target.adaptor, PythonTestsAdaptor): # See https://github.com/pantsbuild/pants/issues/4535 if target.adaptor.type_alias == 'python_tests': - logger.info("Starting tests for {}...".format(target.address.reference())) + logger.info("Starting tests: {}".format(target.address.reference())) result = yield Get(PyTestResult, HydratedTarget, target) logger.info("Tests {}: {}".format( "succeeded" if result.status == Status.SUCCESS else "failed", From 20d4139a03b256daec967727f117da7b7b3b65b8 Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Wed, 15 May 2019 01:24:42 -0700 Subject: [PATCH 5/6] Fix failing integration tests --- .../pants_test/rules/test_test_integration.py | 27 +++++++------------ 1 file changed, 10 insertions(+), 17 deletions(-) diff --git a/tests/python/pants_test/rules/test_test_integration.py b/tests/python/pants_test/rules/test_test_integration.py index 2b5c14a9a0b..c3584fd8f33 100644 --- a/tests/python/pants_test/rules/test_test_integration.py +++ b/tests/python/pants_test/rules/test_test_integration.py @@ -11,7 +11,14 @@ class TestIntegrationTest(PantsRunIntegrationTest): - def run_pants(self, args): + def run_pants(self, trailing_args): + args = [ + '--no-v1', + '--v2', + '--no-colors', + '--level=warn', + 'test', + ] + trailing_args # Set TERM=dumb to stop pytest from trying to be clever and wrap lines which may interfere with # our golden data. return super(TestIntegrationTest, self).run_pants(args, extra_env={'TERM': 'dumb'}) @@ -33,26 +40,12 @@ def assert_fuzzy_string_match(self, got, want): self.assertTrue(got_line.endswith(want_parts[1]), 'Line {} Want "{}" to end with "{}"'.format(line_number, got_line, want_parts[1])) def run_passing_pants_test(self, trailing_args): - args = [ - '--no-v1', - '--v2', - '--no-colors', - 'test', - ] + trailing_args - - pants_run = self.run_pants(args) + pants_run = self.run_pants(trailing_args) self.assert_success(pants_run) return pants_run def run_failing_pants_test(self, trailing_args): - args = [ - '--no-v1', - '--v2', - '--no-colors', - 'test', - ] + trailing_args - - pants_run = self.run_pants(args) + pants_run = self.run_pants(trailing_args) self.assert_failure(pants_run) self.assertEqual('Tests failed\n', pants_run.stderr_data) From 27f4e2bd7835e020592024cdbfa9acb59a9f7790 Mon Sep 17 00:00:00 2001 From: Eric Arellano Date: Wed, 15 May 2019 08:28:12 -0700 Subject: [PATCH 6/6] Add TODO explaining this is a temporary pre-V2-UI workaround --- src/python/pants/rules/core/test.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/python/pants/rules/core/test.py b/src/python/pants/rules/core/test.py index 7e095146e20..e7900d651d5 100644 --- a/src/python/pants/rules/core/test.py +++ b/src/python/pants/rules/core/test.py @@ -72,6 +72,9 @@ def coordinator_of_tests(target): #if isinstance(target.adaptor, PythonTestsAdaptor): # See https://github.com/pantsbuild/pants/issues/4535 if target.adaptor.type_alias == 'python_tests': + # TODO(#6004): when streaming to live TTY, rely on V2 UI for this information. When not a + # live TTY, periodically dump heavy hitters to stderr. See + # https://github.com/pantsbuild/pants/issues/6004#issuecomment-492699898. logger.info("Starting tests: {}".format(target.address.reference())) result = yield Get(PyTestResult, HydratedTarget, target) logger.info("Tests {}: {}".format(