Ensure that unchanged logs are still generated on request even if there are no changes in the entire diff

Author: glennmatthews

diffsync/__init__.py

@@ -484,6 +484,9 @@ def sync_complete(
     ):
         """Callback triggered after a `sync_from` operation has completed and updated the model data of this instance.
 
+        Note that this callback is **only** triggered if the sync actually resulted in data changes. If there are no
+        detected changes, this callback will **not** be called.
+
         The default implementation does nothing, but a subclass could use this, for example, to perform bulk updates
         to a backend (such as a file) that doesn't readily support incremental updates to individual records.
 

diffsync/workers.py

@@ -240,21 +240,25 @@ def __init__(
         self.action: Optional[str] = None
 
     def perform_sync(self) -> bool:
-        """Perform data synchronization based on the provided diff."""
-        if not self.diff.has_diffs():
-            self.base_logger.info("No changes to synchronize")
-            return False
+        """Perform data synchronization based on the provided diff.
 
+        Returns:
+            bool: True if any changes were actually performed, else False.
+        """
+        changed = False
         self.base_logger.info("Beginning sync")
         for element in self.diff.get_children():
-            self.sync_diff_element(element)
+            changed |= self.sync_diff_element(element)
         self.base_logger.info("Sync complete")
-        return True
+        return changed
 
-    def sync_diff_element(self, element: DiffElement, parent_model: "DiffSyncModel" = None):
+    def sync_diff_element(self, element: DiffElement, parent_model: "DiffSyncModel" = None) -> bool:
         """Recursively synchronize the given DiffElement and its children, if any, into the dst_diffsync.
 
         Helper method to `perform_sync`.
+
+        Returns:
+            bool: True if this element or any of its children resulted in actual changes, else False.
         """
         self.model_class = getattr(self.dst_diffsync, element.type)
         diffs = element.get_attrs_diffs()
@@ -276,12 +280,12 @@ def sync_diff_element(self, element: DiffElement, parent_model: "DiffSyncModel"
         except ObjectNotFound:
             model = None
 
-        modified_model = self.sync_model(model, ids, attrs)
+        changed, modified_model = self.sync_model(model, ids, attrs)
         model = modified_model or model
 
         if not modified_model or not model:
             self.logger.warning("No object resulted from sync, will not process child objects.")
-            return
+            return changed
 
         if self.action == "create":
             if parent_model:
@@ -293,22 +297,29 @@ def sync_diff_element(self, element: DiffElement, parent_model: "DiffSyncModel"
             if model.model_flags & DiffSyncModelFlags.SKIP_CHILDREN_ON_DELETE:
                 # We don't need to process the child objects, but we do need to discard them from the dst_diffsync
                 self.dst_diffsync.remove(model, remove_children=True)
-                return
+                return changed
             self.dst_diffsync.remove(model)
 
         for child in element.get_children():
-            self.sync_diff_element(child, parent_model=model)
+            changed |= self.sync_diff_element(child, parent_model=model)
 
-    def sync_model(self, model: Optional["DiffSyncModel"], ids: Mapping, attrs: Mapping) -> Optional["DiffSyncModel"]:
+        return changed
+
+    def sync_model(
+        self, model: Optional["DiffSyncModel"], ids: Mapping, attrs: Mapping
+    ) -> Tuple[bool, Optional["DiffSyncModel"]]:
         """Create/update/delete the current DiffSyncModel with current ids/attrs, and update self.status and self.message.
 
         Helper method to `sync_diff_element`.
+
+        Returns:
+            tuple: (changed, model) where model may be None if an error occurred
         """
         if self.action is None:
             status = DiffSyncStatus.SUCCESS
             message = "No changes to apply; no action needed"
             self.log_sync_status(self.action, status, message)
-            return model
+            return (False, model)
 
         try:
             self.logger.debug(f"Attempting model {self.action}")
@@ -338,12 +349,12 @@ def sync_model(self, model: Optional["DiffSyncModel"], ids: Mapping, attrs: Mapp
             message = str(exception)
             self.log_sync_status(self.action, status, message)
             if self.flags & DiffSyncFlags.CONTINUE_ON_FAILURE:
-                return None
+                return (True, None)
             raise
 
         self.log_sync_status(self.action, status, message)
 
-        return model
+        return (True, model)
 
     def log_sync_status(self, action: Optional[str], status: DiffSyncStatus, message: str):
         """Log the current sync status at the appropriate verbosity with appropriate context.

tests/unit/test_diffsync.py

@@ -368,6 +368,23 @@ def test_diffsync_sync_from(backend_a, backend_b):
         backend_a.get_by_uids(["nyc", "sfo"], "device")
 
 
+def check_successful_sync_log_sanity(log, src, dst, flags):
+    """Given a successful sync, make sure the captured structlogs are correct at a high level."""
+    # All logs generated during the sync should include the src, dst, and flags data
+    for event in log.events:
+        assert "src" in event and event["src"] == src
+        assert "dst" in event and event["dst"] == dst
+        assert "flags" in event and event["flags"] == flags
+
+    # No warnings or errors should have been logged in a fully successful sync
+    assert all(event["level"] == "debug" or event["level"] == "info" for event in log.events)
+
+    # Logs for beginning and end of diff and sync should have been generated
+    assert log.has("Beginning diff calculation", level="info")
+    assert log.has("Diff calculation complete", level="info")
+    assert log.has("Beginning sync", level="info")
+
+
 def check_sync_logs_against_diff(diffsync, diff, log, errors_permitted=False):
     """Given a Diff, make sure the captured structlogs correctly correspond to its contents/actions."""
     for element in diff.get_children():
@@ -441,29 +458,39 @@ def check_sync_logs_against_diff(diffsync, diff, log, errors_permitted=False):
             check_sync_logs_against_diff(diffsync, element.child_diff, log, errors_permitted)
 
 
-def test_diffsync_sync_from_successful_logging(log, backend_a, backend_b):
-    diff = backend_a.diff_from(backend_b)
+def test_diffsync_no_log_unchanged_by_default(log, backend_a):
+    backend_a.sync_from(backend_a)
+
+    # Make sure logs were accurately generated
+    check_successful_sync_log_sanity(log, backend_a, backend_a, DiffSyncFlags.NONE)
+
+    # Since there were no changes, and we didn't set LOG_UNCHANGED_RECORDS, there should be no "unchanged" logs
+    assert not any(event for event in log.events if "action" in event)
+    assert not any(event for event in log.events if "status" in event)
+
+
+def test_diffsync_log_unchanged_even_if_no_changes_overall(log, backend_a):
+    diff = backend_a.diff_from(backend_a)
+    assert not diff.has_diffs()
     # Discard logs generated during diff calculation
     log.events = []
 
-    backend_a.sync_from(backend_b, flags=DiffSyncFlags.LOG_UNCHANGED_RECORDS)
+    backend_a.sync_from(backend_a, flags=DiffSyncFlags.LOG_UNCHANGED_RECORDS)
 
-    # All logs generated during the sync should include the src, dst, and flags data
-    for event in log.events:
-        assert "src" in event and event["src"] == backend_b
-        assert "dst" in event and event["dst"] == backend_a
-        assert "flags" in event and event["flags"] == DiffSyncFlags.LOG_UNCHANGED_RECORDS
+    # Make sure logs were accurately generated
+    check_successful_sync_log_sanity(log, backend_a, backend_a, DiffSyncFlags.LOG_UNCHANGED_RECORDS)
+    check_sync_logs_against_diff(backend_a, diff, log)
 
-    # No warnings or errors should have been logged in a fully successful sync
-    assert all(event["level"] == "debug" or event["level"] == "info" for event in log.events)
 
-    # Logs for beginning and end of diff and sync should have been generated
-    assert log.has("Beginning diff calculation", level="info")
-    assert log.has("Diff calculation complete", level="info")
-    assert log.has("Beginning sync", level="info")
-    assert log.has("Sync complete", level="info")
+def test_diffsync_sync_from_successful_logging(log, backend_a, backend_b):
+    diff = backend_a.diff_from(backend_b)
+    # Discard logs generated during diff calculation
+    log.events = []
+
+    backend_a.sync_from(backend_b, flags=DiffSyncFlags.LOG_UNCHANGED_RECORDS)
 
     # Make sure logs were accurately generated
+    check_successful_sync_log_sanity(log, backend_b, backend_a, DiffSyncFlags.LOG_UNCHANGED_RECORDS)
     check_sync_logs_against_diff(backend_a, diff, log)