Add a logger and update the config handling

baldrick/__init__.py

@@ -1,3 +1,5 @@
+import os
+
 from baldrick import github  # noqa
 
 __all__ = ['create_app', '__version__']
@@ -32,7 +34,8 @@ def create_app(name, register_blueprints=True):
     app
 
     """
-    import os
+    # Setup loguru integration, must be run before import flask.
+    import baldrick.logging  # noqa
 
     from flask import Flask
 

baldrick/conftest.py

@@ -1,8 +1,8 @@
 import os
+import logging
 
 import pytest
-
-from baldrick import create_app
+from loguru import logger
 
 
 PRIVATE_KEY = """
@@ -38,6 +38,7 @@
 
 @pytest.fixture
 def app():
+    from baldrick import create_app
     os.environ['GITHUB_APP_INTEGRATION_ID'] = '1234'
     os.environ['GITHUB_APP_PRIVATE_KEY'] = PRIVATE_KEY
     return create_app('testbot')
@@ -46,3 +47,23 @@ def app():
 @pytest.fixture
 def client(app):
     return app.test_client()
+
+
+@pytest.fixture
+def caplog(caplog):
+    """
+    Override the default pytest caplog fixture to work with loguru.
+    """
+
+    # Remove all logging but this redirect to standard logging
+    logger.remove()
+
+    class PropogateHandler(logging.Handler):
+        def emit(self, record):
+            logging.getLogger(record.name).handle(record)
+
+    handler_id = logger.add(PropogateHandler(), format="{message}")
+
+    yield caplog
+
+    logger.remove(handler_id)

baldrick/github/github_api.py

@@ -2,22 +2,22 @@
 import base64
 import re
 import requests
-import warnings
 from datetime import datetime
 
 import dateutil.parser
 from flask import current_app
+from loguru import logger
 from ttldict import TTLOrderedDict
 
-from baldrick.config import loads
+from baldrick.config import loads, Config
 from baldrick.github.github_auth import github_request_headers
 
 __all__ = ['GitHubHandler', 'IssueHandler', 'RepoHandler', 'PullRequestHandler']
 
 HOST = "https://api.github.com"
 HOST_NONAPI = "https://github.com"
 
-cfg_cache = TTLOrderedDict(default_ttl=60 * 60)
+FILE_CACHE = TTLOrderedDict(default_ttl=60)
 
 
 def paged_github_json_request(url, headers=None):
@@ -70,20 +70,29 @@ def _headers(self):
     def _url_contents(self):
         return f'{HOST}/repos/{self.repo}/contents/'
 
-    def get_file_contents(self, path_to_file, branch=None):
-        if not branch:
-            branch = 'master'
+    def get_file_contents(self, path_to_file, branch='master'):
+        cache_key = f"{self.repo}:{path_to_file}@{branch}"
+
+        # It seems that this is the only safe way to do this with
+        # TTLOrderedDict
+        try:
+            return FILE_CACHE[cache_key]
+        except KeyError:
+            pass
+
         url_file = self._url_contents + path_to_file
         data = {'ref': branch}
         response = requests.get(url_file, params=data, headers=self._headers)
         if not response.ok and response.json()['message'] == 'Not Found':
             raise FileNotFoundError(url_file)
         assert response.ok, response.content
         contents_base64 = response.json()['content']
-        return base64.b64decode(contents_base64).decode()
+        contents = base64.b64decode(contents_base64).decode()
+
+        FILE_CACHE[cache_key] = contents
+        return contents
 
-    def get_repo_config(self, branch=None, path_to_file='pyproject.toml',
-                        warn_on_failure=True):
+    def get_repo_config(self, branch='master', path_to_file='pyproject.toml'):
         """
         Load configuration from the repository.
 
@@ -97,34 +106,43 @@ def get_repo_config(self, branch=None, path_to_file='pyproject.toml',
             Path to the ``pyproject.toml`` file in the repository. Will default
             to the root of the repository.
 
-        warn_on_failure : `bool`
-            Emit warning on failure to load the pyproject file.
-
         Returns
         -------
         cfg : `baldrick.config.Config`
             Configuration parameters.
 
         """
-        # Allow non-existent file but raise error when cannot parse
+        app_config = current_app.conf.copy()
+        fallback_config = Config()
+        repo_config = Config()
+
         try:
             file_content = self.get_file_contents(path_to_file, branch=branch)
-            return loads(file_content, tool=current_app.bot_username)
-        except Exception as e:
-            # Attempt to load the fallback config just in case
+        except FileNotFoundError:
+            logger.debug(f"No config file found in {self.repo}@{branch}.")
+            file_content = None
+
+        if file_content:
+            try:
+                repo_config = loads(file_content, tool=current_app.bot_username)
+                logger.trace(f"Got the following config from {self.repo}@{branch}: {repo_config}")
+            except Exception:
+                logger.error(
+                    f"Failed to load config in {self.repo} on branch {branch}, despite finding a pyproject.toml file.")
+
             if getattr(current_app, "fall_back_config", None):
                 try:
-                    return loads(file_content, tool=current_app.fall_back_config)
-                except Exception:  # pragma: no cover
-                    pass
+                    fallback_config = loads(file_content, tool=current_app.fall_back_config)
+                except Exception:
+                    logger.trace(f"Didn't find a fallback config in {self.repo}@{branch}.")
 
-            if warn_on_failure:
-                warnings.warn(str(e))
+        # Priority is 1) repo_config 2) fallback_config 3) app_config
+        app_config.update_from_config(fallback_config)
+        app_config.update_from_config(repo_config)
 
-            # Empty dict means calling code set the default
-            repo_config = current_app.conf.copy()
+        logger.debug(f"Got this combined config from {self.repo}@{branch}: {app_config}")
 
-        return repo_config
+        return app_config
 
     def get_config_value(self, cfg_key, cfg_default=None, branch=None):
         """
@@ -134,14 +152,7 @@ def get_config_value(self, cfg_key, cfg_default=None, branch=None):
         defined, they are extracted from the global app configuration. If this
         does not exist either, the value is set to the ``cfg_default`` argument.
         """
-
-        global cfg_cache
-
-        cfg_cache_key = (self.repo, branch, self.installation)
-        if cfg_cache_key not in cfg_cache:
-            cfg_cache[cfg_cache_key] = self.get_repo_config(branch=branch)
-
-        cfg = cfg_cache.get(cfg_cache_key, {})
+        cfg = self.get_repo_config(branch=branch)
 
         config = current_app.conf.get(cfg_key, {}).copy()
         config.update(cfg.get(cfg_key, {}))
@@ -675,8 +686,7 @@ def get_file_contents(self, path_to_file, branch=None):
             branch = self.head_branch
         return super().get_file_contents(path_to_file, branch=branch)
 
-    def get_repo_config(self, branch=None, path_to_file='pyproject.toml',
-                        warn_on_failure=True):
+    def get_repo_config(self, branch=None, path_to_file='pyproject.toml'):
         """
         Load user configuration for bot.
 
@@ -690,9 +700,6 @@ def get_repo_config(self, branch=None, path_to_file='pyproject.toml',
             Path to the ``pyproject.toml`` file in the repository. Will default
             to the root of the repository.
 
-        warn_on_failure : `bool`
-            Emit warning on failure to load the pyproject file.
-
         Returns
         -------
         cfg : dict
@@ -701,8 +708,7 @@ def get_repo_config(self, branch=None, path_to_file='pyproject.toml',
         """
         if not branch:
             branch = self.base_branch
-        return super().get_repo_config(branch=branch, path_to_file=path_to_file,
-                                       warn_on_failure=warn_on_failure)
+        return super().get_repo_config(branch=branch, path_to_file=path_to_file)
 
     def has_modified(self, filelist):
         """Check if PR has modified any of the given list of filename(s)."""

baldrick/github/tests/test_github_api.py

@@ -5,7 +5,7 @@
 import pytest
 
 from baldrick.config import loads
-from baldrick.github.github_api import (cfg_cache, RepoHandler, IssueHandler,
+from baldrick.github.github_api import (FILE_CACHE, RepoHandler, IssueHandler,
                                         PullRequestHandler)
 
 
@@ -69,16 +69,15 @@ def test_urls(self):
 TEST_FALLBACK_CONFIG = """
 [tool.nottestbot]
 [tool.nottestbot.pr]
-setting1 = 2
-setting2 = 3
+setting1 = 5
 setting3 = 4
 """
 
 
 class TestRealRepoHandler:
 
     def setup_method(self, method):
-        cfg_cache.clear()
+        FILE_CACHE.clear()
 
     def setup_class(self):
         self.repo = RepoHandler('astropy/astropy-bot')
@@ -103,6 +102,18 @@ def test_get_fallback_config(self, app):
 
                 mock_get.return_value = TEST_FALLBACK_CONFIG
 
+                # These are set to False in YAML; defaults must not be used.
+                assert self.repo.get_config_value('pr')['setting1'] == 5
+                assert self.repo.get_config_value('pr')['setting3'] == 4
+
+    def test_get_fallback_with_primary_config(self, app):
+
+        with app.app_context():
+            app.fall_back_config = "nottestbot"
+            with patch.object(self.repo, 'get_file_contents') as mock_get:  # noqa
+
+                mock_get.return_value = TEST_CONFIG + TEST_FALLBACK_CONFIG
+
                 # These are set to False in YAML; defaults must not be used.
                 assert self.repo.get_config_value('pr')['setting1'] == 2
                 assert self.repo.get_config_value('pr')['setting2'] == 3

baldrick/logging.py

@@ -0,0 +1,34 @@
+import logging
+
+from os import environ
+
+from loguru import logger
+
+LOG_LEVEL_TO_NAME = {5: 'TRACE',
+                     10: 'DEBUG',
+                     20: 'INFO',
+                     25: 'SUCCESS',
+                     30: 'WARNING',
+                     40: 'ERROR',
+                     50: 'CRITICAL'}
+
+LOG_NAME_TO_LEVEL = {v: k for k, v in LOG_LEVEL_TO_NAME.items()}
+
+
+class InterceptHandler(logging.Handler):
+    """
+    Handler to route stdlib logs to loguru
+    """
+    def emit(self, record):
+        # Retrieve context where the logging call occurred, this happens to be in the 6th frame upward
+        logger_opt = logger.opt(depth=6, exception=record.exc_info)
+
+        # Log with name to support formatting if known, otherwise use the level number
+        logger_opt.log(LOG_LEVEL_TO_NAME.get(record.levelno, record.levelno), record.getMessage())
+
+
+# Retrieve default log level from same environment variable as loguru
+log_level = LOG_NAME_TO_LEVEL.get(environ.get("BALDRICK_LOG_LEVEL", "INFO"), "INFO")
+
+# Configuration for stdlib logger to route messages to loguru; must be run before other imports
+logging.basicConfig(handlers=[InterceptHandler()], level=log_level)

baldrick/plugins/circleci_artifacts.py

@@ -1,20 +1,21 @@
-import logging
 import requests
 
-from baldrick.blueprints.circleci import circleci_webhook_handler
+from loguru import logger
 
-LOGGER = logging.getLogger(__name__)
+from baldrick.blueprints.circleci import circleci_webhook_handler
 
 
 @circleci_webhook_handler
 def set_commit_status_for_artifacts(repo_handler, payload, headers):
 
     ci_config = repo_handler.get_config_value("circleci_artifacts", {})
     if not ci_config.get("enabled", False):
-        return "Skipping artifact check, disabled in config."
+        msg = "Skipping artifact check, disabled in config."
+        logger.debug(msg)
+        return msg
 
     if payload['status'] == 'success':
-        LOGGER.info(r"Got successful call for repo: %s/%s", payload['username'], payload['reponame'])
+        logger.info(f"Got CircleCI 'success' status for repo: {payload['username']}/{payload['reponame']}")
         artifacts = get_artifacts_from_build(payload)
 
         for name, config in ci_config.items():
@@ -23,7 +24,7 @@ def set_commit_status_for_artifacts(repo_handler, payload, headers):
                 continue
 
             url = get_documentation_url_from_artifacts(artifacts, config['url'])
-            LOGGER.debug("Found artifact: %s", url)
+            logger.debug(f"Found artifact: {url}")
 
             if url:
                 repo_handler.set_status("success",

baldrick/plugins/github_milestones.py

@@ -1,3 +1,5 @@
+from loguru import logger
+
 from baldrick.plugins.github_pull_requests import pull_request_handler
 
 MISSING_MESSAGE = 'This pull request has no milestone set.'
@@ -9,11 +11,13 @@ def process_milestone(pr_handler, repo_handler):
     """
     A very simple set a failing status if the milestone is not set.
     """
-
     mc_config = pr_handler.get_config_value("milestones", {})
     if not mc_config.get('enabled', False):
+        logger.debug("Skipping milestone plugin as disabled in config")
         return
 
+    logger.debug(f"Checking milestones on {pr_handler.repo}#{pr_handler.number}")
+
     fail_message = mc_config.get("missing_message", MISSING_MESSAGE)
     pass_message = mc_config.get("present_message", PRESENT_MESSAGE)
 

baldrick/plugins/github_pull_requests.py

@@ -1,4 +1,5 @@
 from flask import current_app
+from loguru import logger
 
 from baldrick.github.github_api import RepoHandler, PullRequestHandler
 from baldrick.blueprints.github import github_webhook_handler
@@ -82,6 +83,8 @@ def handle_pull_requests(repo_handler, payload, headers):
 
     is_new = (event == 'pull_request') & (payload['action'] == 'opened')
 
+    logger.debug(f"Processing event {event} #{number} on {repo_handler.repo}")
+
     return process_pull_request(
         repo_handler.repo, number, repo_handler.installation,
         action=payload['action'], is_new=is_new)
@@ -96,11 +99,9 @@ def process_pull_request(repository, number, installation, action,
 
     pr_config = pr_handler.get_config_value("pull_requests", {})
     if not pr_config.get("enabled", False):
-        return "Skipping PR checks, disabled in config."
-
-    # Disable if the config is not present
-    if pr_config is None:
-        return
+        msg = "Skipping PR checks, disabled in config."
+        logger.debug(msg)
+        return msg
 
     # Don't comment on closed PR
     if pr_handler.is_closed: