[fix] Background task update_config launched multiple times #1128

Fixes #1128

Author: pandafy

openwisp_controller/config/base/config.py

@@ -4,6 +4,7 @@
 from collections import defaultdict
 
 from cache_memoize import cache_memoize
+from django.core.cache import cache
 from django.core.exceptions import ObjectDoesNotExist, PermissionDenied, ValidationError
 from django.db import models, transaction
 from django.utils.translation import gettext_lazy as _
@@ -110,6 +111,7 @@ class AbstractConfig(ChecksumCacheMixin, BaseConfig):
     )
 
     _CHECKSUM_CACHE_TIMEOUT = ChecksumCacheMixin._CHECKSUM_CACHE_TIMEOUT
+    _CONFIG_MODIFIED_TIMEOUT = 3
     _config_context_functions = list()
     _old_backend = None
 
@@ -124,9 +126,11 @@ def __init__(self, *args, **kwargs):
         self._just_created = False
         self._initial_status = self.status
         self._send_config_modified_after_save = False
+        self._config_modified_action = "config_changed"
         self._send_config_deactivated = False
         self._send_config_deactivating = False
         self._send_config_status_changed = False
+        self._is_enforcing_required_templates = False
 
     def __str__(self):
         if self._has_device():
@@ -301,17 +305,26 @@ def templates_changed(cls, action, instance, **kwargs):
         # execute only after a config has been saved or deleted
         if action not in ["post_add", "post_remove"] or instance._state.adding:
             return
+        if instance._is_enforcing_required_templates:
+            # The required templates are enforced on "post_clear" action and
+            # they are added back using Config.templates.add(). This sends a
+            # m2m_changed signal with the "post_add" action.
+            # At this stage, all templates have not yet been re-added,
+            # so the checksum cannot be accurately evaluated.
+            # Defer checksum validation until a subsequent post_add or
+            # post_remove signal is received.
+            instance._is_enforcing_required_templates = False
+            return
         # use atomic to ensure any code bound to
         # be executed via transaction.on_commit
         # is executed after the whole block
         with transaction.atomic():
             # do not send config modified signal if
             # config instance has just been created
             if not instance._just_created:
-                # sends only config modified signal
-                instance._send_config_modified_signal(action="m2m_templates_changed")
+                instance._config_modified_action = "m2m_templates_changed"
             instance.update_status_if_checksum_changed(
-                send_config_modified_signal=False
+                send_config_modified_signal=not instance._just_created
             )
 
     @classmethod
@@ -464,6 +477,7 @@ def enforce_required_templates(
                 )
             )
             if required_templates.exists():
+                instance._is_enforcing_required_templates = True
                 instance.templates.add(
                     *required_templates.order_by("name").values_list("pk", flat=True)
                 )
@@ -587,7 +601,7 @@ def save(self, *args, **kwargs):
             self._old_backend = None
         # emit signals if config is modified and/or if status is changing
         if not created and self._send_config_modified_after_save:
-            self._send_config_modified_signal(action="config_changed")
+            self._send_config_modified_signal()
             self._send_config_modified_after_save = False
         if self._send_config_status_changed:
             self._send_config_status_changed_signal()
@@ -648,6 +662,14 @@ def update_status_if_checksum_changed(
                     self._update_checksum_db(new_checksum=self.checksum_db)
                 if send_config_modified_signal:
                     self._send_config_modified_after_save = True
+                    if save:
+                        # When this method is triggered by changes to Config.templates,
+                        # those changes are applied through the related manager rather
+                        # than via Config.save(). As a result, the model's save()
+                        # method (and thus the automatic "config modified" signal)
+                        # is never invoked. To ensure the signal is still emitted,
+                        # we send it explicitly here.
+                        self._send_config_modified_signal()
             self.invalidate_checksum_cache()
         return checksum_changed
 
@@ -678,11 +700,38 @@ def _update_checksum_db(self, new_checksum=None):
         new_checksum = new_checksum or self.checksum
         self._meta.model.objects.filter(pk=self.pk).update(checksum_db=new_checksum)
 
-    def _send_config_modified_signal(self, action):
+    @property
+    def _config_modified_timeout_cache_key(self):
+        return f"config_modified_timeout_{self.pk}"
+
+    def _set_config_modified_timeout_cache(self):
+        cache.set(
+            self._config_modified_timeout_cache_key,
+            True,
+            timeout=self._CONFIG_MODIFIED_TIMEOUT,
+        )
+
+    def _delete_config_modified_timeout_cache(self):
+        cache.delete(self._config_modified_timeout_cache_key)
+
+    def _send_config_modified_signal(self, action=None):
         """
         Emits ``config_modified`` signal.
-        Called also by Template when templates of a device are modified
+
+        A short-lived cache key prevents emitting duplicate signals inside the
+        same change window; if that key exists the method returns early without
+        emitting the signal again.
+
+        Side effects
+        ------------
+        - Emits the ``config_modified`` Django signal with contextual data.
+        - Resets ``_config_modified_action`` back to ``"config_changed"`` so
+            subsequent calls without an explicit action revert to the default.
+        - Sets the debouncing cache key to avoid duplicate emissions.
         """
+        if cache.get(self._config_modified_timeout_cache_key):
+            return
+        action = action or self._config_modified_action
         assert action in [
             "config_changed",
             "related_template_changed",
@@ -697,6 +746,12 @@ def _send_config_modified_signal(self, action):
             config=self,
             device=self.device,
         )
+        cache.set(
+            self._config_modified_timeout_cache_key,
+            True,
+            timeout=self._CONFIG_MODIFIED_TIMEOUT,
+        )
+        self._config_modified_action = "config_changed"
 
     def _send_config_deactivating_signal(self):
         """

openwisp_controller/config/tests/test_admin.py

@@ -54,6 +54,47 @@
 Group = load_model("openwisp_users", "Group")
 
 
+class TestDeviceAdminMixin:
+    _device_params = {
+        "name": "test-device",
+        "hardware_id": "1234",
+        "mac_address": CreateConfigTemplateMixin.TEST_MAC_ADDRESS,
+        "key": CreateConfigTemplateMixin.TEST_KEY,
+        "model": "",
+        "os": "",
+        "notes": "",
+        "config-0-id": "",
+        "config-0-device": "",
+        "config-0-backend": "netjsonconfig.OpenWrt",
+        "config-0-templates": "",
+        "config-0-config": json.dumps({}),
+        "config-0-context": "",
+        "config-TOTAL_FORMS": 1,
+        "config-INITIAL_FORMS": 0,
+        "config-MIN_NUM_FORMS": 0,
+        "config-MAX_NUM_FORMS": 1,
+        # openwisp_controller.connection
+        "deviceconnection_set-TOTAL_FORMS": 0,
+        "deviceconnection_set-INITIAL_FORMS": 0,
+        "deviceconnection_set-MIN_NUM_FORMS": 0,
+        "deviceconnection_set-MAX_NUM_FORMS": 1000,
+        "command_set-TOTAL_FORMS": 0,
+        "command_set-INITIAL_FORMS": 0,
+        "command_set-MIN_NUM_FORMS": 0,
+        "command_set-MAX_NUM_FORMS": 1000,
+    }
+    # WARNING - WATCHOUT
+    # this class attribute is changed dynamically
+    # by other apps which add inlines to DeviceAdmin
+    _additional_params = {}
+
+    def _get_device_params(self, org):
+        p = self._device_params.copy()
+        p.update(self._additional_params)
+        p["organization"] = org.pk
+        return p
+
+
 class TestImportExportMixin:
     """
     Reused in OpenWISP Monitoring
@@ -237,6 +278,7 @@ class TestAdmin(
     CreateDeviceGroupMixin,
     CreateConfigTemplateMixin,
     TestVpnX509Mixin,
+    TestDeviceAdminMixin,
     TestAdminMixin,
     TestCase,
 ):
@@ -278,10 +320,6 @@ class TestAdmin(
         "command_set-MIN_NUM_FORMS": 0,
         "command_set-MAX_NUM_FORMS": 1000,
     }
-    # WARNING - WATCHOUT
-    # this class attribute is changed dynamically
-    # by other apps which add inlines to DeviceAdmin
-    _additional_params = {}
 
     def setUp(self):
         self.client.force_login(self._get_admin())
@@ -291,12 +329,6 @@ def tearDownClass(cls):
         super().tearDownClass()
         devnull.close()
 
-    def _get_device_params(self, org):
-        p = self._device_params.copy()
-        p.update(self._additional_params)
-        p["organization"] = org.pk
-        return p
-
     def test_device_and_template_different_organization(self):
         org1 = self._get_org()
         template = self._create_template(organization=org1)
@@ -2251,6 +2283,7 @@ def test_templates_fetch_queries_10(self):
 class TestTransactionAdmin(
     CreateConfigTemplateMixin,
     TestAdminMixin,
+    TestDeviceAdminMixin,
     TransactionTestCase,
 ):
     app_label = "config"
@@ -2569,6 +2602,152 @@ def test_restoring_template_sends_config_modified(self):
         self.assertEqual(config.status, "modified")
         self.assertNotEqual(config.checksum, config_checksum)
 
+    @patch.object(Config, "_CONFIG_MODIFIED_TIMEOUT", 3)
+    def test_config_modified_signal(self):
+        """
+        Verifies multiple config_modified signal are not sent for
+        a single change
+        """
+        required = self._create_template(
+            name="SSH Keys",
+            required=True,
+            config={
+                "files": [
+                    {
+                        "path": "/etc/dropbear/authorized_keys",
+                        "mode": "0600",
+                        "contents": "ssh-rsa",
+                    }
+                ]
+            },
+        )
+        template1 = self._create_template(
+            default_values={"ssid": "OpenWISP"}, default=True
+        )
+        template2 = self._create_template(
+            name="template2",
+            config={"interfaces": [{"name": "{{ ifname }}", "type": "ethernet"}]},
+            default_values={"ifname": "eth1"},
+            default=True,
+        )
+        path = reverse(f"admin:{self.app_label}_device_add")
+        params = self._get_device_params(org=self._get_org())
+        params.update(
+            {"config-0-templates": f"{required.pk},{template1.pk},{template2.pk}"}
+        )
+        response = self.client.post(path, data=params, follow=True)
+        self.assertEqual(response.status_code, 200)
+
+        config = Device.objects.get(name=params["name"]).config
+        self.assertEqual(config.templates.count(), 3)
+        path = reverse(f"admin:{self.app_label}_device_change", args=[config.device_id])
+        params.update(
+            {
+                "config-0-id": str(config.pk),
+                "config-0-device": str(config.device_id),
+                "config-INITIAL_FORMS": 1,
+                "_continue": True,
+            }
+        )
+
+        config._delete_config_modified_timeout_cache()
+        with self.subTest(
+            "Updating the unused context variable does not send config_modified signal"
+        ):
+            with patch(
+                "openwisp_controller.config.signals.config_modified.send"
+            ) as mocked_signal:
+                params.update(
+                    {
+                        "config-0-context": json.dumps(
+                            {"ssid": "Updated", "ifname": "eth1"}
+                        )
+                    }
+                )
+                response = self.client.post(path, data=params, follow=True)
+                self.assertEqual(response.status_code, 200)
+                config.refresh_from_db()
+                self.assertEqual(config.context["ssid"], "Updated")
+                mocked_signal.assert_not_called()
+
+        config._delete_config_modified_timeout_cache()
+        with self.subTest(
+            "Changing used context variable sends config_modified signal"
+        ):
+            with patch(
+                "openwisp_controller.config.signals.config_modified.send"
+            ) as mocked_signal:
+                params.update(
+                    {
+                        "config-0-context": json.dumps(
+                            {"ssid": "Updated", "ifname": "eth2"}
+                        )
+                    }
+                )
+                response = self.client.post(path, data=params, follow=True)
+                self.assertEqual(response.status_code, 200)
+
+                config.refresh_from_db()
+                self.assertEqual(
+                    config.context["ssid"],
+                    "Updated",
+                )
+                self.assertEqual(config.status, "modified")
+                mocked_signal.assert_called_once()
+
+        config._delete_config_modified_timeout_cache()
+        with self.subTest("Changing device configuration sends config_modified signal"):
+            with patch(
+                "openwisp_controller.config.signals.config_modified.send"
+            ) as mocked_signal:
+                params.update(
+                    {
+                        "config-0-config": json.dumps(
+                            {"interfaces": [{"name": "eth5", "type": "ethernet"}]}
+                        )
+                    }
+                )
+                response = self.client.post(path, data=params, follow=True)
+                self.assertEqual(response.status_code, 200)
+                config.refresh_from_db()
+                self.assertEqual(
+                    config.config["interfaces"][0]["name"],
+                    "eth5",
+                )
+                self.assertEqual(config.status, "modified")
+                mocked_signal.assert_called_once()
+
+        config._delete_config_modified_timeout_cache()
+        with self.subTest("Changing applied template sends config_modified signal"):
+            with patch(
+                "openwisp_controller.config.signals.config_modified.send"
+            ) as mocked_signal:
+                response = self.client.post(
+                    reverse(
+                        f"admin:{self.app_label}_template_change", args=[template2.pk]
+                    ),
+                    data={
+                        "name": template2.name,
+                        "organization": "",
+                        "type": template2.type,
+                        "backend": template2.backend,
+                        "config": json.dumps(template2.config),
+                        "default_values": json.dumps(
+                            {
+                                "ifname": "eth3",
+                            }
+                        ),
+                        "required": False,
+                        "default": True,
+                        "_continue": True,
+                    },
+                    follow=True,
+                )
+                self.assertEqual(response.status_code, 200)
+                template2.refresh_from_db()
+                self.assertEqual(template2.default_values["ifname"], "eth3")
+                mocked_signal.assert_called_once()
+
 
 class TestDeviceGroupAdmin(
     CreateDeviceGroupMixin,