Merge pull request dbt-labs#2723 from tpilewicz/fix/freshness-logs

Feat(result logs): Use three logging levels
jweibel22 · Sep 9, 2020 · 4a21ea6 · 4a21ea6
2 parents fb40efe + 86bbb9f
commit 4a21ea6
Show file tree

Hide file tree

Showing 2 changed files with 45 additions and 19 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -3,6 +3,13 @@
 ### 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))
+
+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)
@@ -52,7 +59,6 @@ Contributors:
 - 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))
 
-
 ### 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)
 - Fix issue where jinja that only contained jinja comments wasn't rendered. ([#2707](https://github.com/fishtown-analytics/dbt/issues/2707), [#2178](https://github.com/fishtown-analytics/dbt/pull/2178))

diff --git 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,44 +64,50 @@ 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(
     statement: str, status: str, index: int, total: int, execution_time: float
 ) -> 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)
 
 
 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]:
+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)
+        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 +118,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 +146,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,14 +163,16 @@ 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(
         info=info, description=description, **cfg)
     print_fancy_output_line(
         msg,
         status,
+        logger_fn,
         index,
         total,
         result.execution_time)
@@ -168,14 +181,15 @@ 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(
             info=info,
             schema=schema_name,
             relation=model.alias),
         status,
+        logger_fn,
         index,
         total,
         result.execution_time)
@@ -185,15 +199,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 +229,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 +316,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)