Improved logging management

Use LoggerAdapters to attach standard logger functions to given objects,
and a dedicated LoggingHandler to route the incoming log messages to the
database & client display.

instance/admin.py

@@ -24,14 +24,22 @@
 
 from django.contrib import admin
 from instance.models.instance import OpenEdXInstance
-from instance.models.logging import InstanceLogEntry, ServerLogEntry
+from instance.models.log_entry import GeneralLogEntry, InstanceLogEntry, ServerLogEntry
 from instance.models.server import OpenStackServer
 
 
 # ModelAdmins #################################################################
 
+class GeneralLogEntryAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
+    list_display = ('created', 'level', 'text', 'modified')
+
+
 class InstanceLogEntryAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
-    list_display = ('instance', 'created', 'level', 'text', 'modified')
+    list_display = ('obj', 'created', 'level', 'text', 'modified')
+
+
+class ServerLogEntryAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
+    list_display = ('obj', 'created', 'level', 'text', 'modified')
 
 
 class OpenStackServerAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
@@ -42,10 +50,8 @@ class OpenEdXInstanceAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
     list_display = ('sub_domain', 'base_domain', 'name', 'created', 'modified')
 
 
-class ServerLogEntryAdmin(admin.ModelAdmin): #pylint: disable=missing-docstring
-    list_display = ('instance', 'server', 'created', 'level', 'text', 'modified')
-
+admin.site.register(GeneralLogEntry, GeneralLogEntryAdmin)
 admin.site.register(InstanceLogEntry, InstanceLogEntryAdmin)
+admin.site.register(ServerLogEntry, ServerLogEntryAdmin)
 admin.site.register(OpenStackServer, OpenStackServerAdmin)
 admin.site.register(OpenEdXInstance, OpenEdXInstanceAdmin)
-admin.site.register(ServerLogEntry, ServerLogEntryAdmin)

instance/logger_adapter.py

@@ -0,0 +1,56 @@
+# -*- coding: utf-8 -*-
+#
+# OpenCraft -- tools to aid developing and hosting free software projects
+# Copyright (C) 2015 OpenCraft <xavier@opencraft.com>
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU Affero General Public License as
+# published by the Free Software Foundation, either version 3 of the
+# License, or (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU Affero General Public License for more details.
+#
+# You should have received a copy of the GNU Affero General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+"""
+Instance app models - Logger Adapters
+"""
+
+# Imports #####################################################################
+
+import logging
+
+
+# Adapters ####################################################################
+
+class InstanceLoggerAdapter(logging.LoggerAdapter):
+    """
+    Custom LoggerAdapter for Instance objects
+    Include the instance name in the output
+    """
+    def process(self, msg, kwargs):
+        msg, kwargs = super().process(msg, kwargs)
+
+        if self.extra.get('obj', None):
+            return 'instance={} | {}'.format(self.extra['obj'].sub_domain, msg), kwargs
+        else:
+            return msg, kwargs
+
+
+class ServerLoggerAdapter(logging.LoggerAdapter):
+    """
+    Custom LoggerAdapter for Server objects
+    Include the instance & server names in the output
+    """
+    def process(self, msg, kwargs):
+        msg, kwargs = super().process(msg, kwargs)
+
+        if self.extra.get('obj', None):
+            server = self.extra['obj']
+            return 'instance={!s:.15},server={!s:.8} | {}'.format(server.instance.sub_domain, server, msg), kwargs
+        else:
+            return msg, kwargs

instance/logging.py

@@ -0,0 +1,85 @@
+# -*- coding: utf-8 -*-
+#
+# OpenCraft -- tools to aid developing and hosting free software projects
+# Copyright (C) 2015 OpenCraft <xavier@opencraft.com>
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU Affero General Public License as
+# published by the Free Software Foundation, either version 3 of the
+# License, or (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU Affero General Public License for more details.
+#
+# You should have received a copy of the GNU Affero General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+"""
+Instance app - Logging utils
+"""
+
+# Imports #####################################################################
+
+import logging
+import traceback
+
+from functools import wraps
+from swampdragon.pubsub_providers.data_publisher import publish_data
+
+from django.apps import apps
+from django.db import models
+
+
+# Logging #####################################################################
+
+logger = logging.getLogger(__name__)
+
+
+# Functions ###################################################################
+
+def log_exception(method):
+    """
+    Decorator to log uncaught exceptions on methods
+    Uses the object logging facilities, ie `self.logger` must be defined
+    """
+    @wraps(method)
+    def wrapper(self, *args, **kwds): #pylint: disable=missing-docstring
+        try:
+            return method(self, *args, **kwds)
+        except:
+            self.logger.critical(traceback.format_exc()) # TODO: Restrict traceback view to administrators
+            raise
+    return wrapper
+
+
+# Classes #####################################################################
+
+class DBHandler(logging.Handler):
+    """
+    Records log messages in database models
+    """
+    def emit(self, record):
+        """
+        Handles an emitted log entry and stores it in the database, optionally linking it to the
+        model object `obj`
+        """
+        obj = record.__dict__.get('obj', None)
+
+        if obj is None or not isinstance(obj, models.Model) or obj.pk is None:
+            log_entry_set = apps.get_model('instance', 'GeneralLogEntry').objects
+        else:
+            log_entry_set = obj.log_entry_set
+
+        log_entry = log_entry_set.create(level=record.levelname, text=self.format(record))
+
+        log_event = {
+            'type': 'instance_log',
+            'log_entry': str(log_entry),
+        }
+        if hasattr(obj, 'event_context'):
+            log_event.update(obj.event_context)
+
+        # TODO: Filter out log entries for which the user doesn't have view rights
+        publish_data('log', log_event)

instance/migrations/0025_auto_20150920_0907.py

@@ -0,0 +1,36 @@
+# -*- coding: utf-8 -*-
+from __future__ import unicode_literals
+
+from django.db import models, migrations
+import instance.models.utils
+import django.db.models.fields
+import django_extensions.db.fields
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('instance', '0024_auto_20150911_2304'),
+    ]
+
+    operations = [
+        migrations.CreateModel(
+            name='GeneralLogEntry',
+            fields=[
+                ('id', models.AutoField(serialize=False, auto_created=True, verbose_name='ID', primary_key=True)),
+                ('created', django_extensions.db.fields.CreationDateTimeField(default=django.db.models.fields.NOT_PROVIDED, verbose_name='created', auto_now_add=True)),
+                ('modified', django_extensions.db.fields.ModificationDateTimeField(auto_now=True, default=django.db.models.fields.NOT_PROVIDED, verbose_name='modified')),
+                ('text', models.TextField(blank=True)),
+                ('level', models.CharField(db_index=True, default='info', max_length=9, choices=[('debug', 'Debug'), ('info', 'Info'), ('warn', 'Warning'), ('error', 'Error'), ('exception', 'Exception')])),
+            ],
+            options={
+                'verbose_name_plural': 'General Log Entries',
+            },
+            bases=(instance.models.utils.ValidateModelMixin, models.Model),
+        ),
+        migrations.AlterField(
+            model_name='openedxinstance',
+            name='base_domain',
+            field=models.CharField(default='plebia.net', max_length=50),
+        ),
+    ]

instance/migrations/0026_auto_20150920_1108.py

@@ -0,0 +1,36 @@
+# -*- coding: utf-8 -*-
+from __future__ import unicode_literals
+
+from django.db import models, migrations
+
+def exception_to_critical(apps, schema_editor):
+    InstanceLogEntry = apps.get_model('instance', 'InstanceLogEntry')
+    ServerLogEntry = apps.get_model('instance', 'ServerLogEntry')
+    for log_entry_model in (InstanceLogEntry, ServerLogEntry):
+        log_entry_model.objects.filter(level='exception').update(level='critical')
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('instance', '0025_auto_20150920_0907'),
+    ]
+
+    operations = [
+        migrations.AlterField(
+            model_name='generallogentry',
+            name='level',
+            field=models.CharField(max_length=9, db_index=True, default='info', choices=[('debug', 'Debug'), ('info', 'Info'), ('warn', 'Warning'), ('error', 'Error'), ('critical', 'Critical')]),
+        ),
+        migrations.AlterField(
+            model_name='instancelogentry',
+            name='level',
+            field=models.CharField(max_length=9, db_index=True, default='info', choices=[('debug', 'Debug'), ('info', 'Info'), ('warn', 'Warning'), ('error', 'Error'), ('critical', 'Critical')]),
+        ),
+        migrations.AlterField(
+            model_name='serverlogentry',
+            name='level',
+            field=models.CharField(max_length=9, db_index=True, default='info', choices=[('debug', 'Debug'), ('info', 'Info'), ('warn', 'Warning'), ('error', 'Error'), ('critical', 'Critical')]),
+        ),
+        migrations.RunPython(exception_to_critical),
+    ]

instance/migrations/0027_auto_20150920_1357.py

@@ -0,0 +1,37 @@
+# -*- coding: utf-8 -*-
+from __future__ import unicode_literals
+
+from django.db import models, migrations
+
+
+def warn_to_warning(apps, schema_editor):
+    InstanceLogEntry = apps.get_model('instance', 'InstanceLogEntry')
+    ServerLogEntry = apps.get_model('instance', 'ServerLogEntry')
+    for log_entry_model in (InstanceLogEntry, ServerLogEntry):
+        log_entry_model.objects.filter(level='warn').update(level='warning')
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('instance', '0026_auto_20150920_1108'),
+    ]
+
+    operations = [
+        migrations.AlterField(
+            model_name='generallogentry',
+            name='level',
+            field=models.CharField(choices=[('debug', 'Debug'), ('info', 'Info'), ('warning', 'Warning'), ('error', 'Error'), ('critical', 'Critical')], db_index=True, max_length=9, default='info'),
+        ),
+        migrations.AlterField(
+            model_name='instancelogentry',
+            name='level',
+            field=models.CharField(choices=[('debug', 'Debug'), ('info', 'Info'), ('warning', 'Warning'), ('error', 'Error'), ('critical', 'Critical')], db_index=True, max_length=9, default='info'),
+        ),
+        migrations.AlterField(
+            model_name='serverlogentry',
+            name='level',
+            field=models.CharField(choices=[('debug', 'Debug'), ('info', 'Info'), ('warning', 'Warning'), ('error', 'Error'), ('critical', 'Critical')], db_index=True, max_length=9, default='info'),
+        ),
+        migrations.RunPython(warn_to_warning),
+    ]

instance/migrations/0028_log_entry_field_rename.py

@@ -0,0 +1,16 @@
+# -*- coding: utf-8 -*-
+from __future__ import unicode_literals
+
+from django.db import models, migrations
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('instance', '0027_auto_20150920_1357'),
+    ]
+
+    operations = [
+        migrations.RenameField('InstanceLogEntry', 'instance', 'obj'),
+        migrations.RenameField('ServerLogEntry', 'server', 'obj'),
+    ]