Skip to content

Commit

Permalink
Adds logger (#16)
Browse files Browse the repository at this point in the history
* Adds logger

Signed-off-by: Alex Flom <[email protected]>

* formatting and tests

Signed-off-by: Alex Flom <[email protected]>

* chore: updates logging statements added post-rebase

Signed-off-by: Jennifer Power <[email protected]>

* Update tests/trestlebot/test_cli.py

Updates test description comment

---------

Signed-off-by: Alex Flom <[email protected]>
Signed-off-by: Jennifer Power <[email protected]>
Co-authored-by: Jennifer Power <[email protected]>
  • Loading branch information
Alex Flom and jpower432 committed Jul 10, 2023
1 parent 68dca61 commit aebe98e
Show file tree
Hide file tree
Showing 8 changed files with 161 additions and 61 deletions.
22 changes: 9 additions & 13 deletions tests/trestlebot/test_cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,6 @@

"""Test for CLI"""

import logging
import sys
from typing import List

Expand Down Expand Up @@ -47,7 +46,7 @@ def args_dict_to_list(args_dict: dict) -> List[str]:
return args


def test_invalid_oscal_model(monkeypatch, valid_args_dict, caplog):
def test_invalid_oscal_model(monkeypatch, valid_args_dict, capsys):
"""Test invalid oscal model"""
args_dict = valid_args_dict
args_dict["oscal-model"] = "fake"
Expand All @@ -56,15 +55,14 @@ def test_invalid_oscal_model(monkeypatch, valid_args_dict, caplog):
with pytest.raises(SystemExit):
cli_main()

assert any(
record.levelno == logging.ERROR
and record.message
== "Invalid value fake for oscal model. Please use catalog, profile, compdef, or ssp."
for record in caplog.records
captured = capsys.readouterr()
assert (
"Invalid value fake for oscal model. Please use catalog, profile, compdef, or ssp."
in captured.err
)


def test_no_ssp_index(monkeypatch, valid_args_dict, caplog):
def test_no_ssp_index(monkeypatch, valid_args_dict, capsys):
"""Test missing index file for ssp"""
args_dict = valid_args_dict
args_dict["oscal-model"] = "ssp"
Expand All @@ -74,8 +72,6 @@ def test_no_ssp_index(monkeypatch, valid_args_dict, caplog):
with pytest.raises(SystemExit):
cli_main()

assert any(
record.levelno == logging.ERROR
and record.message == "Must set ssp_index_path when using SSP as oscal model."
for record in caplog.records
)
captured = capsys.readouterr()

assert "Must set ssp_index_path when using SSP as oscal model." in captured.err
18 changes: 8 additions & 10 deletions trestlebot/bot.py
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,6 @@
"""This module implements functions for the Trestle Bot."""

import logging
import sys
from typing import List, Optional

from git import GitCommandError
Expand All @@ -27,9 +26,7 @@
from trestlebot.tasks.base_task import TaskBase, TaskException


logging.basicConfig(
format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO
)
logger = logging.getLogger(__name__)


class RepoException(Exception):
Expand All @@ -41,14 +38,15 @@ class RepoException(Exception):
def _stage_files(gitwd: Repo, patterns: List[str]) -> None:
"""Stages files in git based on file patterns"""
for pattern in patterns:
gitwd.index.add(pattern)
if pattern == ".":
logging.info("Staging all repository changes")
logger.info("Staging all repository changes")
# Using check to avoid adding git directory
# https://github.com/gitpython-developers/GitPython/issues/292
gitwd.git.add(all=True)
return
else:
logging.info(f"Adding file for pattern {pattern}")
logger.info(f"Adding file for pattern {pattern}")
gitwd.git.add(pattern)


Expand Down Expand Up @@ -144,7 +142,7 @@ def run(
)

if dry_run:
logging.info("Dry run mode is enabled. Do not push to remote.")
logger.info("Dry run mode is enabled. Do not push to remote.")
return commit_sha

try:
Expand All @@ -154,14 +152,14 @@ def run(
# Push changes to the remote repository
remote.push(refspec=f"HEAD:{branch}")

logging.info(f"Changes pushed to {branch} successfully.")
logger.info(f"Changes pushed to {branch} successfully.")
return commit_sha

except GitCommandError as e:
raise RepoException(f"Git push to {branch} failed: {e}") from e
else:
logging.info("Nothing to commit")
logger.info("Nothing to commit")
return commit_sha
else:
logging.info("Nothing to commit")
logger.info("Nothing to commit")
return commit_sha
20 changes: 10 additions & 10 deletions trestlebot/cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,16 +22,14 @@
import sys
from typing import List

from trestlebot import bot
from trestlebot import bot, log
from trestlebot.tasks.assemble_task import AssembleTask
from trestlebot.tasks.authored import types
from trestlebot.tasks.base_task import TaskBase
from trestlebot.tasks.regenerate_task import RegenerateTask


logging.basicConfig(
format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO
)
logger = logging.getLogger("trestlebot")


def _parse_cli_arguments() -> argparse.Namespace:
Expand Down Expand Up @@ -141,13 +139,15 @@ def handle_exception(
exception: Exception, msg: str = "Exception occurred during execution"
) -> int:
"""Log the exception and return the exit code"""
logging.exception(msg + f": {exception}")
logger.error(msg + f": {exception}")

return 1


def run() -> None:
"""Trestle Bot entry point function."""
log.set_global_logging_levels()

args = _parse_cli_arguments()
pre_tasks: List[TaskBase] = []

Expand All @@ -157,18 +157,18 @@ def run() -> None:

if args.oscal_model:
if args.oscal_model not in authored_list:
logging.error(
logger.error(
f"Invalid value {args.oscal_model} for oscal model. "
f"Please use catalog, profile, compdef, or ssp."
)
sys.exit(1)

if not args.markdown_path:
logging.error("Must set markdown path with assemble model.")
logger.error("Must set markdown path with assemble model.")
sys.exit(1)

if args.oscal_model == "ssp" and args.ssp_index_path == "":
logging.error("Must set ssp_index_path when using SSP as oscal model.")
logger.error("Must set ssp_index_path when using SSP as oscal model.")
sys.exit(1)

# Assuming an edit has occurred assemble would be run before regenerate.
Expand All @@ -183,7 +183,7 @@ def run() -> None:
)
pre_tasks.append(assemble_task)
else:
logging.info("Assemble task skipped")
logger.info("Assemble task skipped")

if not args.skip_regenerate:
regenerate_task = RegenerateTask(
Expand All @@ -195,7 +195,7 @@ def run() -> None:
)
pre_tasks.append(regenerate_task)
else:
logging.info("Regeneration task skipped")
logger.info("Regeneration task skipped")

exit_code: int = 0

Expand Down
134 changes: 134 additions & 0 deletions trestlebot/log.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,134 @@
# -*- mode:python; coding:utf-8 -*-

# Copyright (c) 2020 IBM Corp. All rights reserved.
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
# https://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.
"""Common logging utilities."""
import argparse
import logging
import sys
from types import TracebackType
from typing import Optional, Type


# Singleton logger instance
# All other CLI sub module will inherit settings of this logger as long as
# sub-module instantiates a logger with a prefix 'trestlebot' or __name__
_logger = logging.getLogger("trestlebot")


class SpecificLevelFilter(logging.Filter):
"""
Filter for the same level as provided by setLevel for a log handler.
Python by default logs all levels above to a given destination.
This makes it easy to split levels where you might
log all levels to file and only errors to std.err,
however, does not allow logging a specific level elsewhere.
"""

def __init__(self, level: int) -> None:
"""Initialize providing maximum level to be pushed through the filter."""
self._level = level

def filter(self, log_record: logging.LogRecord) -> bool: # noqa: A003
"""Filter log messages."""
return log_record.levelno == self._level


def set_global_logging_levels(level: int = logging.INFO) -> None:
"""Initialise logging.
Should only be invoked by the CLI classes or similar.
"""
# This line stops default root loggers setup for a python context from logging extra messages.
# DO NOT USE THIS COMMAND directly from an SDK. Handle logs levels based on your own application
_logger.propagate = False
# Remove handlers
_logger.handlers.clear()
# set global level
_logger.setLevel(level)
# Create standard out
console_out_handler = logging.StreamHandler(sys.stdout)
console_out_handler.setLevel(logging.INFO)
console_out_handler.addFilter(SpecificLevelFilter(logging.INFO))

console_debug_handler = logging.StreamHandler(sys.stdout)
console_debug_handler.setLevel(logging.DEBUG)
console_debug_handler.addFilter(SpecificLevelFilter(logging.DEBUG))

console_error_handler = logging.StreamHandler(sys.stderr)
console_error_handler.setLevel(logging.WARNING)
# create formatters
error_formatter = logging.Formatter(
"%(name)s:%(lineno)d %(levelname)s: %(message)s"
)
debug_formatter = logging.Formatter(
"%(name)s:%(lineno)d %(levelname)s: %(message)s"
)
console_debug_handler.setFormatter(debug_formatter)
console_error_handler.setFormatter(error_formatter)
# add ch to logger
_logger.addHandler(console_out_handler)
_logger.addHandler(console_error_handler)
_logger.addHandler(console_debug_handler)


def _exception_handler(
exception_type: Type[BaseException],
exception: BaseException,
traceback: Optional[TracebackType],
) -> None:
"""Empty exception handler to prevent stack traceback in quiet mode."""
logging.warning(exception)


def _get_trace_level() -> int:
"""Get special value used for trace - just below DEBUG."""
return logging.DEBUG - 5


def set_log_level_from_args(args: argparse.Namespace) -> None:
"""Vanity function to automatically set log levels based on verbosity flags."""
if args.verbose > 1:
# these msgs only output by trace calls
set_global_logging_levels(_get_trace_level())
elif args.verbose == 1:
set_global_logging_levels(logging.DEBUG)
else:
set_global_logging_levels(logging.INFO)
sys.excepthook = _exception_handler


def get_current_verbosity_level(logger: logging.Logger) -> int:
"""Get the current verbosity level based on logging level."""
level = logger.getEffectiveLevel()
if level < logging.DEBUG:
return 2
elif level == logging.DEBUG:
return 1
return 0


class Trace:
"""Class allowing low priority trace message when verbose > 1 and log level below DEBUG."""

def __init__(self, logger: logging.Logger) -> None:
"""Store the main logger with its module name."""
self._logger = logger

def log(self, msg: str) -> None:
"""Output the trace msg if log level is below DEBUG."""
level = self._logger.getEffectiveLevel()
if level < logging.DEBUG:
self._logger.debug(msg)
7 changes: 0 additions & 7 deletions trestlebot/tasks/authored/catalog.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,8 @@

"""Trestle Bot functions for catalog authoring"""

import logging
import os
import pathlib
import sys

from trestle.common.err import TrestleError
from trestle.core.commands.author.catalog import CatalogAssemble, CatalogGenerate
Expand All @@ -31,11 +29,6 @@
)


logging.basicConfig(
format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO
)


class AuthoredCatalog(AuthorObjectBase):
"""
Class for authoring OSCAL catalogs in automation
Expand Down
7 changes: 0 additions & 7 deletions trestlebot/tasks/authored/compdef.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,8 @@

"""Trestle Bot functions for component definition authoring"""

import logging
import os
import pathlib
import sys

from trestle.common.err import TrestleError
from trestle.core.commands.author.component import ComponentAssemble, ComponentGenerate
Expand All @@ -31,11 +29,6 @@
)


logging.basicConfig(
format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO
)


class AuthoredComponentsDefinition(AuthorObjectBase):
"""
Class for authoring OSCAL Component Definitions in automation
Expand Down
7 changes: 0 additions & 7 deletions trestlebot/tasks/authored/profile.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,8 @@

"""Trestle Bot functions for profile authoring"""

import logging
import os
import pathlib
import sys

from trestle.common.err import TrestleError
from trestle.core.commands.author.profile import ProfileAssemble, ProfileGenerate
Expand All @@ -31,11 +29,6 @@
)


logging.basicConfig(
format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO
)


class AuthoredProfile(AuthorObjectBase):
"""
Class for authoring OSCAL Profiles in automation
Expand Down
Loading

0 comments on commit aebe98e

Please sign in to comment.