Merge pull request #2569 from getsentry/notification-logging

Add logging to digest building and email delivery.

Author: ted kaemming

src/sentry/digests/notifications.py

@@ -92,14 +92,57 @@ def attach_state(project, groups, rules, event_counts, user_counts):
     }
 
 
+class Pipeline(object):
+    def __init__(self):
+        self.operations = []
+
+    def __call__(self, sequence):
+        return reduce(lambda x, operation: operation(x), self.operations, sequence)
+
+    def apply(self, function):
+        def operation(sequence):
+            result = function(sequence)
+            logger.debug('%r applied to %s items.', function, len(sequence))
+            return result
+        self.operations.append(operation)
+        return self
+
+    def filter(self, function):
+        def operation(sequence):
+            result = filter(function, sequence)
+            logger.debug('%r filtered %s items to %s.', function, len(sequence), len(result))
+            return result
+        self.operations.append(operation)
+        return self
+
+    def map(self, function):
+        def operation(sequence):
+            result = map(function, sequence)
+            logger.debug('%r applied to %s items.', function, len(sequence))
+            return result
+        self.operations.append(operation)
+        return self
+
+    def reduce(self, function, initializer):
+        def operation(sequence):
+            result = reduce(function, sequence, initializer(sequence))
+            logger.debug('%r reduced %s items to %s.', function, len(sequence), len(result))
+            return result
+        self.operations.append(operation)
+        return self
+
+
 def rewrite_record(record, project, groups, rules):
     event = record.value.event
+
+    # Reattach the group to the event.
     group = groups.get(event.group_id)
-    if group is None:
+    if group is not None:
+        event.group = group
+    else:
+        logger.debug('%r could not be associated with a group.', record)
         return
 
-    event.group = group
-
     return Record(
         record.key,
         Notification(
@@ -110,36 +153,38 @@ def rewrite_record(record, project, groups, rules):
     )
 
 
-def group_records(records):
-    results = defaultdict(lambda: defaultdict(list))
-    for record in records:
-        group = record.value.event.group
-        for rule in record.value.rules:
-            results[rule][group].append(record)
+def group_records(groups, record):
+    group = record.value.event.group
+    rules = record.value.rules
+    if not rules:
+        logger.debug('%r has no associated rules, and will not be added to any groups.', record)
+
+    for rule in rules:
+        groups[rule][group].append(record)
 
-    return results
+    return groups
 
 
-def sort_groups(grouped):
-    def sort_by_events(groups):
-        return OrderedDict(
+def sort_group_contents(rules):
+    for key, groups in rules.iteritems():
+        rules[key] = OrderedDict(
             sorted(
                 groups.items(),
                 key=lambda (group, records): (group.event_count, group.user_count),
                 reverse=True,
-            ),
+            )
         )
+    return rules
 
-    def sort_by_groups(rules):
-        return OrderedDict(
-            sorted(
-                rules.items(),
-                key=lambda (rule, groups): len(groups),
-                reverse=True,
-            ),
-        )
 
-    return sort_by_groups({rule: sort_by_events(groups) for rule, groups in grouped.iteritems()})
+def sort_rule_groups(rules):
+    return OrderedDict(
+        sorted(
+            rules.items(),
+            key=lambda (rule, groups): len(groups),
+            reverse=True,
+        ),
+    )
 
 
 def build_digest(project, records, state=None):
@@ -153,6 +198,16 @@ def build_digest(project, records, state=None):
         state = fetch_state(project, records)
 
     state = attach_state(**state)
-    records = filter(None, map(functools.partial(rewrite_record, **state), records))
-    records = filter(lambda record: record.value.event.group.get_status() is GroupStatus.UNRESOLVED, records)
-    return sort_groups(group_records(records))
+
+    def check_group_state(record):
+        return record.value.event.group.get_status() is GroupStatus.UNRESOLVED
+
+    pipeline = Pipeline(). \
+        map(functools.partial(rewrite_record, **state)). \
+        filter(bool). \
+        filter(check_group_state). \
+        reduce(group_records, lambda sequence: defaultdict(lambda: defaultdict(list))). \
+        apply(sort_group_contents). \
+        apply(sort_rule_groups)
+
+    return pipeline(records)

src/sentry/plugins/sentry_mail/models.py

@@ -52,6 +52,7 @@ def _build_message(self, subject, template=None, html_template=None, body=None,
                    project=None, group=None, headers=None, context=None):
         send_to = self.get_send_to(project)
         if not send_to:
+            logger.debug('Skipping message rendering, no users to send to.')
             return
 
         subject_prefix = self.get_option('subject_prefix', project) or self.subject_prefix

src/sentry/utils/email.py

@@ -7,6 +7,7 @@
 """
 from __future__ import absolute_import
 
+import logging
 import os
 import time
 import toronado
@@ -25,6 +26,9 @@
 from sentry.utils import metrics
 from sentry.utils.safe import safe_execute
 
+
+logger = logging.getLogger(__name__)
+
 SMTP_HOSTNAME = getattr(settings, 'SENTRY_SMTP_HOSTNAME', 'localhost')
 ENABLE_EMAIL_REPLIES = getattr(settings, 'SENTRY_ENABLE_EMAIL_REPLIES', False)
 
@@ -240,7 +244,10 @@ def build(self, to, reply_to=None, cc=None, bcc=None):
     def get_built_messages(self, to=None, bcc=None):
         send_to = set(to or ())
         send_to.update(self._send_to)
-        return [self.build(to=email, reply_to=send_to, bcc=bcc) for email in send_to]
+        results = [self.build(to=email, reply_to=send_to, bcc=bcc) for email in send_to]
+        if not results:
+            logger.debug('Did not build any messages, no users to send to.')
+        return results
 
     def send(self, to=None, bcc=None, fail_silently=False):
         messages = self.get_built_messages(to, bcc=bcc)

tests/sentry/digests/test_notifications.py

@@ -1,6 +1,9 @@
 from __future__ import absolute_import
 
-from collections import OrderedDict
+from collections import (
+    OrderedDict,
+    defaultdict,
+)
 
 from exam import fixture
 
@@ -10,7 +13,8 @@
     event_to_record,
     rewrite_record,
     group_records,
-    sort_groups,
+    sort_group_contents,
+    sort_rule_groups,
 )
 from sentry.testutils import TestCase
 
@@ -78,7 +82,7 @@ def rule(self):
     def test_success(self):
         events = [self.create_event(group=self.group) for _ in xrange(3)]
         records = [Record(event.id, Notification(event, [self.rule]), event.datetime) for event in events]
-        assert group_records(records) == {
+        assert reduce(group_records, records, defaultdict(lambda: defaultdict(list))) == {
             self.rule: {
                 self.group: records,
             },
@@ -109,7 +113,7 @@ def test_success(self):
             },
         }
 
-        assert sort_groups(grouped) == OrderedDict((
+        assert sort_rule_groups(sort_group_contents(grouped)) == OrderedDict((
             (rules[1], OrderedDict((
                 (groups[1], []),
                 (groups[2], []),