fix(contacts): stop retrying stale contacts the device refuses (#176)

A failed remove_contact leaves the contact on the device, so the next
cleanup sweep selected it again and logged the same warning again. With
the contact list stuck near its limit the sweeps kept coming, which is
the reported flood of hundreds of "Failed to remove stale contact"
warnings that only a restart cleared — and the restart only helped
because it reset the in-memory contact list, not because anything was
fixed.

Refusals are now counted per public key. After 3 consecutive failures
the contact is excluded from future sweeps, with one summary warning
saying the list may stay near its limit and that the contact needs
removing from the companion app. A successful removal clears the count,
so a transient failure costs nothing.

Also stop treating unset and future last_seen values as staleness. An
unset timestamp parses as 1970, and since candidates are sorted by
staleness descending, those entries sorted to the top and consumed the
whole max_remove budget every sweep — starving the contacts that could
actually have been removed. A genuinely old contact (the reporter's 722
days) is still selected; that is a real observation, not a bad
timestamp.

CHANGELOG.md

@@ -20,6 +20,15 @@ semantic versioning.
   unchanged.
 - `cmd` no longer lists commands that are disabled in `config.ini`. Commands
   with no `[<Name>_Command]` section at all are still listed, as before.
+- Stale-contact cleanup no longer retries forever (#176). When the device refuses to
+  remove a contact the contact stays in the list, so every sweep re-selected it and
+  logged the same failure again — hundreds of `Failed to remove stale contact` warnings
+  that only a restart cleared. A contact is now dropped from cleanup after
+  3 consecutive refusals, with one summary warning explaining that the list may stay
+  near its limit. A successful removal clears the count.
+- Contacts whose `last_seen` is unset (parsing as 1970) or in the future are no longer
+  treated as stale. They sorted to the top of the staleness list and consumed the whole
+  per-sweep removal budget, crowding out contacts that could actually be removed.
 
 ### Added
 

modules/repeater_manager.py

@@ -107,6 +107,15 @@ def validate_repeater_tables(db_manager: Any, logger: Any) -> None:
 class RepeaterManager:
     """Manages repeater contacts database and purging operations"""
 
+    # A contact the device keeps refusing is dropped from future sweeps after this many
+    # consecutive failures, so one unremovable contact cannot generate warnings forever.
+    MAX_STALE_REMOVAL_ATTEMPTS = 3
+
+    # last_seen values at or before this are not real observations (a zero/unset
+    # timestamp parses as 1970). They would otherwise sort to the top of the
+    # staleness list and consume the whole removal budget every sweep.
+    MIN_PLAUSIBLE_LAST_SEEN = datetime(2020, 1, 1)
+
     def __init__(self, bot):
         self.bot = bot
         self.logger = bot.logger
@@ -118,6 +127,11 @@ class RepeaterManager:
         # Initialize repeater-specific tables
         self._init_repeater_tables()
 
+        # Public keys the device has refused to remove, and how many times. A refusal
+        # leaves the contact in place, so without this the next sweep re-selects the
+        # same contacts and retries forever (see issue #176).
+        self._stale_removal_failures: dict[str, int] = {}
+
         # Initialize auto-purge monitoring
         self.contact_limit = 300  # MeshCore device limit (will be updated from device info)
         self.auto_purge_threshold = 280  # Start purging when 280+ contacts
@@ -2711,12 +2725,32 @@ class RepeaterManager:
                             # Assume it's already a datetime object
                             last_seen_dt = last_seen
 
+                        now = datetime.now()
+
+                        # A zero/unset timestamp parses as 1970 and would otherwise sort
+                        # to the top of the list, spending the whole removal budget on
+                        # contacts whose staleness is not actually known. Same for a
+                        # timestamp in the future, which cannot be a past observation.
+                        if last_seen_dt < self.MIN_PLAUSIBLE_LAST_SEEN or last_seen_dt > now:
+                            self.logger.debug(
+                                "Ignoring implausible last_seen %r for contact %s",
+                                last_seen,
+                                sanitize_name(contact_data.get('name', 'Unknown')),
+                            )
+                            continue
+
                         if last_seen_dt < cutoff_date:
+                            public_key = contact_data.get('public_key', '')
+                            attempts = self._stale_removal_failures.get(public_key, 0)
+                            if public_key and attempts >= self.MAX_STALE_REMOVAL_ATTEMPTS:
+                                # Already given up on this one; excluded so it does not
+                                # keep occupying the removal budget or the warning log.
+                                continue
                             stale_contacts.append({
                                 'name': contact_data.get('name', contact_data.get('adv_name', 'Unknown')),
-                                'public_key': contact_data.get('public_key', ''),
+                                'public_key': public_key,
                                 'last_seen': last_seen,
-                                'days_stale': (datetime.now() - last_seen_dt).days
+                                'days_stale': (now - last_seen_dt).days
                             })
                     except Exception as e:
                         self.logger.debug(f"Error parsing timestamp for contact {sanitize_name(contact_data.get('name', 'Unknown'))}: {e}")
@@ -2784,6 +2818,7 @@ class RepeaterManager:
         """Remove stale contacts to free up space"""
         try:
             removed_count = 0
+            given_up = 0
 
             for contact in stale_contacts[:max_remove]:
                 try:
@@ -2805,6 +2840,7 @@ class RepeaterManager:
 
                     if result.type == EventType.OK:
                         removed_count += 1
+                        self._stale_removal_failures.pop(public_key, None)
                         self.logger.info(f"✅ Successfully removed stale contact: {contact_name}")
 
                         # Log the removal
@@ -2814,7 +2850,24 @@ class RepeaterManager:
                         )
                     else:
                         error_code = result.payload.get('error_code', 'unknown') if hasattr(result, 'payload') else 'unknown'
-                        self.logger.warning(f"❌ Failed to remove stale contact: {contact_name} - Error: {result.type}, Code: {error_code}")
+                        # A refusal leaves the contact on the device, so the next sweep
+                        # would pick it up again. Count the attempt and stop after a few.
+                        attempts = self._stale_removal_failures.get(public_key, 0) + 1
+                        self._stale_removal_failures[public_key] = attempts
+
+                        if attempts >= self.MAX_STALE_REMOVAL_ATTEMPTS:
+                            given_up += 1
+                            self.logger.warning(
+                                f"❌ Giving up on stale contact: {contact_name} - the device "
+                                f"refused removal {attempts} times (last error: {result.type}, "
+                                f"Code: {error_code}). It will be skipped from now on."
+                            )
+                        else:
+                            self.logger.warning(
+                                f"❌ Failed to remove stale contact: {contact_name} - "
+                                f"Error: {result.type}, Code: {error_code} "
+                                f"(attempt {attempts}/{self.MAX_STALE_REMOVAL_ATTEMPTS})"
+                            )
 
                     # Small delay between removals
                     await asyncio.sleep(1)
@@ -2823,6 +2876,14 @@ class RepeaterManager:
                     self.logger.error(f"Error removing stale contact {sanitize_name(contact.get('name', 'Unknown'))}: {e}")
                     continue
 
+            if given_up:
+                self.logger.warning(
+                    "%d stale contact(s) could not be removed by the device and are now "
+                    "excluded from cleanup. The contact list may stay near its limit; "
+                    "remove them from the companion app if space is needed.",
+                    given_up,
+                )
+
             return removed_count
 
         except Exception as e:

tests/test_repeater_manager.py

@@ -1668,3 +1668,139 @@ class TestUpdateContactLimitFromDevice:
 
         assert rm.contact_limit == 300
         assert rm.auto_purge_threshold == 280
+
+
+class TestStaleContactRemovalStorm:
+    """Issue #176: a contact the device refuses stays in the list, so every sweep
+    re-selected it and logged the same failure forever."""
+
+    @staticmethod
+    def _manager(contacts):
+        mgr = object.__new__(RepeaterManager)
+        mgr.bot = SimpleNamespace(
+            meshcore=SimpleNamespace(contacts=contacts, commands=SimpleNamespace()),
+        )
+        mgr.logger = Mock()
+        mgr._stale_removal_failures = {}
+        mgr._is_repeater_device = lambda contact_data: False
+        mgr.log_purging_action = Mock()
+        return mgr
+
+    @staticmethod
+    def _contact(name, key, days_ago):
+        seen = (datetime.now() - timedelta(days=days_ago)).timestamp()
+        return {'name': name, 'public_key': key, 'last_seen': seen}
+
+    @staticmethod
+    def _result(ok):
+        if ok:
+            return SimpleNamespace(type=EventType.OK, payload={})
+        return SimpleNamespace(type=EventType.ERROR, payload={'error_code': 2})
+
+    def _refusing_device(self, mgr):
+        mgr.bot.meshcore.commands.remove_contact = AsyncMock(return_value=self._result(False))
+
+    @pytest.mark.asyncio
+    async def test_refused_contact_is_dropped_after_the_attempt_limit(self):
+        contacts = {'a': self._contact('variable', 'KEY_A', 30)}
+        mgr = self._manager(contacts)
+        self._refusing_device(mgr)
+
+        with patch('asyncio.sleep', new=AsyncMock()):
+            for _ in range(RepeaterManager.MAX_STALE_REMOVAL_ATTEMPTS):
+                stale = await mgr._get_stale_contacts()
+                assert stale, "should still be attempted before the limit"
+                await mgr._remove_stale_contacts(stale)
+
+            # The storm stops: the contact is no longer selected at all.
+            assert await mgr._get_stale_contacts() == []
+
+    @pytest.mark.asyncio
+    async def test_gives_up_message_is_logged_once(self):
+        contacts = {'a': self._contact('variable', 'KEY_A', 30)}
+        mgr = self._manager(contacts)
+        self._refusing_device(mgr)
+
+        with patch('asyncio.sleep', new=AsyncMock()):
+            for _ in range(RepeaterManager.MAX_STALE_REMOVAL_ATTEMPTS):
+                stale = await mgr._get_stale_contacts()
+                if stale:
+                    await mgr._remove_stale_contacts(stale)
+
+        warnings = [str(c) for c in mgr.logger.warning.call_args_list]
+        assert sum('Giving up' in w for w in warnings) == 1
+
+    @pytest.mark.asyncio
+    async def test_successful_removal_clears_the_failure_count(self):
+        contacts = {'a': self._contact('flaky', 'KEY_A', 30)}
+        mgr = self._manager(contacts)
+        mgr.bot.meshcore.commands.remove_contact = AsyncMock(
+            side_effect=[self._result(False), self._result(True)]
+        )
+
+        with patch('asyncio.sleep', new=AsyncMock()):
+            await mgr._remove_stale_contacts(await mgr._get_stale_contacts())
+            assert mgr._stale_removal_failures.get('KEY_A') == 1
+            removed = await mgr._remove_stale_contacts(await mgr._get_stale_contacts())
+
+        assert removed == 1
+        assert 'KEY_A' not in mgr._stale_removal_failures
+
+    @pytest.mark.asyncio
+    async def test_other_contacts_are_unaffected_by_one_bad_apple(self):
+        contacts = {
+            'a': self._contact('stubborn', 'KEY_A', 40),
+            'b': self._contact('removable', 'KEY_B', 30),
+        }
+        mgr = self._manager(contacts)
+
+        async def remove(public_key):
+            return self._result(public_key != 'KEY_A')
+
+        mgr.bot.meshcore.commands.remove_contact = AsyncMock(side_effect=remove)
+
+        with patch('asyncio.sleep', new=AsyncMock()):
+            removed = await mgr._remove_stale_contacts(await mgr._get_stale_contacts())
+
+        assert removed == 1
+        assert mgr._stale_removal_failures == {'KEY_A': 1}
+
+
+class TestStaleContactTimestampSanity:
+    """Unset timestamps parse as 1970 and sorted to the top, spending the whole
+    removal budget on contacts whose real staleness is unknown."""
+
+    @staticmethod
+    def _manager(contacts):
+        return TestStaleContactRemovalStorm._manager(contacts)
+
+    @pytest.mark.asyncio
+    async def test_zero_timestamp_is_ignored(self):
+        mgr = self._manager({'a': {'name': 'never-heard', 'public_key': 'K', 'last_seen': 0}})
+        assert await mgr._get_stale_contacts() == []
+
+    @pytest.mark.asyncio
+    async def test_future_timestamp_is_ignored(self):
+        future = (datetime.now() + timedelta(days=5)).timestamp()
+        mgr = self._manager({'a': {'name': 'clock-skew', 'public_key': 'K', 'last_seen': future}})
+        assert await mgr._get_stale_contacts() == []
+
+    @pytest.mark.asyncio
+    async def test_genuinely_old_contact_is_still_selected(self):
+        """722 days ago is a real observation, not a bad timestamp."""
+        mgr = self._manager({'a': TestStaleContactRemovalStorm._contact('old', 'K', 722)})
+        stale = await mgr._get_stale_contacts()
+        assert len(stale) == 1
+        assert stale[0]['days_stale'] == 722
+
+    @pytest.mark.asyncio
+    async def test_junk_timestamps_no_longer_crowd_out_real_candidates(self):
+        contacts = {f'junk{i}': {'name': f'j{i}', 'public_key': f'J{i}', 'last_seen': 0}
+                    for i in range(12)}
+        contacts['real'] = TestStaleContactRemovalStorm._contact('real', 'REAL', 30)
+        mgr = self._manager(contacts)
+
+        stale = await mgr._get_stale_contacts()
+
+        # Without the guard the twelve 1970 entries sort first and fill max_remove=10.
+        assert [c['public_key'] for c in stale] == ['REAL']