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.

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

Jump to bottom

Remove unnecessary FILE log level #741

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

Remove unnecessary FILE log level #741

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
58 changes: 24 additions & 34 deletions convert2rhel/logger.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,8 +23,6 @@
INFO (20) Prints info message (no date/time, just plain message)
TASK (15) CUSTOM LABEL - Prints a task header message (using asterisks)
DEBUG (10) Prints debug message (using date/time)
FILE (5) CUSTOM LABEL - Outputs with the DEBUG label but only to a file
handle (using date/time)
"""
import logging
import os
Expand Down Expand Up @@ -81,52 +79,47 @@ class LogLevelTask(object):
label = "TASK"


class LogLevelFile(object):
level = 5
# Label messages DEBUG as it is contains the same messages as debug, just that they always go
# to the log file.
label = "DEBUG"


def setup_logger_handler(log_name, log_dir):
"""Setup custom logging levels, handlers, and so on. Call this method
from your application's main start point.
log_name = the name for the log file
log_dir = path to the dir where log file will be presented
"""
# set custom labels
# set the TASK custom label
logging.addLevelName(LogLevelTask.level, LogLevelTask.label)
logging.addLevelName(LogLevelFile.level, LogLevelFile.label)
logging.Logger.task = _task
logging.Logger.file = _file
logging.Logger.debug = _debug
logging.Logger.critical = _critical

# enable raising exceptions
logging.raiseExceptions = True
# get root logger
# get the highest level app logger
logger = logging.getLogger("convert2rhel")
# propagate
# propagate log messages up to the root logger to be able to capture them in unit tests
# refence: https://github.com/oamg/convert2rhel/pull/179
logger.propagate = True
# set default logging level
logger.setLevel(LogLevelFile.level)
# set the DEBUG level as the lowest allowed level to be handled by convert2rhel
logger.setLevel(logging.DEBUG)

# create sys.stdout handler for info/debug
stdout_handler = logging.StreamHandler(sys.stdout)
formatter = CustomFormatter("%(message)s")
formatter.disable_colors(should_disable_color_output())
stdout_handler.setFormatter(formatter)
debug_flag_filter = DebugFlagFilter()
stdout_handler.addFilter(debug_flag_filter)
# Set the DEBUG level as the lowest allowed level to be printed to stdout.
# Whether a debug message is actually printed or not is decided in DebugFlagFilter.
stdout_handler.setLevel(logging.DEBUG)
Comment on lines 107 to 112
Copy link
Member

Choose a reason for hiding this comment

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

Does it not work to set this to logging.DEBUG if --debug is given, otherwise set it to loggin.INFO? (If the problem is a circular dependency [Need toolopts to know if --debug was given but toolopts requires that logging has been setup in case it needs to log its values, the way that I've setup logging in other projects is to have two phases. Phase 1 sets it up with default values. Then parse the command line, read the config file, consult environment variables, etc. Then Phase 2, reconfigure portions of logging that user settings can affect.

That's a bigger change than this, but I think it's better structure. And at the risk of premature optimization, it's also less work for the computer. Adjusting the log level results in less work being done if the log message is at a less important level. Setting a filter results in more work being done for every log message emitted.

Copy link
Member

Choose a reason for hiding this comment

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

It is definitely due to circular dependencies, but another thing IIRC is about the log files we touch. We had some bug a few years ago that caused us to not log correctly or that the tool didn't work. Hence doing it after toolopts is initialized. We can take a look later if we can change this

logger.addHandler(stdout_handler)

# create file handler
# create a log file handler
if not os.path.isdir(log_dir):
os.makedirs(log_dir) # pragma: no cover
handler = logging.FileHandler(os.path.join(log_dir, log_name), "a")
formatter = CustomFormatter("%(message)s")
formatter.disable_colors(True)
handler.setFormatter(formatter)
handler.setLevel(LogLevelFile.level)
handler.setLevel(logging.DEBUG)
logger.addHandler(handler)


Expand All @@ -143,6 +136,18 @@ def should_disable_color_output():
return False


class DebugFlagFilter(logging.Filter):
"""Print debug messages to the stdout only when --debug is used."""

def filter(self, record):
from convert2rhel.toolopts import tool_opts

Check notice

Code scanning / CodeQL

Cyclic import

Import of module [convert2rhel.toolopts](1) begins an import cycle.
Copy link
Member

Choose a reason for hiding this comment

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

The circular import would also go away with the restructure to have an early log initialization and later log initialization. (If we put the early log initialization into the initialize.py file and leave the second configuration phase with the import convert2rhel.toolopts in this file)


if record.levelno == logging.DEBUG and not tool_opts.debug:
# not logging a debug level message if the --debug option hasn't been used
return False
return True
Comment on lines +145 to +148
Copy link
Member

Choose a reason for hiding this comment

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

Ideally I'd want to set this from within toolopts somehow no?



def archive_old_logger_files(log_name, log_dir):
"""Archive the old log files to not mess with multiple runs outputs.
Every time a new run begins, this method will be called to archive the previous logs
Expand Down Expand Up @@ -187,27 +192,12 @@ def _task(self, msg, *args, **kwargs):
self._log(LogLevelTask.level, msg, args, **kwargs)


def _file(self, msg, *args, **kwargs):
if self.isEnabledFor(LogLevelFile.level):
self._log(LogLevelFile.level, msg, args, **kwargs)


def _critical(self, msg, *args, **kwargs):
if self.isEnabledFor(logging.CRITICAL):
self._log(logging.CRITICAL, msg, args, **kwargs)
sys.exit(msg)


def _debug(self, msg, *args, **kwargs):
if self.isEnabledFor(logging.DEBUG):
from convert2rhel.toolopts import tool_opts

if tool_opts.debug:
self._log(logging.DEBUG, msg, args, **kwargs)
else:
self._log(LogLevelFile.level, msg, args, **kwargs)


class bcolors:
OKGREEN = "\033[92m"
WARNING = "\033[93m"
Expand Down
2 changes: 1 addition & 1 deletion convert2rhel/unit_tests/logger_test.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ def test_logger_custom_logger(tmpdir, caplog, clear_loggers):
logger_module.setup_logger_handler(log_name=log_fname, log_dir=str(tmpdir))
logger = logging.getLogger(__name__)
logger.task("Some task: %s", "data")
logger.file("Some task write to file: %s", "data")
logger.debug("Some task write to file: %s", "data")
with pytest.raises(SystemExit):
logger.critical("Critical error: %s", "data")

Expand Down
7 changes: 1 addition & 6 deletions convert2rhel/utils.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -367,12 +367,7 @@ def log_traceback(debug):
on the debug parameter.
"""
traceback_str = get_traceback_str()
if debug:
# Print the traceback to the user when debug option used
loggerinst.debug(traceback_str)
else:
# Print the traceback to the log file in any way
loggerinst.file(traceback_str)
loggerinst.debug(traceback_str)


def get_traceback_str():
Expand Down