Repository: dbt-labs/dbt-core
Pull request: fix small issues with flags and logger to support dbt-rpc
resolves #6979 https://github.com/dbt-labs/dbt-rpc/issues/122

The helper functions are not in ideal situation but I think we can revisit them in the revisit of Flags module that's happening soon

Problem statement:
[CT-2123] [Bug] Flags are referenced incorrectly (and sometimes at the wrong time) in functions.py

### Current Behavior

Since the merge of the click-cli feature branch, the flags USE_COLOR and LOG_CACHE_EVENTS are accessed inconsistently and sometimes before their values are ready. Consider the following from functions.py:
```python
def _get_logbook_log_config(debug: bool) -> LoggerConfig:
    # use the default one since this code should be removed when we remove logbook
    flags = get_flags()
    config = _get_stdout_config("", debug, bool(flags.USE_COLORS))
    config.name = "logbook_log"
    config.filter = NoFilter if flags.LOG_CACHE_EVENTS else lambda e: not isinstance(e.data, Cache)
    config.logger = GLOBAL_LOGGER
    return config
```
Here LOG_CACHE_EVENTS is looked up using the wrong access pattern.

Also consider:
```python
EVENT_MANAGER: EventManager = EventManager()
EVENT_MANAGER.add_logger(
    _get_logbook_log_config(flags_module.DEBUG)  # type: ignore
    if flags_module.ENABLE_LEGACY_LOGGER
    else _get_stdout_config(flags_module.LOG_FORMAT, flags_module.DEBUG, flags_module.USE_COLORS)  # type: ignore
)
```
Here the flag values are being checked at module load, before they can reasonably be expected to have values set. To remedy this, we will replace the references to flags with specific default values. We also need to remove direct access to flags from functions like _get_stdout_config() and accept their values as parameters instead, to avoid the same access-before-set issue.

### Expected Behavior

The USE_COLOR and LOG_CACHE_EVENTS are not referenced before their values can reasonably be expected to be set, and they are accessed via their global variables in the dbt.flags module, not on the new flags object.

Other flags in the logging code should be inspected for these same issues.

### Steps To Reproduce

Run dbt with ENABLE_LEGACY_LOGGER=True

### Relevant log output

_No response_

### Environment

```markdown
- OS: macOS
- Python: 3.10
- dbt: main/head
```


### Which database adapter are you using with dbt?

_No response_

### Additional Context

_No response_

Hints from issue discussion:

Commit message: fix small issues with flags and logger to support dbt-rpc

Patch to review:
diff --git a/core/dbt/cli/flags.py b/core/dbt/cli/flags.py
index 3506049ba4b..5d0a06189f5 100644
--- a/core/dbt/cli/flags.py
+++ b/core/dbt/cli/flags.py
@@ -8,7 +8,7 @@
 from typing import Set, List
 
 from click import Context, get_current_context, BadOptionUsage
-from click.core import ParameterSource
+from click.core import ParameterSource, Command, Group
 
 from dbt.config.profile import read_user_config
 from dbt.contracts.project import UserConfig
@@ -49,13 +49,33 @@ def convert_config(config_name, config_value):
     # This function should take care of converting the values from config and original
     # set_from_args to the correct type
     ret = config_value
-    if config_name.lower() == "warn_error_options":
+    if config_name.lower() == "warn_error_options" and type(config_value) == dict:
         ret = WarnErrorOptions(
             include=config_value.get("include", []), exclude=config_value.get("exclude", [])
         )
     return ret
 
 
+def args_to_context(args):
+    """Convert a list of args to a click context with proper hierarchy for dbt commands"""
+    from dbt.cli.main import cli
+
+    cli_ctx = cli.make_context(cli.name, args)
+    # args would get converted during make context
+    if len(args) == 1 and "," in args[0]:
+        args = args[0].split(",")
+    sub_command_name, sub_command, args = cli.resolve_command(cli_ctx, args)
+
+    # handle source and docs group
+    if type(sub_command) == Group:
+        sub_command_name, sub_command, args = sub_command.resolve_command(cli_ctx, args)
+
+    assert type(sub_command) == Command
+    sub_command_ctx = sub_command.make_context(sub_command_name, args)
+    sub_command_ctx.parent = cli_ctx
+    return sub_command_ctx
+
+
 @dataclass(frozen=True)
 class Flags:
     def __init__(self, ctx: Context = None, user_config: UserConfig = None) -> None:
diff --git a/core/dbt/cli/requires.py b/core/dbt/cli/requires.py
index dca89d35627..0a30612c96d 100644
--- a/core/dbt/cli/requires.py
+++ b/core/dbt/cli/requires.py
@@ -38,6 +38,8 @@ def wrapper(*args, **kwargs):
             flags.LOG_FORMAT,
             flags.USE_COLORS,
             flags.DEBUG,
+            flags.LOG_CACHE_EVENTS,
+            flags.QUIET,
         )
 
         # Now that we have our logger, fire away!
diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py
index 9756ea320ab..b05aa4c19b1 100644
--- a/core/dbt/events/functions.py
+++ b/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, NoFilter
+from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat
 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,20 +18,31 @@
 metadata_vars: Optional[Dict[str, str]] = None
 
 
-def setup_event_logger(log_path: str, log_format: str, use_colors: bool, debug: bool):
+def setup_event_logger(
+    log_path: str,
+    log_format: str,
+    use_colors: bool,
+    debug: bool,
+    log_cache_events: bool,
+    quiet: bool,
+) -> None:
     cleanup_event_logger()
     make_log_dir_if_missing(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))
+        EVENT_MANAGER.add_logger(
+            _get_stdout_config(log_format, debug, 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, True, use_colors)
+            capture_config = _get_stdout_config(
+                log_format, True, use_colors, log_cache_events, quiet
+            )
             capture_config.output_stream = _CAPTURE_STREAM
             EVENT_MANAGER.add_logger(capture_config)
 
@@ -41,19 +52,15 @@ def setup_event_logger(log_path: str, log_format: str, use_colors: bool, debug:
         )
 
 
-def _get_stdout_config(log_format: str, debug: bool, use_colors: bool) -> LoggerConfig:
-    flags = get_flags()
+def _get_stdout_config(
+    log_format: str, debug: bool, use_colors: bool, 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
-    # We don't have access to these values when we need to setup the default stdout logger!
-    log_cache_events = (
-        bool(flags.LOG_CACHE_EVENTS) if hasattr(flags, "LOG_CACHE_EVENTS") else False
-    )
-    quiet = bool(flags.QUIET) if hasattr(flags, "QUIET") else False
     return LoggerConfig(
         name="stdout_log",
         level=level,
@@ -105,11 +112,11 @@ def _logfile_filter(log_cache_events: bool, log_format: str, msg: EventMsg) -> b
 
 def _get_logbook_log_config(debug: bool) -> LoggerConfig:
     # use the default one since this code should be removed when we remove logbook
-    flags = get_flags()
-    config = _get_stdout_config("", debug, bool(flags.USE_COLORS))
+    config = _get_stdout_config("", debug, False, False, False)
     config.name = "logbook_log"
-    config.filter = NoFilter if flags.LOG_CACHE_EVENTS else lambda e: not isinstance(e.data, Cache)
+    config.filter = lambda e: not isinstance(e.data, Cache)
     config.logger = GLOBAL_LOGGER
+    config.output_stream = None
     return config
 
 
@@ -133,7 +140,7 @@ def cleanup_event_logger():
 EVENT_MANAGER.add_logger(
     _get_logbook_log_config(debug=False)  # type: ignore
     if ENABLE_LEGACY_LOGGER
-    else _get_stdout_config(log_format="text", debug=False, use_colors=True)  # type: ignore
+    else _get_stdout_config(log_format="text", debug=False, use_colors=True, log_cache_events=True, quiet=False)  # type: ignore
 )
 
 # This global, and the following two functions for capturing stdout logs are
diff --git a/core/dbt/flags.py b/core/dbt/flags.py
index 473378ba7bd..5d3d7032c9c 100644
--- a/core/dbt/flags.py
+++ b/core/dbt/flags.py
@@ -18,11 +18,6 @@ def env_set_truthy(key: str) -> Optional[str]:
 
 # for setting up logger for legacy logger
 ENABLE_LEGACY_LOGGER = env_set_truthy("DBT_ENABLE_LEGACY_LOGGER")
-LOG_FORMAT = None
-DEBUG = None
-USE_COLORS = None
-LOG_CACHE_EVENTS = None
-QUIET = None
 
 # This is not a flag, it's a place to store the lock
 MP_CONTEXT = get_context()
@@ -48,6 +43,15 @@ def set_from_args(args: Namespace, user_config):
     from dbt.cli.main import cli
     from dbt.cli.flags import Flags, convert_config
 
+    # we set attributes of args after initialize the flags, but user_config
+    # is being read in the Flags constructor, so we need to read it here and pass in
+    # to make sure we use the correct user_config
+    if (hasattr(args, "PROFILES_DIR") or hasattr(args, "profiles_dir")) and not user_config:
+        from dbt.config.profile import read_user_config
+
+        profiles_dir = getattr(args, "PROFILES_DIR", None) or getattr(args, "profiles_dir")
+        user_config = read_user_config(profiles_dir)
+
     # make a dummy context to get the flags, totally arbitrary
     ctx = cli.make_context("run", ["run"])
     flags = Flags(ctx, user_config)
diff --git a/core/dbt/task/base.py b/core/dbt/task/base.py
index 460152b1f20..3e0b0d592e4 100644
--- a/core/dbt/task/base.py
+++ b/core/dbt/task/base.py
@@ -7,7 +7,7 @@
 from datetime import datetime
 
 from dbt import tracking
-from dbt import flags
+from dbt.flags import get_flags
 from dbt.contracts.graph.manifest import Manifest
 from dbt.contracts.results import (
     NodeStatus,
@@ -56,7 +56,7 @@ def from_args(cls, args):
 def read_profiles(profiles_dir=None):
     """This is only used for some error handling"""
     if profiles_dir is None:
-        profiles_dir = flags.PROFILES_DIR
+        profiles_dir = get_flags().PROFILES_DIR
 
     raw_profiles = read_profile(profiles_dir)
 
@@ -86,7 +86,7 @@ def pre_init_hook(cls, args):
 
     @classmethod
     def set_log_format(cls):
-        if flags.LOG_FORMAT == "json":
+        if get_flags().LOG_FORMAT == "json":
             log_manager.format_json()
         else:
             log_manager.format_text()
@@ -102,7 +102,7 @@ def from_args(cls, args, *pargs, **kwargs):
             tracking.track_invalid_invocation(args=args, result_type=exc.result_type)
             raise dbt.exceptions.DbtRuntimeError("Could not run dbt") from exc
         except dbt.exceptions.DbtProfileError as exc:
-            all_profile_names = list(read_profiles(flags.PROFILES_DIR).keys())
+            all_profile_names = list(read_profiles(get_flags().PROFILES_DIR).keys())
             fire_event(LogDbtProfileError(exc=str(exc), profiles=all_profile_names))
             tracking.track_invalid_invocation(args=args, result_type=exc.result_type)
             raise dbt.exceptions.DbtRuntimeError("Could not run dbt") from exc
diff --git a/core/dbt/task/list.py b/core/dbt/task/list.py
index 0ca9b89b0cc..429e2132e8e 100644
--- a/core/dbt/task/list.py
+++ b/core/dbt/task/list.py
@@ -1,8 +1,7 @@
 import json
 
-import dbt.flags
-
 from dbt.contracts.graph.nodes import Exposure, SourceDefinition, Metric
+from dbt.flags import get_flags
 from dbt.graph import ResourceTypeSelector
 from dbt.task.runnable import GraphRunnableTask
 from dbt.task.test import TestSelector
@@ -143,7 +142,7 @@ def output_results(self, results):
         """Log, or output a plain, newline-delimited, and ready-to-pipe list of nodes found."""
         for result in results:
             self.node_results.append(result)
-            if dbt.flags.LOG_FORMAT == "json":
+            if get_flags().LOG_FORMAT == "json":
                 fire_event(ListCmdOut(msg=result))
             else:
                 # Cleaner to leave as print than to mutate the logger not to print timestamps.
diff --git a/core/dbt/tests/fixtures/project.py b/core/dbt/tests/fixtures/project.py
index 45bb9c99210..6240da33abf 100644
--- a/core/dbt/tests/fixtures/project.py
+++ b/core/dbt/tests/fixtures/project.py
@@ -474,7 +474,7 @@ 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)
+    setup_event_logger(logs_dir, "json", False, False, False, False)
     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


Code review comments:
diff_hunk: @@ -133,7 +140,7 @@ def cleanup_event_logger():
 EVENT_MANAGER.add_logger(
     _get_logbook_log_config(debug=False)  # type: ignore
     if ENABLE_LEGACY_LOGGER
-    else _get_stdout_config(log_format="text", debug=False, use_colors=True)  # type: ignore
+    else _get_stdout_config(log_format="text", debug=False, use_colors=True, log_cache_events=True, quiet=False)  # type: ignore
path: core/dbt/events/functions.py
text: @user2:
I think we'll want `log_cache_events=False` by default

FYI @user1 since you're:
- assigned to #6979
- thinking about how to handle `--quiet` in the default logger, before we have full config (#6847) — it's just being set to `False` here

To be honest, I don't know if it's possible, and it might be motivation for us to really finally uncouple `UserConfig` from `profiles.yml` (#6207), so that we can have a configured logger before we need to parse the profile (and encounter any warnings)