Feature/66 introduce logging config

.github/workflows/test.yml

@@ -14,7 +14,7 @@
 # limitations under the License.
 #
 
-name: Test
+name: Build and Test
 on:
   pull_request:
     branches:

main.py

@@ -22,22 +22,16 @@
 from release_notes_generator.model.custom_chapters import CustomChapters
 from release_notes_generator.action_inputs import ActionInputs
 from release_notes_generator.utils.gh_action import set_action_output
-
-
-# Configure logging
-logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s')
+from release_notes_generator.utils.logging_config import setup_logging
 
 
 def run():
     """
     Runs the 'Release Notes Generator' GitHub Action.
     """
-    logging.info("Starting 'Release Notes Generator' GitHub Action")
-
-    # Enable verbose logging if specified
-    if ActionInputs.get_verbose():
-        logging.info("Verbose logging enabled")
-        logging.getLogger().setLevel(logging.DEBUG)
+    setup_logging()
+    logger = logging.getLogger(__name__)
+    logger.info("Starting 'Release Notes Generator' GitHub Action")
 
     # Authenticate with GitHub
     py_github = Github(auth=Auth.Token(token=ActionInputs.get_github_token()), per_page=100)
@@ -48,12 +42,13 @@ def run():
     custom_chapters = (CustomChapters(print_empty_chapters=ActionInputs.get_print_empty_chapters())
                        .from_json(ActionInputs.get_chapters_json()))
 
-    rls_notes = ReleaseNotesGenerator(py_github, custom_chapters).generate()
-    logging.debug("Release notes: \n%s", rls_notes)
+    generator = ReleaseNotesGenerator(py_github, custom_chapters)
+    rls_notes = generator.generate()
+    logger.debug("Release notes: \n%s", rls_notes)
 
     # Set the output for the GitHub Action
     set_action_output('release-notes', rls_notes)
-    logging.info("GitHub Action 'Release Notes Generator' completed successfully")
+    logger.info("GitHub Action 'Release Notes Generator' completed successfully")
 
 
 if __name__ == '__main__':

release_notes_generator/action_inputs.py

@@ -24,6 +24,8 @@
                                                      PRINT_EMPTY_CHAPTERS, CHAPTERS_TO_PR_WITHOUT_ISSUE)
 from release_notes_generator.utils.gh_action import get_action_input
 
+logger = logging.getLogger(__name__)
+
 
 class ActionInputs:
     @staticmethod
@@ -126,15 +128,14 @@ def validate_inputs():
         # Log errors if any
         if errors:
             for error in errors:
-                logging.error(error)
+                logger.error(error)
             sys.exit(1)
 
-        logging.debug('Repository: %s/%s', owner, repo_name)
-        logging.debug('Tag name: %s', tag_name)
-        logging.debug('Chapters JSON: %s', chapters_json)
-        logging.debug('Published at: %s', published_at)
-        logging.debug('Skip release notes label: %s', skip_release_notes_label)
-        logging.debug('Verbose logging: %s', verbose)
-        logging.debug('Warnings: %s', warnings)
-        logging.debug('Print empty chapters: %s', print_empty_chapters)
-        logging.debug('Chapters to PR without issue: %s', chapters_to_pr_without_issue)
+        logger.debug('Tag name: %s', tag_name)
+        logger.debug('Chapters JSON: %s', chapters_json)
+        logger.debug('Published at: %s', published_at)
+        logger.debug('Skip release notes label: %s', skip_release_notes_label)
+        logger.debug('Verbose logging: %s', verbose)
+        logger.debug('Warnings: %s', warnings)
+        logger.debug('Print empty chapters: %s', print_empty_chapters)
+        logger.debug('Chapters to PR without issue: %s', chapters_to_pr_without_issue)

release_notes_generator/builder.py

@@ -23,6 +23,8 @@
 from release_notes_generator.model.service_chapters import ServiceChapters
 from release_notes_generator.action_inputs import ActionInputs
 
+logger = logging.getLogger(__name__)
+
 
 # TODO - reduce to function only after implementing the features. Will be supported more build ways?
 # pylint: disable=too-few-public-methods
@@ -51,7 +53,7 @@ def build(self) -> str:
 
         @return: The release notes as a string.
         """
-        logging.info("Building Release Notes")
+        logger.info("Building Release Notes")
         user_defined_chapters = self.custom_chapters
         user_defined_chapters.populate(self.records)
         user_defined_chapters_str = user_defined_chapters.to_string()

release_notes_generator/generator.py

@@ -31,8 +31,7 @@
 from release_notes_generator.utils.utils import get_change_url
 from release_notes_generator.utils.github_rate_limiter import GithubRateLimiter
 
-# Configure logging
-logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s')
+logger = logging.getLogger(__name__)
 
 
 class ReleaseNotesGenerator:
@@ -66,7 +65,7 @@ def generate(self) -> Optional[str]:
 
         rls = self._safe_call(repo.get_latest_release)()
         if rls is None:
-            logging.info("Latest release not found for %s. 1st release for repository!", repo.full_name)
+            logger.info("Latest release not found for %s. 1st release for repository!", repo.full_name)
 
         # default is repository creation date if no releases OR created_at of latest release
         since = rls.created_at if rls else repo.created_at
@@ -78,14 +77,14 @@ def generate(self) -> Optional[str]:
         commits = commits_all = list(self._safe_call(repo.get_commits)())
 
         if rls is not None:
-            logging.info("Count of issues: %d", len(list(issues)))
+            logger.info("Count of issues: %d", len(list(issues)))
 
             # filter out merged PRs and commits before the since date
             pulls = list(filter(lambda pull: pull.merged_at is not None and pull.merged_at > since, list(pulls_all)))
-            logging.debug("Count of pulls reduced from %d to %d", len(list(pulls_all)), len(pulls))
+            logger.debug("Count of pulls reduced from %d to %d", len(list(pulls_all)), len(pulls))
 
             commits = list(filter(lambda commit: commit.commit.author.date > since, list(commits_all)))
-            logging.debug("Count of commits reduced from %d to %d", len(list(commits_all)), len(commits))
+            logger.debug("Count of commits reduced from %d to %d", len(list(commits_all)), len(commits))
 
         changelog_url = get_change_url(tag_name=ActionInputs.get_tag_name(), repository=repo, git_release=rls)
 

release_notes_generator/model/record.py

@@ -26,6 +26,8 @@
     RELEASE_NOTE_DETECTION_PATTERN, RELEASE_NOTE_LINE_MARK)
 from release_notes_generator.utils.pull_reuqest_utils import extract_issue_numbers_from_body
 
+logger = logging.getLogger(__name__)
+
 
 # TODO - recheck the size of class, is there a way to reduce or split it?
 # pylint: disable=too-many-instance-attributes, too-many-public-methods
@@ -328,7 +330,7 @@ def register_commit(self, commit: Commit):
                 self.__pull_commits[pull.number].append(commit)
                 return
 
-        logging.error("Commit %s not registered in any PR of record %s", commit.sha, self.number)
+        logger.error("Commit %s not registered in any PR of record %s", commit.sha, self.number)
 
     # TODO in Issue named 'Chapter line formatting - default'
     def to_chapter_row(self, row_format="", increment_in_chapters=True) -> str:

release_notes_generator/record/record_factory.py

@@ -28,6 +28,8 @@
 from release_notes_generator.utils.github_rate_limiter import GithubRateLimiter
 from release_notes_generator.utils.pull_reuqest_utils import extract_issue_numbers_from_body
 
+logger = logging.getLogger(__name__)
+
 
 # pylint: disable=too-few-public-methods
 class RecordFactory:
@@ -54,12 +56,12 @@ def generate(github: Github, repo: Repository, issues: list[Issue], pulls: list[
 
         def create_record_for_issue(r: Repository, i: Issue):
             records[i.number] = Record(r, i)
-            logging.debug("Created record for issue %d: %s", i.number, i.title)
+            logger.debug("Created record for issue %d: %s", i.number, i.title)
 
         def register_pull_request(pull: PullRequest):
             for parent_issue_number in extract_issue_numbers_from_body(pull):
                 if parent_issue_number not in records:
-                    logging.warning(
+                    logger.warning(
                         "Detected PR %d linked to issue %d which is not in the list of received issues. "
                         "Fetching ...",
                         pull.number, parent_issue_number
@@ -70,12 +72,12 @@ def register_pull_request(pull: PullRequest):
 
                 if parent_issue_number in records:
                     records[parent_issue_number].register_pull_request(pull)
-                    logging.debug("Registering PR %d: %s to Issue %d",
+                    logger.debug("Registering PR %d: %s to Issue %d",
                                   pull.number, pull.title, parent_issue_number)
                 else:
                     records[pull.number] = Record(repo)
                     records[pull.number].register_pull_request(pull)
-                    logging.debug(
+                    logger.debug(
                         "Registering stand-alone PR %d: %s as mentioned Issue %d not found.",
                         pull.number, pull.title, parent_issue_number
                     )
@@ -98,12 +100,12 @@ def register_commit_to_record(commit: Commit):
             if not extract_issue_numbers_from_body(pull):
                 records[pull.number] = Record(repo)
                 records[pull.number].register_pull_request(pull)
-                logging.debug("Created record for PR %d: %s", pull.number, pull.title)
+                logger.debug("Created record for PR %d: %s", pull.number, pull.title)
             else:
                 register_pull_request(pull)
 
         detected_prs_count = sum(register_commit_to_record(commit) for commit in commits)
 
-        logging.info("Generated %d records from %d issues and %d PRs, with %d commits detected.",
+        logger.info("Generated %d records from %d issues and %d PRs, with %d commits detected.",
                      len(records), len(issues), len(pulls), detected_prs_count)
         return records

release_notes_generator/utils/decorators.py

@@ -22,16 +22,18 @@
 from requests.exceptions import Timeout, RequestException, ConnectionError as RequestsConnectionError
 from release_notes_generator.utils.github_rate_limiter import GithubRateLimiter
 
+logger = logging.getLogger(__name__)
+
 
 def debug_log_decorator(method: Callable) -> Callable:
     """
     Decorator to add debug logging for a method call.
     """
     @wraps(method)
     def wrapped(*args, **kwargs) -> Optional[Any]:
-        logging.debug("Calling method %s with args: %s and kwargs: %s", method.__name__, args, kwargs)
+        logger.debug("Calling method %s with args: %s and kwargs: %s", method.__name__, args, kwargs)
         result = method(*args, **kwargs)
-        logging.debug("Method %s returned %s", method.__name__, result)
+        logger.debug("Method %s returned %s", method.__name__, result)
         return result
     return wrapped
 
@@ -50,16 +52,16 @@ def wrapped(*args, **kwargs) -> Optional[Any]:
             try:
                 return method(*args, **kwargs)
             except (RequestsConnectionError, Timeout) as e:
-                logging.error("Network error calling %s: %s", method.__name__, e, exc_info=True)
+                logger.error("Network error calling %s: %s", method.__name__, e, exc_info=True)
                 return None
             except GithubException as e:
-                logging.error("GitHub API error calling %s: %s", method.__name__, e, exc_info=True)
+                logger.error("GitHub API error calling %s: %s", method.__name__, e, exc_info=True)
                 return None
             except RequestException as e:
-                logging.error("HTTP error calling %s: %s", method.__name__, e, exc_info=True)
+                logger.error("HTTP error calling %s: %s", method.__name__, e, exc_info=True)
                 return None
             except Exception as e:
-                logging.error("Unexpected error calling %s: %s", method.__name__, e, exc_info=True)
+                logger.error("Unexpected error calling %s: %s", method.__name__, e, exc_info=True)
                 return None
         return wrapped
     return decorator

release_notes_generator/utils/github_rate_limiter.py

@@ -20,6 +20,8 @@
 from typing import Optional, Callable
 from github import Github
 
+logger = logging.getLogger(__name__)
+
 
 # pylint: disable=too-few-public-methods
 class GithubRateLimiter:
@@ -33,7 +35,7 @@ def wrapped_method(*args, **kwargs) -> Optional:
             reset_time = self.github_client.get_rate_limit().core.reset.timestamp()
 
             if remaining_calls < 5:
-                logging.info("Rate limit almost reached. Sleeping until reset time.")
+                logger.info("Rate limit almost reached. Sleeping until reset time.")
                 sleep_time = reset_time - (now := time.time())
                 while sleep_time <= 0:
                     # Note: received values can be in the past, so the time shift to 1st positive value is needed
@@ -44,7 +46,7 @@ def wrapped_method(*args, **kwargs) -> Optional:
                 hours, remainder = divmod(total_sleep_time, 3600)
                 minutes, seconds = divmod(remainder, 60)
 
-                logging.info("Sleeping for %s hours, %s minutes, and %s seconds until %s.",
+                logger.info("Sleeping for %s hours, %s minutes, and %s seconds until %s.",
                              hours, minutes, seconds, datetime.fromtimestamp(reset_time).strftime('%Y-%m-%d %H:%M:%S'))
                 time.sleep(sleep_time + 5)  # Sleep for the calculated time plus 5 seconds
 

release_notes_generator/utils/logging_config.py

@@ -0,0 +1,51 @@
+#
+# Copyright 2024 ABSA Group Limited
+#
+# 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
+#
+#     http://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.
+#
+
+"""
+This module contains a method to set up logging in the project.
+"""
+
+import logging
+import os
+import sys
+
+
+def setup_logging() -> None:
+    """
+    Set up the logging configuration in the project
+
+    @return: None
+    """
+    # Load logging configuration from the environment variables
+    is_verbose_logging: bool = os.getenv("INPUT_VERBOSE", "false").lower() == "true"
+    is_debug_mode = os.getenv("RUNNER_DEBUG", "0") == "1"
+    level = logging.DEBUG if is_verbose_logging or is_debug_mode else logging.INFO
+
+    # Set up the logging configuration
+    logging.basicConfig(
+        level=level,
+        format="%(asctime)s - %(levelname)s - %(message)s",
+        datefmt="%Y-%m-%d %H:%M:%S",
+        handlers=[logging.StreamHandler(sys.stdout)],
+    )
+    sys.stdout.flush()
+
+    logging.info("Setting up logging configuration")
+
+    if is_debug_mode:
+        logging.debug("Debug mode enabled by CI runner")
+    if is_verbose_logging:
+        logging.debug("Verbose logging enabled")

release_notes_generator/utils/utils.py

@@ -20,6 +20,8 @@
 from github.GitRelease import GitRelease
 from github.Repository import Repository
 
+logger = logging.getLogger(__name__)
+
 
 def get_change_url(tag_name: str, repository: Optional[Repository] = None,
                    git_release: Optional[GitRelease] = None) -> Optional[str]:
@@ -32,7 +34,7 @@ def get_change_url(tag_name: str, repository: Optional[Repository] = None,
     :return: An optional string containing the URL to view the changes. Returns a None if the repository is not set.
     """
     if not repository:
-        logging.error("Get change url failed. Repository is not set.")
+        logger.error("Get change url failed. Repository is not set.")
         return ""
 
     repo = repository

tests/test_action_inputs.py

@@ -73,7 +73,7 @@ def test_validate_inputs_failure(method, value, expected_error, mocker):
     case[method] = value
     patchers = apply_mocks(case, mocker)
     try:
-        mock_error = mocker.patch('logging.error')
+        mock_error = mocker.patch('release_notes_generator.action_inputs.logger.error')
         mock_exit = mocker.patch('sys.exit')
 
         ActionInputs.validate_inputs()

tests/utils/test_decorators.py

@@ -26,7 +26,7 @@ def sample_function(x, y):
 
 def test_debug_log_decorator(mocker):
     # Mock logging
-    mock_log_debug = mocker.patch('logging.debug')
+    mock_log_debug = mocker.patch('release_notes_generator.utils.decorators.logger.debug')
 
     decorated_function = debug_log_decorator(sample_function)
     expected_call = [mocker.call("Calling method %s with args: %s and kwargs: %s", 'sample_function', (3, 4), {}),
@@ -50,7 +50,7 @@ def sample_method(x, y):
 
 
 def test_safe_call_decorator_exception(rate_limiter, mocker):
-    mock_log_error = mocker.patch('logging.error')
+    mock_log_error = mocker.patch('release_notes_generator.utils.decorators.logger.error')
 
     @safe_call_decorator(rate_limiter)
     def sample_method(x, y):