Added SVN logging observer.

It isn't triggered by anything yet. When the observer is called, it uses
Blinker to send out a signal for every [T12345] marker it sees in the
first line of each commit log. Those signals aren't connected to anything
yet.

NOTE: this requires the 'svn' Python module , which is a wrapper for the
'svn' commandline client. This client needs to be installed on our docker
when we deploy.

attract_server/attrs_extra.py

@@ -0,0 +1,17 @@
+"""Extra functionality for attrs."""
+
+import logging
+
+import attr
+
+
+def log(name):
+    """Returns a logger attr.ib
+
+    :param name: name to pass to logging.getLogger()
+    :rtype: attr.ib
+    """
+    return attr.ib(default=logging.getLogger(name),
+                   repr=False,
+                   hash=False,
+                   cmp=False)

attract_server/subversion.py

@@ -0,0 +1,53 @@
+"""Subversion interface."""
+
+from __future__ import absolute_import
+
+import re
+
+import attr
+import blinker
+import svn.remote
+
+from . import attrs_extra
+
+task_logged = blinker.NamedSignal('task_logged')
+task_marker_re = re.compile(r'\[(?P<task_id>T\d+)\]')
+FETCH_AND_OBSERVE_CHUNK_SIZE = 10
+
+
+def obtain(server_location):
+    """Returns a Connection object for the given server location."""
+
+    return svn.remote.RemoteClient(server_location)
+
+
+@attr.s
+class CommitLogObserver(object):
+    svn_client = attr.ib(validator=attr.validators.instance_of(svn.remote.RemoteClient))
+    last_seen_revision = attr.ib(default=0, validator=attr.validators.instance_of(int))
+    _log = attrs_extra.log('%s.CommitLogObserver' % __name__)
+
+    def fetch_and_observe(self):
+        """Obtains task IDs from SVN logs."""
+
+        self._log.debug('%s: fetch_and_observe()', self)
+
+        svn_log = self.svn_client.log_default(
+            revision_from=self.last_seen_revision + 1,
+            revision_to=self.last_seen_revision + FETCH_AND_OBSERVE_CHUNK_SIZE)
+
+        for log_entry in svn_log:
+            self._log.debug('- %r', log_entry)
+
+            # assumption: revisions are always logged in strictly increasing order.
+            self.last_seen_revision = log_entry.revision
+
+            # Parse the commit log to see if there are any task markers.
+            lines = log_entry.msg.split('\n', 1)
+            first_line = lines[0]
+            for match in task_marker_re.finditer(first_line):
+                task_id = match.group('task_id')
+
+                task_logged.send(self,
+                                 task_id=task_id,
+                                 log_entry=log_entry)

requirements.txt

@@ -1,9 +1,10 @@
 # Primary requirements:
 pillar
+attrs==16.1.0
+svn==0.3.42
 
 # Testing requirements:
 pytest==3.0.1
 responses==0.5.1
 pytest-cov==2.3.1
 mock==2.0.0
-

tests/logging_config.py

@@ -0,0 +1,26 @@
+LOGGING = {
+    'version': 1,
+    'formatters': {
+        'default': {'format': '%(asctime)-15s %(levelname)8s %(name)s %(message)s'}
+    },
+    'handlers': {
+        'console': {
+            'class': 'logging.StreamHandler',
+            'formatter': 'default',
+            'stream': 'ext://sys.stderr',
+        }
+    },
+    'loggers': {
+        'pillar': {'level': 'DEBUG'},
+        'attract_server': {'level': 'DEBUG'},
+        'werkzeug': {'level': 'INFO'},
+        'eve': {'level': 'WARNING'},
+        # 'requests': {'level': 'DEBUG'},
+    },
+    'root': {
+        'level': 'INFO',
+        'handlers': [
+            'console',
+        ],
+    }
+}

tests/test_subversion.py

@@ -0,0 +1,130 @@
+"""Unit test for SVN interface."""
+
+from __future__ import absolute_import
+
+import collections
+import datetime
+import logging.config
+import unittest
+
+from dateutil.tz import tzutc
+import mock
+
+import logging_config
+from attract_server import subversion
+
+SVN_SERVER_URL = 'svn://biserver/agent327'
+
+logging.config.dictConfig(logging_config.LOGGING)
+
+# Unfortunately, the svn module doesn't use classes, but uses in-function-defined
+# namedtuples instead. As a result, we can't import them, but have to recreate.
+LogEntry = collections.namedtuple('LogEntry', ['date', 'msg', 'revision', 'author', 'changelist'])
+
+SVN_LOG_BATCH_1 = [
+    LogEntry(date=datetime.datetime(2016, 4, 5, 10, 8, 5, 19211, tzinfo=tzutc()),
+             msg='Initial commit', revision=43, author='fsiddi', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 8, 13, 5, 39, 42537, tzinfo=tzutc()),
+             msg='Initial commit of layout files', revision=44, author='hjalti', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 8, 13, 6, 18, 947830, tzinfo=tzutc()),
+             msg='Second commit of layout files', revision=45, author='hjalti', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 8, 14, 22, 24, 411916, tzinfo=tzutc()),
+             msg="Add the eye lattices to the main group\n\nOtherwise when you link the agent group, those two lattices would be\nlinked as regular objects, and you'd need to move both proxy+lattices\nindividually.\n\n\n",
+             revision=46, author='pablo', changelist=None),
+]
+
+SVN_LOG_BATCH_2 = [
+    LogEntry(date=datetime.datetime(2016, 4, 13, 17, 54, 50, 244305, tzinfo=tzutc()),
+             msg='first initial agent model rework.', revision=47, author='andy', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 14, 15, 57, 30, 951714, tzinfo=tzutc()),
+             msg='third day of puching verts around', revision=48, author='andy', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 21, 8, 21, 19, 390478, tzinfo=tzutc()),
+             msg='last weeks edit. a couple of facial expression tests.\nstarting to modify the agent head heavily... W A R N I N G',
+             revision=49, author='andy', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 25, 9, 18, 17, 23841, tzinfo=tzutc()),
+             msg='some expression tests.', revision=50, author='andy', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 25, 10, 12, 23, 233796, tzinfo=tzutc()),
+             msg='older version of the layout', revision=51, author='hjalti', changelist=None),
+]
+
+SVN_LOG_BATCH_WITH_TASK_MARKERS = [
+    LogEntry(date=datetime.datetime(2016, 4, 5, 10, 8, 5, 19211, tzinfo=tzutc()),
+             msg='Initial commit', revision=1, author='fsiddi', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 8, 13, 5, 39, 42537, tzinfo=tzutc()),
+             msg='[T1234] modeled Hendrik IJzerbroot', revision=2, author='andy', changelist=None),
+    LogEntry(date=datetime.datetime(2016, 4, 8, 13, 6, 18, 947830, tzinfo=tzutc()),
+             msg='[T4415] scene layout, which also closes [T4433]', revision=3, author='hjalti',
+             changelist=None),
+]
+
+
+class TestCommitLogObserver(unittest.TestCase):
+    def setUp(self):
+        self.client = subversion.obtain(SVN_SERVER_URL)
+        # Passing in a real client to Mock() will ensure that isinstance() checks return True.
+        self.mock_client = mock.Mock(self.client, name='svn_client')
+        self.observer = subversion.CommitLogObserver(self.mock_client)
+
+    def _test_actual(self):
+        """For performing a quick test against the real SVN server.
+
+        Keep the underscore in the name when committing, and don't call it from
+        anywhere. Unit tests shouldn't be dependent on network connections.
+        """
+        observer = subversion.CommitLogObserver(self.client)
+        observer.fetch_and_observe()
+
+    def test_empty_log(self):
+        self.mock_client.log_default = mock.Mock(name='log_default', return_value=[])
+        self.observer.fetch_and_observe()
+
+        self.mock_client.log_default.assert_called_once_with(
+            revision_from=1,
+            revision_to=subversion.FETCH_AND_OBSERVE_CHUNK_SIZE)
+
+        # Should not have changed from the default.
+        self.assertEqual(self.observer.last_seen_revision, 0)
+
+    def test_two_log_calls(self):
+        self.mock_client.log_default = mock.Mock(name='log_default')
+        self.mock_client.log_default.side_effect = [
+            # First call, only four commits.
+            SVN_LOG_BATCH_1,
+            # Second call, five commits.
+            SVN_LOG_BATCH_2
+        ]
+
+        self.observer.last_seen_revision = 42
+
+        self.observer.fetch_and_observe()
+        self.mock_client.log_default.assert_called_with(
+            revision_from=43,
+            revision_to=42 + subversion.FETCH_AND_OBSERVE_CHUNK_SIZE)
+
+        self.observer.fetch_and_observe()
+        self.mock_client.log_default.assert_called_with(
+            revision_from=47,
+            revision_to=46 + subversion.FETCH_AND_OBSERVE_CHUNK_SIZE)
+
+        self.assertEqual(self.observer.last_seen_revision, 51)
+
+    def test_task_markers(self):
+        self.mock_client.log_default = mock.Mock(name='log_default',
+                                                 return_value=SVN_LOG_BATCH_WITH_TASK_MARKERS)
+        blinks = []
+
+        def record_blink(sender, **kwargs):
+            self.assertIs(self.observer, sender)
+            blinks.append(kwargs)
+
+        subversion.task_logged.connect(record_blink)
+
+        self.observer.fetch_and_observe()
+
+        self.assertEqual(3, len(blinks))
+        self.assertEqual({'log_entry': SVN_LOG_BATCH_WITH_TASK_MARKERS[1], 'task_id': 'T1234'},
+                         blinks[0])
+        self.assertEqual({'log_entry': SVN_LOG_BATCH_WITH_TASK_MARKERS[2], 'task_id': 'T4415'},
+                         blinks[1])
+        self.assertEqual({'log_entry': SVN_LOG_BATCH_WITH_TASK_MARKERS[2], 'task_id': 'T4433'},
+                         blinks[2])