Paw/ct 1844 log params take 2

.changes/unreleased/Features-20230216-144534.yaml

@@ -0,0 +1,6 @@
+kind: Features
+body: Implemented new log cli parameters for finer-grained control.
+time: 2023-02-16T14:45:34.038453-05:00
+custom:
+  Author: peterallenwebb
+  Issue: "6639"

core/dbt/cli/flags.py

@@ -150,13 +150,18 @@ def assign_params(ctx, params_assigned_from_default):
         object.__setattr__(self, "WHICH", invoked_subcommand_name or ctx.info_name)
         object.__setattr__(self, "MP_CONTEXT", get_context("spawn"))
 
+        # Apply the lead/follow relationship between some parameters
+        self._override_if_set("USE_COLORS", "USE_COLORS_FILE", params_assigned_from_default)
+        self._override_if_set("LOG_LEVEL", "LOG_LEVEL_FILE", params_assigned_from_default)
+        self._override_if_set("LOG_FORMAT", "LOG_FORMAT_FILE", params_assigned_from_default)
+
         # Default LOG_PATH from PROJECT_DIR, if available.
         if getattr(self, "LOG_PATH", None) is None:
             project_dir = getattr(self, "PROJECT_DIR", default_project_dir())
             version_check = getattr(self, "VERSION_CHECK", True)
             object.__setattr__(self, "LOG_PATH", default_log_path(project_dir, version_check))
 
-        # Support console DO NOT TRACK initiave
+        # Support console DO NOT TRACK initiative
         if os.getenv("DO_NOT_TRACK", "").lower() in ("1", "t", "true", "y", "yes"):
             object.__setattr__(self, "SEND_ANONYMOUS_USAGE_STATS", False)
 
@@ -172,6 +177,12 @@ def assign_params(ctx, params_assigned_from_default):
         for param in params:
             object.__setattr__(self, param.lower(), getattr(self, param))
 
+    # If the value of the lead parameter was set explicitly, apply the value to follow,
+    # unless follow was also set explicitly.
+    def _override_if_set(self, lead: str, follow: str, defaulted: Set[str]) -> None:
+        if lead.lower() not in defaulted and follow.lower() in defaulted:
+            object.__setattr__(self, follow.upper(), getattr(self, lead.upper(), None))
+
     def __str__(self) -> str:
         return str(pf(self.__dict__))
 

core/dbt/cli/main.py

@@ -83,6 +83,9 @@ def handle_and_check(args):
 @p.fail_fast
 @p.log_cache_events
 @p.log_format
+@p.log_format_file
+@p.log_level
+@p.log_level_file
 @p.log_path
 @p.macro_debugging
 @p.partial_parse
@@ -93,6 +96,7 @@ def handle_and_check(args):
 @p.single_threaded
 @p.static_parser
 @p.use_colors
+@p.use_colors_file
 @p.use_experimental_parser
 @p.version
 @p.version_check

core/dbt/cli/params.py

@@ -121,10 +121,34 @@
     "--log-format",
     envvar="DBT_LOG_FORMAT",
     help="Specify the log format, overriding the command's default.",
-    type=click.Choice(["text", "json", "default"], case_sensitive=False),
+    type=click.Choice(["text", "debug", "json", "default"], case_sensitive=False),
     default="default",
 )
 
+log_format_file = click.option(
+    "--log-format-file",
+    envvar="DBT_LOG_FORMAT_FILE",
+    help="Specify the file log format, overriding the command's default and the value of --log-format.",
+    type=click.Choice(["text", "debug", "json", "default"], case_sensitive=False),
+    default="debug",
+)
+
+log_level = click.option(
+    "--log-level",
+    envvar="DBT_LOG_LEVEL",
+    help="Specify the minimum severity of events that are logged.",
+    type=click.Choice(["debug", "info", "warn", "error", "none"], case_sensitive=False),
+    default="info",
+)
+
+log_level_file = click.option(
+    "--log-level-file",
+    envvar="DBT_LOG_LEVEL_FILE",
+    help="Specify the minimum severity of events that are logged to file, overriding the value of --log-level-file.",
+    type=click.Choice(["debug", "info", "warn", "error", "none"], case_sensitive=False),
+    default="debug",
+)
+
 log_path = click.option(
     "--log-path",
     envvar="DBT_LOG_PATH",
@@ -365,7 +389,14 @@
 use_colors = click.option(
     "--use-colors/--no-use-colors",
     envvar="DBT_USE_COLORS",
-    help="Output is colorized by default and may also be set in a profile or at the command line.",
+    help="Specify whether log output is colorized.",
+    default=True,
+)
+
+use_colors_file = click.option(
+    "--use-colors-file/--no-use-colors-file",
+    envvar="DBT_USE_COLORS_FILE",
+    help="Specify whether log file output is colorized overriding --use-colors/--no-use-colors.",
     default=True,
 )
 

core/dbt/cli/requires.py

@@ -33,14 +33,7 @@ def wrapper(*args, **kwargs):
 
         # Logging
         # N.B. Legacy logger is not supported
-        setup_event_logger(
-            flags.LOG_PATH,
-            flags.LOG_FORMAT,
-            flags.USE_COLORS,
-            flags.DEBUG,
-            flags.LOG_CACHE_EVENTS,
-            flags.QUIET,
-        )
+        setup_event_logger(flags)
 
         # Now that we have our logger, fire away!
         fire_event(MainReportVersion(version=str(installed_version), log_version=LOG_VERSION))

core/dbt/contracts/project.py

@@ -245,12 +245,16 @@ def validate(cls, data):
 class UserConfig(ExtensibleDbtClassMixin, Replaceable, UserConfigContract):
     send_anonymous_usage_stats: bool = DEFAULT_SEND_ANONYMOUS_USAGE_STATS
     use_colors: Optional[bool] = None
+    use_colors_file: Optional[bool] = None
     partial_parse: Optional[bool] = None
     printer_width: Optional[int] = None
     write_json: Optional[bool] = None
     warn_error: Optional[bool] = None
     warn_error_options: Optional[Dict[str, Union[str, List[str]]]] = None
     log_format: Optional[str] = None
+    log_format_file: Optional[str] = None
+    log_level: Optional[str] = None
+    log_level_file: Optional[str] = None
     debug: Optional[bool] = None
     version_check: Optional[bool] = None
     fail_fast: Optional[bool] = None

core/dbt/events/functions.py

@@ -1,7 +1,7 @@
 import betterproto
 from dbt.constants import METADATA_ENV_PREFIX
 from dbt.events.base_types import BaseEvent, Cache, EventLevel, NoFile, NoStdOut, EventMsg
-from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat
+from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter
 from dbt.events.helpers import env_secrets, scrub_secrets
 from dbt.events.types import Formatting
 from dbt.flags import get_flags, ENABLE_LEGACY_LOGGER
@@ -18,103 +18,146 @@
 metadata_vars: Optional[Dict[str, str]] = None
 
 
-def setup_event_logger(
-    log_path: str,
-    log_format: str,
-    use_colors: bool,
-    debug: bool,
-    log_cache_events: bool,
-    quiet: bool,
-) -> None:
+def setup_event_logger(flags) -> None:
     cleanup_event_logger()
-    make_log_dir_if_missing(log_path)
+    make_log_dir_if_missing(flags.LOG_PATH)
 
     if ENABLE_LEGACY_LOGGER:
-        EVENT_MANAGER.add_logger(_get_logbook_log_config(debug))
-    else:
         EVENT_MANAGER.add_logger(
-            _get_stdout_config(log_format, debug, use_colors, log_cache_events, quiet)
+            _get_logbook_log_config(
+                flags.DEBUG, flags.USE_COLORS, flags.LOG_CACHE_EVENTS, flags.QUIET
+            )
         )
+    else:
+        if flags.LOG_LEVEL != "none":
+            log_format = _line_format_from_str(flags.LOG_FORMAT, LineFormat.PlainText)
+            log_level = EventLevel.DEBUG if flags.DEBUG else EventLevel(flags.LOG_LEVEL)
+            EVENT_MANAGER.add_logger(
+                _get_stdout_config(
+                    log_format,
+                    flags.DEBUG,
+                    flags.USE_COLORS,
+                    log_level,
+                    flags.LOG_CACHE_EVENTS,
+                    flags.QUIET,
+                )
+            )
 
-        if _CAPTURE_STREAM:
-            # Create second stdout logger to support test which want to know what's
-            # being sent to stdout.
-            # debug here is true because we need to capture debug events, and we pass in false in main
-            capture_config = _get_stdout_config(
-                log_format, True, use_colors, log_cache_events, quiet
+            if _CAPTURE_STREAM:
+                # Create second stdout logger to support test which want to know what's
+                # being sent to stdout.
+                # debug here is true because we need to capture debug events, and we pass in false in main
+                capture_config = _get_stdout_config(
+                    log_format,
+                    flags.DEBUG,
+                    flags.USE_COLORS,
+                    log_level,
+                    flags.LOG_CACHE_EVENTS,
+                    flags.QUIET,
+                )
+                capture_config.output_stream = _CAPTURE_STREAM
+                EVENT_MANAGER.add_logger(capture_config)
+
+        if flags.LOG_LEVEL_FILE != "none":
+            # create and add the file logger to the event manager
+            log_file = os.path.join(flags.LOG_PATH, "dbt.log")
+            log_file_format = _line_format_from_str(flags.LOG_FORMAT_FILE, LineFormat.DebugText)
+            log_level_file = EventLevel.DEBUG if flags.DEBUG else EventLevel(flags.LOG_LEVEL_FILE)
+            EVENT_MANAGER.add_logger(
+                _get_logfile_config(
+                    log_file, flags.USE_COLORS_FILE, log_file_format, log_level_file
+                )
             )
-            capture_config.output_stream = _CAPTURE_STREAM
-            EVENT_MANAGER.add_logger(capture_config)
 
-        # create and add the file logger to the event manager
-        EVENT_MANAGER.add_logger(
-            _get_logfile_config(os.path.join(log_path, "dbt.log"), use_colors, log_format)
-        )
+
+def _line_format_from_str(format_str: str, default: LineFormat) -> LineFormat:
+    if format_str == "text":
+        return LineFormat.PlainText
+    elif format_str == "debug":
+        return LineFormat.DebugText
+    elif format_str == "json":
+        return LineFormat.Json
+
+    return default
 
 
 def _get_stdout_config(
-    log_format: str, debug: bool, use_colors: bool, log_cache_events: bool, quiet: bool
+    line_format: LineFormat,
+    debug: bool,
+    use_colors: bool,
+    level: EventLevel,
+    log_cache_events: bool,
+    quiet: bool,
 ) -> LoggerConfig:
-    fmt = LineFormat.PlainText
-    if log_format == "json":
-        fmt = LineFormat.Json
-    elif debug:
-        fmt = LineFormat.DebugText
-    level = EventLevel.DEBUG if debug else EventLevel.INFO
+
     return LoggerConfig(
         name="stdout_log",
         level=level,
         use_colors=use_colors,
-        line_format=fmt,
+        line_format=line_format,
         scrubber=env_scrubber,
         filter=partial(
             _stdout_filter,
             log_cache_events,
             debug,
             quiet,
-            log_format,
+            line_format,
         ),
         output_stream=sys.stdout,
     )
 
 
 def _stdout_filter(
-    log_cache_events: bool, debug_mode: bool, quiet_mode: bool, log_format: str, msg: EventMsg
+    log_cache_events: bool,
+    debug_mode: bool,
+    quiet_mode: bool,
+    line_format: LineFormat,
+    msg: EventMsg,
 ) -> bool:
     return (
         not isinstance(msg.data, NoStdOut)
         and (not isinstance(msg.data, Cache) or log_cache_events)
         and (EventLevel(msg.info.level) != EventLevel.DEBUG or debug_mode)
         and (EventLevel(msg.info.level) == EventLevel.ERROR or not quiet_mode)
-        and not (log_format == "json" and type(msg.data) == Formatting)
+        and not (line_format == LineFormat.Json and type(msg.data) == Formatting)
     )
 
 
-def _get_logfile_config(log_path: str, use_colors: bool, log_format: str) -> LoggerConfig:
+def _get_logfile_config(
+    log_path: str, use_colors: bool, line_format: LineFormat, level: EventLevel
+) -> LoggerConfig:
     return LoggerConfig(
         name="file_log",
-        line_format=LineFormat.Json if log_format == "json" else LineFormat.DebugText,
+        line_format=line_format,
         use_colors=use_colors,
-        level=EventLevel.DEBUG,  # File log is *always* debug level
+        level=level,  # File log is *always* debug level
         scrubber=env_scrubber,
-        filter=partial(_logfile_filter, bool(get_flags().LOG_CACHE_EVENTS), log_format),
+        filter=partial(_logfile_filter, bool(get_flags().LOG_CACHE_EVENTS), line_format),
         output_file_name=log_path,
     )
 
 
-def _logfile_filter(log_cache_events: bool, log_format: str, msg: EventMsg) -> bool:
+def _logfile_filter(log_cache_events: bool, line_format: LineFormat, msg: EventMsg) -> bool:
     return (
         not isinstance(msg.data, NoFile)
         and not (isinstance(msg.data, Cache) and not log_cache_events)
-        and not (log_format == "json" and type(msg.data) == Formatting)
+        and not (line_format == LineFormat.Json and type(msg.data) == Formatting)
     )
 
 
-def _get_logbook_log_config(debug: bool) -> LoggerConfig:
-    # use the default one since this code should be removed when we remove logbook
-    config = _get_stdout_config("", debug, False, False, False)
+def _get_logbook_log_config(
+    debug: bool, use_colors: bool, log_cache_events: bool, quiet: bool
+) -> LoggerConfig:
+    config = _get_stdout_config(
+        LineFormat.PlainText,
+        debug,
+        use_colors,
+        EventLevel.DEBUG if debug else EventLevel.INFO,
+        log_cache_events,
+        quiet,
+    )
     config.name = "logbook_log"
-    config.filter = lambda e: not isinstance(e.data, Cache)
+    config.filter = NoFilter if log_cache_events else lambda e: not isinstance(e.data, Cache)
     config.logger = GLOBAL_LOGGER
     config.output_stream = None
     return config
@@ -136,13 +179,10 @@ def cleanup_event_logger():
 # currently fire before logs can be configured by setup_event_logger(), we
 # create a default configuration with default settings and no file output.
 EVENT_MANAGER: EventManager = EventManager()
-# Problem: This needs to be set *BEFORE* we've resolved any flags (even CLI params)
 EVENT_MANAGER.add_logger(
-    _get_logbook_log_config(debug=False)  # type: ignore
+    _get_logbook_log_config(False, True, False, False)  # type: ignore
     if ENABLE_LEGACY_LOGGER
-    else _get_stdout_config(
-        log_format="text", debug=False, use_colors=True, log_cache_events=False, quiet=False
-    )  # type: ignore
+    else _get_stdout_config(LineFormat.PlainText, False, True, EventLevel.INFO, False, False)
 )
 
 # This global, and the following two functions for capturing stdout logs are

core/dbt/tests/fixtures/project.py

@@ -473,7 +473,19 @@ def project(
     # Logbook warnings are ignored so we don't have to fork logbook to support python 3.10.
     # This _only_ works for tests in `tests/` that use the project fixture.
     warnings.filterwarnings("ignore", category=DeprecationWarning, module="logbook")
-    setup_event_logger(logs_dir, "json", False, False, False, False)
+    log_flags = Namespace(
+        LOG_PATH=logs_dir,
+        LOG_FORMAT="json",
+        LOG_FORMAT_FILE="json",
+        USE_COLORS=False,
+        USE_COLORS_FILE=False,
+        LOG_LEVEL="info",
+        LOG_LEVEL_FILE="debug",
+        DEBUG=False,
+        LOG_CACHE_EVENTS=False,
+        QUIET=False,
+    )
+    setup_event_logger(log_flags)
     orig_cwd = os.getcwd()
     os.chdir(project_root)
     # Return whatever is needed later in tests but can only come from fixtures, so we can keep