Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Feat(result logs): Use three logging levels #2723

Merged
merged 6 commits into from
Sep 9, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 7 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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))
Expand Down
56 changes: 38 additions & 18 deletions core/dbt/task/printer.py
Original file line number Diff line number Diff line change
@@ -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,
Expand All @@ -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 = ''
Expand All @@ -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:
Expand All @@ -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(
Expand All @@ -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)
Expand All @@ -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)
Expand All @@ -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)
Expand All @@ -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)
Expand All @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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)


Expand Down