diff --git a/aprsd/cli_helper.py b/aprsd/cli_helper.py index d49e398..5b96658 100644 --- a/aprsd/cli_helper.py +++ b/aprsd/cli_helper.py @@ -34,6 +34,12 @@ log_options = [ is_flag=True, help='Show log level in log format (disabled by default for listen).', ), + click.option( + '--show-location', + default=False, + is_flag=True, + help='Show location in log format (disabled by default for listen).', + ), ] common_options = [ @@ -124,9 +130,9 @@ def add_options(options): def setup_logging_with_options( show_thread: bool, show_level: bool, + show_location: bool, loglevel: str, quiet: bool, - include_location: bool = True, ) -> None: """Setup logging with custom format based on show_thread and show_level options. @@ -153,7 +159,7 @@ def setup_logging_with_options( # Message is always included parts.append(conf_log.DEFAULT_LOG_FORMAT_MESSAGE) - if include_location: + if show_location: parts.append(conf_log.DEFAULT_LOG_FORMAT_LOCATION) # Set the custom log format @@ -172,6 +178,7 @@ def process_standard_options(f: F) -> F: # Extract show_thread and show_level show_thread = kwargs.get('show_thread', False) show_level = kwargs.get('show_level', False) + show_location = kwargs.get('show_location', False) if kwargs['config_file']: default_config_files = [kwargs['config_file']] @@ -196,9 +203,9 @@ def process_standard_options(f: F) -> F: setup_logging_with_options( show_thread=show_thread, show_level=show_level, + show_location=show_location, loglevel=ctx.obj['loglevel'], quiet=ctx.obj['quiet'], - include_location=True, ) if CONF.trace_enabled: trace.setup_tracing(['method', 'api']) @@ -213,6 +220,7 @@ def process_standard_options(f: F) -> F: del kwargs['quiet'] del kwargs['show_thread'] del kwargs['show_level'] + del kwargs['show_location'] # Enable profiling if requested if profile_output is not None: @@ -247,6 +255,7 @@ def process_standard_options_no_config(f: F) -> F: # Extract show_thread and show_level show_thread = kwargs.get('show_thread', False) show_level = kwargs.get('show_level', False) + show_location = kwargs.get('show_location', False) # Initialize CONF without config file for log format access try: @@ -268,9 +277,9 @@ def process_standard_options_no_config(f: F) -> F: setup_logging_with_options( show_thread=show_thread, show_level=show_level, + show_location=show_location, loglevel=ctx.obj['loglevel'], quiet=ctx.obj['quiet'], - include_location=True, ) profile_output = kwargs.pop('profile_output', None) @@ -279,6 +288,7 @@ def process_standard_options_no_config(f: F) -> F: del kwargs['quiet'] del kwargs['show_thread'] del kwargs['show_level'] + del kwargs['show_location'] # Enable profiling if requested if profile_output is not None: diff --git a/aprsd/packets/watch_list.py b/aprsd/packets/watch_list.py index 4344e9c..d9a82d9 100644 --- a/aprsd/packets/watch_list.py +++ b/aprsd/packets/watch_list.py @@ -5,11 +5,10 @@ from oslo_config import cfg from aprsd import utils from aprsd.packets import core -from aprsd.utils import objectstore - +from aprsd.utils import objectstore, trace CONF = cfg.CONF -LOG = logging.getLogger("APRSD") +LOG = logging.getLogger('APRSD') class WatchList(objectstore.ObjectStoreMixin): @@ -17,40 +16,47 @@ class WatchList(objectstore.ObjectStoreMixin): _instance = None data = {} + initialized = False def __new__(cls, *args, **kwargs): if cls._instance is None: cls._instance = super().__new__(cls) return cls._instance + @trace.no_trace def __init__(self): super().__init__() - self._update_from_conf() + if not self.initialized: + self._update_from_conf() + self.initialized = True def _update_from_conf(self, config=None): with self.lock: if CONF.watch_list.enabled and CONF.watch_list.callsigns: for callsign in CONF.watch_list.callsigns: - call = callsign.replace("*", "") + call = callsign.replace('*', '') # FIXME(waboring) - we should fetch the last time we saw # a beacon from a callsign or some other mechanism to find # last time a message was seen by aprs-is. For now this # is all we can do. if call not in self.data: self.data[call] = { - "last": None, - "packet": None, + 'last': None, + 'packet': None, + 'was_old_before_update': False, } + @trace.no_trace def stats(self, serializable=False) -> dict: stats = {} + return self.data with self.lock: for callsign in self.data: stats[callsign] = { - "last": self.data[callsign]["last"], - "packet": self.data[callsign]["packet"], - "age": self.age(callsign), - "old": self.is_old(callsign), + 'last': self.data[callsign]['last'], + 'packet': self.data[callsign]['packet'], + 'age': self.age(callsign), + 'old': self.is_old(callsign), } return stats @@ -67,8 +73,25 @@ class WatchList(objectstore.ObjectStoreMixin): if self.callsign_in_watchlist(callsign): with self.lock: - self.data[callsign]["last"] = datetime.datetime.now() - self.data[callsign]["packet"] = packet + # Check if callsign was old BEFORE updating the timestamp + # This allows plugins to check if it was old before this update + # We check directly here to avoid nested locking + was_old = False + last_seen_time = self.data[callsign].get('last') + if last_seen_time: + age_delta = datetime.datetime.now() - last_seen_time + max_delta = self.max_delta() + if age_delta > max_delta: + was_old = True + + # Now update the timestamp and packet + if last_seen_time: + self.data[callsign]['age'] = str( + datetime.datetime.now() - last_seen_time + ) + self.data[callsign]['last'] = datetime.datetime.now() + self.data[callsign]['packet'] = packet + self.data[callsign]['was_old_before_update'] = was_old def tx(self, packet: type[core.Packet]) -> None: """We don't care about TX packets.""" @@ -76,7 +99,7 @@ class WatchList(objectstore.ObjectStoreMixin): def last_seen(self, callsign): with self.lock: if self.callsign_in_watchlist(callsign): - return self.data[callsign]["last"] + return self.data[callsign]['last'] def age(self, callsign): now = datetime.datetime.now() @@ -89,9 +112,32 @@ class WatchList(objectstore.ObjectStoreMixin): def max_delta(self, seconds=None): if not seconds: seconds = CONF.watch_list.alert_time_seconds - max_timeout = {"seconds": seconds} + max_timeout = {'seconds': seconds} return datetime.timedelta(**max_timeout) + def was_old_before_last_update(self, callsign): + """Check if the callsign was old before the last rx() update. + + This is useful for plugins that need to know if a callsign was + old before the current packet updated the timestamp. This allows + plugins to determine if they should notify about a callsign that + was previously old but is now being seen again. + """ + with self.lock: + if not self.callsign_in_watchlist(callsign): + return False + return self.data[callsign].get('was_old_before_update', False) + + def mark_as_new(self, callsign): + """Mark a callsign as new, resetting the was_old_before_update flag. + + This is useful after sending a notification to prevent duplicate + notifications until the callsign becomes old again. + """ + with self.lock: + if self.callsign_in_watchlist(callsign): + self.data[callsign]['was_old_before_update'] = False + def is_old(self, callsign, seconds=None): """Watch list callsign last seen is old compared to now? diff --git a/aprsd/plugins/notify.py b/aprsd/plugins/notify.py index 1a47f9f..30fb9cd 100644 --- a/aprsd/plugins/notify.py +++ b/aprsd/plugins/notify.py @@ -5,7 +5,7 @@ from oslo_config import cfg from aprsd import packets, plugin CONF = cfg.CONF -LOG = logging.getLogger("APRSD") +LOG = logging.getLogger('APRSD') class NotifySeenPlugin(plugin.APRSDWatchListPluginBase): @@ -17,10 +17,10 @@ class NotifySeenPlugin(plugin.APRSDWatchListPluginBase): seen was older than the configured age limit. """ - short_description = "Notify me when a CALLSIGN is recently seen on APRS-IS" + short_description = 'Notify me when a CALLSIGN is recently seen on APRS-IS' def process(self, packet: packets.MessagePacket): - LOG.info("NotifySeenPlugin") + LOG.info('NotifySeenPlugin') notify_callsign = CONF.watch_list.alert_callsign fromcall = packet.from_call @@ -29,14 +29,19 @@ class NotifySeenPlugin(plugin.APRSDWatchListPluginBase): age = wl.age(fromcall) if fromcall != notify_callsign: - if wl.is_old(fromcall): + # Check if the callsign was old BEFORE WatchList.rx() updated the timestamp + # This ensures we can detect when a previously old callsign is seen again + if wl.was_old_before_last_update(fromcall): LOG.info( - "NOTIFY {} last seen {} max age={}".format( + 'NOTIFY {} last seen {} max age={}'.format( fromcall, age, wl.max_delta(), ), ) + # Mark the callsign as new to prevent duplicate notifications + # until it becomes old again + wl.mark_as_new(fromcall) packet_type = packet.__class__.__name__ # we shouldn't notify the alert user that they are online. pkt = packets.MessagePacket( @@ -49,10 +54,10 @@ class NotifySeenPlugin(plugin.APRSDWatchListPluginBase): return pkt else: LOG.debug( - "Not old enough to notify on callsign " + 'Not old enough to notify on callsign ' f"'{fromcall}' : {age} < {wl.max_delta()}", ) return packets.NULL_MESSAGE else: - LOG.debug("fromcall and notify_callsign are the same, ignoring") + LOG.debug('fromcall and notify_callsign are the same, ignoring') return packets.NULL_MESSAGE diff --git a/tests/plugins/test_notify.py b/tests/plugins/test_notify.py index 7cdd31d..d15fc38 100644 --- a/tests/plugins/test_notify.py +++ b/tests/plugins/test_notify.py @@ -140,9 +140,7 @@ class TestNotifySeenPlugin(TestWatchListPlugin): expected = packets.NULL_MESSAGE self.assertEqual(expected, actual) - @mock.patch('aprsd.packets.WatchList.is_old') - def test_callsign_in_watchlist_not_old(self, mock_is_old): - mock_is_old.return_value = False + def test_callsign_in_watchlist_not_old(self): self.config_and_init( watchlist_enabled=True, watchlist_callsigns=['WB4BOR'], @@ -154,46 +152,77 @@ class TestNotifySeenPlugin(TestWatchListPlugin): message='ping', msg_number=1, ) + # Simulate WatchList.rx() being called first (with recent timestamp) + # This will set was_old_before_update to False since it's not old + packets.WatchList().rx(packet) actual = plugin.filter(packet) expected = packets.NULL_MESSAGE self.assertEqual(expected, actual) - @mock.patch('aprsd.packets.WatchList.is_old') - def test_callsign_in_watchlist_old_same_alert_callsign(self, mock_is_old): - mock_is_old.return_value = True + def test_callsign_in_watchlist_old_same_alert_callsign(self): + import datetime + self.config_and_init( watchlist_enabled=True, watchlist_alert_callsign='WB4BOR', watchlist_callsigns=['WB4BOR'], + watchlist_alert_time_seconds=60, ) plugin = notify_plugin.NotifySeenPlugin() + # Set up WatchList with an old timestamp + wl = packets.WatchList() + old_time = datetime.datetime.now() - datetime.timedelta(seconds=120) + with wl.lock: + wl.data['WB4BOR'] = { + 'last': old_time, + 'packet': None, + 'was_old_before_update': False, + } + packet = fake.fake_packet( fromcall='WB4BOR', message='ping', msg_number=1, ) + # Simulate WatchList.rx() being called first + # This will set was_old_before_update to True since it was old + wl.rx(packet) actual = plugin.filter(packet) expected = packets.NULL_MESSAGE self.assertEqual(expected, actual) - @mock.patch('aprsd.packets.WatchList.is_old') - def test_callsign_in_watchlist_old_send_alert(self, mock_is_old): - mock_is_old.return_value = True + def test_callsign_in_watchlist_old_send_alert(self): + import datetime + notify_callsign = fake.FAKE_TO_CALLSIGN fromcall = 'WB4BOR' self.config_and_init( watchlist_enabled=True, watchlist_alert_callsign=notify_callsign, watchlist_callsigns=['WB4BOR'], + watchlist_alert_time_seconds=60, ) plugin = notify_plugin.NotifySeenPlugin() + # Set up WatchList with an old timestamp + wl = packets.WatchList() + old_time = datetime.datetime.now() - datetime.timedelta(seconds=120) + with wl.lock: + wl.data[fromcall] = { + 'last': old_time, + 'packet': None, + 'was_old_before_update': False, + } + packet = fake.fake_packet( fromcall=fromcall, message='ping', msg_number=1, ) + # Simulate WatchList.rx() being called first + # This will set was_old_before_update to True since it was old + wl.rx(packet) packet_type = packet.__class__.__name__ actual = plugin.filter(packet) msg = f"{fromcall} was just seen by type:'{packet_type}'" @@ -202,3 +231,6 @@ class TestNotifySeenPlugin(TestWatchListPlugin): self.assertEqual(fake.FAKE_FROM_CALLSIGN, actual.from_call) self.assertEqual(notify_callsign, actual.to_call) self.assertEqual(msg, actual.message_text) + # Verify that mark_as_new was called to prevent duplicate notifications + # by checking that was_old_before_update is now False + self.assertFalse(wl.was_old_before_last_update(fromcall))