Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 6 commits into from
May 21, 2024
Merged
Show file tree
Hide file tree
Changes from 5 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 6 additions & 0 deletions .changes/unreleased/Features-20240515-161106.yaml
Original file line number Diff line number Diff line change
@@ -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"
16 changes: 14 additions & 2 deletions dbt_common/events/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@
from dbt_common.events.format import timestamp_to_datetime_string
from dbt_common.utils.encoding import ForgivingJSONEncoder

from dbt_common.events.types_pb2 import PrintEvent
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be nice if we could avoid importing from types_pb2 if we can, because those classes don't always behave like "real" Python classes and it would be nice to isolate the importing of those classes to just the matching xxx_types.py files. Could we look at msg.info.name instead? It should be the string "PrintEvent".

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks!! This also makes it easier if we need to do some expansion.


# A Filter is a function which takes a BaseEvent and returns True if the event
# should be logged, False otherwise.
Filter = Callable[[EventMsg], bool]
Expand Down Expand Up @@ -120,7 +122,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 isinstance(msg.data, PrintEvent):
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@peterallenwebb This is a draft to help me understand some way of achieving the goal. Let's discuss Monday and see what you think.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks like the best way to achieve what we want, the only drawback is we can not have core inherent this event and define new ones since the proto namespace will change.

level = "error"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not following why this happens?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is to make sure the PrintEvent still makes it to stdout even when quiet is specified. Let me add a comment since it is not obvious

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

else:
level = msg.info.level
send_to_logger(self._python_logger, level, line)

def flush(self):
if self._python_logger is not None:
Expand All @@ -138,8 +147,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 isinstance(msg.data, PrintEvent):
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:
Expand Down
10 changes: 10 additions & 0 deletions dbt_common/events/types.proto
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
11 changes: 11 additions & 0 deletions dbt_common/events/types.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
107 changes: 56 additions & 51 deletions dbt_common/events/types_pb2.py

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

40 changes: 40 additions & 0 deletions tests/unit/events/test_logger.py
Original file line number Diff line number Diff line change
@@ -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",
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@peterallenwebb level is expected

"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
1 change: 1 addition & 0 deletions tests/unit/test_events.py
Original file line number Diff line number Diff line change
Expand Up @@ -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):
Expand Down
Loading