Merge pull request #34 from thread/logging-plugins

Logging plugin infrastructure

.circleci/config.yml

@@ -47,7 +47,7 @@ jobs:
           name: Restore .tox cache
           key: deps-tox-{{ .Branch }}-{{ checksum "scripts/linting/requirements.txt" }}-{{ checksum "scripts/typechecking/requirements.txt" }}-{{ checksum "scripts/testing/requirements.txt" }}-{{ checksum "setup.py" }}
       - run:
-          name: Test/Lint/Typecheck
+          name: Test
           command: |
             . venv/bin/activate
             TOXENV=py36 tox
@@ -93,7 +93,7 @@ jobs:
           name: Restore .tox cache
           key: deps-tox-{{ .Branch }}-{{ checksum "scripts/linting/requirements.txt" }}
       - run:
-          name: Test/Lint/Typecheck
+          name: Lint
           command: |
             . venv/bin/activate
             TOXENV=lint tox
@@ -129,7 +129,7 @@ jobs:
           name: Restore .tox cache
           key: deps-tox-{{ .Branch }}-{{ checksum "scripts/typechecking/requirements.txt" }}
       - run:
-          name: Test/Lint/Typecheck
+          name: Typecheck
           command: |
             . venv/bin/activate
             TOXENV=mypy tox
@@ -161,6 +161,12 @@ jobs:
             python3 -m venv venv
             . venv/bin/activate
             pip install twine wheel m2r
+
+            python setup.py sdist
+            python setup.py bdist_wheel
+            twine upload dist/*
+
+            cd plugins/routemaster-sentry
             python setup.py sdist
             python setup.py bdist_wheel
             twine upload dist/*

.gitignore

@@ -47,6 +47,7 @@ nosetests.xml
 coverage.xml
 *.cover
 .hypothesis/
+.pytest_cache/
 
 # Translations
 *.mo

Dockerfile

@@ -7,6 +7,10 @@ WORKDIR /routemaster/app
 COPY routemaster/migrations/ routemaster/migrations/
 
 COPY dist/ .
+
+# Install first-party plugins (inactive by default).
+COPY plugins/routemaster-sentry/dist/ .
+
 RUN pip install --no-cache-dir *.whl
 
 COPY scripts/build/default_config.yaml config.yaml

MANIFEST.in

@@ -1,2 +1,3 @@
 include README.md
 include routemaster/config/schema.yaml
+include version.py

README.md

@@ -214,8 +214,8 @@ results from not specifying any other transition. This creates an end state that
 cannot be progressed from.
 
 
-[label]: docs/glossary.md#label
-[metadata]: docs/glossary.md#metadata
-[action]: docs/glossary.md#action
-[gate]: docs/glossary.md#gate
-[exit-condition]: docs/glossary.md#exit-condition
+[label]: docs/glossary.md
+[metadata]: docs/glossary.md
+[action]: docs/glossary.md
+[gate]: docs/glossary.md
+[exit-condition]: docs/glossary.md

plugins/routemaster-sentry/MANIFEST.in

@@ -0,0 +1,2 @@
+include README.md
+include version.py

plugins/routemaster-sentry/README.md

@@ -0,0 +1,11 @@
+### routemaster-sentry
+
+Usage, in your Routemaster configuration file:
+
+```yaml
+plugins:
+  logging:
+    - class: routemaster_sentry.logger:SentryLogger
+      kwargs:
+        dsn: https://xxxxxxx:xxxxxxx@sentry.io/xxxxxxx
+```

plugins/routemaster-sentry/routemaster_sentry/__init__.py

@@ -0,0 +1,67 @@
+"""
+Sentry logger for Routemaster.
+
+This package provides a Routemaster logging plugin that interfaces to Raven,
+Sentry's Python reporting package.
+
+It adds per-request exception reporting to Flask for the API, and also wraps
+the cron, webhook request, and feed request processes with Sentry reporting.
+All wrapping re-raises exceptions, as Routemaster/Flask/the cron subsystem will
+all handle exceptions appropriately.
+"""
+import contextlib
+
+from raven import Client
+from raven.contrib.flask import Sentry
+
+from routemaster.logging import BaseLogger
+from routemaster.version import get_version
+
+
+class SentryLogger(BaseLogger):
+    """Instruments Routemaster with Sentry."""
+
+    def __init__(self, *args, dsn):
+        version = get_version()
+
+        self.client = Client(
+            dsn,
+            release=version,
+            sample_rate=0 if 'dev' in version else 1,
+            include_paths=[
+                'routemaster',
+            ],
+        )
+
+        super().__init__(*args)
+
+    def init_flask(self, flask_app):
+        """Instrument Flask with Sentry."""
+        Sentry(flask_app, client=self.client)
+
+    @contextlib.contextmanager
+    def process_cron(self, state_machine, state, fn_name):
+        """Send cron exceptions to Sentry."""
+        try:
+            yield
+        except Exception:
+            self.client.captureException()
+            raise
+
+    @contextlib.contextmanager
+    def process_webhook(self, state_machine, state):
+        """Send webhook request exceptions to Sentry."""
+        try:
+            yield
+        except Exception:
+            self.client.captureException()
+            raise
+
+    @contextlib.contextmanager
+    def process_feed(self, state_machine, state, feed_url):
+        """Send feed request exceptions to Sentry."""
+        try:
+            yield
+        except Exception:
+            self.client.captureException()
+            raise

plugins/routemaster-sentry/setup.py

@@ -0,0 +1,51 @@
+"""Package setup."""
+
+import version
+from setuptools import setup, find_packages
+
+with open('README.md', 'r', encoding='utf-8') as f:
+    long_description = f.read()
+
+try:
+    from m2r import convert
+    long_description = convert(long_description)
+except ImportError:
+    # Fall back to markdown formatted readme when no m2r package.
+    pass
+
+
+setup(
+    name='routemaster_sentry',
+    version=version.get_version(),
+    url='https://github.com/thread/routemaster',
+    description="Sentry error reporting for Routemaster.",
+    long_description=long_description,
+
+    author="Thread",
+    author_email="tech@thread.com",
+
+    keywords=(
+    ),
+    license='MIT',
+
+    zip_safe=False,
+
+    packages=find_packages(),
+    include_package_data=True,
+
+    classifiers=(
+        'Development Status :: 2 - Pre-Alpha',
+        'Environment :: Console',
+        'Natural Language :: English',
+        'Operating System :: POSIX',
+        'Programming Language :: Python',
+        'Programming Language :: Python :: 3 :: Only',
+        'Programming Language :: Python :: 3.6',
+        'Topic :: Office/Business',
+    ),
+
+    install_requires=(
+        'routemaster',
+        'raven[flask]',
+    ),
+)

plugins/routemaster-sentry/version.py

@@ -0,0 +1,88 @@
+"""
+Versioning utils.
+"""
+
+__all__ = ('get_version')
+
+import os
+import re
+import logging
+import os.path
+import subprocess
+from os.path import dirname
+
+import pkg_resources
+
+version_re = re.compile('^Version: (.+)$', re.M)
+
+logger = logging.getLogger(__file__)
+
+
+def find_git_root(test):
+    prev, test = None, os.path.abspath(test)
+    while prev != test:
+        if os.path.isdir(os.path.join(test, '.git')):
+            return test
+        prev, test = test, os.path.abspath(os.path.join(test, os.pardir))
+    return None
+
+
+def get_version():
+    """
+    Gets the current version number.
+
+    If in a git repository, it is the current git tag.
+    Otherwise it is the one contained in the PKG-INFO file.
+    To use this script, simply import it in your setup.py file
+    and use the results of get_version() as your package version:
+        from version import *
+        setup(
+            ...
+            version=get_version(),
+            ...
+        )
+    """
+    git_root = find_git_root(dirname(__file__))
+
+    if git_root is not None:
+        # Get the version using "git describe".
+        cmd = 'git describe --tags --match [0-9]*'.split()
+        try:
+            version = subprocess.check_output(cmd).decode().strip()
+        except subprocess.CalledProcessError:
+            logger.exception('Unable to get version number from git tags')
+            exit(1)
+
+        # PEP 386 compatibility
+        if '-' in version:
+            version = '.post'.join(version.split('-')[:2])
+
+        # Don't declare a version "dirty" merely because a time stamp has
+        # changed. If it is dirty, append a ".dev1" suffix to indicate a
+        # development revision after the release.
+        with open(os.devnull, 'w') as fd_devnull:
+            subprocess.call(
+                ['git', 'status'],
+                stdout=fd_devnull,
+                stderr=fd_devnull,
+            )
+
+        cmd = 'git diff-index --name-only HEAD'.split()
+        try:
+            dirty = subprocess.check_output(cmd).decode().strip()
+        except subprocess.CalledProcessError:
+            logger.exception('Unable to get git index status')
+            exit(1)
+
+        if dirty != '':
+            version += '.dev1'
+
+        return version
+
+    else:
+        try:
+            return pkg_resources.working_set.by_key[
+                'routemaster_sentry'
+            ].version
+        except KeyError:
+            return '0.0.0-unreleased'

routemaster/app.py

@@ -5,16 +5,22 @@
 
 from routemaster.db import initialise_db
 from routemaster.config import Config
+from routemaster.logging import BaseLogger, SplitLogger, register_loggers
 
 
 class App(threading.local):
     """Core application state."""
 
     db: Engine
     config: Config
+    logger: BaseLogger
 
-    def __init__(self, config: Config, log_level: str = 'INFO') -> None:
+    def __init__(
+        self,
+        config: Config,
+    ) -> None:
         """Initialisation of the app state."""
         self.config = config
         self.db = initialise_db(self.config.database)
-        self.log_level = log_level
+
+        self.logger = SplitLogger(config, loggers=register_loggers(config))

routemaster/cli.py

@@ -22,31 +22,9 @@
     type=click.File(encoding='utf-8'),
     required=True,
 )
-@click.option(
-    '-l',
-    '--log-level',
-    help="Logging level.",
-    type=click.Choice((
-        'CRITICAL',
-        'ERROR',
-        'WARNING',
-        'INFO',
-        'DEBUG',
-    )),
-    default='INFO',
-)
 @click.pass_context
-def main(ctx, config_file, log_level):
+def main(ctx, config_file):
     """Shared entrypoint configuration."""
-    logging.basicConfig(
-        format=(
-            "[%(asctime)s] [%(process)d] [%(levelname)s] "
-            "[%(name)s] %(message)s"
-        ),
-        datefmt="%Y-%m-%d %H:%M:%S %z",
-        level=getattr(logging, log_level),
-    )
-
     logging.getLogger('schedule').setLevel(logging.CRITICAL)
 
     try:
@@ -55,7 +33,7 @@ def main(ctx, config_file, log_level):
         logger.exception("Configuration Error")
         click.get_current_context().exit(1)
 
-    ctx.obj = App(config, log_level)
+    ctx.obj = App(config)
     _validate_config(ctx.obj)
 
 
@@ -93,16 +71,13 @@ def serve(ctx, bind, debug):  # pragma: no cover
     if debug:
         server.config['DEBUG'] = True
 
+    app.logger.init_flask(server)
+
     cron_thread = CronThread(app)
     cron_thread.start()
 
     try:
-        instance = GunicornWSGIApplication(
-            server,
-            bind=bind,
-            debug=debug,
-            log_level=ctx.obj.log_level,
-        )
+        instance = GunicornWSGIApplication(server, bind=bind, debug=debug)
         instance.run()
     finally:
         cron_thread.stop()