Merge pull request #457 from opdemand/394-app-lifecycle-events

Added syslog events for app lifecycle, fixes #394.

Author: Gabriel Monroy

api/models.py

@@ -6,6 +6,7 @@
 
 from __future__ import unicode_literals
 import importlib
+import logging
 import os
 import subprocess
 
@@ -26,6 +27,9 @@
 from utils import dict_diff
 
 
+
+logger = logging.getLogger(__name__)
+
 # import user-defined configuration management module
 CM = importlib.import_module(settings.CM_MODULE)
 
@@ -445,6 +449,11 @@ def run(self, command, **kwargs):
         return tasks.run_node.delay(self, command).wait()
 
 
+def log_event(app, msg, level=logging.INFO):
+    msg = "{}: {}".format(app.id, msg)
+    logger.log(level, msg)
+
+
 @python_2_unicode_compatible
 class App(UuidAuditedModel):
     """
@@ -546,6 +555,7 @@ def run(self, command):
              'deis/slugrunner'])
         env_args = ' '.join(["-e '{k}={v}'".format(**locals())
                              for k, v in release.config.values.items()])
+        log_event(self, "deis run '{}'".format(command))
         command = "sudo docker run {env_args} {docker_args} {command}".format(**locals())
         return node.run(command)
 
@@ -559,6 +569,8 @@ def scale(self, app, structure, **kwargs):
         # increment new container nums off the most recent container
         all_containers = app.container_set.all().order_by('-created')
         container_num = 1 if not all_containers else all_containers[0].num + 1
+        msg = 'Containers scaled ' + ' '.join(
+            "{}={}".format(k, v) for k, v in requested_containers.items())
         # iterate and scale by container type (web, worker, etc)
         changed = False
         for container_type in requested_containers.keys():
@@ -593,6 +605,7 @@ def scale(self, app, structure, **kwargs):
                 containers.append(c)
                 container_num += 1
                 diff -= 1
+        log_event(app, msg)
         return changed
 
     def balance(self, formation, **kwargs):
@@ -601,6 +614,7 @@ def balance(self, formation, **kwargs):
         # get the next container number (e.g. web.19)
         container_num = 1 if not all_containers else all_containers[0].num + 1
         changed = False
+        app = None
         # iterate by unique container type
         for container_type in set([c.type for c in all_containers]):
             # map node container counts => { 2: [b3, b4], 3: [ b1, b2 ] }
@@ -638,6 +652,8 @@ def balance(self, formation, **kwargs):
                     ct = len(n.container_set.filter(type=container_type))
                     n_map.setdefault(ct, []).append(n)
                 changed = True
+        if app:
+            log_event(app, 'Containers balanced')
         return changed
 
 
@@ -718,7 +734,7 @@ class Meta:
         unique_together = (('app', 'uuid'),)
 
     def __str__(self):
-        return "{0}-{1}".format(self.app.id, self.sha[8:])
+        return "{0}-{1}".format(self.app.id, self.sha[:7])
 
 
 @python_2_unicode_compatible
@@ -748,7 +764,7 @@ class Meta:
         unique_together = (('app', 'uuid'),)
 
     def __str__(self):
-        return "{0}-{1}".format(self.app.id, self.sha)
+        return "{0}-{1}".format(self.app.id, self.sha[:7])
 
     @classmethod
     def push(cls, push):
@@ -931,9 +947,30 @@ def _purge_user_from_cm(**kwargs):
     kwargs['instance'].purge()
 
 
-# use django signals to synchronize database updates with
-# the configuration management backend
+def _log_build_created(**kwargs):
+    if kwargs.get('created'):
+        build = kwargs['instance']
+        log_event(build.app, "Build {} created".format(build))
+
+
+def _log_release_created(**kwargs):
+    if kwargs.get('created'):
+        release = kwargs['instance']
+        log_event(release.app, "Release {} created".format(release))
+
+
+def _log_config_updated(**kwargs):
+    config = kwargs['instance']
+    log_event(config.app, "Config {} updated".format(config))
+
+
+# Connect Django model signals
+# Sync database updates with the configuration management backend
 post_save.connect(_publish_to_cm, sender=App, dispatch_uid='api.models')
 post_save.connect(_publish_to_cm, sender=Formation, dispatch_uid='api.models')
 post_save.connect(_publish_user_to_cm, sender=User, dispatch_uid='api.models')
 post_delete.connect(_purge_user_from_cm, sender=User, dispatch_uid='api.models')
+# Log significant app-related events
+post_save.connect(_log_build_created, sender=Build, dispatch_uid='api.models')
+post_save.connect(_log_release_created, sender=Release, dispatch_uid='api.models')
+post_save.connect(_log_config_updated, sender=Config, dispatch_uid='api.models')

api/tests/__init__.py

@@ -1,11 +1,13 @@
 
 from __future__ import unicode_literals
-
-# add patch support to built-in django test client
+import logging
 
 from django.test.client import RequestFactory, Client
+from django.test.simple import DjangoTestSuiteRunner
 
 
+# add patch support to built-in django test client
+
 def construct_patch(self, path, data='',
                     content_type='application/octet-stream', **extra):
     """Construct a PATCH request."""
@@ -27,6 +29,18 @@ def send_patch(self, path, data='', content_type='application/octet-stream',
 RequestFactory.patch = construct_patch
 Client.patch = send_patch
 
+
+class SilentDjangoTestSuiteRunner(DjangoTestSuiteRunner):
+    """Prevents api log messages from cluttering the console during tests."""
+
+    def run_tests(self, test_labels, extra_tests=None, **kwargs):
+        """Run tests with all but critical log messages disabled."""
+        # hide any log messages less than critical
+        logging.disable(logging.CRITICAL)
+        return super(SilentDjangoTestSuiteRunner, self).run_tests(
+            test_labels, extra_tests, **kwargs)
+
+
 from .test_app import *  # noqa
 from .test_auth import *  # noqa
 from .test_build import *  # noqa

api/views.py

@@ -380,6 +380,7 @@ def create(self, request, **kwargs):
         assign_perm(self.perm, user, app)
         app.publish()
         tasks.converge_controller.apply_async().wait()
+        models.log_event(app, "User {} was granted access to {}".format(user, app))
         return Response(status=status.HTTP_201_CREATED)
 
     def destroy(self, request, **kwargs):
@@ -391,6 +392,7 @@ def destroy(self, request, **kwargs):
             remove_perm(self.perm, user, app)
             app.publish()
             tasks.converge_controller.apply_async().wait()
+            models.log_event(app, "User {} was revoked access to {}".format(user, app))
             return Response(status=status.HTTP_204_NO_CONTENT)
         else:
             return Response(status=status.HTTP_404_NOT_FOUND)

deis/settings.py

@@ -193,6 +193,14 @@
 # URLs that end with slashes are ugly
 APPEND_SLASH = False
 
+# Determine where to send syslog messages
+if os.path.exists('/dev/log'):           # Linux rsyslog
+    SYSLOG_ADDRESS = '/dev/log'
+elif os.path.exists('/var/log/syslog'):  # Mac OS X syslog
+    SYSLOG_ADDRESS = '/var/log/syslog'
+else:                                    # default SysLogHandler address
+    SYSLOG_ADDRESS = ('localhost', 514)
+
 # A sample logging configuration. The only tangible logging
 # performed by this configuration is to send an email to
 # the site admins on every HTTP 500 error when DEBUG=False.
@@ -228,26 +236,32 @@
             'level': 'ERROR',
             'filters': ['require_debug_false'],
             'class': 'django.utils.log.AdminEmailHandler'
-        }
+        },
+        'rsyslog': {
+            'class': 'logging.handlers.SysLogHandler',
+            'address': SYSLOG_ADDRESS,
+            'facility': 'local0',
+        },
     },
     'loggers': {
         'django': {
             'handlers': ['null'],
-            'propagate': True,
             'level': 'INFO',
+            'propagate': True,
         },
         'django.request': {
             'handlers': ['console', 'mail_admins'],
             'level': 'WARNING',
             'propagate': True,
         },
         'api': {
-            'handlers': ['console', 'mail_admins'],
+            'handlers': ['console', 'mail_admins', 'rsyslog'],
             'level': 'INFO',
             'propagate': True,
         },
     }
 }
+TEST_RUNNER = 'api.tests.SilentDjangoTestSuiteRunner'
 
 
 # celery task execution settings