add formatting events into json logs (#8308)

* add formatting events into json logs

* changelog

* Delete Under the Hood-20230803-100811.yaml

core/dbt/events/functions.py

@@ -2,7 +2,7 @@
 from dbt.events.base_types import BaseEvent, EventLevel, EventMsg
 from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter, IEventManager
 from dbt.events.helpers import env_secrets, scrub_secrets
-from dbt.events.types import Formatting, Note
+from dbt.events.types import Note
 from dbt.flags import get_flags, ENABLE_LEGACY_LOGGER
 from dbt.logger import GLOBAL_LOGGER, make_log_dir_if_missing
 from functools import partial
@@ -115,9 +115,7 @@ def _stdout_filter(
     line_format: LineFormat,
     msg: EventMsg,
 ) -> bool:
-    return (msg.info.name not in ["CacheAction", "CacheDumpGraph"] or log_cache_events) and not (
-        line_format == LineFormat.Json and type(msg.data) == Formatting
-    )
+    return msg.info.name not in ["CacheAction", "CacheDumpGraph"] or log_cache_events
 
 
 def _get_logfile_config(
@@ -140,10 +138,8 @@ def _get_logfile_config(
 
 
 def _logfile_filter(log_cache_events: bool, line_format: LineFormat, msg: EventMsg) -> bool:
-    return (
-        msg.info.code not in nofile_codes
-        and not (msg.info.name in ["CacheAction", "CacheDumpGraph"] and not log_cache_events)
-        and not (line_format == LineFormat.Json and type(msg.data) == Formatting)
+    return msg.info.code not in nofile_codes and not (
+        msg.info.name in ["CacheAction", "CacheDumpGraph"] and not log_cache_events
     )
 
 

tests/functional/logging/test_logging.py

@@ -68,6 +68,26 @@ def test_basic(project, logs_dir):
             assert "orig_conn_name" in data and data["orig_conn_name"]
 
 
+def test_formatted_logs(project, logs_dir):
+    # a basic run of dbt with a single model should have 5 `Formatting` events in the json logs
+    results = run_dbt(["--log-format=json", "run"])
+    assert len(results) == 1
+
+    # get log file
+    json_log_file = read_file(logs_dir, "dbt.log")
+    formatted_json_lines = 0
+    for log_line in json_log_file.split("\n"):
+        # skip the empty line at the end
+        if len(log_line) == 0:
+            continue
+        log_dct = json.loads(log_line)
+        log_event = log_dct["info"]["name"]
+        if log_event == "Formatting":
+            formatted_json_lines += 1
+
+    assert formatted_json_lines == 5
+
+
 def test_invalid_event_value(project, logs_dir):
     results = run_dbt(["--log-format=json", "run"])
     assert len(results) == 1