Add tracking logs (#206)

* feat: add tracking logs
* chore: bump edx-completion
* chore: bumps version to 4.1.0 and adds CHANGELOG entry.
* test: make COMPLETION_AGGREGATOR_ASYNC_AGGREGATION consistent between test settings and plugin settings.
* test: adds test for plugin settings

---------

Co-authored-by: andrey-canon <[email protected]>

CHANGELOG.rst

@@ -14,6 +14,12 @@ Change Log
 Unreleased
 ~~~~~~~~~~
 
+[4.1.0] - 2024-06-18
+~~~~~~~~~~~~~~~~~~~~
+
+* Emit `openedx.completion_aggregator.progress.*` tracking log events for the
+  various block/course types
+
 [4.0.3] - 2023-10-24
 ~~~~~~~~~~~~~~~~~~~~
 

README.rst

@@ -47,6 +47,15 @@ API Details
 
 For details about how the completion aggregator's REST APIs can be used, please refer to `the docstrings in views.py <https://github.com/open-craft/openedx-completion-aggregator/blob/master/completion_aggregator/api/v1/views.py#L24>`_.
 
+Event tracking
+--------------
+
+Like other parts of Open edX, the completion aggregator emits "tracking logs" events whenever completion aggregator records are created or updated by this plugin. These events can be used for analytics, for example to track learner progress in a course.
+
+Event tracking is enabled by default for edx-platform, and so event tracking is also enabled by default in the completion aggregator. This can result in a lot of events being generated — for example when a user completes the final block in a course, aggregator completion events will be generated for the containing unit, subsection, section, and course.
+
+You can limit which aggregator events are emitted by modifying the ``COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES`` setting to limit which block types (``course``, ``chapter``, ``sequential``, ``vertical``) cause tracking events to be emitted. To disable sending any completion aggregator tracking events, set ``COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES = None``.
+
 Installation and Configuration
 ------------------------------
 

completion_aggregator/__init__.py

@@ -5,4 +5,4 @@
 
 from __future__ import absolute_import, unicode_literals
 
-__version__ = '4.0.3'
+__version__ = '4.1.0'

completion_aggregator/models.py

@@ -5,6 +5,7 @@
 
 from __future__ import absolute_import, division, print_function, unicode_literals
 
+from eventtracking import tracker
 from opaque_keys.edx.django.models import CourseKeyField, UsageKeyField
 from opaque_keys.edx.keys import CourseKey, UsageKey
 
@@ -171,8 +172,46 @@ def submit_completion(self, user, course_key, block_key, aggregation_name, earne
                 'last_modified': last_modified,
             },
         )
+        self.emit_completion_aggregator_logs([obj])
+
         return obj, is_new
 
+    @staticmethod
+    def emit_completion_aggregator_logs(updated_aggregators):
+        """
+        Emit a tracking log for each element of the list parameter.
+
+        Parameters
+        ----------
+            updated_aggregators: List of Aggregator instances
+
+        """
+        if not settings.COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES:
+            return
+
+        for aggregator in updated_aggregators:
+            block_type = aggregator.aggregation_name
+
+            if block_type not in settings.COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES:
+                continue
+
+            event_name = f"openedx.completion_aggregator.progress.{block_type}"
+
+            tracker.emit(
+                event_name,
+                {
+                    "user_id": aggregator.user_id,
+                    "course_id": str(aggregator.course_key),
+                    "block_id": str(aggregator.block_key),
+                    "modified": aggregator.modified,
+                    "created": aggregator.created,
+                    "earned": aggregator.earned,
+                    "possible": aggregator.possible,
+                    "percent": aggregator.percent,
+                    "type": block_type,
+                }
+            )
+
     def bulk_create_or_update(self, updated_aggregators):
         """
         Update the collection of aggregator object using mysql insert on duplicate update query.
@@ -194,6 +233,7 @@ def bulk_create_or_update(self, updated_aggregators):
                 else:
                     aggregation_data = [obj.get_values() for obj in updated_aggregators]
                     cur.executemany(INSERT_OR_UPDATE_AGGREGATOR_QUERY, aggregation_data)
+                    self.emit_completion_aggregator_logs(updated_aggregators)
 
 
 class Aggregator(TimeStampedModel):

completion_aggregator/settings/aws.py

@@ -9,6 +9,11 @@ def plugin_settings(settings):
     """
     Modify the provided settings object with settings specific to this plugin.
     """
+    settings.COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES = settings.ENV_TOKENS.get(
+        'COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES',
+        settings.COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES,
+    )
+
     settings.COMPLETION_AGGREGATOR_BLOCK_TYPES = set(settings.ENV_TOKENS.get(
         'COMPLETION_AGGREGATOR_BLOCK_TYPES',
         settings.COMPLETION_AGGREGATOR_BLOCK_TYPES,

completion_aggregator/settings/common.py

@@ -15,6 +15,13 @@ def plugin_settings(settings):
         'sequential',
         'vertical',
     }
+
+    # Emit feature publishes progress events to track aggregated completion.
+    # Defaults to the full set of block types subject to completion aggregation.
+    # Block types may be removed from this list to limit the tracking log events emitted.
+    settings.COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES = settings.COMPLETION_AGGREGATOR_BLOCK_TYPES.copy()
+
+    # Synchronous completion aggregation is enabled by default
     settings.COMPLETION_AGGREGATOR_ASYNC_AGGREGATION = False
 
     # Names of the batch operations locks

requirements/base.in

@@ -9,5 +9,6 @@ django-model-utils    # Provides TimeStampedModel abstract base class
 edx-opaque-keys    # Provides CourseKey and UsageKey
 edx-completion
 edx-toggles
+event-tracking     # Allows the aggregator to emit tracking events
 six
 XBlock[django]

requirements/base.txt

@@ -97,7 +97,7 @@ drf-jwt==1.19.2
     # via edx-drf-extensions
 edx-celeryutils==1.2.5
     # via -r requirements/base.in
-edx-completion==4.4.0
+edx-completion==4.6.0
     # via -r requirements/base.in
 edx-django-utils==5.10.1
     # via
@@ -119,7 +119,9 @@ edx-toggles==5.1.1
     #   edx-completion
     #   event-tracking
 event-tracking==2.3.0
-    # via edx-completion
+    # via
+    #   -r requirements/base.in
+    # edx-completion
 fastavro==1.9.4
     # via openedx-events
 fs==2.4.16

requirements/dev.txt

@@ -173,7 +173,7 @@ drf-jwt==1.19.2
     #   edx-drf-extensions
 edx-celeryutils==1.2.5
     # via -r requirements/quality.txt
-edx-completion==4.4.0
+edx-completion==4.6.0
     # via -r requirements/quality.txt
 edx-django-utils==5.10.1
     # via

requirements/doc.txt

@@ -184,7 +184,7 @@ edx-celeryutils==1.2.5
     # via
     #   -r requirements/base.txt
     #   -r requirements/test.txt
-edx-completion==4.4.0
+edx-completion==4.6.0
     # via
     #   -r requirements/base.txt
     #   -r requirements/test.txt

requirements/quality.txt

@@ -158,7 +158,7 @@ drf-jwt==1.19.2
     #   edx-drf-extensions
 edx-celeryutils==1.2.5
     # via -r requirements/test.txt
-edx-completion==4.4.0
+edx-completion==4.6.0
     # via -r requirements/test.txt
 edx-django-utils==5.10.1
     # via

requirements/test.txt

@@ -143,7 +143,7 @@ drf-jwt==1.19.2
     #   edx-drf-extensions
 edx-celeryutils==1.2.5
     # via -r requirements/base.txt
-edx-completion==4.4.0
+edx-completion==4.6.0
     # via -r requirements/base.txt
 edx-django-utils==5.10.1
     # via

test_settings.py

@@ -20,8 +20,9 @@ def root(*args):
 
 AUTH_USER_MODEL = 'auth.User'
 CELERY_ALWAYS_EAGER = True
-COMPLETION_AGGREGATOR_BLOCK_TYPES = {'course', 'chapter', 'sequential'}
-COMPLETION_AGGREGATOR_ASYNC_AGGREGATION = True
+COMPLETION_AGGREGATOR_ASYNC_AGGREGATION = False
+COMPLETION_AGGREGATOR_BLOCK_TYPES = {'course', 'chapter', 'sequential', 'vertical'}
+COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES = COMPLETION_AGGREGATOR_BLOCK_TYPES
 COMPLETION_AGGREGATOR_AGGREGATION_LOCK = 'COMPLETION_AGGREGATOR_AGGREGATION_LOCK'
 COMPLETION_AGGREGATOR_CLEANUP_LOCK = 'COMPLETION_AGGREGATOR_CLEANUP_LOCK'
 COMPLETION_AGGREGATOR_AGGREGATION_LOCK_TIMEOUT_SECONDS = 1800
@@ -53,6 +54,7 @@ def root(*args):
     'oauth2_provider',
     'waffle',
     'test_utils.test_app',
+    'eventtracking.django.apps.EventTrackingConfig',
 )
 
 LOCALE_PATHS = [root('completion_aggregator', 'conf', 'locale')]
@@ -81,5 +83,8 @@ def root(*args):
 ]
 USE_TZ = True
 
+# Enables event tracking in the tests, see https://github.com/openedx/event-tracking
+EVENT_TRACKING_ENABLED = True
+
 # pylint: disable=unused-import,wrong-import-position
 from test_utils.test_app import celery  # isort:skip

tests/test_batch.py

@@ -60,6 +60,7 @@ def test_synchronous_aggregation(mock_task, users):
     assert mock_task.call_count == 4  # Called once per created BlockCompletion
 
 
+@override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
 @patch('completion_aggregator.tasks.aggregation_tasks.update_aggregators.apply_async')
 def test_with_multiple_batches(mock_task, users):
     course_key = CourseKey.from_string('course-v1:OpenCraft+Onboarding+2018')
@@ -87,6 +88,7 @@ def test_with_multiple_batches(mock_task, users):
     }
 
 
+@override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
 @patch('completion_aggregator.tasks.aggregation_tasks.update_aggregators.apply_async')
 def test_with_stale_completions(mock_task, users):
     course_key = CourseKey.from_string('course-v1:OpenCraft+Onboarding+2018')
@@ -107,6 +109,7 @@ def test_with_stale_completions(mock_task, users):
     assert mock_task.call_count == 2  # Called once for each user
 
 
+@override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
 @patch('completion_aggregator.tasks.aggregation_tasks.update_aggregators.apply_async')
 def test_with_full_course_stale_completion(mock_task, users):
     course_key = CourseKey.from_string('course-v1:OpenCraft+Onboarding+2018')

tests/test_core.py

@@ -15,7 +15,7 @@
 from xblock.core import XBlock
 
 from django.contrib.auth import get_user_model
-from django.test import TestCase
+from django.test import TestCase, override_settings
 from django.utils.timezone import now
 
 from completion.models import BlockCompletion
@@ -282,6 +282,7 @@ def test_unmodified_course(self):
             ]
         )
 
+    @override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
     @XBlock.register_temp_plugin(CourseBlock, 'course')
     @XBlock.register_temp_plugin(OtherAggBlock, 'chapter')
     @XBlock.register_temp_plugin(HTMLBlock, 'html')
@@ -319,6 +320,7 @@ def test_modified_course(self):
             ]
         )
 
+    @override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
     @XBlock.register_temp_plugin(CourseBlock, 'course')
     @XBlock.register_temp_plugin(OtherAggBlock, 'chapter')
     @XBlock.register_temp_plugin(HTMLBlock, 'html')
@@ -356,6 +358,7 @@ def test_pass_changed_blocks_argument(self):
             ]
         )
 
+    @override_settings(COMPLETION_AGGREGATOR_ASYNC_AGGREGATION=True)
     @XBlock.register_temp_plugin(CourseBlock, 'course')
     @XBlock.register_temp_plugin(OtherAggBlock, 'chapter')
     @XBlock.register_temp_plugin(HTMLBlock, 'html')

tests/test_models.py

@@ -9,14 +9,17 @@
 import ddt
 import pytest
 import six
+from mock import patch
 from opaque_keys.edx.keys import UsageKey
 
+from django.conf import settings
 from django.contrib.auth import get_user_model
 from django.core.exceptions import ValidationError
-from django.test import TestCase
+from django.test import TestCase, override_settings
 from django.utils.timezone import now
 
 from completion_aggregator.models import Aggregator
+from completion_aggregator.settings import common as common_settings
 
 
 @ddt.ddt
@@ -31,6 +34,13 @@ class AggregatorTestCase(TestCase):
     def setUp(self):
         super().setUp()
         self.user = get_user_model().objects.create(username='testuser')
+        self.tracker_patch = patch('completion_aggregator.models.tracker')
+        self.tracker_mock = self.tracker_patch.start()
+        common_settings.plugin_settings(settings)
+
+    def tearDown(self):
+        """Stop patching."""
+        self.tracker_mock.stop()
 
     def test_submit_completion_with_invalid_user(self):
         with pytest.raises(TypeError):
@@ -43,6 +53,7 @@ def test_submit_completion_with_invalid_user(self):
                 possible=27.0,
                 last_modified=now(),
             )
+            self.tracker_mock.assert_not_called()
 
     @ddt.data(
         # Valid arguments
@@ -64,6 +75,7 @@ def test_submit_completion_with_valid_data(self, block_key_obj, aggregate_name,
         self.assertEqual(obj.earned, earned)
         self.assertEqual(obj.possible, possible)
         self.assertEqual(obj.percent, expected_percent)
+        self.assert_emit_method_called(obj)
 
     @ddt.data(
         # Earned greater than possible
@@ -105,6 +117,7 @@ def test_submit_completion_with_exception(
             )
 
             self.assertEqual(exception_message, str(context_manager.exception))
+            self.tracker_mock.assert_not_called()
 
     @ddt.data(
         (
@@ -129,6 +142,7 @@ def test_aggregate_completion_string(
             f'{six.text_type(block_key_obj)}: {expected_percent}'
         )
         self.assertEqual(six.text_type(obj), expected_string)
+        self.assert_emit_method_called(obj)
 
     @ddt.data(
         # Changes the value of earned. This does not create a new object.
@@ -179,6 +193,7 @@ def test_submit_completion_twice_with_changes(
         )
         self.assertEqual(obj.percent, expected_percent)
         self.assertTrue(is_new)
+        self.assert_emit_method_called(obj)
 
         new_obj, is_new = Aggregator.objects.submit_completion(
             user=self.user,
@@ -193,6 +208,7 @@ def test_submit_completion_twice_with_changes(
         self.assertEqual(is_new, is_second_obj_new)
         if is_second_obj_new:
             self.assertNotEqual(obj.id, new_obj.id)
+        self.assert_emit_method_called(new_obj)
 
     @ddt.data(
         (BLOCK_KEY_OBJ, 'course', 0.5, 1, 0.5),
@@ -211,3 +227,37 @@ def test_get_values(self, block_key_obj, aggregate_name, earned, possible, expec
         values = aggregator.get_values()
         self.assertEqual(values['user'], self.user.id)
         self.assertEqual(values['percent'], expected_percent)
+
+    @override_settings(COMPLETION_AGGREGATOR_TRACKING_EVENT_TYPES=None)
+    def test_submit_completion_with_tracking_disabled(self):
+        _obj, is_new = Aggregator.objects.submit_completion(
+            user=self.user,
+            course_key=self.BLOCK_KEY_OBJ.course_key,
+            block_key=self.BLOCK_KEY_OBJ,
+            aggregation_name='course',
+            earned=0.5,
+            possible=1,
+            last_modified=now(),
+        )
+        self.assertTrue(is_new)
+        self.assertEqual(len(Aggregator.objects.all()), 1)
+        self.tracker_mock.emit.assert_not_called()
+
+    def assert_emit_method_called(self, obj):
+        """Verify that the tracker.emit method was called once with the right values."""
+
+        self.tracker_mock.emit.assert_called_once_with(
+            f"openedx.completion_aggregator.progress.{obj.aggregation_name}",
+            {
+                "user_id": obj.user_id,
+                "course_id": str(obj.course_key),
+                "block_id": str(obj.block_key),
+                "modified": obj.modified,
+                "created": obj.created,
+                "earned": obj.earned,
+                "possible": obj.possible,
+                "percent": obj.percent,
+                "type": obj.aggregation_name,
+            }
+        )
+        self.tracker_mock.emit.reset_mock()