From c738928ea34c0ea07933ff9ce74fa29dabfef9d0 Mon Sep 17 00:00:00 2001 From: Thomas Pilewicz Date: Mon, 24 Aug 2020 14:04:05 +0200 Subject: [PATCH 1/5] Feat(result logs): Use three logging levels --- core/dbt/task/printer.py | 53 +++++++++++++++++++++++++++------------- 1 file changed, 36 insertions(+), 17 deletions(-) diff --git a/core/dbt/task/printer.py b/core/dbt/task/printer.py index 938c3e5bcad..9c312ccbc2e 100644 --- a/core/dbt/task/printer.py +++ b/core/dbt/task/printer.py @@ -1,4 +1,4 @@ -from typing import Dict, Optional, Tuple +from typing import Dict, Optional, Tuple, Callable from dbt.logger import ( GLOBAL_LOGGER as logger, DbtStatusMessage, @@ -13,8 +13,9 @@ def print_fancy_output_line( - msg: str, status: str, index: Optional[int], total: Optional[int], - execution_time: Optional[float] = None, truncate: bool = False + msg: str, status: str, logger_fn: Callable, index: Optional[int], + total: Optional[int], execution_time: Optional[float] = None, + truncate: bool = False ) -> None: if index is None or total is None: progress = '' @@ -39,7 +40,7 @@ def print_fancy_output_line( output = "{justified} [{status}{status_time}]".format( justified=justified, status=status, status_time=status_time) - logger.info(output) + logger_fn(output) def get_counts(flat_nodes) -> str: @@ -63,12 +64,13 @@ def get_counts(flat_nodes) -> str: def print_start_line(description: str, index: int, total: int) -> None: msg = "START {}".format(description) - print_fancy_output_line(msg, 'RUN', index, total) + print_fancy_output_line(msg, 'RUN', logger.info, index, total) def print_hook_start_line(statement: str, index: int, total: int) -> None: msg = 'START hook: {}'.format(statement) - print_fancy_output_line(msg, 'RUN', index, total, truncate=True) + print_fancy_output_line( + msg, 'RUN', logger.info, index, total, truncate=True) def print_hook_end_line( @@ -76,7 +78,7 @@ def print_hook_end_line( ) -> None: msg = 'OK hook: {}'.format(statement) # hooks don't fail into this path, so always green - print_fancy_output_line(msg, ui.green(status), index, total, + print_fancy_output_line(msg, ui.green(status), logger.info, index, total, execution_time=execution_time, truncate=True) @@ -84,23 +86,27 @@ def print_skip_line( model, schema: str, relation: str, index: int, num_models: int ) -> None: msg = 'SKIP relation {}.{}'.format(schema, relation) - print_fancy_output_line(msg, ui.yellow('SKIP'), index, num_models) + print_fancy_output_line( + msg, ui.yellow('SKIP'), logger.info, index, num_models) def print_cancel_line(model) -> None: msg = 'CANCEL query {}'.format(model) - print_fancy_output_line(msg, ui.red('CANCEL'), index=None, total=None) + print_fancy_output_line( + msg, ui.red('CANCEL'), logger.error, index=None, total=None) def get_printable_result(result, success: str, error: str) -> Tuple[str, str]: if result.error is not None: info = 'ERROR {}'.format(error) status = ui.red(result.status) + logger_fn = logger.error else: info = 'OK {}'.format(success) status = ui.green(result.status) + logger_fn = logger.info - return info, status + return info, status, logger_fn def print_test_result_line( @@ -111,24 +117,26 @@ def print_test_result_line( if result.error is not None: info = "ERROR" color = ui.red + logger_fn = logger.error elif result.status == 0: info = 'PASS' color = ui.green - + logger_fn = logger.info elif result.warn: info = 'WARN {}'.format(result.status) color = ui.yellow - + logger_fn = logger.warning elif result.fail: info = 'FAIL {}'.format(result.status) color = ui.red - + logger_fn = logger.error else: raise RuntimeError("unexpected status: {}".format(result.status)) print_fancy_output_line( "{info} {name}".format(info=info, name=model.name), color(info), + logger_fn, index, total, result.execution_time) @@ -137,11 +145,13 @@ def print_test_result_line( def print_model_result_line( result, description: str, index: int, total: int ) -> None: - info, status = get_printable_result(result, 'created', 'creating') + info, status, logger_fn = get_printable_result( + result, 'created', 'creating') print_fancy_output_line( "{info} {description}".format(info=info, description=description), status, + logger_fn, index, total, result.execution_time) @@ -152,7 +162,8 @@ def print_snapshot_result_line( ) -> None: model = result.node - info, status = get_printable_result(result, 'snapshotted', 'snapshotting') + info, status, logger_fn = get_printable_result( + result, 'snapshotted', 'snapshotting') cfg = model.config.to_dict() msg = "{info} {description}".format( @@ -160,6 +171,7 @@ def print_snapshot_result_line( print_fancy_output_line( msg, status, + logger_fn, index, total, result.execution_time) @@ -168,7 +180,7 @@ def print_snapshot_result_line( def print_seed_result_line(result, schema_name: str, index: int, total: int): model = result.node - info, status = get_printable_result(result, 'loaded', 'loading') + info, status, logger_fn = get_printable_result(result, 'loaded', 'loading') print_fancy_output_line( "{info} seed file {schema}.{relation}".format( @@ -176,6 +188,7 @@ def print_seed_result_line(result, schema_name: str, index: int, total: int): schema=schema_name, relation=model.alias), status, + logger_fn, index, total, result.execution_time) @@ -185,15 +198,19 @@ def print_freshness_result_line(result, index: int, total: int) -> None: if result.error: info = 'ERROR' color = ui.red + logger_fn = logger.error elif result.status == 'error': info = 'ERROR STALE' color = ui.red + logger_fn = logger.error elif result.status == 'warn': info = 'WARN' color = ui.yellow + logger_fn = logger.warning else: info = 'PASS' color = ui.green + logger_fn = logger.info if hasattr(result, 'node'): source_name = result.node.source_name @@ -211,6 +228,7 @@ def print_freshness_result_line(result, index: int, total: int) -> None: print_fancy_output_line( msg, color(info), + logger_fn, index, total, execution_time=result.execution_time @@ -297,7 +315,8 @@ def print_skip_caused_by_error( ) -> None: msg = ('SKIP relation {}.{} due to ephemeral model error' .format(schema, relation)) - print_fancy_output_line(msg, ui.red('ERROR SKIP'), index, num_models) + print_fancy_output_line( + msg, ui.red('ERROR SKIP'), logger.error, index, num_models) print_run_result_error(result, newline=False) From 5d93c64c0ec4af15be25cdd242e651d7f12e7bec Mon Sep 17 00:00:00 2001 From: Thomas Pilewicz Date: Mon, 24 Aug 2020 15:59:31 +0200 Subject: [PATCH 2/5] Add logging levels to features of 0.18.0 --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 0ea8db2d870..8ce0e30cd1f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -30,6 +30,7 @@ - Macros in the current project can override internal dbt macros that are called through `execute_macros`. ([#2301](https://github.com/fishtown-analytics/dbt/issues/2301), [#2686](https://github.com/fishtown-analytics/dbt/pull/2686)) - Add state:modified and state:new selectors ([#2641](https://github.com/fishtown-analytics/dbt/issues/2641), [#2695](https://github.com/fishtown-analytics/dbt/pull/2695)) - Add two new flags `--use-colors` and `--no-use-colors` to `dbt run` command to enable or disable log colorization from the command line ([#2708](https://github.com/fishtown-analytics/dbt/pull/2708)) +- Specify all three logging levels (`INFO`, `WARNING`, `ERROR`) in result logs for commands `test`, `seed`, `run`, `snapshot` and `source snapshot-freshness` ### Fixes From cf02c7fd02695d90c44b352aa92d35c115e74dba Mon Sep 17 00:00:00 2001 From: Thomas Pilewicz Date: Tue, 25 Aug 2020 16:52:21 +0200 Subject: [PATCH 3/5] Fix(get_printable_result): return type hints --- core/dbt/task/printer.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/core/dbt/task/printer.py b/core/dbt/task/printer.py index 9c312ccbc2e..850e9009251 100644 --- a/core/dbt/task/printer.py +++ b/core/dbt/task/printer.py @@ -96,7 +96,8 @@ def print_cancel_line(model) -> None: msg, ui.red('CANCEL'), logger.error, index=None, total=None) -def get_printable_result(result, success: str, error: str) -> Tuple[str, str]: +def get_printable_result( + result, success: str, error: str) -> Tuple[str, str, Callable]: if result.error is not None: info = 'ERROR {}'.format(error) status = ui.red(result.status) From 4030d4fc20478b05d096ff70ba7dfd9995677c72 Mon Sep 17 00:00:00 2001 From: Thomas Pilewicz Date: Wed, 9 Sep 2020 18:50:27 +0200 Subject: [PATCH 4/5] Move logging levels changelog entry to 0.18.1 --- CHANGELOG.md | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a06d6a9a04a..5d676828839 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,9 @@ ### Under the hood - If column config says quote, use quoting in SQL for adding a comment. ([#2539](https://github.com/fishtown-analytics/dbt/issues/2539), [#2733](https://github.com/fishtown-analytics/dbt/pull/2733)) +### Features +- Specify all three logging levels (`INFO`, `WARNING`, `ERROR`) in result logs for commands `test`, `seed`, `run`, `snapshot` and `source snapshot-freshness` ([#2680](https://github.com/fishtown-analytics/dbt/pull/2680), [#2723](https://github.com/fishtown-analytics/dbt/pull/2723)) + ## dbt 0.18.0 (September 03, 2020) ## dbt 0.18.0rc2 (September 03, 2020) @@ -51,8 +54,6 @@ Contributors: - Macros in the current project can override internal dbt macros that are called through `execute_macros`. ([#2301](https://github.com/fishtown-analytics/dbt/issues/2301), [#2686](https://github.com/fishtown-analytics/dbt/pull/2686)) - Add state:modified and state:new selectors ([#2641](https://github.com/fishtown-analytics/dbt/issues/2641), [#2695](https://github.com/fishtown-analytics/dbt/pull/2695)) - Add two new flags `--use-colors` and `--no-use-colors` to `dbt run` command to enable or disable log colorization from the command line ([#2708](https://github.com/fishtown-analytics/dbt/pull/2708)) -- Specify all three logging levels (`INFO`, `WARNING`, `ERROR`) in result logs for commands `test`, `seed`, `run`, `snapshot` and `source snapshot-freshness` - ### Fixes - Fix Redshift table size estimation; e.g. 44 GB tables are no longer reported as 44 KB. [#2702](https://github.com/fishtown-analytics/dbt/issues/2702) From 86bbb9fe388c1d7b45cbe68bf369fc0b10afe34a Mon Sep 17 00:00:00 2001 From: Thomas Pilewicz Date: Wed, 9 Sep 2020 18:50:39 +0200 Subject: [PATCH 5/5] Add contributors section to 0.18.1 --- CHANGELOG.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 5d676828839..74c34522949 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ ### Features - Specify all three logging levels (`INFO`, `WARNING`, `ERROR`) in result logs for commands `test`, `seed`, `run`, `snapshot` and `source snapshot-freshness` ([#2680](https://github.com/fishtown-analytics/dbt/pull/2680), [#2723](https://github.com/fishtown-analytics/dbt/pull/2723)) +Contributors: +- [@tpilewicz](https://github.com/tpilewicz) ([#2723](https://github.com/fishtown-analytics/dbt/pull/2723)) + + ## dbt 0.18.0 (September 03, 2020) ## dbt 0.18.0rc2 (September 03, 2020)