Colorize levels in text logs, rm duplicate WARNINGs

core/dbt/deps/git.py

@@ -94,7 +94,7 @@ class GitPinnedPackage(GitPackageMixin, PinnedPackage):
                 'The git package "{}" \n\tis {}.\n\tThis can introduce '
                 'breaking changes into your project without warning!\n\nSee {}'
                 .format(self.git, self.unpinned_msg(), PIN_PACKAGE_URL),
-                log_fmt=ui.yellow('WARNING: {}')
+                log_fmt=ui.warning_tag('{}')
             )
         loaded = Project.from_project_root(path, renderer)
         return ProjectPackageMetadata.from_project(loaded)

core/dbt/events/functions.py

@@ -3,6 +3,7 @@ from colorama import Style
 import dbt.events.functions as this  # don't worry I hate it too.
 from dbt.events.base_types import Cli, Event, File, ShowException
 import dbt.flags as flags
+import dbt.ui as ui
 # TODO this will need to move eventually
 from dbt.logger import SECRET_ENV_PREFIX, make_log_dir_if_missing, GLOBAL_LOGGER
 import io
@@ -110,6 +111,19 @@ def scrub_secrets(msg: str, secrets: List[str]) -> str:
 T_Event = TypeVar('T_Event', bound=Event)
 
 
+def format_level(level):
+    fixed_width = level.ljust(5)
+    # TODO turn off all color everwhere for file + JSON
+    if not this.format_color:
+        return fixed_width
+    elif level == 'warn':
+        return ui.yellow(fixed_width)
+    elif level == 'error':
+        return ui.red(fixed_width)
+    else:
+        return fixed_width
+
+
 # translates an Event to a completely formatted text-based log line
 # you have to specify which message you want. (i.e. - e.message, e.cli_msg(), e.file_msg())
 # type hinting everything as strings so we don't get any unintentional string conversions via str()
@@ -117,7 +131,7 @@ def create_text_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
     color_tag: str = '' if this.format_color else Style.RESET_ALL
     ts: str = e.ts.strftime("%H:%M:%S")
     scrubbed_msg: str = scrub_secrets(msg_fn(e), env_secrets())
-    level: str = e.level_tag()
+    level: str = format_level(e.level_tag())
     log_line: str = f"{color_tag}{ts} | [ {level} ] | {scrubbed_msg}"
     return log_line
 
@@ -223,7 +237,11 @@ def fire_event(e: Event) -> None:
 
     # always logs debug level regardless of user input
     if isinstance(e, File):
-        log_line = create_json_log_line(e, msg_fn=lambda x: x.file_msg())
+        log_line = (
+            create_json_log_line(e, msg_fn=lambda x: x.file_msg())
+            if this.format_json else
+            create_text_log_line(e, msg_fn=lambda x: x.file_msg())
+        )
         # doesn't send exceptions to exception logger
         send_to_logger(FILE_LOG, level_tag=e.level_tag(), log_line=log_line)
 
@@ -233,7 +251,11 @@ def fire_event(e: Event) -> None:
         if e.level_tag() == 'debug' and not flags.DEBUG:
             return  # eat the message in case it was one of the expensive ones
 
-        log_line = create_json_log_line(e, msg_fn=lambda x: x.cli_msg())
+        log_line = (
+            create_json_log_line(e, msg_fn=lambda x: x.cli_msg())
+            if this.format_json else
+            create_text_log_line(e, msg_fn=lambda x: x.cli_msg())
+        )
         if not isinstance(e, ShowException):
             send_to_logger(STDOUT_LOG, level_tag=e.level_tag(), log_line=log_line)
         # CliEventABC and ShowException

core/dbt/events/types.py

@@ -282,34 +282,6 @@ class SystemReportReturnCode(DebugLevel, Cli, File):
         return f"command return code={self.code}"
 
 
-@dataclass
-class SelectorAlertUpto3UnusedNodes(InfoLevel, Cli, File):
-    node_names: List[str]
-
-    def message(self) -> str:
-        summary_nodes_str = ("\n  - ").join(self.node_names[:3])
-        and_more_str = (
-            f"\n  - and {len(self.node_names) - 3} more" if len(self.node_names) > 4 else ""
-        )
-        return (
-            f"\nSome tests were excluded because at least one parent is not selected. "
-            f"Use the --greedy flag to include them."
-            f"\n  - {summary_nodes_str}{and_more_str}"
-        )
-
-
-@dataclass
-class SelectorAlertAllUnusedNodes(DebugLevel, Cli, File):
-    node_names: List[str]
-
-    def message(self) -> str:
-        debug_nodes_str = ("\n  - ").join(self.node_names)
-        return (
-            f"Full list of tests that were excluded:"
-            f"\n  - {debug_nodes_str}"
-        )
-
-
 @dataclass
 class SelectorReportInvalidSelector(InfoLevel, Cli, File):
     selector_methods: dict
@@ -680,7 +652,7 @@ class ProfileNotFound(InfoLevel, Cli, File):
 
 class InvalidVarsYAML(ErrorLevel, Cli, File):
     def message(self) -> str:
-        return "The YAML provided in the --vars argument is not valid.\n"
+        return "The YAML provided in the --vars argument is not valid."
 
 
 @dataclass
@@ -1265,7 +1237,7 @@ class DepsNotifyUpdatesAvailable(InfoLevel, Cli, File):
     packages: List[str]
 
     def message(self) -> str:
-        return ('\nUpdates available for packages: {} \
+        return ('Updates available for packages: {} \
                 \nUpdate your versions in packages.yml, then run dbt deps'.format(self.packages))
 
 
@@ -1277,7 +1249,9 @@ class DatabaseErrorRunning(InfoLevel, Cli, File):
         return f"Database error while running {self.hook_type}"
 
 
-class EmptyLine(InfoLevel, Cli, File):
+class EmptyLine(InfoLevel, Cli):
+    # ignore in file
+    # TODO: ignore if JSON formatted?
     def message(self) -> str:
         return ''
 
@@ -1357,7 +1331,7 @@ class ServingDocsAccessInfo(InfoLevel, Cli, File):
 
 class ServingDocsExitInfo(InfoLevel, Cli, File):
     def message(self) -> str:
-        return "Press Ctrl+C to exit.\n\n"
+        return "Press Ctrl+C to exit."
 
 
 @dataclass
@@ -1403,7 +1377,7 @@ class StatsLine(InfoLevel, Cli, File):
     stats: Dict
 
     def message(self) -> str:
-        stats_line = ("\nDone. PASS={pass} WARN={warn} ERROR={error} SKIP={skip} TOTAL={total}")
+        stats_line = ("Done. PASS={pass} WARN={warn} ERROR={error} SKIP={skip} TOTAL={total}")
         return stats_line.format(**self.stats)
 
 
@@ -1869,10 +1843,11 @@ class QueryCancelationUnsupported(InfoLevel, Cli, File):
 
 @dataclass
 class ConcurrencyLine(InfoLevel, Cli, File):
-    concurrency_line: str
+    num_threads: int
+    target_name: str
 
     def message(self) -> str:
-        return self.concurrency_line
+        return f"Concurrency: {self.num_threads} threads (target='{self.target_name}')"
 
 
 @dataclass
@@ -2176,8 +2151,6 @@ if 1 == 0:
     SystemStdOutMsg(bmsg=b'')
     SystemStdErrMsg(bmsg=b'')
     SystemReportReturnCode(code=0)
-    SelectorAlertUpto3UnusedNodes(node_names=[])
-    SelectorAlertAllUnusedNodes(node_names=[])
     SelectorReportInvalidSelector(selector_methods={'': ''}, spec_method='', raw_spec='')
     MacroEventInfo(msg='')
     MacroEventDebug(msg='')
@@ -2306,7 +2279,7 @@ if 1 == 0:
     NodeStart(unique_id='')
     NodeFinished(unique_id='')
     QueryCancelationUnsupported(type='')
-    ConcurrencyLine(concurrency_line='')
+    ConcurrencyLine(num_threads=0, target_name='')
     StarterProjectPath(dir='')
     ConfigFolderDirectory(dir='')
     NoSampleProfileFound(adapter='')

core/dbt/parser/schemas.py

@@ -961,7 +961,7 @@ class MacroPatchParser(NonSourceParser[UnparsedMacroUpdate, ParsedMacroPatch]):
         macro = self.manifest.macros.get(unique_id)
         if not macro:
             warn_or_error(
-                f'WARNING: Found patch for macro "{patch.name}" '
+                f'Found patch for macro "{patch.name}" '
                 f'which was not found'
             )
             return

core/dbt/task/deps.py

@@ -10,7 +10,7 @@ from dbt.deps.resolver import resolve_packages
 from dbt.events.functions import fire_event
 from dbt.events.types import (
     DepsNoPackagesFound, DepsStartPackageInstall, DepsUpdateAvailable, DepsUTD,
-    DepsInstallInfo, DepsListSubdirectory, DepsNotifyUpdatesAvailable
+    DepsInstallInfo, DepsListSubdirectory, DepsNotifyUpdatesAvailable, EmptyLine
 )
 from dbt.clients import system
 
@@ -81,6 +81,7 @@ class DepsTask(BaseTask):
                     source_type=source_type,
                     version=version)
             if packages_to_upgrade:
+                fire_event(EmptyLine())
                 fire_event(DepsNotifyUpdatesAvailable(packages=packages_to_upgrade))
 
     @classmethod

core/dbt/task/printer.py

@@ -65,6 +65,8 @@ def print_run_status_line(results) -> None:
         stats[result_type] += 1
         stats['total'] += 1
 
+    with TextOnly():
+        fire_event(EmptyLine())
     fire_event(StatsLine(stats=stats))
 
 

core/dbt/task/runnable.py

@@ -353,10 +353,8 @@ class GraphRunnableTask(ManifestTask):
         num_threads = self.config.threads
         target_name = self.config.target_name
 
-        text = "Concurrency: {} threads (target='{}')"
-        concurrency_line = text.format(num_threads, target_name)
         with NodeCount(self.num_nodes):
-            fire_event(ConcurrencyLine(concurrency_line=concurrency_line))
+            fire_event(ConcurrencyLine(num_threads=num_threads, target_name=target_name))
         with TextOnly():
             fire_event(EmptyLine())
 

core/dbt/task/serve.py

@@ -6,7 +6,7 @@ from dbt.include.global_project import DOCS_INDEX_FILE_PATH
 from http.server import SimpleHTTPRequestHandler
 from socketserver import TCPServer
 from dbt.events.functions import fire_event
-from dbt.events.types import ServingDocsPort, ServingDocsAccessInfo, ServingDocsExitInfo
+from dbt.events.types import ServingDocsPort, ServingDocsAccessInfo, ServingDocsExitInfo, EmptyLine
 
 from dbt.task.base import ConfiguredTask
 
@@ -22,6 +22,8 @@ class ServeTask(ConfiguredTask):
 
         fire_event(ServingDocsPort(address=address, port=port))
         fire_event(ServingDocsAccessInfo(port=port))
+        fire_event(EmptyLine())
+        fire_event(EmptyLine())
         fire_event(ServingDocsExitInfo())
 
         # mypy doesn't think SimpleHTTPRequestHandler is ok here, but it is

core/dbt/ui.py

@@ -66,4 +66,6 @@ def line_wrap_message(
 
 
 def warning_tag(msg: str) -> str:
-    return f'[{yellow("WARNING")}]: {msg}'
+    # duplicative now that new structured logs include levels
+    # return f'[{yellow("WARNING")}]: {msg}'
+    return msg