Skip to content

logger: check isatty stream to print colored logs or not instead of depending on colorama (#8993 #8993

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.

Sign up for GitHub

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

Merged
skshetry merged 1 commit into from
Feb 9, 2023
Merged

logger: check isatty stream to print colored logs or not instead of depending on colorama (#8993 #8993

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
93 changes: 42 additions & 51 deletions dvc/logger.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -87,55 +87,55 @@ class ColorFormatter(logging.Formatter):
exception cause, just the message and the traceback.
"""

color_code = {
reset = colorama.Fore.RESET
color_codes = {
"TRACE": colorama.Fore.GREEN,
"DEBUG": colorama.Fore.BLUE,
"WARNING": colorama.Fore.YELLOW,
"ERROR": colorama.Fore.RED,
"CRITICAL": colorama.Fore.RED,
}

def format(self, record): # noqa: A003
def __init__(self, log_colors: bool = True) -> None:
super().__init__()
self.log_colors = log_colors

def format(self, record) -> str: # noqa: A003, C901
record.message = record.getMessage()
msg = self.formatMessage(record)

if record.levelname == "INFO":
if record.levelno == logging.INFO:
return msg

if record.exc_info:
if getattr(record, "tb_only", False):
cause = ""
else:
cause = ": ".join(_iter_causes(record.exc_info[1]))

msg = "{message}{separator}{cause}".format(
message=msg or "",
separator=" - " if msg and cause else "",
cause=cause,
)

if _is_verbose():
msg += _stack_trace(record.exc_info)

return "{asctime}{color}{levelname}{nc}: {msg}".format(
asctime=self.formatTime(record, self.datefmt),
color=self.color_code[record.levelname],
nc=colorama.Fore.RESET,
levelname=record.levelname,
msg=msg,
)

def formatTime(self, record, datefmt=None):
# only show if current level is set to DEBUG
# also, skip INFO as it is used for UI
if not _is_verbose() or record.levelno == logging.INFO:
return ""

return "{green}{date}{nc} ".format(
green=colorama.Fore.GREEN,
date=super().formatTime(record, datefmt),
nc=colorama.Fore.RESET,
)
ei = record.exc_info
if ei:
cause = ""
if not getattr(record, "tb_only", False):
cause = ": ".join(_iter_causes(ei[1]))
sep = " - " if msg and cause else ""
msg = msg + sep + cause

asctime = ""
if _is_verbose():
asctime = self.formatTime(record, self.datefmt)
if ei and not record.exc_text:
record.exc_text = self.formatException(ei)
if record.exc_text:
if msg[-1:] != "\n":
msg = msg + "\n"
msg = msg + record.exc_text + "\n"
if record.stack_info:
if msg[-1:] != "\n":
msg = msg + "\n"
msg = msg + self.formatStack(record.stack_info) + "\n"

level = record.levelname
if self.log_colors:
color = self.color_codes[level]
if asctime:
asctime = color + asctime + self.reset
level = color + level + self.reset
return asctime + (" " if asctime else "") + level + ": " + msg


class LoggerHandler(logging.StreamHandler):
Expand Down Expand Up @@ -180,17 +180,6 @@ def _iter_causes(exc):
exc = exc.__cause__


def _stack_trace(exc_info):
import traceback

return "\n{red}{line}{nc}\n{trace}{red}{line}{nc}".format(
red=colorama.Fore.RED,
line="-" * 60,
trace="".join(traceback.format_exception(*exc_info)),
nc=colorama.Fore.RESET,
)


def disable_other_loggers():
logging.captureWarnings(True)
loggerDict = logging.root.manager.loggerDict # pylint: disable=no-member
Expand All @@ -204,9 +193,10 @@ def set_loggers_level(level: int = logging.INFO) -> None:
logging.getLogger(name).setLevel(level)


def setup(level: int = logging.INFO) -> None:
def setup(level: int = logging.INFO, log_colors: bool = True) -> None:
colorama.init()
formatter = ColorFormatter()

formatter = ColorFormatter(log_colors=log_colors and sys.stdout.isatty())

console_info = LoggerHandler(sys.stdout)
console_info.setLevel(logging.INFO)
Expand All @@ -225,9 +215,10 @@ def setup(level: int = logging.INFO) -> None:
console_trace.setFormatter(formatter)
console_trace.addFilter(exclude_filter(logging.DEBUG))

err_formatter = ColorFormatter(log_colors=log_colors and sys.stderr.isatty())
console_errors = LoggerHandler(sys.stderr)
console_errors.setLevel(logging.WARNING)
console_errors.setFormatter(formatter)
console_errors.setFormatter(err_formatter)

for name in ["dvc", "dvc_objects", "dvc_data"]:
logger = logging.getLogger(name)
Expand Down
30 changes: 9 additions & 21 deletions tests/unit/test_logger.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ def test_debug(self, caplog, dt):
with caplog.at_level(logging.DEBUG, logger="dvc"):
logger.debug("message")

expected = "{green}{datetime}{nc} {blue}DEBUG{nc}: message".format(
expected = "{blue}{datetime}{nc} {blue}DEBUG{nc}: message".format(
**colors, datetime=dt
)

Expand Down Expand Up @@ -103,12 +103,9 @@ def test_exception_under_verbose(self, caplog, dt):
logger.exception("")

expected = (
"{green}{datetime}{nc} "
"{red}{datetime}{nc} "
"{red}ERROR{nc}: description\n"
"{red}{line}{nc}\n"
"{stack_trace}"
"{red}{line}{nc}".format(
line="-" * 60,
"{stack_trace}".format(
stack_trace=stack_trace,
**colors,
datetime=dt,
Expand All @@ -126,12 +123,9 @@ def test_exc_info_on_other_record_types(self, caplog, dt):
logger.debug("", exc_info=True)

expected = (
"{green}{datetime}{nc} "
"{blue}{datetime}{nc} "
"{blue}DEBUG{nc}: description\n"
"{red}{line}{nc}\n"
"{stack_trace}"
"{red}{line}{nc}".format(
line="-" * 60,
"{stack_trace}".format(
stack_trace=stack_trace,
datetime=dt,
**colors,
Expand All @@ -149,12 +143,9 @@ def test_tb_only(self, caplog, dt):
logger.exception("something", extra={"tb_only": True})

expected = (
"{green}{datetime}{nc} "
"{red}{datetime}{nc} "
"{red}ERROR{nc}: something\n"
"{red}{line}{nc}\n"
"{stack_trace}"
"{red}{line}{nc}".format(
line="-" * 60,
"{stack_trace}".format(
stack_trace=stack_trace,
**colors,
datetime=dt,
Expand All @@ -175,12 +166,9 @@ def test_nested_exceptions(self, caplog, dt):
logger.exception("message")

expected = (
"{green}{datetime}{nc} "
"{red}{datetime}{nc} "
"{red}ERROR{nc}: message - second: first\n"
"{red}{line}{nc}\n"
"{stack_trace}"
"{red}{line}{nc}".format(
line="-" * 60,
"{stack_trace}".format(
stack_trace=stack_trace,
**colors,
datetime=dt,
Expand Down