Create a print Event to replace the print usage in dbt-core (#130)

* first_iter

* add tests

* nits

* comment

* check using name

.changes/unreleased/Features-20240515-161106.yaml

@@ -0,0 +1,6 @@
+kind: Features
+body: Add a print event to support firing event to console in --quiet mode
+time: 2024-05-15T16:11:06.815526-07:00
+custom:
+  Author: ChenyuLInx
+  Issue: "8756"

dbt_common/events/logger.py

@@ -13,6 +13,13 @@
 from dbt_common.events.format import timestamp_to_datetime_string
 from dbt_common.utils.encoding import ForgivingJSONEncoder
 
+PRINT_EVENT_NAME = "PrintEvent"
+
+
+def _is_print_event(msg: EventMsg) -> bool:
+    return msg.info.name == PRINT_EVENT_NAME
+
+
 # A Filter is a function which takes a BaseEvent and returns True if the event
 # should be logged, False otherwise.
 Filter = Callable[[EventMsg], bool]
@@ -120,7 +127,14 @@ def create_line(self, msg: EventMsg) -> str:
     def write_line(self, msg: EventMsg):
         line = self.create_line(msg)
         if self._python_logger is not None:
-            send_to_logger(self._python_logger, msg.info.level, line)
+            # We send PrintEvent to logger as error so it goes to stdout
+            # when --quiet flag is set.
+            # --quiet flag will filter out all events lower than ERROR.
+            if _is_print_event(msg):
+                level = "error"
+            else:
+                level = msg.info.level
+            send_to_logger(self._python_logger, level, line)
 
     def flush(self):
         if self._python_logger is not None:
@@ -138,8 +152,11 @@ def create_line(self, msg: EventMsg) -> str:
         return self.create_debug_line(msg) if self.use_debug_format else self.create_info_line(msg)
 
     def create_info_line(self, msg: EventMsg) -> str:
-        ts: str = datetime.utcnow().strftime("%H:%M:%S")
         scrubbed_msg: str = self.scrubber(msg.info.msg)  # type: ignore
+        if _is_print_event(msg):
+            # PrintEvent is a special case, we don't want to add a timestamp
+            return scrubbed_msg
+        ts: str = datetime.utcnow().strftime("%H:%M:%S")
         return f"{self._get_color_tag()}{ts}  {scrubbed_msg}"
 
     def create_debug_line(self, msg: EventMsg) -> str:

dbt_common/events/types.proto

@@ -119,3 +119,13 @@ message NoteMsg {
     EventInfo info = 1;
     Note data = 2;
 }
+
+// Z052
+message PrintEvent {
+    string msg = 1;
+}
+
+message PrintEventMsg {
+    EventInfo info = 1;
+    PrintEvent data = 2;
+}

dbt_common/events/types.py

@@ -125,3 +125,14 @@ def code(self) -> str:
 
     def message(self) -> str:
         return self.msg
+
+
+class PrintEvent(InfoLevel):
+    # Use this event to skip any formatting and just print a message
+    # This event will get to stdout even if the logger is set to ERROR
+    # This is to support commands that want --quiet option but also log something to stdout
+    def code(self) -> str:
+        return "Z052"
+
+    def message(self) -> str:
+        return self.msg

tests/unit/events/test_logger.py

@@ -0,0 +1,40 @@
+import json
+from dbt_common.events.logger import LoggerConfig, _TextLogger, _JsonLogger
+from dbt_common.events.base_types import EventLevel, msg_from_base_event
+from dbt_common.events.types import PrintEvent
+
+
+def test_create_print_line():
+    # No format, still fired even when error is the level
+    config = LoggerConfig(name="test_logger", level=EventLevel.ERROR)
+    logger = _TextLogger(config)
+    msg = msg_from_base_event(PrintEvent(msg="This is a print event"))
+    expected_line = "This is a print event"
+    actual_line = logger.create_line(msg)
+    assert actual_line == expected_line
+
+
+def test_create_print_json():
+    # JSON format still have event level being info
+    config = LoggerConfig(name="test_logger", level=EventLevel.ERROR)
+    logger = _JsonLogger(config)
+    msg = msg_from_base_event(PrintEvent(msg="This is a print event"))
+    expected_json = {
+        "data": {"msg": "This is a print event"},
+        "info": {
+            "category": "",
+            "code": "Z052",
+            "extra": {},
+            "level": "info",
+            "msg": "This is a print event",
+            "name": "PrintEvent",
+            "thread": "MainThread",
+        },
+    }
+    actual_line = logger.create_line(msg)
+    actual_json = json.loads(actual_line)
+    assert "info" in actual_json
+    actual_json["info"].pop("invocation_id")
+    actual_json["info"].pop("ts")
+    actual_json["info"].pop("pid")
+    assert actual_json == expected_json

tests/unit/test_events.py

@@ -72,6 +72,7 @@ class TestEventJSONSerialization:
         types.SystemReportReturnCode(returncode=0),
         types.Formatting(),
         types.Note(msg="This is a note."),
+        types.PrintEvent(msg="This is a print event."),
     ]
 
     def test_all_serializable(self):