Resolve missing kind preventing successful sync of quiz logs and quieter sync logging

kolibri/core/auth/management/utils.py

@@ -530,8 +530,6 @@ def _sync(self, sync_session_client, **options):  # noqa: C901
                 )
             )
 
-        logger.info("Syncing has been initiated (this may take a while)...")
-
         try:
             # pull from server
             if not no_pull:
@@ -578,7 +576,8 @@ def _sync(self, sync_session_client, **options):  # noqa: C901
             self.job.save_meta()
 
         dataset_cache.deactivate()
-        logger.info("Syncing has been completed.")
+        if not noninteractive:
+            logger.info("Syncing has been completed.")
 
     @contextmanager
     def _lock(self):
@@ -634,8 +633,7 @@ def _pull(
 
         self._session_tracker_adapter(
             sync_client.signals.session,
-            "Creating pull transfer session",
-            "Completed pull transfer session",
+            noninteractive,
         )
 
         sync_client.initialize(sync_filter)
@@ -679,8 +677,7 @@ def _push(
 
         self._session_tracker_adapter(
             sync_client.signals.session,
-            "Creating push transfer session",
-            "Completed push transfer session",
+            noninteractive,
         )
 
         with self._lock():
@@ -705,29 +702,26 @@ def _update_all_progress(self, progress_fraction, progress):
             self.job.extra_metadata.update(progress.extra_data)
             self.job.save_meta()
 
-    def _session_tracker_adapter(self, signal_group, started_msg, completed_msg):
+    def _session_tracker_adapter(self, signal_group, noninteractive):
         """
         Attaches a signal handler to session creation signals
 
         :type signal_group: morango.sync.syncsession.SyncSignalGroup
-        :type started_msg: str
-        :type completed_msg: str
+        :type noninteractive: bool
         """
 
         @run_once
         def session_creation(transfer_session):
             """
             A session is created individually for pushing and pulling
             """
-            logger.info(started_msg)
             if self.job:
                 self.job.extra_metadata.update(sync_state=State.SESSION_CREATION)
 
         @run_once
         def session_destruction(transfer_session):
-            if transfer_session.records_total == 0:
+            if not noninteractive and transfer_session.records_total == 0:
                 logger.info("There are no records to transfer")
-            logger.info(completed_msg)
 
         signal_group.started.connect(session_creation)
         signal_group.completed.connect(session_destruction)
@@ -756,7 +750,8 @@ def stats_msg(transfer_session):
             )
 
         def stats(transfer_session):
-            logger.info(stats_msg(transfer_session))
+            if transfer_session.records_total > 0:
+                logger.info(stats_msg(transfer_session))
 
         def handler(transfer_session):
             """
@@ -787,9 +782,6 @@ def handler(transfer_session):
 
         signal_group.connect(handler)
 
-        # log one more time at end to capture in logging output
-        signal_group.completed.connect(stats)
-
     def _queueing_tracker_adapter(
         self, signal_group, message, sync_state, noninteractive
     ):
@@ -806,16 +798,18 @@ def _queueing_tracker_adapter(
         def started(transfer_session):
             dataset_cache.clear()
             if noninteractive or tracker.progressbar is None:
-                logger.info(message)
+                if (
+                    not sync_state.endswith("DEQUEUING")
+                    or transfer_session.records_total > 0
+                ):
+                    logger.info(message)
+                else:
+                    logger.info("No records transferred")
 
         def handler(transfer_session):
             tracker.update_progress(
                 message=message, extra_data=dict(sync_state=sync_state)
             )
 
-        if noninteractive or tracker.progressbar is None:
-            signal_group.started.connect(started)
-
         signal_group.started.connect(started)
         signal_group.started.connect(handler)
-        signal_group.completed.connect(handler)

kolibri/core/logger/api.py

@@ -386,6 +386,7 @@ def create(self, request):
                 start_timestamp=start_timestamp,
                 end_timestamp=start_timestamp,
                 user=user,
+                kind=kind,
                 visitor_id=visitor_id,
                 extra_fields={"context": context.to_dict()},
             )

kolibri/core/logger/migrations/0010_min_length_validation.py

@@ -0,0 +1,49 @@
+# -*- coding: utf-8 -*-
+# Generated by Django 1.11.29 on 2021-11-04 16:08
+from __future__ import unicode_literals
+
+import django.core.validators
+from django.db import migrations
+from django.db import models
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ("logger", "0009_null_channel_id_unconstrained_mastery_level"),
+    ]
+
+    operations = [
+        migrations.AlterField(
+            model_name="attemptlog",
+            name="item",
+            field=models.CharField(
+                max_length=200,
+                validators=[django.core.validators.MinLengthValidator(1)],
+            ),
+        ),
+        migrations.AlterField(
+            model_name="contentsessionlog",
+            name="kind",
+            field=models.CharField(
+                max_length=200,
+                validators=[django.core.validators.MinLengthValidator(1)],
+            ),
+        ),
+        migrations.AlterField(
+            model_name="contentsummarylog",
+            name="kind",
+            field=models.CharField(
+                max_length=200,
+                validators=[django.core.validators.MinLengthValidator(1)],
+            ),
+        ),
+        migrations.AlterField(
+            model_name="examattemptlog",
+            name="item",
+            field=models.CharField(
+                max_length=200,
+                validators=[django.core.validators.MinLengthValidator(1)],
+            ),
+        ),
+    ]

kolibri/core/logger/models.py

@@ -17,6 +17,7 @@
 from django.core.exceptions import ObjectDoesNotExist
 from django.core.exceptions import ValidationError
 from django.core.validators import MaxValueValidator
+from django.core.validators import MinLengthValidator
 from django.core.validators import MinValueValidator
 from django.db import models
 from django.utils import timezone
@@ -119,7 +120,7 @@ class ContentSessionLog(BaseLogModel):
         help_text="(in seconds)", default=0.0, validators=[MinValueValidator(0)]
     )
     progress = models.FloatField(default=0, validators=[MinValueValidator(0)])
-    kind = models.CharField(max_length=200)
+    kind = models.CharField(max_length=200, validators=[MinLengthValidator(1)])
     extra_fields = JSONField(default={}, blank=True)
 
     def save(self, *args, **kwargs):
@@ -150,7 +151,7 @@ class ContentSummaryLog(BaseLogModel):
     progress = models.FloatField(
         default=0, validators=[MinValueValidator(0), MaxValueValidator(1.01)]
     )
-    kind = models.CharField(max_length=200)
+    kind = models.CharField(max_length=200, validators=[MinLengthValidator(1)])
     extra_fields = JSONField(default={}, blank=True)
 
     def calculate_source_id(self):
@@ -259,7 +260,7 @@ class BaseAttemptLog(BaseLogModel):
 
     # Unique identifier within the relevant assessment for the particular question/item
     # that this attemptlog is a record of an interaction with.
-    item = models.CharField(max_length=200)
+    item = models.CharField(max_length=200, validators=[MinLengthValidator(1)])
     start_timestamp = DateTimeTzField()
     end_timestamp = DateTimeTzField()
     completion_timestamp = DateTimeTzField(blank=True, null=True)

kolibri/core/logger/test/test_integrated_api.py

@@ -101,6 +101,7 @@ def test_start_session_anonymous_succeeds(self):
         self.assertEqual(log.content_id, self.content_id)
         self.assertEqual(log.channel_id, self.channel_id)
         self.assertIsNotNone(log.visitor_id)
+        self.assertEqual(self.node.kind, log.kind)
         self.assertEqual(log.extra_fields["context"]["node_id"], self.node.id)
         self.assertEqual(ContentSummaryLog.objects.all().count(), 0)
         result = response.json()
@@ -124,6 +125,7 @@ def test_start_session_logged_in_succeeds(self):
         self.assertEqual(log.content_id, self.content_id)
         self.assertEqual(log.channel_id, self.channel_id)
         self.assertEqual(log.extra_fields["context"]["node_id"], self.node.id)
+        self.assertEqual(self.node.kind, log.kind)
         self.assertEqual(ContentSummaryLog.objects.all().count(), 1)
         log = ContentSummaryLog.objects.get()
         self.assertEqual(log.content_id, self.content_id)
@@ -314,6 +316,7 @@ def test_start_assessment_session_logged_in_coach_assigned_succeeds(self):
         self.assertEqual(ContentSessionLog.objects.all().count(), 1)
         log = ContentSessionLog.objects.get()
         self.assertEqual(log.content_id, quiz.id)
+        self.assertEqual(content_kinds.QUIZ, log.kind)
         self.assertIsNone(log.channel_id)
         self.assertEqual(log.extra_fields["context"]["quiz_id"], quiz.id)
         self.assertEqual(ContentSummaryLog.objects.all().count(), 1)