Logging Plugin

README.md

@@ -12,6 +12,7 @@ This package provides analytics and distributed tracing for event-driven applica
   - [Custom Metrics](#custom-metrics)
 - [Plugins](#plugins)
   - [Event Info Plugin](#event-info-plugin)
+  - [Logging Plugin](#logging-plugin)
   - [Profiler Plugin](#profiler-plugin)
   - [Trace Plugin](#trace-plugin)
   - [Creating Plugins](#creating-plugins)
@@ -183,9 +184,83 @@ When this plugin is installed, custom metrics will be created automatically for
 * SNS
 * Scheduled Events
 
-### Profiler Plugin
+### Logging Plugin
+
+The IOpipe agent comes bundled with a logging plugin that allows you to attach IOpipe to the `logging` module so that you can see your log messages in the IOpipe dashboard.
+
+Here's an example of how to use the logging plugin:
+
+```python
+from iopipe import IOpipe
+from iopipe.contrib.logging import LoggingPlugin
+
+iopipe = IOpipe(plugins=[LoggingPlugin()])
+
+@iopipe
+def handler(event, context):
+    context.iopipe.log.info('Handler has started execution')
+```
+
+Since this plugin just adds a handler to the `logging` module, you can use `logging` directly as well:
+
+```python
+import logging
+
+from iopipe import IOpipe
+from iopipe.contrib.logging import LoggingPlugin
+
+iopipe = IOpipe(plugins=[LoggingPlugin()])
+logger = logging.getLogger()
+
+@iopipe
+def handler(event, context):
+    logger.error('Uh oh')
+```
+
+You can also specify a log name, such as if you only wanted to log messages for `mymodule`:
+
+```python
+from iopipe import IOpipe
+from iopipe.contrib.logging import LoggingPlugin
 
-**Note:** This feature is still in beta. Want to try it out? Find us on [Slack](https://iopipe.now.sh).
+iopipe = IOpipe(plugins=[LoggingPlugin('mymodule')])
+```
+
+This would be equivalent to `logging.getLogger('mymodule')`.
+
+By default, the logging plugin log level is `logging.INFO`, but it can be set like this:
+
+```python
+import logging
+
+from iopipe import IOpipe
+from iopipe.contrib.logging import LoggingPlugin
+
+iopipe = IOpipe(plugins=[LoggingPlugin(level=logging.DEBUG)])
+```
+
+Putting IOpipe into `debug` mode also sets the log level to `logging.DEBUG`.
+
+The logging plugin also redirects stdout by default, so you can do the following:
+
+```python
+from iopipe import IOpipe
+from iopipe.contrib.logging import LoggingPlugin
+
+iopipe = IOpipe(plugins=[LoggingPlugin()])
+
+@iopipe
+def handler(event, context):
+    print('I will be logged')
+```
+
+If you prefer your print statements not to be logged, you can disable this by setting `redirect_stdout` to `False`:
+
+```python
+iopipe = IOpipe(plugins=[LoggingPlugin(redirect_stdout=False)])
+```
+
+### Profiler Plugin
 
 The IOpipe agent comes bundled with a profiler plugin that allows you to profile your functions with [cProfile](https://docs.python.org/3/library/profile.html#module-cProfile).
 

acceptance/serverless/handler.py

@@ -10,13 +10,17 @@
 
 from iopipe import IOpipe
 from iopipe.contrib.eventinfo import EventInfoPlugin
+from iopipe.contrib.logging import LoggingPlugin
 from iopipe.contrib.profiler import ProfilerPlugin
 from iopipe.contrib.trace import TracePlugin
 
 iopipe = IOpipe(debug=True)
 eventinfo_plugin = EventInfoPlugin()
 iopipe_with_eventinfo = IOpipe(debug=True, plugins=[eventinfo_plugin])
 
+logging_plugin = LoggingPlugin()
+iopipe_with_logging = IOpipe(debug=True, plugins=[logging_plugin])
+
 profiler_plugin = ProfilerPlugin(enabled=True)
 iopipe_with_profiling = IOpipe(debug=True, plugins=[profiler_plugin])
 
@@ -69,6 +73,16 @@ def custom_metrics(event, context):
     context.iopipe.label('has-metrics')
 
 
+@iopipe_with_logging
+def logging(event, context):
+    context.iopipe.log('time', time.time())
+    context.iopipe.log.debug("I'm a debug message.")
+    context.iopipe.log.info("I'm an info message.")
+    context.iopipe.log.warn("I'm a warning message.")
+    context.iopipe.log.error("I'm an error message.")
+    context.iopipe.log.critical("I'm a critical message.")
+
+
 @iopipe_with_profiling
 def profiling(event, context):
     time.sleep(1)

acceptance/serverless/serverless.yml

@@ -95,6 +95,17 @@ functions:
     handler: handler.custom_metrics
     runtime: python3.6
 
+  py2-logging:
+    events:
+      - schedule: rate(10 minutes)
+    handler: handler.logging
+    runtime: python2.7
+  py3-logging:
+    events:
+      - schedule: rate(10 minutes)
+    handler: handler.logging
+    runtime: python3.6
+
   py2-profiling:
     events:
       - schedule: rate(10 minutes)

iopipe/context.py

@@ -71,8 +71,8 @@ def error(self, error):
         self.instance.run_hooks('post:report')
         raise error
 
-    def register(self, name, value):
-        if not hasattr(self, name):
+    def register(self, name, value, force=False):
+        if not hasattr(self, name) or force:
             setattr(self, name, value)
 
     def unregister(self, name):

iopipe/contrib/logging/__init__.py

@@ -0,0 +1 @@
+from .plugin import LoggingPlugin  # noqa

iopipe/contrib/logging/plugin.py

@@ -0,0 +1,83 @@
+import logging
+import sys
+
+from logging import Formatter, StreamHandler
+
+try:
+    from StringIO import StringIO
+except ImportError:
+    from io import StringIO
+
+from iopipe.plugins import Plugin
+from iopipe.signer import get_signed_request
+
+from .request import upload_log_data
+from .stream import StreamToLogger
+from .wrapper import LogWrapper
+
+
+class LoggingPlugin(Plugin):
+    name = 'logging'
+    version = '0.1.0'
+    homepage = 'https://github.com/iopipe/iopipe-python#logging-plugin'
+    enabled = True
+
+    def __init__(self, name=None, level=logging.INFO, formatter=None, redirect_stdout=True):
+        """
+        Instantiates the logging plugin
+
+        :param name: Specify custom log name.
+        :type name: str
+        :param level: Specify a log level for the handler.
+        :type level: int
+        :param formatter: Specify a custom log message formatter.
+        :type formatter: :class:`Formatter`
+        :param redirect_stdout: Whether or not to redirect stdout.
+        :type redirect_print: bool
+        """
+        if formatter is None or not isinstance(formatter, Formatter):
+            formatter = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
+
+        self.handler = StreamHandler(StringIO())
+        self.handler.setFormatter(formatter)
+        self.handler.setLevel(level)
+
+        self.logger = logging.getLogger(name)
+        self.logger.addHandler(self.handler)
+        self.logger.setLevel(level)
+
+        self.redirect_stdout = redirect_stdout
+
+    def pre_setup(self, iopipe):
+        pass
+
+    def post_setup(self, iopipe):
+        if iopipe.config['debug'] is True:
+            self.handler.setLevel(logging.DEBUG)
+            self.logger.setLevel(logging.DEBUG)
+
+    def pre_invoke(self, event, context):
+        context.iopipe.register('log', LogWrapper(self.logger, context), force=True)
+        self.handler.stream = StringIO()
+
+        if self.redirect_stdout is True:
+            sys.stdout = StreamToLogger(self.logger)
+
+    def post_invoke(self, event, context):
+        self.handler.flush()
+
+        if self.redirect_stdout is True:
+            sys.stdout = sys.__stdout__
+
+    def pre_report(self, report):
+        pass
+
+    def post_report(self, report):
+                signed_request = get_signed_request(report, '.log')
+                if signed_request and 'signedRequest' in signed_request:
+                    upload_log_data(signed_request['signedRequest'], self.handler.stream)
+                    if 'jwtAccess' in signed_request:
+                        plugin = next((p for p in report.plugins if p['name'] == self.name))
+                        if 'uploads' not in plugin:
+                            plugin['uploads'] = []
+                        plugin['uploads'].append(signed_request['jwtAccess'])

iopipe/contrib/logging/request.py

@@ -0,0 +1,28 @@
+import logging
+
+try:
+    import requests
+except ImportError:
+    from botocore.vendored import requests
+
+logger = logging.getLogger(__name__)
+
+
+def upload_log_data(url, data):
+    """
+    Uploads log data to IOpipe.
+
+    :param url: The signed URL
+    :param data: The log data
+    """
+    data.seek(0)
+    try:
+        logger.debug('Uploading log data to IOpipe')
+        response = requests.put(url, data=data)
+        response.raise_for_status()
+    except Exception as e:
+        logger.debug('Error while uploading log data: %s', e)
+        if hasattr(e, 'response'):
+            logger.debug(e.response.content)
+    else:
+        logger.debug('Log data uploaded successfully')

iopipe/contrib/logging/stream.py

@@ -0,0 +1,7 @@
+class StreamToLogger(object):
+    def __init__(self, logger):
+        self.logger = logger
+
+    def write(self, buf):
+        for line in buf.rstrip().splitlines():
+            self.logger.info(line.rstrip())

iopipe/contrib/logging/wrapper.py

@@ -0,0 +1,10 @@
+class LogWrapper(object):
+    def __init__(self, logger, context):
+        self.logger = logger
+        self.context = context
+
+    def __call__(self, key, value):
+        return self.context.metric(key, value)
+
+    def __getattr__(self, name):
+        return getattr(self.logger, name)

iopipe/contrib/profiler/plugin.py

@@ -8,8 +8,9 @@
 import tempfile
 
 from iopipe.plugins import Plugin
+from iopipe.signer import get_signed_request
 
-from .request import get_signed_request, upload_profiler_report
+from .request import upload_profiler_report
 
 logger = logging.getLogger(__name__)
 
@@ -57,7 +58,7 @@ def pre_report(self, report):
         if self.profile is not None:
             with tempfile.NamedTemporaryFile() as stats_file:
                 self.profile.dump_stats(stats_file.name)
-                signed_request = get_signed_request(report)
+                signed_request = get_signed_request(report, '.cprofile')
                 if signed_request and 'signedRequest' in signed_request:
                     upload_profiler_report(signed_request['signedRequest'], stats_file.file)
                     if 'jwtAccess' in signed_request:

iopipe/contrib/profiler/request.py

@@ -5,45 +5,9 @@
 except ImportError:
     from botocore.vendored import requests
 
-from .signer import get_signer_hostname
-
 logger = logging.getLogger(__name__)
 
 
-def get_signed_request(report):
-    """
-    Returns a signed request URL from IOpipe
-
-    :param report: The IOpipe report to request a signed URL
-    :returns: A signed request URL
-    :rtype: str
-    """
-    url = 'https://{hostname}/'.format(hostname=get_signer_hostname())
-
-    try:
-        logger.debug('Requesting signed request URL from %s' % url)
-        response = requests.post(
-            url,
-            json={
-                'arn': report.report['aws']['invokedFunctionArn'],
-                'requestId': report.report['aws']['awsRequestId'],
-                'timestamp': report.report['timestamp'],
-                'extension': '.cprofile'
-            },
-            headers={
-                'Authorization': report.report['client_id']
-            })
-        response.raise_for_status()
-    except Exception as e:
-        logger.debug('Error requesting signed request URL: %s' % e)
-        if hasattr(e, 'response'):
-            logger.debug(e.response.content)
-    else:
-        response = response.json()
-        logger.debug('Signed request URL received for %s' % response['url'])
-        return response
-
-
 def upload_profiler_report(url, data):
     """
     Uploads a profiler report to IOpipe
@@ -57,7 +21,7 @@ def upload_profiler_report(url, data):
         response = requests.put(url, data=data)
         response.raise_for_status()
     except Exception as e:
-        logger.debug('Error while uploading profiler report: %s' % e)
+        logger.debug('Error while uploading profiler report: %s', e)
         if hasattr(e, 'response'):
             logger.debug(e.response.content)
     else: