diff --git a/CHANGELOG.md b/CHANGELOG.md index 446e770173d..f0c25562006 100644 --- a/CHANGELOG.md +++ b/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)) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 6ab07a4098a..76c1f01c633 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -40,7 +40,7 @@ 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 @@ -48,7 +48,7 @@ def setup_event_logger(log_path): 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') diff --git a/core/dbt/events/types.py b/core/dbt/events/types.py index 4ec722d2583..4d00bfaa590 100644 --- a/core/dbt/events/types.py +++ b/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" diff --git a/core/dbt/main.py b/core/dbt/main.py index fac1eca64ab..00b4e70e804 100644 --- a/core/dbt/main.py +++ b/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())) diff --git a/core/dbt/task/base.py b/core/dbt/task/base.py index 9bc6171dcda..62406c677aa 100644 --- a/core/dbt/task/base.py +++ b/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,6 +65,9 @@ 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() @@ -71,6 +75,9 @@ def pre_init_hook(cls, args): 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() diff --git a/core/dbt/task/list.py b/core/dbt/task/list.py index 8d34d2da7c5..741022c8033 100644 --- a/core/dbt/task/list.py +++ b/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()