Logging: restore previous (small) behaviors

CHANGELOG.md

@@ -9,6 +9,7 @@
 - Reorder logic for static parser sampling to speed up model parsing ([#4332](https://github.com/dbt-labs/dbt-core/pull/4332))
 - Use more augmented assignment statements ([#4315](https://github.com/dbt-labs/dbt-core/issues/4315)), ([#4311](https://github.com/dbt-labs/dbt-core/pull/4331))
 - Adjust logic when finding approximate matches for models and tests ([#3835](https://github.com/dbt-labs/dbt-core/issues/3835)), [#4076](https://github.com/dbt-labs/dbt-core/pull/4076))
+- Restore small previous behaviors for logging: JSON formatting for first few events; `WARN`-level stdout for `list` task; include tracking events in `dbt.log` ([#4341](https://github.com/dbt-labs/dbt-core/pull/4341))
 
 Contributors:
 - [@sarah-weatherbee](https://github.com/sarah-weatherbee) ([#4331](https://github.com/dbt-labs/dbt-core/pull/4331))

core/dbt/events/functions.py

@@ -40,15 +40,15 @@
 invocation_id: Optional[str] = None
 
 
-def setup_event_logger(log_path):
+def setup_event_logger(log_path, level_override=None):
     make_log_dir_if_missing(log_path)
     this.format_json = flags.LOG_FORMAT == 'json'
     # USE_COLORS can be None if the app just started and the cli flags
     # havent been applied yet
     this.format_color = True if flags.USE_COLORS else False
     # TODO this default should live somewhere better
     log_dest = os.path.join(log_path, 'dbt.log')
-    level = logging.DEBUG if flags.DEBUG else logging.INFO
+    level = level_override or (logging.DEBUG if flags.DEBUG else logging.INFO)
 
     # overwrite the STDOUT_LOG logger with the configured one
     this.STDOUT_LOG = logging.getLogger('configured_std_out')

core/dbt/events/types.py

@@ -137,7 +137,7 @@ def message(self):
 
 
 @dataclass
-class MainTrackingUserState(DebugLevel, Cli):
+class MainTrackingUserState(DebugLevel, Cli, File):
     user_state: str
     code: str = "A003"
 
@@ -2365,7 +2365,7 @@ def message(self) -> str:
 
 
 @dataclass
-class SendingEvent(DebugLevel, Cli):
+class SendingEvent(DebugLevel, Cli, File):
     kwargs: str
     code: str = "Z040"
 

core/dbt/main.py

@@ -223,7 +223,8 @@ def run_from_args(parsed):
 
     # we can now use the logger for stdout
     # set log_format in the logger
-    parsed.cls.pre_init_hook(parsed)
+    # if 'list' task: set stdout to WARN instead of INFO
+    level_override = parsed.cls.pre_init_hook(parsed)
 
     fire_event(MainReportVersion(v=dbt.version.installed))
 
@@ -237,7 +238,7 @@ def run_from_args(parsed):
         log_path = getattr(task.config, 'log_path', None)
     # we can finally set the file logger up
     log_manager.set_path(log_path)
-    setup_event_logger(log_path or 'logs')
+    setup_event_logger(log_path or 'logs', level_override)
     if dbt.tracking.active_user is not None:  # mypy appeasement, always true
         fire_event(MainTrackingUserState(dbt.tracking.active_user.state()))
 

core/dbt/task/base.py

@@ -15,6 +15,7 @@
     InternalException
 )
 from dbt.logger import log_manager
+import dbt.events.functions as event_logger
 from dbt.events.functions import fire_event
 from dbt.events.types import (
     DbtProjectError, DbtProjectErrorException, DbtProfileError, DbtProfileErrorException,
@@ -64,13 +65,19 @@ def pre_init_hook(cls, args):
         """A hook called before the task is initialized."""
         if args.log_format == 'json':
             log_manager.format_json()
+            # we're mutating the initialized, but not-yet-configured event logger
+            # because it's being configured too late -- bad! TODO refactor!
+            event_logger.format_json = True
         else:
             log_manager.format_text()
 
     @classmethod
     def set_log_format(cls):
         if flags.LOG_FORMAT == 'json':
             log_manager.format_json()
+            # we're mutating the initialized, but not-yet-configured event logger
+            # because it's being configured too late -- bad! TODO refactor!
+            event_logger.format_json = True
         else:
             log_manager.format_text()
 

core/dbt/task/list.py

@@ -11,6 +11,8 @@
 from dbt.node_types import NodeType
 from dbt.exceptions import RuntimeException, InternalException, warn_or_error
 from dbt.logger import log_manager
+import logging
+import dbt.events.functions as event_logger
 
 
 class ListTask(GraphRunnableTask):
@@ -55,8 +57,17 @@ def __init__(self, args, config):
     @classmethod
     def pre_init_hook(cls, args):
         """A hook called before the task is initialized."""
+        # Filter out all INFO-level logging to allow piping ls output to jq, etc
+        # WARN level will still include all warnings + errors
+        # Do this by:
+        #  - returning the log level so that we can pass it into the 'level_override'
+        #    arg of events.functions.setup_event_logger() -- good!
+        #  - mutating the initialized, not-yet-configured STDOUT event logger
+        #    because it's being configured too late -- bad! TODO refactor!
         log_manager.stderr_console()
+        event_logger.STDOUT_LOG.level = logging.WARN
         super().pre_init_hook(args)
+        return logging.WARN
 
     def _iterate_selected_nodes(self):
         selector = self.get_node_selector()