From 800355ec2f2eb5a611af0d54841da33d517853f3 Mon Sep 17 00:00:00 2001 From: Drew Banin Date: Sat, 3 Aug 2019 12:33:56 -0400 Subject: [PATCH] (#1597) summarize warnings at end of test invocations --- core/dbt/compilation.py | 18 +++--- core/dbt/contracts/results.py | 16 +++-- core/dbt/node_runners.py | 16 ++++- core/dbt/ui/printer.py | 58 ++++++++++++------- core/dbt/utils.py | 7 +++ .../test_docs_generate.py | 8 +++ .../045_test_severity_tests/test_severity.py | 9 +++ 7 files changed, 96 insertions(+), 36 deletions(-) diff --git a/core/dbt/compilation.py b/core/dbt/compilation.py index 0ab041948a1..3f0dce9afe4 100644 --- a/core/dbt/compilation.py +++ b/core/dbt/compilation.py @@ -25,21 +25,21 @@ def print_compile_stats(stats): names = { - NodeType.Model: 'models', - NodeType.Test: 'tests', - NodeType.Snapshot: 'snapshots', - NodeType.Analysis: 'analyses', - NodeType.Macro: 'macros', - NodeType.Operation: 'operations', - NodeType.Seed: 'seed files', - NodeType.Source: 'sources', + NodeType.Model: 'model', + NodeType.Test: 'test', + NodeType.Snapshot: 'snapshot', + NodeType.Analysis: 'analyse', + NodeType.Macro: 'macro', + NodeType.Operation: 'operation', + NodeType.Seed: 'seed file', + NodeType.Source: 'source', } results = {k: 0 for k in names.keys()} results.update(stats) stat_line = ", ".join( - ["{} {}".format(ct, names.get(t)) for t, ct in results.items()]) + [dbt.utils.pluralize(ct, names.get(t)) for t, ct in results.items()]) logger.notice("Found {}".format(stat_line)) diff --git a/core/dbt/contracts/results.py b/core/dbt/contracts/results.py index e43cc8eb56e..71841ea9364 100644 --- a/core/dbt/contracts/results.py +++ b/core/dbt/contracts/results.py @@ -130,14 +130,16 @@ def failed(self): 'type': 'boolean', 'description': 'True if this node was skipped', }, - # This is assigned by dbt.ui.printer.print_test_result_line, if a test - # has no error and a non-zero status + 'warn': { + 'type': ['boolean', 'null'], + 'description': 'True if this node succeeded with a warning', + }, 'fail': { 'type': ['boolean', 'null'], 'description': 'On tests, true if the test failed', }, }, - 'required': ['skip', 'fail'] + 'required': ['skip', 'fail', 'warn'] }) @@ -145,7 +147,7 @@ class RunModelResult(NodeSerializable): SCHEMA = RUN_MODEL_RESULT_CONTRACT def __init__(self, node, error=None, skip=False, status=None, failed=None, - thread_id=None, timing=None, execution_time=0): + warned=None, thread_id=None, timing=None, execution_time=0): if timing is None: timing = [] super(RunModelResult, self).__init__( @@ -154,6 +156,7 @@ def __init__(self, node, error=None, skip=False, status=None, failed=None, skip=skip, status=status, fail=failed, + warn=warned, execution_time=execution_time, thread_id=thread_id, timing=timing, @@ -163,6 +166,7 @@ def __init__(self, node, error=None, skip=False, status=None, failed=None, error = named_property('error', 'If there was an error, the text of that error') skip = named_property('skip', 'True if the model was skipped') + warn = named_property('warn', 'True if this was a test and it warned') fail = named_property('fail', 'True if this was a test and it failed') status = named_property('status', 'The status of the model execution') execution_time = named_property('execution_time', @@ -180,6 +184,10 @@ def __init__(self, node, error=None, skip=False, status=None, failed=None, def failed(self): return self.fail + @property + def warned(self): + return self.warn + @property def skipped(self): return self.skip diff --git a/core/dbt/node_runners.py b/core/dbt/node_runners.py index a467a5aa24a..4819e4bfdfc 100644 --- a/core/dbt/node_runners.py +++ b/core/dbt/node_runners.py @@ -11,6 +11,7 @@ import dbt.utils import dbt.tracking import dbt.ui.printer +import dbt.flags from dbt import rpc import threading @@ -77,7 +78,7 @@ def run_with_hooks(self, manifest): return result def _build_run_result(self, node, start_time, error, status, timing_info, - skip=False, failed=None): + skip=False, failed=None, warn=None): execution_time = time.time() - start_time thread_id = threading.current_thread().name timing = [t.serialize() for t in timing_info] @@ -87,6 +88,7 @@ def _build_run_result(self, node, start_time, error, status, timing_info, skip=skip, status=status, failed=failed, + warned=warn, execution_time=execution_time, thread_id=thread_id, timing=timing @@ -118,6 +120,7 @@ def from_run_result(self, result, start_time, timing_info): skip=result.skip, status=result.status, failed=result.failed, + warn=result.warned, timing_info=timing_info ) @@ -478,8 +481,15 @@ def before_execute(self): self.print_start_line() def execute(self, test, manifest): - status = self.execute_test(test) - return RunModelResult(test, status=status) + failed_rows = self.execute_test(test) + severity = test.config['severity'].upper() + + if failed_rows == 0: + return RunModelResult(test, status=failed_rows) + elif severity == 'ERROR' or dbt.flags.WARN_ERROR: + return RunModelResult(test, status=failed_rows, failed=True) + else: + return RunModelResult(test, status=failed_rows, warned=True) def after_execute(self, result): self.print_result_line(result) diff --git a/core/dbt/ui/printer.py b/core/dbt/ui/printer.py index cd9c4b8f2d3..e832b937cf0 100644 --- a/core/dbt/ui/printer.py +++ b/core/dbt/ui/printer.py @@ -100,7 +100,7 @@ def get_counts(flat_nodes): counts[t] = counts.get(t, 0) + 1 stat_line = ", ".join( - ["{} {}s".format(v, k) for k, v in counts.items()]) + [dbt.utils.pluralize(v, k) for k, v in counts.items()]) return stat_line @@ -145,25 +145,23 @@ def get_printable_result(result, success, error): def print_test_result_line(result, schema_name, index, total): model = result.node - info = 'PASS' if result.error is not None: info = "ERROR" color = red - elif result.status > 0: - severity = result.node.config['severity'].upper() - if severity == 'ERROR' or dbt.flags.WARN_ERROR: - info = 'FAIL {}'.format(result.status) - color = red - result.fail = True - else: - info = 'WARN {}'.format(result.status) - color = yellow elif result.status == 0: info = 'PASS' color = green + elif result.warn: + info = 'WARN {}'.format(result.status) + color = yellow + + elif result.fail: + info = 'FAIL {}'.format(result.status) + color = red + else: raise RuntimeError("unexpected status: {}".format(result.status)) @@ -259,6 +257,8 @@ def interpret_run_result(result): return 'error' elif result.skipped: return 'skip' + elif result.warned: + return 'warn' else: return 'pass' @@ -268,6 +268,7 @@ def print_run_status_line(results): 'error': 0, 'skip': 0, 'pass': 0, + 'warn': 0, 'total': 0, } @@ -276,20 +277,28 @@ def print_run_status_line(results): stats[result_type] += 1 stats['total'] += 1 - stats_line = "\nDone. PASS={pass} ERROR={error} SKIP={skip} TOTAL={total}" + stats_line = "\nDone. PASS={pass} WARN={warn} ERROR={error} SKIP={skip} TOTAL={total}" # noqa logger.info(stats_line.format(**stats)) -def print_run_result_error(result, newline=True): +def print_run_result_error(result, newline=True, is_warning=False): if newline: logger.info("") - if result.failed: - logger.info(yellow("Failure in {} {} ({})").format( + if result.failed or (is_warning and result.warned): + if is_warning: + color = yellow + info = 'Warning' + else: + color = red + info = 'Failure' + logger.info(color("{} in {} {} ({})").format( + info, result.node.get('resource_type'), result.node.get('name'), result.node.get('original_file_path'))) - logger.info(" Got {} results, expected 0.".format(result.status)) + status = dbt.utils.pluralize(result.status, 'result') + logger.info(" Got {}, expected 0.".format(status)) if result.node.get('build_path') is not None: logger.info("") @@ -314,11 +323,16 @@ def print_skip_caused_by_error(model, schema, relation, index, num_models, print_run_result_error(result, newline=False) -def print_end_of_run_summary(num_errors, early_exit=False): +def print_end_of_run_summary(num_errors, num_warnings, early_exit=False): + error_plural = dbt.utils.pluralize(num_errors, 'error') + warn_plural = dbt.utils.pluralize(num_warnings, 'warning') if early_exit: message = yellow('Exited because of keyboard interrupt.') elif num_errors > 0: - message = red('Completed with {} errors:'.format(num_errors)) + message = red("Completed with {} and {}:".format( + error_plural, warn_plural)) + elif num_warnings > 0: + message = yellow('Completed with {}:'.format(warn_plural)) else: message = green('Completed successfully') @@ -328,9 +342,13 @@ def print_end_of_run_summary(num_errors, early_exit=False): def print_run_end_messages(results, early_exit=False): errors = [r for r in results if r.error is not None or r.failed] - print_end_of_run_summary(len(errors), early_exit) + warnings = [r for r in results if r.warned] + print_end_of_run_summary(len(errors), len(warnings), early_exit) for error in errors: - print_run_result_error(error) + print_run_result_error(error, is_warning=False) + + for warning in warnings: + print_run_result_error(warning, is_warning=True) print_run_status_line(results) diff --git a/core/dbt/utils.py b/core/dbt/utils.py index b194f0aa5db..ebf0c04930e 100644 --- a/core/dbt/utils.py +++ b/core/dbt/utils.py @@ -481,3 +481,10 @@ def translate_aliases(kwargs, aliases): result[canonical_key] = value return result + + +def pluralize(count, string): + if count == 1: + return "{} {}".format(count, string) + else: + return "{} {}s".format(count, string) diff --git a/test/integration/029_docs_generate_tests/test_docs_generate.py b/test/integration/029_docs_generate_tests/test_docs_generate.py index 196a0746526..f8e5b8556a1 100644 --- a/test/integration/029_docs_generate_tests/test_docs_generate.py +++ b/test/integration/029_docs_generate_tests/test_docs_generate.py @@ -1878,6 +1878,7 @@ def expected_run_results(self, quote_schema=True, quote_model=False, 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'model', 'build_path': _normalize( @@ -1930,6 +1931,7 @@ def expected_run_results(self, quote_schema=True, quote_model=False, 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'seed', 'build_path': _normalize( @@ -1980,6 +1982,7 @@ def expected_run_results(self, quote_schema=True, quote_model=False, 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'not_null_model_id', 'build_path': _normalize('target/compiled/test/schema_test/not_null_model_id.sql'), @@ -2030,6 +2033,7 @@ def expected_run_results(self, quote_schema=True, quote_model=False, 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'nothing_model_', 'build_path': _normalize('target/compiled/test/schema_test/nothing_model_.sql'), @@ -2079,6 +2083,7 @@ def expected_run_results(self, quote_schema=True, quote_model=False, 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'unique_model_id', 'build_path': _normalize('target/compiled/test/schema_test/unique_model_id.sql'), @@ -2156,6 +2161,7 @@ def expected_postgres_references_run_results(self): 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'ephemeral_summary', 'build_path': _normalize( @@ -2244,6 +2250,7 @@ def expected_postgres_references_run_results(self): 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'view_summary', 'build_path': _normalize( @@ -2331,6 +2338,7 @@ def expected_postgres_references_run_results(self): 'error': None, 'execution_time': AnyFloat(), 'fail': None, + 'warn': None, 'node': { 'alias': 'seed', 'build_path': _normalize( diff --git a/test/integration/045_test_severity_tests/test_severity.py b/test/integration/045_test_severity_tests/test_severity.py index 5e240893284..25c74ed40f8 100644 --- a/test/integration/045_test_severity_tests/test_severity.py +++ b/test/integration/045_test_severity_tests/test_severity.py @@ -28,8 +28,10 @@ def test_postgres_severity_warnings(self): results = self.run_dbt_with_vars(['test', '--schema'], 'false', strict=False) self.assertEqual(len(results), 2) self.assertFalse(results[0].fail) + self.assertTrue(results[0].warn) self.assertEqual(results[0].status, 2) self.assertFalse(results[1].fail) + self.assertTrue(results[1].warn) self.assertEqual(results[1].status, 2) @use_profile('postgres') @@ -39,8 +41,10 @@ def test_postgres_severity_rendered_errors(self): results = self.run_dbt_with_vars(['test', '--schema'], 'true', strict=False, expect_pass=False) self.assertEqual(len(results), 2) self.assertTrue(results[0].fail) + self.assertFalse(results[0].warn) self.assertEqual(results[0].status, 2) self.assertTrue(results[1].fail) + self.assertFalse(results[1].warn) self.assertEqual(results[1].status, 2) @use_profile('postgres') @@ -50,8 +54,10 @@ def test_postgres_severity_warnings_strict(self): results = self.run_dbt_with_vars(['test', '--schema'], 'false', expect_pass=False) self.assertEqual(len(results), 2) self.assertTrue(results[0].fail) + self.assertFalse(results[0].warn) self.assertEqual(results[0].status, 2) self.assertTrue(results[1].fail) + self.assertFalse(results[1].warn) self.assertEqual(results[1].status, 2) @use_profile('postgres') @@ -61,6 +67,7 @@ def test_postgres_data_severity_warnings(self): results = self.run_dbt_with_vars(['test', '--data'], 'false', strict=False) self.assertEqual(len(results), 1) self.assertFalse(results[0].fail) + self.assertTrue(results[0].warn) self.assertEqual(results[0].status, 2) @use_profile('postgres') @@ -70,6 +77,7 @@ def test_postgres_data_severity_rendered_errors(self): results = self.run_dbt_with_vars(['test', '--data'], 'true', strict=False, expect_pass=False) self.assertEqual(len(results), 1) self.assertTrue(results[0].fail) + self.assertFalse(results[0].warn) self.assertEqual(results[0].status, 2) @use_profile('postgres') @@ -79,4 +87,5 @@ def test_postgres_data_severity_warnings_strict(self): results = self.run_dbt_with_vars(['test', '--data'], 'false', expect_pass=False) self.assertEqual(len(results), 1) self.assertTrue(results[0].fail) + self.assertFalse(results[0].warn) self.assertEqual(results[0].status, 2)